Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Suppress some irrelevant stack traces #274

Merged
merged 2 commits into from
Jun 7, 2018

Conversation

jglick
Copy link
Member

@jglick jglick commented May 31, 2018

Noticed a bunch of stack traces during io.jenkins.plugins.artifact_manager_jclouds.NetworkTest#unrecoverableExceptionArchiving (jenkinsci/artifact-manager-s3-plugin#41) for example, but really these have been irritating me for a long time (years?):

WARNING	hudson.remoting.Request$2#run: Failed to send back a reply to the request hudson.remoting.Request$2@…
Command Close created at
	at hudson.remoting.Command.<init>(Command.java:65)
	at hudson.remoting.Channel$CloseCommand.<init>(Channel.java:1265)
	at hudson.remoting.Channel$CloseCommand.<init>(Channel.java:1263)
	at hudson.remoting.Channel.close(Channel.java:1436)
	at hudson.remoting.Channel.close(Channel.java:1403)
	at hudson.remoting.Channel$CloseCommand.execute(Channel.java:1270)
Caused: hudson.remoting.Channel$OrderlyShutdown
	at hudson.remoting.Channel$CloseCommand.execute(Channel.java:1271)
	at hudson.remoting.Channel$1.handle(Channel.java:565)
	at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:87)
Caused: hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@…:remote": channel is already closed
	at hudson.remoting.Channel.send(Channel.java:717)
	at hudson.remoting.Request$2.run(Request.java:382)
	at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
	at org.jenkinsci.remoting.CallableDecorator.call(CallableDecorator.java:19)
	at hudson.remoting.CallableDecoratorList$1.call(CallableDecoratorList.java:21)
	at jenkins.util.ContextResettingExecutorService$2.call(ContextResettingExecutorService.java:46)
	at jenkins.security.ImpersonatingExecutorService$2.call(ImpersonatingExecutorService.java:71)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
INFO	jenkins.model.Jenkins#cleanUp: Stopping Jenkins
WARNING	h.u.ExceptionCatchingThreadFactory#uncaughtException: Thread Computer.threadPoolForRemoting [#9] terminated unexpectedly
java.nio.channels.ClosedSelectorException
	at sun.nio.ch.SelectorImpl.keys(SelectorImpl.java:68)
	at org.jenkinsci.remoting.protocol.IOHub.getThreadNameBase(IOHub.java:426)
	at org.jenkinsci.remoting.protocol.IOHub.access$200(IOHub.java:69)
	at org.jenkinsci.remoting.protocol.IOHub$IOHubSelectorWatcher.run(IOHub.java:536)
	at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
	at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:59)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

Should now be reduced to:

INFO	hudson.remoting.Request$2#run: Failed to send back a reply to the request hudson.remoting.Request$2@…: hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@…:remote": channel is already closed
INFO	jenkins.model.Jenkins#cleanUp: Stopping Jenkins

See also JENKINS-31652, a different case.

@jglick jglick requested a review from oleg-nenashev May 31, 2018 16:23
@@ -383,7 +383,11 @@ public void run() {
} catch (IOException e) {
// communication error.
// this means the caller will block forever
logger.log(Level.WARNING, "Failed to send back a reply to the request " + this, e);
if (e instanceof ChannelClosedException) {
logger.log(Level.INFO, "Failed to send back a reply to the request {0}: {1}", new Object[] {this, e});
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would retain the original behavior on the FINE level so that we can locate what caused Closed in some cases.
Or maybe you could retrieve the cause message via new API method or getMessage() update in ChannelStateException

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

retrieve the cause message

Should not be necessary. Throwable.toString by default prints the toString of a cause.

Copy link
Member

@oleg-nenashev oleg-nenashev left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Information about Close Cause should be printed on the FINE level at least.

int keySize;
try {
keySize = selector.keys().size();
} catch (ClosedSelectorException x) {
Copy link
Member

@oleg-nenashev oleg-nenashev Jun 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Separate bugfix IIUC

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

See the PR description. There were two exceptions. I fixed both.

@oleg-nenashev oleg-nenashev merged commit 304ef82 into jenkinsci:master Jun 7, 2018
@jglick jglick deleted the stack-traces branch June 7, 2018 19:16
saptarshide007 pushed a commit to saptarshide007/remoting that referenced this pull request Mar 22, 2021
After updating from java 8 to java 11 getting the below error:-
Exception in thread "main" java.lang.IllegalArgumentException: object is not an instance of declaring class
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at hudson.remoting.Launcher.addClasspath(Launcher.java:129)

On analysing the remoting source code found that the hudson.remoting.Launcher.addClasspath invokes URLClassLoader and passes the instance using ClassLoader.getSystemClassLoader().
However in java 11, this seems like an illegal operation as ClassLoader.getSystemClassLoader() does not get the instance of  URLClassLoader due to which we are getting the error "object is not an instance of declaring class".

To fix this issue what updated the addClasspath method to invoke the URLClassLoader using a new instance of the class.

Reference:-
GitIssues:-jenkinsci#274,jenkinsci#275
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants