You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@brooklyn.apache.org by "Alex Heneveld (JIRA)" <ji...@apache.org> on 2016/02/25 02:36:18 UTC

[jira] [Issue Comment Deleted] (BROOKLYN-206) Unreliable test: AbstractControllerTest.testUpdateCalledWhenChildHostnameAndPortChanges

     [ https://issues.apache.org/jira/browse/BROOKLYN-206?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Alex Heneveld updated BROOKLYN-206:
-----------------------------------
    Comment: was deleted

(was: got debug log from jenkins workspace on failure at builds.apache.org

{code}
2016-02-24 23:34:52,276 INFO  o.a.b.t.s.LoggingVerboseReporter [main]: TESTNG INVOKING: "Surefire test" - org.apache.brooklyn.core.mgmt.rebind.RebindCatalogItemTest.testAddAndRebindAndDeleteLocation()
2016-02-24 23:34:52,278 DEBUG o.a.b.c.c.i.CatalogInitialization [main]: Populating catalog unofficially (org.apache.brooklyn.core.catalog.internal.BasicBrooklynCatalog@6af14528)
2016-02-24 23:34:52,278 WARN  o.a.b.c.c.i.CatalogInitialization [main]: Legacy CatalogLoadMode LOAD_BROOKLYN_CATALOG_URL set: applying, but this should be changed to use new CLI --catalogXxx commands
2016-02-24 23:34:52,279 DEBUG o.a.b.c.c.i.CatalogInitialization [main]: Loading initial catalog from classpath://brooklyn/entity/rebind/rebind-catalog-item-test-catalog.xml
2016-02-24 23:34:52,279 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Forcing catalog load on access of catalog items
2016-02-24 23:34:52,279 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Loading catalog for LocalManagementContext[E5deSfFR-xoVyTRQg]
2016-02-24 23:34:52,279 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Loading catalog Loaded:CatalogDto{name=empty catalog, contentsDescription=empty catalog, expected to be reset later}(not yet loaded) into null
2016-02-24 23:34:52,279 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Building cache for Loaded:CatalogDto{name=empty catalog, contentsDescription=empty catalog, expected to be reset later}(not yet loaded)
2016-02-24 23:34:52,279 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Loaded catalog for LocalManagementContext[E5deSfFR-xoVyTRQg]: Loaded:CatalogDto{name=empty catalog, contentsDescription=empty catalog, expected to be reset later}(size 0); search classpath is AggregateClassLoader[sun.misc.Launcher$AppClassLoader@46c6c084, AggregateClassLoader[]]
2016-02-24 23:34:52,279 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Resetting org.apache.brooklyn.core.catalog.internal.BasicBrooklynCatalog@6af14528 catalog to CatalogDto{contentsDescription=explicit-catalog-reset}
2016-02-24 23:34:52,280 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Loading catalog Loaded:CatalogDto{contentsDescription=explicit-catalog-reset}(not yet loaded) into null
2016-02-24 23:34:52,280 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Building cache for Loaded:CatalogDto{contentsDescription=explicit-catalog-reset}(not yet loaded)
2016-02-24 23:34:52,280 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Reloaded catalog for org.apache.brooklyn.core.catalog.internal.BasicBrooklynCatalog@6af14528, now switching
2016-02-24 23:34:52,280 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Adding manual catalog item to LocalManagementContext[E5deSfFR-xoVyTRQg]: <?xml version="1.0" encoding="UTF-8"?>
<!--
    Licensed to the Apache Software Foundation (ASF) under one
    or more contributor license agreements.  See the NOTICE file
    distributed with this work for additional information
    regarding copyright ownership.  The ASF licenses this file
    to you under the Apache License, Version 2.0 (the
    "License"); you may not use this file except in compliance
    with the License.  You may obtain a copy of the License at

     http://www.apache.org/licenses/LICENSE-2.0

    Unless required by applicable law or agreed to in writing,
    software distributed under the License is distributed on an
    "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
    KIND, either express or implied.  See the License for the
    specific language governing permissions and limitations
    under the License.
-->
<catalog>
    <name>Rebind catalog item test</name>

    <template name="Entity name" version="9.1.3" type="com.example.ExampleApp">
        <description>An example application</description>
        <iconUrl>http://www.example.com/icon.jpg</iconUrl>
    </template>

</catalog>

2016-02-24 23:34:52,285 DEBUG o.a.b.c.c.internal.CatalogDto [main]: Retrieved catalog from: classpath://brooklyn/entity/rebind/rebind-catalog-item-test-catalog.xml
2016-02-24 23:34:52,285 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Resetting org.apache.brooklyn.core.catalog.internal.BasicBrooklynCatalog@6af14528 catalog to CatalogDto{name=Rebind catalog item test, contentsDescription=classpath://brooklyn/entity/rebind/rebind-catalog-item-test-catalog.xml}
2016-02-24 23:34:52,285 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Loading catalog Loaded:CatalogDto{name=Rebind catalog item test, contentsDescription=classpath://brooklyn/entity/rebind/rebind-catalog-item-test-catalog.xml}(not yet loaded) into null
2016-02-24 23:34:52,285 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Building cache for Loaded:CatalogDto{name=Rebind catalog item test, contentsDescription=classpath://brooklyn/entity/rebind/rebind-catalog-item-test-catalog.xml}(not yet loaded)
2016-02-24 23:34:52,285 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Reloaded catalog for org.apache.brooklyn.core.catalog.internal.BasicBrooklynCatalog@6af14528, now switching
2016-02-24 23:34:52,285 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Adding manual catalog item to LocalManagementContext[E5deSfFR-xoVyTRQg]: CatalogLocationItemDto[sample_location:0.0.1/sample_location]
2016-02-24 23:34:52,285 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Loading catalog Loaded:CatalogDto{name=Manual Catalog Additions, contentsDescription=manual-additions}(not yet loaded) into Loaded:CatalogDto{name=Rebind catalog item test, contentsDescription=classpath://brooklyn/entity/rebind/rebind-catalog-item-test-catalog.xml}(size 1)
2016-02-24 23:34:52,285 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Building cache for Loaded:CatalogDto{name=Manual Catalog Additions, contentsDescription=manual-additions}(not yet loaded)
2016-02-24 23:34:52,286 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Creating manual additions catalog for LocalManagementContext[E5deSfFR-xoVyTRQg]: Loaded:CatalogDto{name=Manual Catalog Additions, contentsDescription=manual-additions}(size 0)
2016-02-24 23:34:52,287 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: File-based objectStore will use directory /tmp/RebindCatalogItemTest-nM9k
2016-02-24 23:34:52,287 DEBUG o.a.b.c.e.d.ReflectiveEntityDriverFactory [main]: Added driver mapping rule org.apache.brooklyn.core.entity.drivers.ReflectiveEntityDriverFactory$DriverInferenceForSshLocation@2674b975
2016-02-24 23:34:52,287 DEBUG o.a.b.c.e.d.ReflectiveEntityDriverFactory [main]: Added driver mapping rule org.apache.brooklyn.core.entity.drivers.ReflectiveEntityDriverFactory$DriverInferenceForPaasLocation@393bc40c
2016-02-24 23:34:52,287 DEBUG o.a.b.c.e.d.ReflectiveEntityDriverFactory [main]: Added driver mapping rule org.apache.brooklyn.core.entity.drivers.ReflectiveEntityDriverFactory$DriverInferenceForWinRmLocation@7b3431f0
2016-02-24 23:34:52,288 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl@1fbac2c1[mgmt=null] initialized, settings: policies=true, enrichers=true, feeds=true, catalog=true
2016-02-24 23:34:52,288 DEBUG o.a.b.c.BrooklynFeatureEnablement [main]: Init feature enablement did nothing, as no settings in brooklyn properties
2016-02-24 23:34:52,288 DEBUG o.a.b.c.m.i.LocalManagementContext [main]: Created management context LocalManagementContext[xp3AjYaC-XmCah7ox]
2016-02-24 23:34:52,288 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,291 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/entities for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,291 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/locations for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,291 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/policies for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,291 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/enrichers for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,291 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/feeds for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,291 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/catalog for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,291 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/plane for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,297 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-xoVyTRQg-1]: Checkpointed delta of memento in 19ms: updated 1 entities, 0 locations, 0 policies, 2 enrichers, 0 catalog items; removed 0 entities, 0 locations, 0 policies, 0 enrichers, 0 catalog items
2016-02-24 23:34:52,304 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-xoVyTRQg-3]: Checkpointed delta of memento in 5ms: updated 0 entities, 0 locations, 0 policies, 0 enrichers, 2 catalog items; removed 0 entities, 0 locations, 0 policies, 0 enrichers, 0 catalog items
2016-02-24 23:34:52,314 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/nodes for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,314 DEBUG o.a.b.c.m.h.ManagementPlaneSyncRecordPersisterToObjectStore [main]: ManagementPlaneMemento-persister will use store FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,314 INFO  o.a.b.c.m.r.RebindTestUtils [main]: Rebinding app, using mementoDir /tmp/RebindCatalogItemTest-nM9k; object store null
2016-02-24 23:34:52,317 DEBUG o.a.b.c.m.r.InitialFullRebindIteration [brooklyn-execmanager-XmCah7ox-0]: Rebinding (MASTER) from /tmp/RebindCatalogItemTest-nM9k...
2016-02-24 23:34:52,317 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-XmCah7ox-0]: Loaded rebind lists; took 0ms: 2 entities, 0 locations, 0 policies, 2 enrichers, 0 feeds, 2 catalog items; from /tmp/RebindCatalogItemTest-nM9k
2016-02-24 23:34:52,336 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-XmCah7ox-0]: Loaded rebind raw data; took 18ms; 2 entities, 0 locations, 0 policies, 2 enrichers, 0 feeds, 2 catalog items, from /tmp/RebindCatalogItemTest-nM9k
2016-02-24 23:34:52,375 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-XmCah7ox-0]: Loaded rebind manifests; took 38ms: 2 entities, 0 locations, 0 policies, 2 enrichers, 0 feeds, 2 catalog items; from /tmp/RebindCatalogItemTest-nM9k
2016-02-24 23:34:52,375 INFO  o.a.b.c.m.r.InitialFullRebindIteration [brooklyn-execmanager-XmCah7ox-0]: Rebinding from /tmp/RebindCatalogItemTest-nM9k for master XmCah7ox...
2016-02-24 23:34:52,375 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager instantiating catalog items: [com.example.ExampleApp:9.1.3, sample_location:0.0.1]
2016-02-24 23:34:52,375 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager instantiating catalog item BasicCatalogItemMemento{type=org.apache.brooklyn.core.catalog.internal.CatalogTemplateItemDto, id=com.example.ExampleApp:9.1.3}
2016-02-24 23:34:52,375 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager instantiating catalog item BasicCatalogItemMemento{type=org.apache.brooklyn.core.catalog.internal.CatalogLocationItemDto, id=sample_location:0.0.1}
2016-02-24 23:34:52,376 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing catalog items
2016-02-24 23:34:52,376 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing catalog item BasicCatalogItemMemento{type=org.apache.brooklyn.core.catalog.internal.CatalogTemplateItemDto, id=com.example.ExampleApp:9.1.3}
2016-02-24 23:34:52,377 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing catalog item BasicCatalogItemMemento{type=org.apache.brooklyn.core.catalog.internal.CatalogLocationItemDto, id=sample_location:0.0.1}
2016-02-24 23:34:52,378 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager clearing local catalog and loading from persisted state
2016-02-24 23:34:52,378 DEBUG o.a.b.c.c.i.CatalogInitialization [brooklyn-execmanager-XmCah7ox-0]: Populating catalog for MASTER, needsInitial=false, needsAdditional=true, explicitItems=2; from RebindIteration.rebuildCatalog
2016-02-24 23:34:52,378 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [brooklyn-execmanager-XmCah7ox-0]: Loading catalog for LocalManagementContext[xp3AjYaC-XmCah7ox]
2016-02-24 23:34:52,379 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [brooklyn-execmanager-XmCah7ox-0]: Loaded catalog for LocalManagementContext[xp3AjYaC-XmCah7ox]: Loaded:CatalogDto{name=empty catalog, contentsDescription=empty catalog, expected to be reset later}(size 0); search classpath is AggregateClassLoader[sun.misc.Launcher$AppClassLoader@46c6c084, AggregateClassLoader[]]
2016-02-24 23:34:52,379 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager instantiating locations: []
2016-02-24 23:34:52,379 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager instantiating entities: [jo59Kab9, OMtzAZpT]
2016-02-24 23:34:52,412 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-XmCah7ox-0]: Entity type interface not found for entity Application[OMtzAZpT]; instead using org.apache.brooklyn.core.test.entity.TestApplicationNoEnrichersImpl as entity type name
2016-02-24 23:34:52,540 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-XmCah7ox-0]: Loaded rebind mementos; took 99ms: 2 entities, 0 locations, 0 policies, 2 enrichers, 0 feeds, 2 catalog items, from /tmp/RebindCatalogItemTest-nM9k
2016-02-24 23:34:52,540 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager instantiating policies: []
2016-02-24 23:34:52,540 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager instantiating enrichers: [OY9xOujn, odlgb9CL]
2016-02-24 23:34:52,540 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager instantiating enricher BasicEnricherMemento{type=org.apache.brooklyn.enricher.stock.Transformer, id=OY9xOujn}
2016-02-24 23:34:52,540 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager instantiating enricher BasicEnricherMemento{type=org.apache.brooklyn.core.entity.lifecycle.ServiceStateLogic$ComputeServiceState, id=odlgb9CL}
2016-02-24 23:34:52,541 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager instantiating feeds: []
2016-02-24 23:34:52,541 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing locations
2016-02-24 23:34:52,541 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing policies
2016-02-24 23:34:52,541 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing enrichers
2016-02-24 23:34:52,541 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing enricher BasicEnricherMemento{type=org.apache.brooklyn.enricher.stock.Transformer, id=OY9xOujn}
2016-02-24 23:34:52,541 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing enricher BasicEnricherMemento{type=org.apache.brooklyn.core.entity.lifecycle.ServiceStateLogic$ComputeServiceState, id=odlgb9CL}
2016-02-24 23:34:52,541 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing feeds
2016-02-24 23:34:52,541 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing entities
2016-02-24 23:34:52,541 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing entity BasicEntityMemento{type=org.apache.brooklyn.core.test.entity.TestApplicationNoEnrichersImpl, id=OMtzAZpT}
2016-02-24 23:34:52,542 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-XmCah7ox-0]: Emitting sensor notification entity.children.added value TestEntityImpl{id=jo59Kab9} on Application[OMtzAZpT]
2016-02-24 23:34:52,542 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager reconstructing entity BasicEntityMemento{type=org.apache.brooklyn.core.test.entity.TestEntityImpl, id=jo59Kab9}
2016-02-24 23:34:52,542 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager associating adjuncts to entities
2016-02-24 23:34:52,542 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager associating adjuncts to entity BasicEntityMemento{type=org.apache.brooklyn.core.test.entity.TestApplicationNoEnrichersImpl, id=OMtzAZpT}
2016-02-24 23:34:52,542 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager associating adjuncts to entity BasicEntityMemento{type=org.apache.brooklyn.core.test.entity.TestEntityImpl, id=jo59Kab9}
2016-02-24 23:34:52,543 DEBUG o.a.b.core.sensor.AttributeMap [brooklyn-execmanager-XmCah7ox-0]: removing attribute service.state on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,543 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-XmCah7ox-0]: Emitting sensor notification entity.sensor.removed value Sensor: service.state (org.apache.brooklyn.core.entity.lifecycle.Lifecycle) on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,543 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager managing locations
2016-02-24 23:34:52,543 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager managing entities
2016-02-24 23:34:52,543 DEBUG o.a.b.c.m.i.LocalEntityManager [brooklyn-execmanager-XmCah7ox-0]: org.apache.brooklyn.core.mgmt.internal.LocalEntityManager@1e0b62e0 starting management of entity Application[OMtzAZpT]
2016-02-24 23:34:52,543 DEBUG o.a.b.c.m.i.LocalSubscriptionManager [brooklyn-execmanager-XmCah7ox-0]: Creating subscription cul1mLuM for TestEntityImpl{id=jo59Kab9} on TestEntityImpl{id=jo59Kab9} Sensor: service.notUp.indicators (java.util.Map) in SubscriptionContext(9RUDx)
2016-02-24 23:34:52,543 DEBUG o.a.b.c.m.i.LocalSubscriptionManager [brooklyn-execmanager-XmCah7ox-0]: Creating subscription Yck2SWVq for TestEntityImpl{id=jo59Kab9} on TestEntityImpl{id=jo59Kab9} Sensor: service.problems (java.util.Map) in SubscriptionContext(9RUDx)
2016-02-24 23:34:52,543 DEBUG o.a.b.c.m.i.LocalSubscriptionManager [brooklyn-execmanager-XmCah7ox-0]: Creating subscription IiqaoUVi for TestEntityImpl{id=jo59Kab9} on TestEntityImpl{id=jo59Kab9} Sensor: service.isUp (java.lang.Boolean) in SubscriptionContext(9RUDx)
2016-02-24 23:34:52,543 DEBUG o.a.b.c.m.i.LocalSubscriptionManager [brooklyn-execmanager-XmCah7ox-0]: Creating subscription UZKUMUO9 for TestEntityImpl{id=jo59Kab9} on TestEntityImpl{id=jo59Kab9} Sensor: service.state.expected (org.apache.brooklyn.core.entity.lifecycle.Lifecycle$Transition) in SubscriptionContext(9RUDx)
2016-02-24 23:34:52,543 DEBUG o.a.b.c.m.i.LocalEntityManager [brooklyn-execmanager-XmCah7ox-0]: org.apache.brooklyn.core.mgmt.internal.LocalEntityManager@1e0b62e0 starting management of entity TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,543 INFO  o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: Rebind complete (MASTER) in 226ms: 1 app, 2 entities, 0 locations, 0 policies, 2 enrichers, 0 feeds, 2 catalog items
2016-02-24 23:34:52,543 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-XmCah7ox-0]: RebindManager complete; apps: [OMtzAZpT]
2016-02-24 23:34:52,560 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: Starting persistence (org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl@1fbac2c1[mgmt=XmCah7ox]), mgmt XmCah7ox
2016-02-24 23:34:52,565 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Building cache for Loaded:CatalogDto{name=Rebind catalog item test, contentsDescription=classpath://brooklyn/entity/rebind/rebind-catalog-item-test-catalog.xml}(not yet loaded)
2016-02-24 23:34:52,565 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Deleting manual catalog item from LocalManagementContext[xp3AjYaC-XmCah7ox]: sample_location:0.0.1
2016-02-24 23:34:52,565 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Loading catalog Loaded:CatalogDto{name=Manual Catalog Additions, contentsDescription=manual-additions}(not yet loaded) into Loaded:CatalogDto{contentsDescription=explicit-catalog-reset}(size 2)
2016-02-24 23:34:52,565 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Building cache for Loaded:CatalogDto{name=Manual Catalog Additions, contentsDescription=manual-additions}(not yet loaded)
2016-02-24 23:34:52,565 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [main]: Creating manual additions catalog for LocalManagementContext[xp3AjYaC-XmCah7ox]: Loaded:CatalogDto{name=Manual Catalog Additions, contentsDescription=manual-additions}(size 0)
2016-02-24 23:34:52,567 DEBUG o.a.b.c.l.BasicLocationRegistry [main]: Location resolvers are: {id=org.apache.brooklyn.core.location.DefinedLocationByIdResolver@62580db5, named=org.apache.brooklyn.core.location.NamedLocationResolver@2ec1884, brooklyn.catalog=org.apache.brooklyn.core.location.CatalogLocationResolver@5a3d839b, portForwardManager=org.apache.brooklyn.core.location.access.PortForwardManagerLocationResolver@7c8b6365, byon=org.apache.brooklyn.location.byon.ByonLocationResolver@232abbc4, single=org.apache.brooklyn.location.byon.SingleMachineLocationResolver@4a8d52e5, host=org.apache.brooklyn.location.byon.HostLocationResolver@43d5ea0, localhost=org.apache.brooklyn.location.localhost.LocalhostLocationResolver@590f5c8c, multi=org.apache.brooklyn.location.multi.MultiLocationResolver@7f851901}
2016-02-24 23:34:52,568 DEBUG o.a.b.c.l.BasicLocationRegistry [main]: Found 0 defined locations from properties (*.named.* syntax): []
2016-02-24 23:34:52,568 DEBUG o.a.b.c.l.BasicLocationRegistry [main]: Adding a defined location for localhost
2016-02-24 23:34:52,568 DEBUG o.a.b.c.c.internal.CatalogDo [main]: Building cache for Loaded:CatalogDto{contentsDescription=explicit-catalog-reset}(not yet loaded)
2016-02-24 23:34:52,568 DEBUG o.a.b.c.l.BasicLocationRegistry [main]: org.apache.brooklyn.core.location.BasicLocationRegistry@7b2cd20e was asked to remove location with id sample_location but no such location was registered
2016-02-24 23:34:52,568 INFO  o.a.b.c.m.r.RebindCatalogItemTest [main]: Deleted item from catalog: sample_location:0.0.1
2016-02-24 23:34:52,569 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: Stopping persistence (org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl@3e9c3b13[mgmt=xoVyTRQg]), mgmt xoVyTRQg
2016-02-24 23:34:52,569 DEBUG o.a.b.util.core.task.BasicTask [main]: call from Thread[main,5,main], blocking until 'Task[scheduled[periodic-persister]]@tiznf9av' finishes, ended with error: java.util.concurrent.CancellationException
2016-02-24 23:34:52,569 DEBUG o.a.b.util.core.task.BasicTask [main]: call from Thread[main,5,main], blocking until 'Task[scheduled[periodic-persister]]@tiznf9av' finishes, ended with error: java.util.concurrent.CancellationException
2016-02-24 23:34:52,569 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: Stopped rebind (persistence), mgmt xoVyTRQg
2016-02-24 23:34:52,569 DEBUG o.a.b.c.m.i.EffectorUtils [brooklyn-execmanager-xoVyTRQg-3]: Invoking effector stop on Application[OMtzAZpT]
2016-02-24 23:34:52,570 DEBUG o.a.b.c.t.e.TestApplication [brooklyn-execmanager-xoVyTRQg-3]: Stopping application Application[OMtzAZpT]
2016-02-24 23:34:52,570 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-xoVyTRQg-3]: Emitting sensor notification entity.sensor.added value Sensor: service.notUp.indicators (java.util.Map) on Application[OMtzAZpT]
2016-02-24 23:34:52,570 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-xoVyTRQg-3]: Emitting sensor notification entity.sensor.added value Sensor: service.state.expected (org.apache.brooklyn.core.entity.lifecycle.Lifecycle$Transition) on Application[OMtzAZpT]
2016-02-24 23:34:52,570 DEBUG o.a.b.c.m.i.LocalUsageManager [brooklyn-execmanager-xoVyTRQg-3]: Storing application lifecycle usage event: application Application[OMtzAZpT] in state stopping
2016-02-24 23:34:52,570 DEBUG o.a.b.c.e.t.StartableMethods [brooklyn-execmanager-xoVyTRQg-3]: Stopping entity Application[OMtzAZpT]
2016-02-24 23:34:52,571 DEBUG o.a.b.u.c.t.BasicExecutionContext [brooklyn-execmanager-xoVyTRQg-4]: Switching task context on execution of Task[stop]@WdO9rRSV: from org.apache.brooklyn.util.core.task.BasicExecutionContext@3b92d44f([Wrapped[contextEntity:Application[OMtzAZpT]], LocalManagementContext[E5deSfFR-xoVyTRQg]]) to TestEntityImpl{id=jo59Kab9} (in Task[invoking stop[] on 1 node]@gwZuNSQF)
2016-02-24 23:34:52,584 DEBUG o.a.b.c.m.i.EffectorUtils [brooklyn-execmanager-xoVyTRQg-2]: Invoking effector stop on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,603 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-xoVyTRQg-2]: Emitting sensor notification entity.sensor.added value Sensor: service.state.expected (org.apache.brooklyn.core.entity.lifecycle.Lifecycle$Transition) on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,603 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-xoVyTRQg-2]: Emitting sensor notification entity.sensor.added value Sensor: service.state (org.apache.brooklyn.core.entity.lifecycle.Lifecycle) on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,604 DEBUG o.a.b.c.m.r.PeriodicDeltaChangeListener [brooklyn-execmanager-XmCah7ox-1]: Checkpointing delta of memento: updating entities=[Application[OMtzAZpT], TestEntityImpl{id=jo59Kab9}], locations=[], policies=[], enrichers=[Transformer{name=org.apache.brooklyn.enricher.stock.Transformer, uniqueTag=service.isUp if no service.notUp.indicators, running=true, entity=TestEntityImpl{id=jo59Kab9}, id=OY9xOujn}, ComputeServiceState{name=org.apache.brooklyn.core.entity.lifecycle.ServiceStateLogic.ComputeServiceState, uniqueTag=service.state.actual, running=true, entity=TestEntityImpl{id=jo59Kab9}, id=odlgb9CL}], catalog items=[org.apache.brooklyn.core.catalog.internal.CatalogItemDo[CatalogLocationItemDto[sample_location:0.0.1/sample_location]], org.apache.brooklyn.core.catalog.internal.CatalogItemDo[CatalogTemplateItemDto[com.example.ExampleApp:9.1.3/Entity name]]]; removing entities=[], locations=[], policies=[], enrichers=[], catalog items=[sample_location:0.0.1]
2016-02-24 23:34:52,611 DEBUG o.a.b.c.e.t.StartableMethods [brooklyn-execmanager-xoVyTRQg-3]: Stopped entity Application[OMtzAZpT]
2016-02-24 23:34:52,612 DEBUG o.a.b.c.m.i.LocalUsageManager [brooklyn-execmanager-xoVyTRQg-3]: Storing application lifecycle usage event: application Application[OMtzAZpT] in state stopped
2016-02-24 23:34:52,612 DEBUG o.a.b.c.m.i.LocalUsageManager [brooklyn-execmanager-xoVyTRQg-3]: Storing application lifecycle usage event: application Application[OMtzAZpT] in state destroyed
2016-02-24 23:34:52,612 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-xoVyTRQg-3]: Emitting sensor notification entity.children.removed value TestEntityImpl{id=jo59Kab9} on Application[OMtzAZpT]
2016-02-24 23:34:52,612 DEBUG o.a.b.c.m.i.LocalEntityManager [brooklyn-execmanager-xoVyTRQg-3]: org.apache.brooklyn.core.mgmt.internal.LocalEntityManager@56669f71 stopped management of entity Application[OMtzAZpT]
2016-02-24 23:34:52,612 DEBUG o.a.b.c.m.i.LocalEntityManager [brooklyn-execmanager-xoVyTRQg-3]: org.apache.brooklyn.core.mgmt.internal.LocalEntityManager@56669f71 stopped management of entity TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,612 DEBUG o.a.b.c.t.e.TestApplication [brooklyn-execmanager-xoVyTRQg-3]: Stopped application Application[OMtzAZpT]
2016-02-24 23:34:52,613 DEBUG o.a.b.c.m.i.BrooklynGarbageCollector [main]: brooklyn gc (before) - using 311 MB / 792 MB memory (0 B soft); 47 threads; storage: {datagrid={size=6, createCount=6}, refsMapSize=0, listsMapSize=0}; tasks: 0 active, 3 unfinished; 8 remembered, 263 total submitted)
2016-02-24 23:34:52,613 DEBUG o.a.b.c.m.i.BrooklynGarbageCollector [main]: brooklyn gc (after) - using 311 MB / 792 MB memory (0 B soft); 47 threads; storage: {datagrid={size=6, createCount=6}, refsMapSize=0, listsMapSize=0}; tasks: 0 active, 2 unfinished; 2 remembered, 263 total submitted)
2016-02-24 23:34:52,614 INFO  o.a.b.c.m.r.RebindTestFixture [main]: Count of incomplete tasks now 2, 2 unended; tasks remembered are: [Task[LSM.publish(TestEntityImpl{id=jo59Kab9}.Sensor: service.state.expected (org.apache.brooklyn.core.entity.lifecycle.Lifecycle$Transition)=stopped @ 1456356892603 / Wed Feb 24 23:34:52 UTC 2016 @ 1456356892603);[subscription-delivery-entity-jo59Kab9[TestEntityImpl{id=jo59Kab9}]]]@bVGuMNQQ, Task[LSM.publish(TestEntityImpl{id=jo59Kab9}.Sensor: service.isUp (java.lang.Boolean)=false @ 1456356892603);[subscription-delivery-entity-jo59Kab9[TestEntityImpl{id=jo59Kab9}]]]@V0LrJqjO]
2016-02-24 23:34:52,614 DEBUG o.a.b.util.repeat.Repeater [main]: Repeater: unsatisfied during iteration 1 (10.00s remaining)
2016-02-24 23:34:52,618 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-XmCah7ox-1]: Checkpointed delta of memento in 13ms: updated 2 entities, 0 locations, 0 policies, 2 enrichers, 2 catalog items; removed 0 entities, 0 locations, 0 policies, 0 enrichers, 1 catalog items
2016-02-24 23:34:52,618 DEBUG o.a.b.c.e.l.ServiceStateLogic [brooklyn-execmanager-xoVyTRQg-5]: TestEntityImpl{id=jo59Kab9} is no longer managed when told to set actual state to stopped; suppressing
2016-02-24 23:34:52,619 DEBUG o.a.b.c.e.l.ServiceStateLogic [brooklyn-execmanager-xoVyTRQg-1]: TestEntityImpl{id=jo59Kab9} is no longer managed when told to set actual state to stopped; suppressing
2016-02-24 23:34:52,634 DEBUG o.a.b.c.m.i.BrooklynGarbageCollector [main]: brooklyn gc (before) - using 311 MB / 792 MB memory (0 B soft); 48 threads; storage: {datagrid={size=6, createCount=6}, refsMapSize=0, listsMapSize=0}; tasks: 0 active, 0 unfinished; 0 remembered, 263 total submitted)
2016-02-24 23:34:52,635 DEBUG o.a.b.c.m.i.BrooklynGarbageCollector [main]: brooklyn gc (after) - using 311 MB / 792 MB memory (0 B soft); 48 threads; storage: {datagrid={size=6, createCount=6}, refsMapSize=0, listsMapSize=0}; tasks: 0 active, 0 unfinished; 0 remembered, 263 total submitted)
2016-02-24 23:34:52,635 INFO  o.a.b.c.m.r.RebindTestFixture [main]: Count of incomplete tasks now 0, 0 unended; tasks remembered are: []
2016-02-24 23:34:52,635 DEBUG o.a.b.util.repeat.Repeater [main]: Repeater: condition satisfied
2016-02-24 23:34:52,635 DEBUG o.a.b.c.m.i.LocalManagementContext [main]: Terminating management context LocalManagementContext[E5deSfFR-xoVyTRQg]
2016-02-24 23:34:52,635 DEBUG o.a.b.c.m.h.HighAvailabilityManagerImpl [main]: Stopping org.apache.brooklyn.core.mgmt.ha.HighAvailabilityManagerImpl@553e14d7[node:xoVyTRQg;running=false]
2016-02-24 23:34:52,635 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: Stopping persistence (org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl@3e9c3b13[mgmt=xoVyTRQg]), mgmt xoVyTRQg
2016-02-24 23:34:52,635 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: Stopped rebind (persistence), mgmt xoVyTRQg
2016-02-24 23:34:52,636 DEBUG o.a.b.c.m.i.LocalManagementContext [main]: Terminated management context LocalManagementContext[E5deSfFR-xoVyTRQg]
2016-02-24 23:34:52,637 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: File-based objectStore will use directory /tmp/RebindCatalogItemTest-nM9k
2016-02-24 23:34:52,637 DEBUG o.a.b.c.e.d.ReflectiveEntityDriverFactory [main]: Added driver mapping rule org.apache.brooklyn.core.entity.drivers.ReflectiveEntityDriverFactory$DriverInferenceForSshLocation@3db9ffbe
2016-02-24 23:34:52,637 DEBUG o.a.b.c.e.d.ReflectiveEntityDriverFactory [main]: Added driver mapping rule org.apache.brooklyn.core.entity.drivers.ReflectiveEntityDriverFactory$DriverInferenceForPaasLocation@7e45329a
2016-02-24 23:34:52,637 DEBUG o.a.b.c.e.d.ReflectiveEntityDriverFactory [main]: Added driver mapping rule org.apache.brooklyn.core.entity.drivers.ReflectiveEntityDriverFactory$DriverInferenceForWinRmLocation@70fd5d39
2016-02-24 23:34:52,638 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl@9f38323[mgmt=null] initialized, settings: policies=true, enrichers=true, feeds=true, catalog=true
2016-02-24 23:34:52,638 DEBUG o.a.b.c.BrooklynFeatureEnablement [main]: Init feature enablement did nothing, as no settings in brooklyn properties
2016-02-24 23:34:52,638 DEBUG o.a.b.c.m.i.LocalManagementContext [main]: Created management context LocalManagementContext[RG7mnfYn-BhmfGC8U]
2016-02-24 23:34:52,638 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,640 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/entities for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,640 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/locations for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,640 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/policies for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,640 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/enrichers for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,640 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/feeds for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,640 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/catalog for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,640 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/plane for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,645 DEBUG o.a.b.c.m.p.FileBasedObjectStore [main]: Created dir /tmp/RebindCatalogItemTest-nM9k/nodes for FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,645 DEBUG o.a.b.c.m.h.ManagementPlaneSyncRecordPersisterToObjectStore [main]: ManagementPlaneMemento-persister will use store FileBasedObjectStore{basedir=/tmp/RebindCatalogItemTest-nM9k}
2016-02-24 23:34:52,645 INFO  o.a.b.c.m.r.RebindTestUtils [main]: Rebinding app, using mementoDir /tmp/RebindCatalogItemTest-nM9k; object store null
2016-02-24 23:34:52,650 DEBUG o.a.b.c.m.r.InitialFullRebindIteration [brooklyn-execmanager-BhmfGC8U-0]: Rebinding (MASTER) from /tmp/RebindCatalogItemTest-nM9k...
2016-02-24 23:34:52,650 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-BhmfGC8U-0]: Loaded rebind lists; took 0ms: 2 entities, 0 locations, 0 policies, 2 enrichers, 0 feeds, 2 catalog items; from /tmp/RebindCatalogItemTest-nM9k
2016-02-24 23:34:52,663 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-BhmfGC8U-0]: Loaded rebind raw data; took 12ms; 2 entities, 0 locations, 0 policies, 2 enrichers, 0 feeds, 2 catalog items, from /tmp/RebindCatalogItemTest-nM9k
2016-02-24 23:34:52,672 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-BhmfGC8U-0]: Loaded rebind manifests; took 9ms: 2 entities, 0 locations, 0 policies, 2 enrichers, 0 feeds, 2 catalog items; from /tmp/RebindCatalogItemTest-nM9k
2016-02-24 23:34:52,672 INFO  o.a.b.c.m.r.InitialFullRebindIteration [brooklyn-execmanager-BhmfGC8U-0]: Rebinding from /tmp/RebindCatalogItemTest-nM9k for master BhmfGC8U...
2016-02-24 23:34:52,673 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager instantiating catalog items: [com.example.ExampleApp:9.1.3, sample_location:0.0.1]
2016-02-24 23:34:52,673 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager instantiating catalog item BasicCatalogItemMemento{type=org.apache.brooklyn.core.catalog.internal.CatalogTemplateItemDto, id=com.example.ExampleApp:9.1.3}
2016-02-24 23:34:52,673 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager instantiating catalog item BasicCatalogItemMemento{type=org.apache.brooklyn.core.catalog.internal.CatalogLocationItemDto, id=sample_location:0.0.1}
2016-02-24 23:34:52,673 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing catalog items
2016-02-24 23:34:52,673 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing catalog item BasicCatalogItemMemento{type=org.apache.brooklyn.core.catalog.internal.CatalogTemplateItemDto, id=com.example.ExampleApp:9.1.3}
2016-02-24 23:34:52,673 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing catalog item BasicCatalogItemMemento{type=org.apache.brooklyn.core.catalog.internal.CatalogLocationItemDto, id=sample_location:0.0.1}
2016-02-24 23:34:52,674 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager clearing local catalog and loading from persisted state
2016-02-24 23:34:52,674 DEBUG o.a.b.c.c.i.CatalogInitialization [brooklyn-execmanager-BhmfGC8U-0]: Populating catalog for MASTER, needsInitial=false, needsAdditional=true, explicitItems=2; from RebindIteration.rebuildCatalog
2016-02-24 23:34:52,674 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [brooklyn-execmanager-BhmfGC8U-0]: Loading catalog for LocalManagementContext[RG7mnfYn-BhmfGC8U]
2016-02-24 23:34:52,674 DEBUG o.a.b.c.c.i.BasicBrooklynCatalog [brooklyn-execmanager-BhmfGC8U-0]: Loaded catalog for LocalManagementContext[RG7mnfYn-BhmfGC8U]: Loaded:CatalogDto{name=empty catalog, contentsDescription=empty catalog, expected to be reset later}(size 0); search classpath is AggregateClassLoader[sun.misc.Launcher$AppClassLoader@46c6c084, AggregateClassLoader[]]
2016-02-24 23:34:52,675 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager instantiating locations: []
2016-02-24 23:34:52,675 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager instantiating entities: [jo59Kab9, OMtzAZpT]
2016-02-24 23:34:52,709 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-BhmfGC8U-0]: Entity type interface not found for entity Application[OMtzAZpT]; instead using org.apache.brooklyn.core.test.entity.TestApplicationNoEnrichersImpl as entity type name
2016-02-24 23:34:52,719 DEBUG o.a.b.c.m.r.PeriodicDeltaChangeListener [brooklyn-execmanager-XmCah7ox-0]: Checkpointing delta of memento: updating entities=[], locations=[], policies=[], enrichers=[], catalog items=[]; removing entities=[], locations=[], policies=[], enrichers=[], catalog items=[]
2016-02-24 23:34:52,750 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-BhmfGC8U-0]: Loaded rebind mementos; took 27ms: 2 entities, 0 locations, 0 policies, 2 enrichers, 0 feeds, 2 catalog items, from /tmp/RebindCatalogItemTest-nM9k
2016-02-24 23:34:52,750 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager instantiating policies: []
2016-02-24 23:34:52,750 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager instantiating enrichers: [OY9xOujn, odlgb9CL]
2016-02-24 23:34:52,750 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager instantiating enricher BasicEnricherMemento{type=org.apache.brooklyn.enricher.stock.Transformer, id=OY9xOujn}
2016-02-24 23:34:52,751 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager instantiating enricher BasicEnricherMemento{type=org.apache.brooklyn.core.entity.lifecycle.ServiceStateLogic$ComputeServiceState, id=odlgb9CL}
2016-02-24 23:34:52,751 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager instantiating feeds: []
2016-02-24 23:34:52,751 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing locations
2016-02-24 23:34:52,751 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing policies
2016-02-24 23:34:52,751 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing enrichers
2016-02-24 23:34:52,751 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing enricher BasicEnricherMemento{type=org.apache.brooklyn.enricher.stock.Transformer, id=OY9xOujn}
2016-02-24 23:34:52,751 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing enricher BasicEnricherMemento{type=org.apache.brooklyn.core.entity.lifecycle.ServiceStateLogic$ComputeServiceState, id=odlgb9CL}
2016-02-24 23:34:52,752 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing feeds
2016-02-24 23:34:52,752 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing entities
2016-02-24 23:34:52,752 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing entity BasicEntityMemento{type=org.apache.brooklyn.core.test.entity.TestApplicationNoEnrichersImpl, id=OMtzAZpT}
2016-02-24 23:34:52,752 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-BhmfGC8U-0]: Emitting sensor notification entity.children.added value TestEntityImpl{id=jo59Kab9} on Application[OMtzAZpT]
2016-02-24 23:34:52,752 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager reconstructing entity BasicEntityMemento{type=org.apache.brooklyn.core.test.entity.TestEntityImpl, id=jo59Kab9}
2016-02-24 23:34:52,752 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager associating adjuncts to entities
2016-02-24 23:34:52,753 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager associating adjuncts to entity BasicEntityMemento{type=org.apache.brooklyn.core.test.entity.TestApplicationNoEnrichersImpl, id=OMtzAZpT}
2016-02-24 23:34:52,753 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager associating adjuncts to entity BasicEntityMemento{type=org.apache.brooklyn.core.test.entity.TestEntityImpl, id=jo59Kab9}
2016-02-24 23:34:52,753 DEBUG o.a.b.core.sensor.AttributeMap [brooklyn-execmanager-BhmfGC8U-0]: removing attribute service.state on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,753 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-BhmfGC8U-0]: Emitting sensor notification entity.sensor.removed value Sensor: service.state (org.apache.brooklyn.core.entity.lifecycle.Lifecycle) on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,753 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager managing locations
2016-02-24 23:34:52,753 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager managing entities
2016-02-24 23:34:52,753 DEBUG o.a.b.c.m.i.LocalEntityManager [brooklyn-execmanager-BhmfGC8U-0]: org.apache.brooklyn.core.mgmt.internal.LocalEntityManager@75d8f0f2 starting management of entity Application[OMtzAZpT]
2016-02-24 23:34:52,754 DEBUG o.a.b.c.m.i.LocalSubscriptionManager [brooklyn-execmanager-BhmfGC8U-0]: Creating subscription jNlR2dXS for TestEntityImpl{id=jo59Kab9} on TestEntityImpl{id=jo59Kab9} Sensor: service.notUp.indicators (java.util.Map) in SubscriptionContext(HsU8t)
2016-02-24 23:34:52,754 DEBUG o.a.b.c.m.i.LocalSubscriptionManager [brooklyn-execmanager-BhmfGC8U-0]: Creating subscription kBMO1dfe for TestEntityImpl{id=jo59Kab9} on TestEntityImpl{id=jo59Kab9} Sensor: service.problems (java.util.Map) in SubscriptionContext(HsU8t)
2016-02-24 23:34:52,754 DEBUG o.a.b.c.m.i.LocalSubscriptionManager [brooklyn-execmanager-BhmfGC8U-0]: Creating subscription WGwqkbFv for TestEntityImpl{id=jo59Kab9} on TestEntityImpl{id=jo59Kab9} Sensor: service.isUp (java.lang.Boolean) in SubscriptionContext(HsU8t)
2016-02-24 23:34:52,755 DEBUG o.a.b.c.m.i.LocalSubscriptionManager [brooklyn-execmanager-BhmfGC8U-0]: Creating subscription vQbtQypL for TestEntityImpl{id=jo59Kab9} on TestEntityImpl{id=jo59Kab9} Sensor: service.state.expected (org.apache.brooklyn.core.entity.lifecycle.Lifecycle$Transition) in SubscriptionContext(HsU8t)
2016-02-24 23:34:52,755 DEBUG o.a.b.c.m.i.LocalEntityManager [brooklyn-execmanager-BhmfGC8U-0]: org.apache.brooklyn.core.mgmt.internal.LocalEntityManager@75d8f0f2 starting management of entity TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,755 INFO  o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: Rebind complete (MASTER) in 105ms: 1 app, 2 entities, 0 locations, 0 policies, 2 enrichers, 0 feeds, 2 catalog items
2016-02-24 23:34:52,755 DEBUG o.a.b.c.m.r.RebindIteration [brooklyn-execmanager-BhmfGC8U-0]: RebindManager complete; apps: [OMtzAZpT]
2016-02-24 23:34:52,764 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: Starting persistence (org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl@9f38323[mgmt=BhmfGC8U]), mgmt BhmfGC8U
2016-02-24 23:34:52,767 INFO  o.a.b.t.s.LoggingVerboseReporter [main]: TESTNG FAILED: "Surefire test" - org.apache.brooklyn.core.mgmt.rebind.RebindCatalogItemTest.testAddAndRebindAndDeleteLocation() finished in 489 ms
java.lang.AssertionError: Sets differ: expected [com.example.ExampleApp:9.1.3] but got [com.example.ExampleApp:9.1.3, sample_location:0.0.1]
	at org.apache.brooklyn.core.mgmt.rebind.RebindTestFixture.assertCatalogsEqual(RebindTestFixture.java:288)
	at org.apache.brooklyn.core.mgmt.rebind.RebindCatalogItemTest.rebindAndAssertCatalogsAreEqual(RebindCatalogItemTest.java:283)
	at org.apache.brooklyn.core.mgmt.rebind.RebindCatalogItemTest.testAddAndRebindAndDeleteLocation(RebindCatalogItemTest.java:185)
