Aled Sage created BROOKLYN-227:
----------------------------------
Summary: Exceptions not being logged
Key: BROOKLYN-227
URL: https://issues.apache.org/jira/browse/BROOKLYN-227
Project: Brooklyn
Issue Type: Bug
Reporter: Aled Sage
In 0.9.0-SNAPSHOT, a couple of times now I've hit exceptions that are not
logged anywhere within brooklyn debug log. A good example is:
{noformat}
2016-02-20 22:09:00,037 DEBUG b.l.docker.DockerResolver
[brooklyn-execmanager-dO9Ptbsx-0]: Resolving location
'docker:j1M7T5XG:(name="my-docker-cloud-vagrant")' with flags
provisioner=FixedListMachineProvisioningLocation{id=DtPfBrpb,
name=FixedListMachineProvisioningLocation:DtPf},strat
egies=[DockerAwarePlacementStrategy(MaxContainersPlacementStrategy@j8yVexHt),
DockerAwarePlacementStrategy(BreadthFirstPlacementStrategy@ce2SXY0W)],spec.named.name=my-docker-cloud-vagrant,spec.original=my-docker-cloud-vagrant
2016-02-20 22:09:00,048 WARN o.a.b.c.m.r.RebindExceptionHandlerImpl
[brooklyn-execmanager-dO9Ptbsx-0]: Rebind: continuing after problem rebinding
entity j1M7T5XG (DockerInfrastructureImpl{id=j1M7T5XG})
java.lang.IllegalStateException: Cannot instantiate location
'LocationDefinition{id='gzuSFMac', name='my-docker-cloud-vagrant',
spec='docker:j1M7T5XG:(name="my-docker-cloud-vagrant")',
config={provisioner=FixedListMachineProvisioningLocation{id=DtPfBrpb,
name=FixedListMachineProvisioningLocation:DtPf},
strategies=[DockerAwarePlacementStrategy(MaxContainersPlacementStrategy@j8yVexHt),
DockerAwarePlacementStrategy(BreadthFirstPlacementStrategy@ce2SXY0W)]}}'
pointing at docker:j1M7T5XG:(name="my-docker-cloud-vagrant"):
java.lang.NullPointerException
at
org.apache.brooklyn.core.location.BasicLocationRegistry.resolve(BasicLocationRegistry.java:490)
~[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at
org.apache.brooklyn.core.location.BasicLocationRegistry.resolve(BasicLocationRegistry.java:459)
~[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at
brooklyn.entity.container.DockerUtils$ReloadDockerLocation.reloaded(DockerUtils.java:392)
~[brooklyn-clocker-docker-1.1.0-20160125.1743-p1.jar:1.1.0-20160125.1743-p1]
at
brooklyn.entity.container.docker.DockerInfrastructureImpl.rebind(DockerInfrastructureImpl.java:346)
~[brooklyn-clocker-docker-1.1.0-20160125.1743-p1.jar:1.1.0-20160125.1743-p1]
at
org.apache.brooklyn.core.mgmt.rebind.AbstractBrooklynObjectRebindSupport.reconstruct(AbstractBrooklynObjectRebindSupport.java:69)
~[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at
org.apache.brooklyn.core.mgmt.rebind.RebindIteration.reconstructEverything(RebindIteration.java:623)
[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at
org.apache.brooklyn.core.mgmt.rebind.RebindIteration.doRun(RebindIteration.java:242)
[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at
org.apache.brooklyn.core.mgmt.rebind.InitialFullRebindIteration.doRun(InitialFullRebindIteration.java:69)
[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at
org.apache.brooklyn.core.mgmt.rebind.RebindIteration.run(RebindIteration.java:265)
[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at
org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl.rebindImpl(RebindManagerImpl.java:552)
[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at
org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl$3.call(RebindManagerImpl.java:502)
[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at
org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl$3.call(RebindManagerImpl.java:500)
[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at
org.apache.brooklyn.util.core.task.BasicExecutionManager$SubmissionCallable.call(BasicExecutionManager.java:499)
[brooklyn-core-0.9.0-20160125.1743-p1.jar:0.9.0-20160125.1743-p1]
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[na:1.7.0_71]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[na:1.7.0_71]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[na:1.7.0_71]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_71]
{noformat}
See the code change that was made in
https://github.com/apache/brooklyn-server/commit/4cb25a42938dcc4383bd831d00841d91b400ac99
(where I've just added a comment).
In that particular situation, we should change it to include the cause in the
{{IllegalStateException}} that is thrown. Or alternatively we could log the
exception, and then throw the new simplified exception (but I'm not convinced
of the point in that).
We need to be extremely cautious about using {{Exceptions.collapseText}}. There
was another situation recently that I need to dig out when I have a few
minutes, where another NullPointerException wasn't being logged anywhere,
except for that one phrase (I think it was when calling an effector from the
REST api).
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
