Am 18.12.2013 um 00:17 schrieb Lukas Krejci <lkrejci(a)redhat.com>:
I'm not sure I can agree with that..
Customer: We have this issue, our server doesn't work.
Support: What does the log say?
Customer: [ERROR] - Failed to collect important stuff because of: null (this
is just to exacerbate the change in logging I started this thread with).
Support: Oh, could you please go back to your server and replicate the issue
with debug logging on? We need to see the stacktraces.
Customer: You mean reconfiguring a production server? Why didn't include
enough info in the message so that you can diagnose the error?
Or a slightly different conversation:
... start off the same as above ...
Support: We can't diagnose the issue unless we send you a diagnostic patch.
Customer: What kind of muppets are you, seriously?
What you say is correct, but not sufficient IMHO - the information the log
message provides should be digestable by non-developers. But at the same time,
it should also provide the developer with enough info to diagnose the
underlying issue. And the more severe the log message is, the more it applies.
So I just got this trace below ~100 times in the logs (tests after code modification):
That stack trace(s) shows me a 100 times where such a rejected execution has happened, but
not the
cause -- that cause is in the 1st line "Failed to stop.. ".
It may be interesting to see that this execution failed in
at
org.rhq.core.pc.inventory.ResourceContainer$ResourceComponentInvocationHandler.invokeInNewThreadWithLock(ResourceContainer.java:639)
at
org.rhq.core.pc.inventory.ResourceContainer$ResourceComponentInvocationHandler.invoke(ResourceContainer.java:629)
But that is all -- every other line in the log is just confusing to everyone.
What I really would like to see in the log is the real cause (why was the component not
stopped? E.g. because
of an exception or because it was never started.). But this one is just plain useless and
distracts from the
real information.
10:25:57,671 WARN [main] (rhq.core.pc.inventory.InventoryManager) - Plugin Error: Failed
to stop component for [Resource[id=3, uuid=06df1776-9e99-4bd2-9403-14f6f726d0f8,
type={availPlugin}AvailParentServer1, key=AvailParentServer1_1, name=AvailParentServer1_1,
parent=testplatform, version=1]].
java.util.concurrent.RejectedExecutionException: Task
java.util.concurrent.FutureTask@632117dc rejected from
java.util.concurrent.ThreadPoolExecutor@3ae948c3[Terminated, pool size = 0, active threads
= 0, queued tasks = 0, completed tasks = 2]
at
java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048)
at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821)
at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372)
at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:132)
at
org.rhq.core.pc.inventory.ResourceContainer$ResourceComponentInvocationHandler.invokeInNewThreadWithLock(ResourceContainer.java:639)
at
org.rhq.core.pc.inventory.ResourceContainer$ResourceComponentInvocationHandler.invoke(ResourceContainer.java:629)
at com.sun.proxy.$Proxy23.stop(Unknown Source)
at
org.rhq.core.pc.inventory.InventoryManager.deactivateResource(InventoryManager.java:2207)
at
org.rhq.core.pc.inventory.InventoryManager.deactivateResource(InventoryManager.java:2201)
at org.rhq.core.pc.inventory.InventoryManager.persistToDisk(InventoryManager.java:2229)
at org.rhq.core.pc.inventory.InventoryManager.shutdown(InventoryManager.java:295)
at org.rhq.core.pc.PluginContainer.shutdown(PluginContainer.java:401)
at
org.rhq.test.arquillian.impl.RhqAgentPluginContainer.stopPc(RhqAgentPluginContainer.java:384)
at
org.rhq.test.arquillian.impl.RhqAgentPluginContainer.stop(RhqAgentPluginContainer.java:203)
at org.jboss.arquillian.container.impl.ContainerImpl.stop(ContainerImpl.java:217)
at
org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController$9.perform(ContainerLifecycleController.java:178)
at
org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController$9.perform(ContainerLifecycleController.java:172)
at
org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController.forContainer(ContainerLifecycleController.java:255)
at
org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController.stopContainer(ContainerLifecycleController.java:171)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
at
org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99)
at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81)
at
org.jboss.arquillian.container.impl.client.ContainerDeploymentContextHandler.createContainerContext(ContainerDeploymentContextHandler.java:57)
at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88)
at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135)
at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:115)
at org.jboss.arquillian.core.impl.EventImpl.fire(EventImpl.java:67)
at
org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController$4.perform(ContainerLifecycleController.java:107)
at
org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController$4.perform(ContainerLifecycleController.java:100)
at
org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController.forEachSuiteContainer(ContainerLifecycleController.java:221)
at
org.jboss.arquillian.container.impl.client.container.ContainerLifecycleController.stopSuiteContainers(ContainerLifecycleController.java:99)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
at
org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99)
at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81)
at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135)
at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:115)
at org.jboss.arquillian.core.impl.EventImpl.fire(EventImpl.java:67)
at
org.jboss.arquillian.container.test.impl.client.ContainerEventController.execute(ContainerEventController.java:91)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
at
org.jboss.arquillian.core.impl.EventContextImpl.invokeObservers(EventContextImpl.java:99)
at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:81)
at
org.jboss.arquillian.test.impl.TestContextHandler.createSuiteContext(TestContextHandler.java:60)
at sun.reflect.GeneratedMethodAccessor30.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.jboss.arquillian.core.impl.ObserverImpl.invoke(ObserverImpl.java:94)
at org.jboss.arquillian.core.impl.EventContextImpl.proceed(EventContextImpl.java:88)
at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:135)
at org.jboss.arquillian.core.impl.ManagerImpl.fire(ManagerImpl.java:115)
at
org.jboss.arquillian.test.impl.EventTestRunnerAdaptor.afterSuite(EventTestRunnerAdaptor.java:73)
at org.jboss.arquillian.testng.Arquillian.arquillianAfterSuite(Arquillian.java:90)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:80)
at org.testng.internal.Invoker.invokeConfigurationMethod(Invoker.java:551)
at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:213)
at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:138)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:308)
at org.testng.SuiteRunner.run(SuiteRunner.java:240)
at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53)
at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:87)
at org.testng.TestNG.runSuitesSequentially(TestNG.java:1188)
at org.testng.TestNG.runSuitesLocally(TestNG.java:1113)
at org.testng.TestNG.run(TestNG.java:1025)
at org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:77)
at
org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.executeMulti(TestNGDirectoryTestSuite.java:159)
at
org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.execute(TestNGDirectoryTestSuite.java:99)
at org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
at
org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
at
org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
at
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)