2016-02-24 23:34:52,770 DEBUG o.a.b.c.m.r.PeriodicDeltaChangeListener [brooklyn-execmanager-BhmfGC8U-1]: Checkpointing delta of memento: updating entities=[Application[OMtzAZpT], TestEntityImpl{id=jo59Kab9}], locations=[], policies=[], enrichers=[Transformer{name=org.apache.brooklyn.enricher.stock.Transformer, uniqueTag=service.isUp if no service.notUp.indicators, running=true, entity=TestEntityImpl{id=jo59Kab9}, id=OY9xOujn}, ComputeServiceState{name=org.apache.brooklyn.core.entity.lifecycle.ServiceStateLogic.ComputeServiceState, uniqueTag=service.state.actual, running=true, entity=TestEntityImpl{id=jo59Kab9}, id=odlgb9CL}], catalog items=[org.apache.brooklyn.core.catalog.internal.CatalogItemDo[CatalogLocationItemDto[sample_location:0.0.1/sample_location]], org.apache.brooklyn.core.catalog.internal.CatalogItemDo[CatalogTemplateItemDto[com.example.ExampleApp:9.1.3/Entity name]]]; removing entities=[], locations=[], policies=[], enrichers=[], catalog items=[]
2016-02-24 23:34:52,774 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-BhmfGC8U-1]: Checkpointed delta of memento in 3ms: updated 2 entities, 0 locations, 0 policies, 2 enrichers, 2 catalog items; removed 0 entities, 0 locations, 0 policies, 0 enrichers, 0 catalog items
2016-02-24 23:34:52,809 INFO  o.a.b.t.s.LoggingVerboseReporter [main]: TESTNG INVOKING CONFIGURATION: "Surefire test" - @AfterMethod org.apache.brooklyn.core.mgmt.rebind.RebindCatalogItemTest.tearDown()
2016-02-24 23:34:52,809 DEBUG o.a.b.core.entity.Entities [main]: destroying all apps in LocalManagementContext[xp3AjYaC-XmCah7ox]: [Application[OMtzAZpT]]
2016-02-24 23:34:52,810 DEBUG o.a.b.core.entity.Entities [pool-1648-thread-1]: destroying app Application[OMtzAZpT] (managed? true; mgmt is LocalManagementContext[xp3AjYaC-XmCah7ox])
2016-02-24 23:34:52,810 DEBUG o.a.b.c.m.i.EffectorUtils [brooklyn-execmanager-XmCah7ox-1]: Invoking effector stop on Application[OMtzAZpT]
2016-02-24 23:34:52,810 DEBUG o.a.b.c.t.e.TestApplication [brooklyn-execmanager-XmCah7ox-1]: Stopping application Application[OMtzAZpT]
2016-02-24 23:34:52,810 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-XmCah7ox-1]: Emitting sensor notification entity.sensor.added value Sensor: service.notUp.indicators (java.util.Map) on Application[OMtzAZpT]
2016-02-24 23:34:52,810 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-XmCah7ox-1]: Emitting sensor notification entity.sensor.added value Sensor: service.state.expected (org.apache.brooklyn.core.entity.lifecycle.Lifecycle$Transition) on Application[OMtzAZpT]
2016-02-24 23:34:52,810 DEBUG o.a.b.c.m.i.LocalUsageManager [brooklyn-execmanager-XmCah7ox-1]: Storing application lifecycle usage event: application Application[OMtzAZpT] in state stopping
2016-02-24 23:34:52,811 DEBUG o.a.b.c.e.t.StartableMethods [brooklyn-execmanager-XmCah7ox-1]: Stopping entity Application[OMtzAZpT]
2016-02-24 23:34:52,816 DEBUG o.a.b.u.c.t.BasicExecutionContext [brooklyn-execmanager-XmCah7ox-3]: Switching task context on execution of Task[stop]@Pfl1SkV5: from org.apache.brooklyn.util.core.task.BasicExecutionContext@73fe10b6([Wrapped[contextEntity:Application[OMtzAZpT]], LocalManagementContext[xp3AjYaC-XmCah7ox]]) to TestEntityImpl{id=jo59Kab9} (in Task[invoking stop[] on 1 node]@Y5Vhl0zC)
2016-02-24 23:34:52,834 DEBUG o.a.b.c.m.r.PeriodicDeltaChangeListener [brooklyn-execmanager-XmCah7ox-5]: Checkpointing delta of memento: updating entities=[Application[OMtzAZpT]], locations=[], policies=[], enrichers=[], catalog items=[]; removing entities=[], locations=[], policies=[], enrichers=[], catalog items=[]
2016-02-24 23:34:52,836 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [brooklyn-execmanager-XmCah7ox-5]: Checkpointed delta of memento in 1ms: updated 1 entities, 0 locations, 0 policies, 0 enrichers, 0 catalog items; removed 0 entities, 0 locations, 0 policies, 0 enrichers, 0 catalog items
2016-02-24 23:34:52,842 DEBUG o.a.b.c.m.i.EffectorUtils [brooklyn-execmanager-XmCah7ox-4]: Invoking effector stop on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,847 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-XmCah7ox-4]: Emitting sensor notification entity.sensor.added value Sensor: service.state.expected (org.apache.brooklyn.core.entity.lifecycle.Lifecycle$Transition) on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,848 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-XmCah7ox-4]: Emitting sensor notification entity.sensor.added value Sensor: service.state (org.apache.brooklyn.core.entity.lifecycle.Lifecycle) on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,866 DEBUG o.a.b.c.e.t.StartableMethods [brooklyn-execmanager-XmCah7ox-1]: Stopped entity Application[OMtzAZpT]
2016-02-24 23:34:52,867 DEBUG o.a.b.c.m.i.LocalUsageManager [brooklyn-execmanager-XmCah7ox-1]: Storing application lifecycle usage event: application Application[OMtzAZpT] in state stopped
2016-02-24 23:34:52,867 DEBUG o.a.b.c.m.i.LocalUsageManager [brooklyn-execmanager-XmCah7ox-1]: Storing application lifecycle usage event: application Application[OMtzAZpT] in state destroyed
2016-02-24 23:34:52,867 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-XmCah7ox-1]: Emitting sensor notification entity.children.removed value TestEntityImpl{id=jo59Kab9} on Application[OMtzAZpT]
2016-02-24 23:34:52,867 DEBUG o.a.b.c.m.i.LocalEntityManager [brooklyn-execmanager-XmCah7ox-1]: org.apache.brooklyn.core.mgmt.internal.LocalEntityManager@1e0b62e0 stopped management of entity Application[OMtzAZpT]
2016-02-24 23:34:52,867 DEBUG o.a.b.c.m.i.LocalEntityManager [brooklyn-execmanager-XmCah7ox-1]: org.apache.brooklyn.core.mgmt.internal.LocalEntityManager@1e0b62e0 stopped management of entity TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,868 DEBUG o.a.b.c.t.e.TestApplication [brooklyn-execmanager-XmCah7ox-1]: Stopped application Application[OMtzAZpT]
2016-02-24 23:34:52,868 DEBUG o.a.b.core.entity.Entities [pool-1648-thread-1]: destroyed and unmanaged Application[OMtzAZpT]; mgmt now NonDeploymentManagementContext{entity=OMtzAZpT, mode=MANAGEMENT_STOPPED} - managed? false
2016-02-24 23:34:52,868 DEBUG o.a.b.core.entity.Entities [pool-1648-thread-1]: destroyed app Application[OMtzAZpT]; mgmt now LocalManagementContext[xp3AjYaC-XmCah7ox]
2016-02-24 23:34:52,868 DEBUG o.a.b.c.m.i.LocalManagementContext [main]: Terminating management context LocalManagementContext[xp3AjYaC-XmCah7ox]
2016-02-24 23:34:52,868 DEBUG o.a.b.c.m.h.HighAvailabilityManagerImpl [main]: Stopping org.apache.brooklyn.core.mgmt.ha.HighAvailabilityManagerImpl@3a5581ce[node:null;running=false]
2016-02-24 23:34:52,868 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: Stopping persistence (org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl@1fbac2c1[mgmt=XmCah7ox]), mgmt XmCah7ox
2016-02-24 23:34:52,868 DEBUG o.a.b.c.m.r.PeriodicDeltaChangeListener [main]: Checkpointing delta of memento: updating entities=[], locations=[], policies=[], enrichers=[], catalog items=[]; removing entities=[OMtzAZpT, jo59Kab9], locations=[], policies=[], enrichers=[OY9xOujn, odlgb9CL], catalog items=[]
2016-02-24 23:34:52,869 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [main]: Checkpointed delta of memento in 0ms: updated 0 entities, 0 locations, 0 policies, 0 enrichers, 0 catalog items; removed 2 entities, 0 locations, 0 policies, 2 enrichers, 0 catalog items
2016-02-24 23:34:52,869 DEBUG o.a.b.util.core.task.BasicTask [main]: call from Thread[main,5,main], blocking until 'Task[scheduled[periodic-persister]]@pd9vXkKk' finishes, ended with error: java.util.concurrent.CancellationException
2016-02-24 23:34:52,869 DEBUG o.a.b.util.core.task.BasicTask [main]: call from Thread[main,5,main], blocking until 'Task[scheduled[periodic-persister]]@pd9vXkKk' finishes, ended with error: java.util.concurrent.CancellationException
2016-02-24 23:34:52,869 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: Stopped rebind (persistence), mgmt XmCah7ox
2016-02-24 23:34:52,870 DEBUG o.a.b.c.m.i.LocalManagementContext [main]: Terminated management context LocalManagementContext[xp3AjYaC-XmCah7ox]
2016-02-24 23:34:52,870 DEBUG o.a.b.core.entity.Entities [main]: destroying all apps in LocalManagementContext[RG7mnfYn-BhmfGC8U]: [Application[OMtzAZpT]]
2016-02-24 23:34:52,875 DEBUG o.a.b.c.m.r.PeriodicDeltaChangeListener [brooklyn-execmanager-BhmfGC8U-1]: Checkpointing delta of memento: updating entities=[], locations=[], policies=[], enrichers=[], catalog items=[]; removing entities=[], locations=[], policies=[], enrichers=[], catalog items=[]
2016-02-24 23:34:52,876 DEBUG o.a.b.core.entity.Entities [pool-1649-thread-1]: destroying app Application[OMtzAZpT] (managed? true; mgmt is LocalManagementContext[RG7mnfYn-BhmfGC8U])
2016-02-24 23:34:52,876 DEBUG o.a.b.c.m.i.EffectorUtils [brooklyn-execmanager-BhmfGC8U-0]: Invoking effector stop on Application[OMtzAZpT]
2016-02-24 23:34:52,876 DEBUG o.a.b.c.t.e.TestApplication [brooklyn-execmanager-BhmfGC8U-0]: Stopping application Application[OMtzAZpT]
2016-02-24 23:34:52,876 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-BhmfGC8U-0]: Emitting sensor notification entity.sensor.added value Sensor: service.notUp.indicators (java.util.Map) on Application[OMtzAZpT]
2016-02-24 23:34:52,876 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-BhmfGC8U-0]: Emitting sensor notification entity.sensor.added value Sensor: service.state.expected (org.apache.brooklyn.core.entity.lifecycle.Lifecycle$Transition) on Application[OMtzAZpT]
2016-02-24 23:34:52,877 DEBUG o.a.b.c.m.i.LocalUsageManager [brooklyn-execmanager-BhmfGC8U-0]: Storing application lifecycle usage event: application Application[OMtzAZpT] in state stopping
2016-02-24 23:34:52,877 DEBUG o.a.b.c.e.t.StartableMethods [brooklyn-execmanager-BhmfGC8U-0]: Stopping entity Application[OMtzAZpT]
2016-02-24 23:34:52,887 DEBUG o.a.b.u.c.t.BasicExecutionContext [brooklyn-execmanager-BhmfGC8U-3]: Switching task context on execution of Task[stop]@HhuYlW7x: from org.apache.brooklyn.util.core.task.BasicExecutionContext@6eb841ee([Wrapped[contextEntity:Application[OMtzAZpT]], LocalManagementContext[RG7mnfYn-BhmfGC8U]]) to TestEntityImpl{id=jo59Kab9} (in Task[invoking stop[] on 1 node]@uUa8Gtlg)
2016-02-24 23:34:52,904 DEBUG o.a.b.c.m.i.EffectorUtils [brooklyn-execmanager-BhmfGC8U-4]: Invoking effector stop on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,917 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-BhmfGC8U-4]: Emitting sensor notification entity.sensor.added value Sensor: service.state.expected (org.apache.brooklyn.core.entity.lifecycle.Lifecycle$Transition) on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,918 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-BhmfGC8U-6]: Emitting sensor notification entity.sensor.added value Sensor: service.state (org.apache.brooklyn.core.entity.lifecycle.Lifecycle) on TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,925 DEBUG o.a.b.c.e.t.StartableMethods [brooklyn-execmanager-BhmfGC8U-0]: Stopped entity Application[OMtzAZpT]
2016-02-24 23:34:52,925 DEBUG o.a.b.c.m.i.LocalUsageManager [brooklyn-execmanager-BhmfGC8U-0]: Storing application lifecycle usage event: application Application[OMtzAZpT] in state stopped
2016-02-24 23:34:52,925 DEBUG o.a.b.c.m.i.LocalUsageManager [brooklyn-execmanager-BhmfGC8U-0]: Storing application lifecycle usage event: application Application[OMtzAZpT] in state destroyed
2016-02-24 23:34:52,925 DEBUG o.a.b.c.entity.AbstractEntity [brooklyn-execmanager-BhmfGC8U-0]: Emitting sensor notification entity.children.removed value TestEntityImpl{id=jo59Kab9} on Application[OMtzAZpT]
2016-02-24 23:34:52,925 DEBUG o.a.b.c.m.i.LocalEntityManager [brooklyn-execmanager-BhmfGC8U-0]: org.apache.brooklyn.core.mgmt.internal.LocalEntityManager@75d8f0f2 stopped management of entity Application[OMtzAZpT]
2016-02-24 23:34:52,926 DEBUG o.a.b.c.m.i.LocalEntityManager [brooklyn-execmanager-BhmfGC8U-0]: org.apache.brooklyn.core.mgmt.internal.LocalEntityManager@75d8f0f2 stopped management of entity TestEntityImpl{id=jo59Kab9}
2016-02-24 23:34:52,926 DEBUG o.a.b.c.t.e.TestApplication [brooklyn-execmanager-BhmfGC8U-0]: Stopped application Application[OMtzAZpT]
2016-02-24 23:34:52,926 DEBUG o.a.b.core.entity.Entities [pool-1649-thread-1]: destroyed and unmanaged Application[OMtzAZpT]; mgmt now NonDeploymentManagementContext{entity=OMtzAZpT, mode=MANAGEMENT_STOPPED} - managed? false
2016-02-24 23:34:52,926 DEBUG o.a.b.core.entity.Entities [pool-1649-thread-1]: destroyed app Application[OMtzAZpT]; mgmt now LocalManagementContext[RG7mnfYn-BhmfGC8U]
2016-02-24 23:34:52,926 DEBUG o.a.b.c.m.i.LocalManagementContext [main]: Terminating management context LocalManagementContext[RG7mnfYn-BhmfGC8U]
2016-02-24 23:34:52,926 DEBUG o.a.b.c.m.h.HighAvailabilityManagerImpl [main]: Stopping org.apache.brooklyn.core.mgmt.ha.HighAvailabilityManagerImpl@6b4cb9d5[node:null;running=false]
2016-02-24 23:34:52,926 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: Stopping persistence (org.apache.brooklyn.core.mgmt.rebind.RebindManagerImpl@9f38323[mgmt=BhmfGC8U]), mgmt BhmfGC8U
2016-02-24 23:34:52,927 DEBUG o.a.b.c.m.r.PeriodicDeltaChangeListener [main]: Checkpointing delta of memento: updating entities=[], locations=[], policies=[], enrichers=[], catalog items=[]; removing entities=[OMtzAZpT, jo59Kab9], locations=[], policies=[], enrichers=[OY9xOujn, odlgb9CL], catalog items=[]
2016-02-24 23:34:52,927 DEBUG o.a.b.c.m.p.FileBasedStoreObjectAccessor [brooklyn-persister]: Unable to delete /tmp/RebindCatalogItemTest-nM9k/entities/OMtzAZpT. Probably did not exist.
2016-02-24 23:34:52,927 DEBUG o.a.b.c.m.p.FileBasedStoreObjectAccessor [brooklyn-persister]: Unable to delete /tmp/RebindCatalogItemTest-nM9k/entities/jo59Kab9. Probably did not exist.
2016-02-24 23:34:52,927 DEBUG o.a.b.c.m.p.FileBasedStoreObjectAccessor [brooklyn-persister]: Unable to delete /tmp/RebindCatalogItemTest-nM9k/enrichers/OY9xOujn. Probably did not exist.
2016-02-24 23:34:52,927 DEBUG o.a.b.c.m.p.FileBasedStoreObjectAccessor [brooklyn-persister]: Unable to delete /tmp/RebindCatalogItemTest-nM9k/enrichers/odlgb9CL. Probably did not exist.
2016-02-24 23:34:52,927 DEBUG o.a.b.c.m.p.BrooklynMementoPersisterToObjectStore [main]: Checkpointed delta of memento in 0ms: updated 0 entities, 0 locations, 0 policies, 0 enrichers, 0 catalog items; removed 2 entities, 0 locations, 0 policies, 2 enrichers, 0 catalog items
2016-02-24 23:34:52,927 DEBUG o.a.b.util.core.task.BasicTask [main]: call from Thread[main,5,main], blocking until 'Task[scheduled[periodic-persister]]@lUc39Z7h' finishes, ended with error: java.util.concurrent.CancellationException
2016-02-24 23:34:52,927 DEBUG o.a.b.util.core.task.BasicTask [main]: call from Thread[main,5,main], blocking until 'Task[scheduled[periodic-persister]]@lUc39Z7h' finishes, ended with error: java.util.concurrent.CancellationException
2016-02-24 23:34:52,927 DEBUG o.a.b.c.m.r.RebindManagerImpl [main]: Stopped rebind (persistence), mgmt BhmfGC8U
2016-02-24 23:34:52,928 DEBUG o.a.b.c.m.i.LocalManagementContext [main]: Terminated management context LocalManagementContext[RG7mnfYn-BhmfGC8U]
2016-02-24 23:34:52,930 INFO  o.a.b.t.s.LoggingVerboseReporter [main]: TESTNG PASSED CONFIGURATION: "Surefire test" - @AfterMethod org.apache.brooklyn.core.mgmt.rebind.RebindCatalogItemTest.tearDown() finished in 121 ms
{code})

