mesos-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Dominic Hamon (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (MESOS-1436) AllocatorZooKeeperTest/0.SlaveReregistersFirst flaky and can run forever
Date Fri, 06 Jun 2014 19:12:02 GMT

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

Dominic Hamon updated MESOS-1436:
---------------------------------

    Sprint:   (was: Q2 Sprint 3)

> AllocatorZooKeeperTest/0.SlaveReregistersFirst flaky and can run forever
> ------------------------------------------------------------------------
>
>                 Key: MESOS-1436
>                 URL: https://issues.apache.org/jira/browse/MESOS-1436
>             Project: Mesos
>          Issue Type: Bug
>          Components: test
>            Reporter: Yan Xu
>
> {noformat}
> [ RUN      ] AllocatorZooKeeperTest/0.SlaveReregistersFirst
> Using temporary directory '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_qNbdLi'
> I0528 23:01:30.969173  2525 leveldb.cpp:176] Opened db in 4.455089ms
> I0528 23:01:30.969794  2525 leveldb.cpp:183] Compacted db in 460493ns
> I0528 23:01:30.969945  2525 leveldb.cpp:198] Created db iterator in 5290ns
> I0528 23:01:30.970137  2525 leveldb.cpp:204] Seeked to beginning of db in 1015ns
> I0528 23:01:30.970294  2525 leveldb.cpp:273] Iterated through 0 keys in the db in 560ns
> I0528 23:01:30.970537  2525 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> 2014-05-28 23:01:30,971:2525(0x2b2136157700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 23:01:30,971:2525(0x2b2136157700):ZOO_INFO@log_env@716: Client environment:host.name=trusty
> 2014-05-28 23:01:30,971:2525(0x2b2136157700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 23:01:30,971:2525(0x2b2136157700):ZOO_INFO@log_env@724: Client environment:os.arch=3.13.0-27-generic
> 2014-05-28 23:01:30,971:2525(0x2b2136157700):ZOO_INFO@log_env@725: Client environment:os.version=#50-Ubuntu SMP Thu May 15 18:06:16 UTC 2014
> 2014-05-28 23:01:30,971:2525(0x2b2136157700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 23:01:30,972:2525(0x2b2136157700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 23:01:30,972:2525(0x2b2136157700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_qNbdLi
> 2014-05-28 23:01:30,972:2525(0x2b2136157700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:44966 sessionTimeout=10000 watcher=0x2b2132ca6890 sessionId=0 sessionPasswd=<null> context=0x2b215400e7e0 flags=0
> 2014-05-28 23:01:30,974:2525(0x2b2136358700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 23:01:30,974:2525(0x2b2136358700):ZOO_INFO@log_env@716: Client environment:host.name=trusty
> 2014-05-28 23:01:30,974:2525(0x2b2136358700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 23:01:30,974:2525(0x2b2136358700):ZOO_INFO@log_env@724: Client environment:os.arch=3.13.0-27-generic
> 2014-05-28 23:01:30,974:2525(0x2b2136358700):ZOO_INFO@log_env@725: Client environment:os.version=#50-Ubuntu SMP Thu May 15 18:06:16 UTC 2014
> 2014-05-28 23:01:30,974:2525(0x2b2136358700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 23:01:30,974:2525(0x2b2136358700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 23:01:30,974:2525(0x2b2136358700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_qNbdLi
> 2014-05-28 23:01:30,974:2525(0x2b2136358700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:44966 sessionTimeout=10000 watcher=0x2b2132ca6890 sessionId=0 sessionPasswd=<null> context=0x2b2138038920 flags=0
> I0528 23:01:30.975096  2546 log.cpp:238] Attempting to join replica to ZooKeeper group
> I0528 23:01:30.975348  2546 recover.cpp:425] Starting replica recovery
> I0528 23:01:30.975419  2546 recover.cpp:451] Replica is in EMPTY status
> I0528 23:01:30.975723  2546 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request
> I0528 23:01:30.975800  2546 recover.cpp:188] Received a recover response from a replica in EMPTY status
> I0528 23:01:30.975918  2546 recover.cpp:542] Updating replica status to STARTING
> I0528 23:01:30.976851  2546 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 851005ns
> I0528 23:01:30.976871  2546 replica.cpp:320] Persisted replica status to STARTING
> I0528 23:01:30.977144  2544 recover.cpp:451] Replica is in STARTING status
> I0528 23:01:30.977465  2546 replica.cpp:638] Replica in STARTING status received a broadcasted recover request
> I0528 23:01:30.977524  2546 recover.cpp:188] Received a recover response from a replica in STARTING status
> I0528 23:01:30.977612  2546 recover.cpp:542] Updating replica status to VOTING
> I0528 23:01:30.977906  2546 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 231564ns
> I0528 23:01:30.978054  2546 replica.cpp:320] Persisted replica status to VOTING
> I0528 23:01:30.978399  2545 recover.cpp:556] Successfully joined the Paxos group
> I0528 23:01:30.978674  2549 recover.cpp:440] Recover process terminated
> 2014-05-28 23:01:30,982:2525(0x2b2135d55700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 23:01:30,983:2525(0x2b2135d55700):ZOO_INFO@log_env@716: Client environment:host.name=trusty
> 2014-05-28 23:01:30,983:2525(0x2b2135d55700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 23:01:30,983:2525(0x2b2135d55700):ZOO_INFO@log_env@724: Client environment:os.arch=3.13.0-27-generic
> 2014-05-28 23:01:30,983:2525(0x2b2135d55700):ZOO_INFO@log_env@725: Client environment:os.version=#50-Ubuntu SMP Thu May 15 18:06:16 UTC 2014
> 2014-05-28 23:01:30,983:2525(0x2b2135d55700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 23:01:30,983:2525(0x2b2135d55700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 23:01:30,983:2525(0x2b2135d55700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_qNbdLi
> 2014-05-28 23:01:30,983:2525(0x2b2135d55700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:44966 sessionTimeout=10000 watcher=0x2b2132ca6890 sessionId=0 sessionPasswd=<null> context=0x2b214005e050 flags=0
> 2014-05-28 23:01:30,983:2525(0x2b2135b54700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 23:01:30,983:2525(0x2b2135b54700):ZOO_INFO@log_env@716: Client environment:host.name=trusty
> 2014-05-28 23:01:30,983:2525(0x2b2135b54700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 23:01:30,983:2525(0x2b2135b54700):ZOO_INFO@log_env@724: Client environment:os.arch=3.13.0-27-generic
> 2014-05-28 23:01:30,983:2525(0x2b2135b54700):ZOO_INFO@log_env@725: Client environment:os.version=#50-Ubuntu SMP Thu May 15 18:06:16 UTC 2014
> 2014-05-28 23:01:30,984:2525(0x2b2135b54700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 23:01:30,984:2525(0x2b2135b54700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 23:01:30,984:2525(0x2b2135b54700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_qNbdLi
> 2014-05-28 23:01:30,984:2525(0x2b2135b54700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:44966 sessionTimeout=10000 watcher=0x2b2132ca6890 sessionId=0 sessionPasswd=<null> context=0x2b214801e690 flags=0
> I0528 23:01:30.987109  2544 master.cpp:272] Master 20140528-230130-16842879-56711-2525 (trusty) started on 127.0.1.1:56711
> I0528 23:01:30.987134  2544 master.cpp:309] Master only allowing authenticated frameworks to register
> I0528 23:01:30.987143  2544 master.cpp:314] Master only allowing authenticated slaves to register
> I0528 23:01:30.987150  2544 credentials.hpp:35] Loading credentials for authentication from '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_qNbdLi/credentials'
> I0528 23:01:30.987229  2544 master.cpp:340] Master enabling authorization
> I0528 23:01:30.987613  2544 hierarchical_allocator_process.hpp:301] Initializing hierarchical allocator process with master : master@127.0.1.1:56711
> I0528 23:01:30.987649  2544 master.cpp:108] No whitelist given. Advertising offers for all slaves
> I0528 23:01:30.987859  2544 contender.cpp:127] Joining the ZK group
> 2014-05-28 23:01:30,994:2525(0x2b21600ed700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:44966]
> 2014-05-28 23:01:30,994:2525(0x2b2160901700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:44966]
> 2014-05-28 23:01:30,995:2525(0x2b21604ff700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:44966]
> 2014-05-28 23:01:30,995:2525(0x2b215fceb700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:44966]
> 2014-05-28 23:01:31,018:2525(0x2b215fceb700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:44966], sessionId=0x1464691adb10000, negotiated timeout=10000
> I0528 23:01:31.026738  2549 group.cpp:310] Group process ((940)@127.0.1.1:56711) connected to ZooKeeper
> I0528 23:01:31.026772  2549 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
> I0528 23:01:31.026787  2549 group.cpp:382] Trying to create path '/znode/log_replicas' in ZooKeeper
> 2014-05-28 23:01:31,028:2525(0x2b21600ed700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:44966], sessionId=0x1464691adb10001, negotiated timeout=10000
> I0528 23:01:31.029418  2548 group.cpp:310] Group process ((942)@127.0.1.1:56711) connected to ZooKeeper
> I0528 23:01:31.029439  2548 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0)
> I0528 23:01:31.029448  2548 group.cpp:382] Trying to create path '/znode/log_replicas' in ZooKeeper
> 2014-05-28 23:01:31,030:2525(0x2b2160901700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:44966], sessionId=0x1464691adb10002, negotiated timeout=10000
> I0528 23:01:31.031448  2550 group.cpp:310] Group process ((951)@127.0.1.1:56711) connected to ZooKeeper
> I0528 23:01:31.031469  2550 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
> I0528 23:01:31.031478  2550 group.cpp:382] Trying to create path '/znode' in ZooKeeper
> 2014-05-28 23:01:31,032:2525(0x2b21604ff700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:44966], sessionId=0x1464691adb10003, negotiated timeout=10000
> I0528 23:01:31.033535  2547 group.cpp:310] Group process ((948)@127.0.1.1:56711) connected to ZooKeeper
> I0528 23:01:31.033555  2547 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0)
> I0528 23:01:31.033565  2547 group.cpp:382] Trying to create path '/znode' in ZooKeeper
> I0528 23:01:31.097532  2550 contender.cpp:243] New candidate (id='0') has entered the contest for leadership
> I0528 23:01:31.100992  2545 group.cpp:711] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
> I0528 23:01:31.101076  2545 detector.cpp:135] Detected a new leader: (id='0')
> I0528 23:01:31.101272  2545 group.cpp:655] Trying to get '/znode/info_0000000000' in ZooKeeper
> I0528 23:01:31.102300  2547 group.cpp:711] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
> I0528 23:01:31.107453  2545 detector.cpp:377] A new leading master (UPID=master@127.0.1.1:56711) is detected
> I0528 23:01:31.107509  2545 master.cpp:957] The newly elected leader is master@127.0.1.1:56711 with id 20140528-230130-16842879-56711-2525
> I0528 23:01:31.107522  2545 master.cpp:970] Elected as the leading master!
> I0528 23:01:31.107529  2545 master.cpp:788] Recovering from registrar
> I0528 23:01:31.107585  2545 registrar.cpp:313] Recovering registrar
> I0528 23:01:31.107826  2545 log.cpp:656] Attempting to start the writer
> I0528 23:01:31.108115  2545 replica.cpp:474] Replica received implicit promise request with proposal 1
> I0528 23:01:31.109215  2544 network.hpp:423] ZooKeeper group memberships changed
> I0528 23:01:31.109334  2544 group.cpp:655] Trying to get '/znode/log_replicas/0000000000' in ZooKeeper
> I0528 23:01:31.109900  2545 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 1.761338ms
> I0528 23:01:31.109932  2545 replica.cpp:342] Persisted promised to 1
> I0528 23:01:31.110085  2545 coordinator.cpp:230] Coordinator attemping to fill missing position
> I0528 23:01:31.110600  2545 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
> I0528 23:01:31.111697  2545 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 1.073287ms
> I0528 23:01:31.111722  2545 replica.cpp:676] Persisted action at 0
> I0528 23:01:31.111968  2545 replica.cpp:508] Replica received write request for position 0
> I0528 23:01:31.111996  2545 leveldb.cpp:438] Reading position from leveldb took 12438ns
> I0528 23:01:31.112372  2545 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 359269ns
> I0528 23:01:31.112521  2545 replica.cpp:676] Persisted action at 0
> I0528 23:01:31.119140  2547 replica.cpp:655] Replica received learned notice for position 0
> I0528 23:01:31.119611  2545 network.hpp:461] ZooKeeper group PIDs: { log-replica(26)@127.0.1.1:56711 }
> I0528 23:01:31.120671  2547 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 1.503773ms
> I0528 23:01:31.120697  2547 replica.cpp:676] Persisted action at 0
> I0528 23:01:31.120895  2547 replica.cpp:661] Replica learned NOP action at position 0
> I0528 23:01:31.121294  2547 log.cpp:672] Writer started with ending position 0
> I0528 23:01:31.121515  2547 leveldb.cpp:438] Reading position from leveldb took 10183ns
> I0528 23:01:31.126590  2547 registrar.cpp:346] Successfully fetched the registry (0B)
> I0528 23:01:31.126885  2547 registrar.cpp:422] Attempting to update the 'registry'
> I0528 23:01:31.128154  2546 log.cpp:680] Attempting to append 118 bytes to the log
> I0528 23:01:31.128200  2546 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
> I0528 23:01:31.128362  2546 replica.cpp:508] Replica received write request for position 1
> I0528 23:01:31.128859  2546 leveldb.cpp:343] Persisting action (135 bytes) to leveldb took 475805ns
> I0528 23:01:31.128878  2546 replica.cpp:676] Persisted action at 1
> I0528 23:01:31.129030  2546 replica.cpp:655] Replica received learned notice for position 1
> I0528 23:01:31.129323  2546 leveldb.cpp:343] Persisting action (137 bytes) to leveldb took 271504ns
> I0528 23:01:31.129343  2546 replica.cpp:676] Persisted action at 1
> I0528 23:01:31.129351  2546 replica.cpp:661] Replica learned APPEND action at position 1
> I0528 23:01:31.129549  2546 log.cpp:699] Attempting to truncate the log to 1
> I0528 23:01:31.129585  2546 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2
> I0528 23:01:31.129734  2546 replica.cpp:508] Replica received write request for position 2
> I0528 23:01:31.130116  2546 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 362587ns
> I0528 23:01:31.130136  2546 replica.cpp:676] Persisted action at 2
> I0528 23:01:31.134672  2550 replica.cpp:655] Replica received learned notice for position 2
> I0528 23:01:31.135171  2547 registrar.cpp:479] Successfully updated 'registry'
> I0528 23:01:31.135449  2547 registrar.cpp:372] Successfully recovered registrar
> I0528 23:01:31.135730  2547 master.cpp:815] Recovered 0 slaves from the Registry (82B) ; allowing 10mins for slaves to re-register
> I0528 23:01:31.135622  2550 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 924046ns
> I0528 23:01:31.138051  2550 leveldb.cpp:401] Deleting ~1 keys from leveldb took 19299ns
> I0528 23:01:31.138068  2550 replica.cpp:676] Persisted action at 2
> I0528 23:01:31.138078  2550 replica.cpp:661] Replica learned TRUNCATE action at position 2
> I0528 23:01:31.137892  2548 slave.cpp:143] Slave started on 46)@127.0.1.1:56711
> I0528 23:01:31.138206  2548 credentials.hpp:35] Loading credentials for authentication from '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_FCGlTk/credential'
> I0528 23:01:31.138278  2548 slave.cpp:242] Slave using credential for: test-principal
> I0528 23:01:31.138401  2548 slave.cpp:255] Slave resources: cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000]
> 2014-05-28 23:01:31,136:2525(0x2b2135953700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 23:01:31,138:2525(0x2b2135953700):ZOO_INFO@log_env@716: Client environment:host.name=trusty
> 2014-05-28 23:01:31,138:2525(0x2b2135953700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 23:01:31,138:2525(0x2b2135953700):ZOO_INFO@log_env@724: Client environment:os.arch=3.13.0-27-generic
> 2014-05-28 23:01:31,138:2525(0x2b2135953700):ZOO_INFO@log_env@725: Client environment:os.version=#50-Ubuntu SMP Thu May 15 18:06:16 UTC 2014
> 2014-05-28 23:01:31,137:2525(0x2b2135f56700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 23:01:31,138:2525(0x2b2135f56700):ZOO_INFO@log_env@716: Client environment:host.name=trusty
> 2014-05-28 23:01:31,138:2525(0x2b2135f56700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 23:01:31,138:2525(0x2b2135f56700):ZOO_INFO@log_env@724: Client environment:os.arch=3.13.0-27-generic
> 2014-05-28 23:01:31,138:2525(0x2b2135f56700):ZOO_INFO@log_env@725: Client environment:os.version=#50-Ubuntu SMP Thu May 15 18:06:16 UTC 2014
> 2014-05-28 23:01:31,138:2525(0x2b2135f56700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 23:01:31,138:2525(0x2b2135f56700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 23:01:31,138:2525(0x2b2135f56700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_qNbdLi
> 2014-05-28 23:01:31,139:2525(0x2b2135f56700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:44966 sessionTimeout=10000 watcher=0x2b2132ca6890 sessionId=0 sessionPasswd=<null> context=0x2b213c00c1e0 flags=0
> 2014-05-28 23:01:31,139:2525(0x2b2135953700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 23:01:31,139:2525(0x2b2135953700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 23:01:31,139:2525(0x2b2135953700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_qNbdLi
> 2014-05-28 23:01:31,139:2525(0x2b2135953700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:44966 sessionTimeout=10000 watcher=0x2b2132ca6890 sessionId=0 sessionPasswd=<null> context=0x2b214c032390 flags=0
> I0528 23:01:31.139881  2548 slave.cpp:283] Slave hostname: trusty
> I0528 23:01:31.140270  2548 slave.cpp:284] Slave checkpoint: false
> I0528 23:01:31.140605  2548 state.cpp:33] Recovering state from '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_FCGlTk/meta'
> I0528 23:01:31.140688  2548 status_update_manager.cpp:193] Recovering status update manager
> I0528 23:01:31.140772  2548 slave.cpp:3018] Finished recovery
> I0528 23:01:31.137737  2525 sched.cpp:126] Version: 0.19.0
> 2014-05-28 23:01:31,144:2525(0x2b2160d03700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:44966]
> 2014-05-28 23:01:31,145:2525(0x2b2160d03700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:44966], sessionId=0x1464691adb10004, negotiated timeout=10000
> I0528 23:01:31.145869  2547 group.cpp:310] Group process ((969)@127.0.1.1:56711) connected to ZooKeeper
> I0528 23:01:31.145889  2547 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
> I0528 23:01:31.145900  2547 group.cpp:382] Trying to create path '/znode' in ZooKeeper
> 2014-05-28 23:01:31,145:2525(0x2b2161105700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:44966]
> 2014-05-28 23:01:31,146:2525(0x2b2161105700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:44966], sessionId=0x1464691adb10005, negotiated timeout=10000
> I0528 23:01:31.146834  2546 group.cpp:310] Group process ((962)@127.0.1.1:56711) connected to ZooKeeper
> I0528 23:01:31.146853  2546 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
> I0528 23:01:31.146862  2546 group.cpp:382] Trying to create path '/znode' in ZooKeeper
> I0528 23:01:31.159360  2547 group.cpp:711] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
> I0528 23:01:31.159420  2547 detector.cpp:135] Detected a new leader: (id='0')
> I0528 23:01:31.159508  2547 group.cpp:655] Trying to get '/znode/info_0000000000' in ZooKeeper
> I0528 23:01:31.161211  2546 group.cpp:711] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
> I0528 23:01:31.161262  2546 detector.cpp:135] Detected a new leader: (id='0')
> I0528 23:01:31.161335  2546 group.cpp:655] Trying to get '/znode/info_0000000000' in ZooKeeper
> I0528 23:01:31.162050  2547 detector.cpp:377] A new leading master (UPID=master@127.0.1.1:56711) is detected
> I0528 23:01:31.162106  2547 sched.cpp:222] New master detected at master@127.0.1.1:56711
> I0528 23:01:31.162122  2547 sched.cpp:273] Authenticating with master master@127.0.1.1:56711
> I0528 23:01:31.162195  2547 authenticatee.hpp:128] Creating new client SASL connection
> I0528 23:01:31.162734  2547 master.cpp:2986] Authenticating scheduler(27)@127.0.1.1:56711
> I0528 23:01:31.162821  2547 authenticator.hpp:156] Creating new server SASL connection
> I0528 23:01:31.163161  2547 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
> I0528 23:01:31.163184  2547 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0528 23:01:31.163211  2547 authenticator.hpp:262] Received SASL authentication start
> I0528 23:01:31.163249  2547 authenticator.hpp:384] Authentication requires more steps
> I0528 23:01:31.163275  2547 authenticatee.hpp:265] Received SASL authentication step
> I0528 23:01:31.163310  2547 authenticator.hpp:290] Received SASL authentication step
> I0528 23:01:31.163326  2547 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'trusty' server FQDN: 'trusty' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
> I0528 23:01:31.163334  2547 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I0528 23:01:31.163346  2547 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0528 23:01:31.163355  2547 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'trusty' server FQDN: 'trusty' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
> I0528 23:01:31.163362  2547 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0528 23:01:31.163367  2547 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0528 23:01:31.163379  2547 authenticator.hpp:376] Authentication success
> I0528 23:01:31.163403  2547 authenticatee.hpp:305] Authentication success
> I0528 23:01:31.163424  2547 master.cpp:3026] Successfully authenticated principal 'test-principal' at scheduler(27)@127.0.1.1:56711
> I0528 23:01:31.163486  2547 sched.cpp:347] Successfully authenticated with master master@127.0.1.1:56711
> I0528 23:01:31.163501  2547 sched.cpp:466] Sending registration request to master@127.0.1.1:56711
> I0528 23:01:31.163542  2547 master.cpp:1041] Received registration request from scheduler(27)@127.0.1.1:56711
> I0528 23:01:31.163574  2547 master.cpp:1059] Registering framework 20140528-230130-16842879-56711-2525-0000 at scheduler(27)@127.0.1.1:56711
> I0528 23:01:31.163630  2547 sched.cpp:397] Framework registered with 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.163650  2547 sched.cpp:411] Scheduler::registered took 8605ns
> I0528 23:01:31.163684  2547 hierarchical_allocator_process.hpp:331] Added framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.163694  2547 hierarchical_allocator_process.hpp:725] No resources available to allocate!
> I0528 23:01:31.163700  2547 hierarchical_allocator_process.hpp:687] Performed allocation for 0 slaves in 6764ns
> I0528 23:01:31.164517  2546 detector.cpp:377] A new leading master (UPID=master@127.0.1.1:56711) is detected
> I0528 23:01:31.164572  2546 slave.cpp:536] New master detected at master@127.0.1.1:56711
> I0528 23:01:31.164592  2546 slave.cpp:612] Authenticating with master master@127.0.1.1:56711
> I0528 23:01:31.164628  2546 slave.cpp:585] Detecting new master
> I0528 23:01:31.164659  2546 status_update_manager.cpp:167] New master detected at master@127.0.1.1:56711
> I0528 23:01:31.164685  2546 authenticatee.hpp:128] Creating new client SASL connection
> I0528 23:01:31.164811  2546 master.cpp:2986] Authenticating slave(46)@127.0.1.1:56711
> I0528 23:01:31.164876  2546 authenticator.hpp:156] Creating new server SASL connection
> I0528 23:01:31.164980  2546 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
> I0528 23:01:31.164999  2546 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0528 23:01:31.165021  2546 authenticator.hpp:262] Received SASL authentication start
> I0528 23:01:31.165051  2546 authenticator.hpp:384] Authentication requires more steps
> I0528 23:01:31.165076  2546 authenticatee.hpp:265] Received SASL authentication step
> I0528 23:01:31.165104  2546 authenticator.hpp:290] Received SASL authentication step
> I0528 23:01:31.165117  2546 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'trusty' server FQDN: 'trusty' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
> I0528 23:01:31.165124  2546 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I0528 23:01:31.165133  2546 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0528 23:01:31.165143  2546 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'trusty' server FQDN: 'trusty' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
> I0528 23:01:31.165148  2546 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0528 23:01:31.165154  2546 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0528 23:01:31.165164  2546 authenticator.hpp:376] Authentication success
> I0528 23:01:31.165186  2546 authenticatee.hpp:305] Authentication success
> I0528 23:01:31.165206  2546 master.cpp:3026] Successfully authenticated principal 'test-principal' at slave(46)@127.0.1.1:56711
> I0528 23:01:31.165261  2546 slave.cpp:669] Successfully authenticated with master master@127.0.1.1:56711
> I0528 23:01:31.165302  2546 slave.cpp:902] Will retry registration in 14.493836ms if necessary
> I0528 23:01:31.165391  2550 master.cpp:2302] Registering slave at slave(46)@127.0.1.1:56711 (trusty) with id 20140528-230130-16842879-56711-2525-0
> I0528 23:01:31.165484  2550 registrar.cpp:422] Attempting to update the 'registry'
> I0528 23:01:31.166597  2548 log.cpp:680] Attempting to append 290 bytes to the log
> I0528 23:01:31.166643  2548 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
> I0528 23:01:31.166854  2548 replica.cpp:508] Replica received write request for position 3
> I0528 23:01:31.167264  2548 leveldb.cpp:343] Persisting action (309 bytes) to leveldb took 388182ns
> I0528 23:01:31.167284  2548 replica.cpp:676] Persisted action at 3
> I0528 23:01:31.167439  2548 replica.cpp:655] Replica received learned notice for position 3
> I0528 23:01:31.168390  2548 leveldb.cpp:343] Persisting action (311 bytes) to leveldb took 930010ns
> I0528 23:01:31.168412  2548 replica.cpp:676] Persisted action at 3
> I0528 23:01:31.168421  2548 replica.cpp:661] Replica learned APPEND action at position 3
> I0528 23:01:31.168673  2548 registrar.cpp:479] Successfully updated 'registry'
> I0528 23:01:31.168738  2548 log.cpp:699] Attempting to truncate the log to 3
> I0528 23:01:31.168784  2548 master.cpp:2342] Registered slave 20140528-230130-16842879-56711-2525-0 at slave(46)@127.0.1.1:56711 (trusty)
> I0528 23:01:31.168800  2548 master.cpp:3472] Adding slave 20140528-230130-16842879-56711-2525-0 at slave(46)@127.0.1.1:56711 (trusty) with cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000]
> I0528 23:01:31.168881  2548 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
> I0528 23:01:31.168939  2548 slave.cpp:703] Registered with master master@127.0.1.1:56711; given slave ID 20140528-230130-16842879-56711-2525-0
> I0528 23:01:31.168999  2548 hierarchical_allocator_process.hpp:444] Added slave 20140528-230130-16842879-56711-2525-0 (trusty) with cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000] available)
> I0528 23:01:31.169050  2548 hierarchical_allocator_process.hpp:751] Offering cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000] on slave 20140528-230130-16842879-56711-2525-0 to framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.169126  2548 hierarchical_allocator_process.hpp:707] Performed allocation for slave 20140528-230130-16842879-56711-2525-0 in 96190ns
> I0528 23:01:31.169203  2548 master.hpp:683] Adding offer 20140528-230130-16842879-56711-2525-0 with resources cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000] on slave 20140528-230130-16842879-56711-2525-0 (trusty)
> I0528 23:01:31.169245  2548 master.cpp:2933] Sending 1 offers to framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.169461  2548 sched.cpp:534] Scheduler::resourceOffers took 116834ns
> I0528 23:01:31.169615  2548 master.hpp:693] Removing offer 20140528-230130-16842879-56711-2525-0 with resources cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000] on slave 20140528-230130-16842879-56711-2525-0 (trusty)
> I0528 23:01:31.169664  2548 master.cpp:1889] Processing reply for offers: [ 20140528-230130-16842879-56711-2525-0 ] on slave 20140528-230130-16842879-56711-2525-0 at slave(46)@127.0.1.1:56711 (trusty) for framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.169745  2548 master.hpp:655] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 20140528-230130-16842879-56711-2525-0 (trusty)
> I0528 23:01:31.169772  2548 master.cpp:3111] Launching task 0 of framework 20140528-230130-16842879-56711-2525-0000 with resources cpus(*):1; mem(*):500 on slave 20140528-230130-16842879-56711-2525-0 at slave(46)@127.0.1.1:56711 (trusty)
> I0528 23:01:31.169911  2548 slave.cpp:933] Got assigned task 0 for framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.170063  2548 slave.cpp:1043] Launching task 0 for framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.170703  2550 hierarchical_allocator_process.hpp:546] Framework 20140528-230130-16842879-56711-2525-0000 left cpus(*):1; mem(*):524; disk(*):24988; ports(*):[31000-32000] unused on slave 20140528-230130-16842879-56711-2525-0
> I0528 23:01:31.171082  2550 hierarchical_allocator_process.hpp:589] Framework 20140528-230130-16842879-56711-2525-0000 filtered slave 20140528-230130-16842879-56711-2525-0 for 5secs
> I0528 23:01:31.170990  2551 replica.cpp:508] Replica received write request for position 4
> I0528 23:01:31.171852  2551 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 577081ns
> I0528 23:01:31.171872  2551 replica.cpp:676] Persisted action at 4
> I0528 23:01:31.172268  2551 replica.cpp:655] Replica received learned notice for position 4
> I0528 23:01:31.172605  2551 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 313596ns
> I0528 23:01:31.172642  2551 leveldb.cpp:401] Deleting ~2 keys from leveldb took 18631ns
> I0528 23:01:31.172653  2551 replica.cpp:676] Persisted action at 4
> I0528 23:01:31.172662  2551 replica.cpp:661] Replica learned TRUNCATE action at position 4
> I0528 23:01:31.174681  2548 exec.cpp:131] Version: 0.19.0
> I0528 23:01:31.175060  2544 exec.cpp:181] Executor started at: executor(1)@127.0.1.1:56711 with pid 2525
> I0528 23:01:31.175324  2548 slave.cpp:1153] Queuing task '0' for executor default of framework '20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.175658  2548 slave.cpp:497] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_FCGlTk/slaves/20140528-230130-16842879-56711-2525-0/frameworks/20140528-230130-16842879-56711-2525-0000/executors/default/runs/8fdd0ca9-af9b-416a-8507-9112f7aa403d'
> I0528 23:01:31.175969  2548 slave.cpp:1664] Got registration for executor 'default' of framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.176446  2545 exec.cpp:205] Executor registered on slave 20140528-230130-16842879-56711-2525-0
> I0528 23:01:31.177356  2545 exec.cpp:217] Executor::registered took 29066ns
> I0528 23:01:31.177556  2548 slave.cpp:1783] Flushing queued task 0 for executor 'default' of framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.177978  2551 exec.cpp:292] Executor asked to run task '0'
> I0528 23:01:31.178040  2551 exec.cpp:301] Executor::launchTask took 42285ns
> I0528 23:01:31.179141  2551 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 08ed6d92-b404-4835-9fa8-85df7c809850) for task 0 of framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.179358  2548 slave.cpp:2355] Monitoring executor 'default' of framework '20140528-230130-16842879-56711-2525-0000' in container '8fdd0ca9-af9b-416a-8507-9112f7aa403d'
> I0528 23:01:31.179858  2548 slave.cpp:2018] Handling status update TASK_RUNNING (UUID: 08ed6d92-b404-4835-9fa8-85df7c809850) for task 0 of framework 20140528-230130-16842879-56711-2525-0000 from executor(1)@127.0.1.1:56711
> I0528 23:01:31.180249  2544 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 08ed6d92-b404-4835-9fa8-85df7c809850) for task 0 of framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.180270  2544 status_update_manager.cpp:499] Creating StatusUpdate stream for task 0 of framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.180320  2544 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 08ed6d92-b404-4835-9fa8-85df7c809850) for task 0 of framework 20140528-230130-16842879-56711-2525-0000 to master@127.0.1.1:56711
> I0528 23:01:31.180428  2544 master.cpp:2628] Status update TASK_RUNNING (UUID: 08ed6d92-b404-4835-9fa8-85df7c809850) for task 0 of framework 20140528-230130-16842879-56711-2525-0000 from slave 20140528-230130-16842879-56711-2525-0 at slave(46)@127.0.1.1:56711 (trusty)
> I0528 23:01:31.180495  2544 sched.cpp:625] Scheduler::statusUpdate took 13954ns
> I0528 23:01:31.180604  2525 master.cpp:574] Master terminating
> I0528 23:01:31.180641  2525 master.hpp:673] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 20140528-230130-16842879-56711-2525-0 (trusty)
> W0528 23:01:31.180707  2525 master.cpp:3758] Removing task 0 of framework 20140528-230130-16842879-56711-2525-0000 and slave 20140528-230130-16842879-56711-2525-0 in non-terminal state TASK_RUNNING
> 2014-05-28 23:01:31,182:2525(0x2b213233aa80):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x1464691adb10001 to [127.0.0.1:44966]
> 2014-05-28 23:01:31,186:2525(0x2b213233aa80):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x1464691adb10000 to [127.0.0.1:44966]
> I0528 23:01:31.189216  2525 contender.cpp:182] Now cancelling the membership: 0
> 2014-05-28 23:01:31,189:2525(0x2b213233aa80):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x1464691adb10003 to [127.0.0.1:44966]
> I0528 23:01:31.198542  2549 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 08ed6d92-b404-4835-9fa8-85df7c809850) for task 0 of framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.198971  2548 slave.cpp:2224] master@127.0.1.1:56711 exited
> W0528 23:01:31.199281  2548 slave.cpp:2227] Master disconnected! Waiting for a new master to be elected
> I0528 23:01:31.199578  2548 slave.cpp:2139] Status update manager successfully handled status update TASK_RUNNING (UUID: 08ed6d92-b404-4835-9fa8-85df7c809850) for task 0 of framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.199882  2548 slave.cpp:2145] Sending acknowledgement for status update TASK_RUNNING (UUID: 08ed6d92-b404-4835-9fa8-85df7c809850) for task 0 of framework 20140528-230130-16842879-56711-2525-0000 to executor(1)@127.0.1.1:56711
> I0528 23:01:31.200449  2546 exec.cpp:338] Executor received status update acknowledgement 08ed6d92-b404-4835-9fa8-85df7c809850 for task 0 of framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.200644  2548 slave.cpp:1604] Status update manager successfully handled status update acknowledgement (UUID: 08ed6d92-b404-4835-9fa8-85df7c809850) for task 0 of framework 20140528-230130-16842879-56711-2525-0000
> I0528 23:01:31.201449  2551 group.cpp:711] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
> I0528 23:01:31.201501  2551 detector.cpp:123] The current leader (id=0) is lost
> I0528 23:01:31.201513  2551 detector.cpp:135] Detected a new leader: None
> I0528 23:01:31.201594  2551 slave.cpp:581] Lost leading master
> I0528 23:01:31.201606  2551 slave.cpp:585] Detecting new master
> I0528 23:01:31.202530  2545 group.cpp:711] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
> I0528 23:01:31.202581  2545 detector.cpp:123] The current leader (id=0) is lost
> I0528 23:01:31.202592  2545 detector.cpp:135] Detected a new leader: None
> I0528 23:01:31.202672  2545 sched.cpp:216] Scheduler::disconnected took 7248ns
> I0528 23:01:31.202795  2545 sched.cpp:238] No master detected
> I0528 23:02:31.141058  2547 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:03:31.141691  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:04:31.141957  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:05:31.142191  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:06:31.143242  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:07:31.143743  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:08:31.145093  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:09:31.145867  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:10:31.146836  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:11:31.147409  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:12:31.148776  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:13:31.149660  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:14:31.150027  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:15:31.150233  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:16:31.151170  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:17:31.151763  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:18:31.152526  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:19:31.153273  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:20:31.154023  2546 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:21:31.155117  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:22:31.156105  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:23:31.157466  2547 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:24:31.158442  2547 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:25:31.159039  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:26:31.159661  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:27:31.159891  2545 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:28:31.160538  2545 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:29:31.161767  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:30:31.162417  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:31:31.165843  2546 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:32:31.170677  2550 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:33:31.171139  2547 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:34:31.172304  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:35:31.173142  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:36:31.173465  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:37:31.174376  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:38:31.174832  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:39:31.175855  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:40:31.176722  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:41:31.177461  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:42:31.178416  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:43:31.178985  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:44:31.179862  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:45:31.180521  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:46:31.181726  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:47:31.181965  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:48:31.183176  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:49:31.183990  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:50:31.184509  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:51:31.185294  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:52:31.186136  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:53:31.187158  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148755232129930days
> I0528 23:54:31.187582  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0528 23:55:31.188880  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0528 23:56:31.189348  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0528 23:57:31.190219  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0528 23:58:31.191210  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0528 23:59:31.191658  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:00:31.192495  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:01:31.193559  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:02:31.194813  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:03:31.195615  2546 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:04:31.196190  2546 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:05:31.196672  2546 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:06:31.196949  2550 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:07:31.197409  2547 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:08:31.198567  2547 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:09:31.199897  2544 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:10:31.201149  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:11:31.201594  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:12:31.202734  2545 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:13:31.203193  2546 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:14:31.203938  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:15:31.212468  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:16:31.213429  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:17:31.214761  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:18:31.216003  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:19:31.217118  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:20:31.218351  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:21:31.219198  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:22:31.220232  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:23:31.220885  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:24:31.221834  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:25:31.223023  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:26:31.223954  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:27:31.225189  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:28:31.226090  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:29:31.226436  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:30:31.227349  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:31:31.227589  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:32:31.228602  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:33:31.228768  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:34:31.229239  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:35:31.229789  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:36:31.230901  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:37:31.231127  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:38:31.232071  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:39:31.232647  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:40:31.233716  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:41:31.234802  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:42:31.236125  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:43:31.238757  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:44:31.240754  2550 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:45:31.241252  2550 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:46:31.242573  2550 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:47:31.243199  2546 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:48:31.243666  2544 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:49:31.244987  2547 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:50:31.245450  2546 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:51:31.245956  2546 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:52:31.246163  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:53:31.247390  2545 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:54:31.248394  2545 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:55:31.249528  2551 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:56:31.250185  2550 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:57:31.250687  2548 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:58:31.251855  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 00:59:31.252113  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:00:31.252485  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:01:31.252909  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:02:31.254098  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:03:31.255105  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:04:31.256420  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:05:31.257699  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:06:31.257926  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:07:31.258950  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:08:31.260201  2549 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:09:31.261404  2544 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:10:31.262702  2544 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:11:31.263573  2544 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:12:31.265055  2544 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:13:31.266525  2544 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:14:31.266850  2544 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:15:31.267858  2544 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> I0529 01:16:31.268621  2544 slave.cpp:2873] Current usage 45.02%. Max allowed age: 3.148754323971123days
> Build timed out (after 240 minutes). Marking the build as failed.
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.2#6252)

Mime
View raw message