> Unreliable test: AbstractControllerTest.testUpdateCalledWhenChildHostnameAndPortChanges
> ---------------------------------------------------------------------------------------
>
>                 Key: BROOKLYN-206
>                 URL: https://issues.apache.org/jira/browse/BROOKLYN-206
>             Project: Brooklyn
>          Issue Type: Bug
>            Reporter: Sam Corbett
>
> Stacktrace
> {code}
> java.lang.AssertionError: expected [true] but found [false]
> 	at org.testng.Assert.fail(Assert.java:94)
> 	at org.testng.Assert.failNotEquals(Assert.java:494)
> 	at org.testng.Assert.assertTrue(Assert.java:42)
> 	at org.testng.Assert.assertTrue(Assert.java:52)
> 	at org.apache.brooklyn.entity.proxy.AbstractControllerTest.assertAddressesMatch(AbstractControllerTest.java:308)
> 	at org.apache.brooklyn.entity.proxy.AbstractControllerTest.access$100(AbstractControllerTest.java:67)
> {code}
> Debug log
> {code}
> 2015-12-15 15:30:17,853 INFO  TESTNG INVOKING CONFIGURATION: "Surefire test" - @BeforeMethod org.apache.brooklyn.entity.proxy.AbstractControllerTest.setUp()
> 2015-12-15 15:30:18,096 INFO  Starting TrackingAbstractControllerImpl{id=Zveoz16x}, obtaining a new location instance in FixedListMachineProvisioningLocation{id=HsQneYPD, name=FixedListMachineProvisioningLocation:HsQn} with ports [22, 8000, 8443]
> 2015-12-15 15:30:18,108 INFO  Starting TrackingAbstractControllerImpl{id=Zveoz16x} on machine SshMachineLocation[SshMachineLocation:TM32:null@/1.1.1.1:22(id=TM32DuVH)]
> 2015-12-15 15:30:18,242 INFO  Added policy ServerPoolMemberTrackerPolicy{name=Controller targets tracker, running=true} to TrackingAbstractControllerImpl{id=Zveoz16x}
> 2015-12-15 15:30:18,242 INFO  Resetting TrackingAbstractControllerImpl{id=Zveoz16x}, server pool targets {}
> 2015-12-15 15:30:18,244 INFO  Updating TrackingAbstractControllerImpl{id=Zveoz16x}, server pool targets {}
> 2015-12-15 15:30:18,244 INFO  test controller reconfigure, targets []
> 2015-12-15 15:30:18,252 INFO  TESTNG PASSED CONFIGURATION: "Surefire test" - @BeforeMethod org.apache.brooklyn.entity.proxy.AbstractControllerTest.setUp() finished in 399 ms
> 2015-12-15 15:30:18,253 INFO  TESTNG INVOKING: "Surefire test" - org.apache.brooklyn.entity.proxy.AbstractControllerTest.testUpdateCalledWhenChildHostnameAndPortChanges()
> 2015-12-15 15:30:33,398 INFO  succeedsEventually exceeded max attempts or timeout - 39 attempts lasting 15001 ms, for RunnableAdapter(org.apache.brooklyn.entity.proxy.AbstractControllerTest$3@186540e1)
> 2015-12-15 15:30:33,398 INFO  failed succeeds-eventually, 39 attempts, 15001ms elapsed (rethrowing): java.lang.AssertionError: expected [true] but found [false]
> 2015-12-15 15:30:33,401 INFO  TESTNG FAILED: "Surefire test" - org.apache.brooklyn.entity.proxy.AbstractControllerTest.testUpdateCalledWhenChildHostnameAndPortChanges() finished in 15147 ms
> java.lang.AssertionError: expected [true] but found [false]
> 	at org.apache.brooklyn.entity.proxy.AbstractControllerTest.assertAddressesMatch(AbstractControllerTest.java:308)
> 	at org.apache.brooklyn.entity.proxy.AbstractControllerTest.access$100(AbstractControllerTest.java:67)
> 	at org.apache.brooklyn.entity.proxy.AbstractControllerTest$3.run(AbstractControllerTest.java:300)
> 	at org.apache.brooklyn.test.Asserts$RunnableAdapter.call(Asserts.java:1208)
> 	at org.apache.brooklyn.test.Asserts.succeedsEventually(Asserts.java:870)
> 	at org.apache.brooklyn.test.Asserts.succeedsEventually(Asserts.java:797)
> 	at org.apache.brooklyn.entity.proxy.AbstractControllerTest.assertEventuallyExplicitAddressesMatch(AbstractControllerTest.java:298)
> 	at org.apache.brooklyn.entity.proxy.AbstractControllerTest.testUpdateCalledWhenChildHostnameAndPortChanges(AbstractControllerTest.java:120)
> 2015-12-15 15:30:33,406 INFO  TESTNG INVOKING CONFIGURATION: "Surefire test" - @AfterMethod org.apache.brooklyn.core.test.BrooklynMgmtUnitTestSupport.tearDown()
> 2015-12-15 15:30:33,417 INFO  Stopping TrackingAbstractControllerImpl{id=Zveoz16x} in [SshMachineLocation[SshMachineLocation:TM32:null@1.1.1.1/1.1.1.1:22(id=TM32DuVH)]]
> 2015-12-15 15:30:33,460 INFO  TESTNG PASSED CONFIGURATION: "Surefire test" - @AfterMethod org.apache.brooklyn.core.test.BrooklynMgmtUnitTestSupport.tearDown() finished in 55 ms
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)