You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by "Vinod Kone (JIRA)" <ji...@apache.org> on 2014/06/12 21:41:04 UTC
[jira] [Resolved] (MESOS-1435) RegistrarZooKeeperTest.TaskRunning
is flaky, sometimes runs forever.
[ https://issues.apache.org/jira/browse/MESOS-1435?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Vinod Kone resolved MESOS-1435.
-------------------------------
Resolution: Fixed
Fix Version/s: 0.20.0
The linked ticket should fix this.
> RegistrarZooKeeperTest.TaskRunning is flaky, sometimes runs forever.
> --------------------------------------------------------------------
>
> Key: MESOS-1435
> URL: https://issues.apache.org/jira/browse/MESOS-1435
> Project: Mesos
> Issue Type: Bug
> Components: test
> Reporter: Benjamin Mahler
> Assignee: Dominic Hamon
> Fix For: 0.20.0
>
>
> {noformat}
> [----------] 1 test from RegistrarZooKeeperTest
> I0528 22:41:47.430505 3296 zookeeper_test_server.cpp:158] Started ZooKeeperTestServer on port 55350
> [ RUN ] RegistrarZooKeeperTest.TaskRunning
> Using temporary directory '/tmp/RegistrarZooKeeperTest_TaskRunning_kEyNsO'
> I0528 22:41:47.435749 3296 leveldb.cpp:176] Opened db in 4.577156ms
> I0528 22:41:47.436529 3296 leveldb.cpp:183] Compacted db in 459586ns
> I0528 22:41:47.436895 3296 leveldb.cpp:198] Created db iterator in 20854ns
> I0528 22:41:47.437150 3296 leveldb.cpp:204] Seeked to beginning of db in 1344ns
> I0528 22:41:47.437412 3296 leveldb.cpp:273] Iterated through 0 keys in the db in 704ns
> I0528 22:41:47.437696 3296 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> 2014-05-28 22:41:47,438:3296(0x2b7328010700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 22:41:47,438:3296(0x2b7328010700):ZOO_INFO@log_env@716: Client environment:host.name=saucy
> 2014-05-28 22:41:47,438:3296(0x2b7328010700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 22:41:47,438:3296(0x2b7328010700):ZOO_INFO@log_env@724: Client environment:os.arch=3.11.0-22-generic
> 2014-05-28 22:41:47,438:3296(0x2b7328010700):ZOO_INFO@log_env@725: Client environment:os.version=#38-Ubuntu SMP Thu May 15 20:47:00 UTC 2014
> 2014-05-28 22:41:47,438:3296(0x2b7328010700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 22:41:47,438:3296(0x2b7328010700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 22:41:47,438:3296(0x2b7328010700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/RegistrarZooKeeperTest_TaskRunning_kEyNsO
> 2014-05-28 22:41:47,438:3296(0x2b7328010700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:55350 sessionTimeout=10000 watcher=0x2b7324b602b0 sessionId=0 sessionPasswd=<null> context=0x2b732c024060 flags=0
> 2014-05-28 22:41:47,438:3296(0x2b7328211700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 22:41:47,438:3296(0x2b7328211700):ZOO_INFO@log_env@716: Client environment:host.name=saucy
> 2014-05-28 22:41:47,438:3296(0x2b7328211700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 22:41:47,438:3296(0x2b7328211700):ZOO_INFO@log_env@724: Client environment:os.arch=3.11.0-22-generic
> 2014-05-28 22:41:47,438:3296(0x2b7328211700):ZOO_INFO@log_env@725: Client environment:os.version=#38-Ubuntu SMP Thu May 15 20:47:00 UTC 2014
> 2014-05-28 22:41:47,438:3296(0x2b7328211700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 22:41:47,439:3296(0x2b7328211700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 22:41:47,439:3296(0x2b7328211700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/RegistrarZooKeeperTest_TaskRunning_kEyNsO
> 2014-05-28 22:41:47,439:3296(0x2b7328211700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:55350 sessionTimeout=10000 watcher=0x2b7324b602b0 sessionId=0 sessionPasswd=<null> context=0x2b73300374e0 flags=0
> I0528 22:41:47.439354 3319 log.cpp:238] Attempting to join replica to ZooKeeper group
> I0528 22:41:47.439486 3319 recover.cpp:425] Starting replica recovery
> I0528 22:41:47.439551 3319 recover.cpp:451] Replica is in EMPTY status
> I0528 22:41:47.439867 3319 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request
> I0528 22:41:47.439929 3319 recover.cpp:188] Received a recover response from a replica in EMPTY status
> I0528 22:41:47.440027 3319 recover.cpp:542] Updating replica status to STARTING
> I0528 22:41:47.441241 3319 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 1.153628ms
> I0528 22:41:47.441268 3319 replica.cpp:320] Persisted replica status to STARTING
> I0528 22:41:47.441329 3319 recover.cpp:451] Replica is in STARTING status
> I0528 22:41:47.441565 3319 replica.cpp:638] Replica in STARTING status received a broadcasted recover request
> I0528 22:41:47.441617 3319 recover.cpp:188] Received a recover response from a replica in STARTING status
> I0528 22:41:47.441700 3319 recover.cpp:542] Updating replica status to VOTING
> I0528 22:41:47.442756 3319 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 1.010175ms
> I0528 22:41:47.442781 3319 replica.cpp:320] Persisted replica status to VOTING
> I0528 22:41:47.442841 3318 recover.cpp:556] Successfully joined the Paxos group
> I0528 22:41:47.442909 3317 recover.cpp:440] Recover process terminated
> 2014-05-28 22:41:47,445:3296(0x2b7327e0f700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 22:41:47,445:3296(0x2b7327e0f700):ZOO_INFO@log_env@716: Client environment:host.name=saucy
> 2014-05-28 22:41:47,445:3296(0x2b7327e0f700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 22:41:47,445:3296(0x2b7327e0f700):ZOO_INFO@log_env@724: Client environment:os.arch=3.11.0-22-generic
> 2014-05-28 22:41:47,445:3296(0x2b7327e0f700):ZOO_INFO@log_env@725: Client environment:os.version=#38-Ubuntu SMP Thu May 15 20:47:00 UTC 2014
> 2014-05-28 22:41:47,445:3296(0x2b7327e0f700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 22:41:47,445:3296(0x2b7327e0f700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 22:41:47,445:3296(0x2b7327e0f700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/RegistrarZooKeeperTest_TaskRunning_kEyNsO
> 2014-05-28 22:41:47,445:3296(0x2b7327e0f700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:55350 sessionTimeout=10000 watcher=0x2b7324b602b0 sessionId=0 sessionPasswd=<null> context=0x2b7334022700 flags=0
> 2014-05-28 22:41:47,446:3296(0x2b7327c0e700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 22:41:47,446:3296(0x2b7327c0e700):ZOO_INFO@log_env@716: Client environment:host.name=saucy
> 2014-05-28 22:41:47,446:3296(0x2b7327c0e700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 22:41:47,446:3296(0x2b7327c0e700):ZOO_INFO@log_env@724: Client environment:os.arch=3.11.0-22-generic
> 2014-05-28 22:41:47,446:3296(0x2b7327c0e700):ZOO_INFO@log_env@725: Client environment:os.version=#38-Ubuntu SMP Thu May 15 20:47:00 UTC 2014
> 2014-05-28 22:41:47,446:3296(0x2b7327c0e700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 22:41:47,446:3296(0x2b7327c0e700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 22:41:47,446:3296(0x2b7327c0e700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/RegistrarZooKeeperTest_TaskRunning_kEyNsO
> 2014-05-28 22:41:47,446:3296(0x2b7327c0e700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:55350 sessionTimeout=10000 watcher=0x2b7324b602b0 sessionId=0 sessionPasswd=<null> context=0x2b7338033000 flags=0
> I0528 22:41:47.448636 3316 master.cpp:272] Master 20140528-224147-16842879-49023-3296 (saucy) started on 127.0.1.1:49023
> I0528 22:41:47.448658 3316 master.cpp:309] Master only allowing authenticated frameworks to register
> I0528 22:41:47.448664 3316 master.cpp:314] Master only allowing authenticated slaves to register
> I0528 22:41:47.448670 3316 credentials.hpp:35] Loading credentials for authentication from '/tmp/RegistrarZooKeeperTest_TaskRunning_kEyNsO/credentials'
> I0528 22:41:47.448745 3316 master.cpp:340] Master enabling authorization
> I0528 22:41:47.449457 3316 hierarchical_allocator_process.hpp:301] Initializing hierarchical allocator process with master : master@127.0.1.1:49023
> I0528 22:41:47.449499 3316 master.cpp:108] No whitelist given. Advertising offers for all slaves
> I0528 22:41:47.449676 3316 contender.cpp:127] Joining the ZK group
> 2014-05-28 22:41:47,453:3296(0x2b7353787700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:55350]
> 2014-05-28 22:41:47,461:3296(0x2b7353787700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:55350], sessionId=0x146467f9f250002, negotiated timeout=10000
> I0528 22:41:47.464191 3322 group.cpp:310] Group process ((2782)@127.0.1.1:49023) connected to ZooKeeper
> I0528 22:41:47.464221 3322 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
> I0528 22:41:47.464229 3322 group.cpp:382] Trying to create path '/znode/log_replicas' in ZooKeeper
> 2014-05-28 22:41:47,456:3296(0x2b7353385700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:55350]
> 2014-05-28 22:41:47,464:3296(0x2b7353385700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:55350], sessionId=0x146467f9f250003, negotiated timeout=10000
> 2014-05-28 22:41:47,457:3296(0x2b7353b89700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:55350]
> 2014-05-28 22:41:47,468:3296(0x2b7353b89700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:55350], sessionId=0x146467f9f250001, negotiated timeout=10000
> I0528 22:41:47.469382 3320 group.cpp:310] Group process ((2790)@127.0.1.1:49023) connected to ZooKeeper
> I0528 22:41:47.469403 3320 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0)
> I0528 22:41:47.469409 3320 group.cpp:382] Trying to create path '/znode' in ZooKeeper
> 2014-05-28 22:41:47,456:3296(0x2b7353f8b700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:55350]
> 2014-05-28 22:41:47,469:3296(0x2b7353f8b700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:55350], sessionId=0x146467f9f250000, negotiated timeout=10000
> I0528 22:41:47.470062 3318 group.cpp:310] Group process ((2793)@127.0.1.1:49023) connected to ZooKeeper
> I0528 22:41:47.470082 3318 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
> I0528 22:41:47.470088 3318 group.cpp:382] Trying to create path '/znode' in ZooKeeper
> I0528 22:41:47.479825 3316 group.cpp:310] Group process ((2784)@127.0.1.1:49023) connected to ZooKeeper
> I0528 22:41:47.479859 3316 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0)
> I0528 22:41:47.479868 3316 group.cpp:382] Trying to create path '/znode/log_replicas' in ZooKeeper
> I0528 22:41:47.484319 3317 contender.cpp:243] New candidate (id='1') has entered the contest for leadership
> I0528 22:41:47.486291 3319 group.cpp:711] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
> I0528 22:41:47.486443 3319 detector.cpp:135] Detected a new leader: (id='1')
> I0528 22:41:47.486553 3319 group.cpp:655] Trying to get '/znode/info_0000000001' in ZooKeeper
> I0528 22:41:47.488080 3320 group.cpp:711] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
> I0528 22:41:47.490825 3319 detector.cpp:377] A new leading master (UPID=master@127.0.1.1:49023) is detected
> I0528 22:41:47.490887 3319 master.cpp:957] The newly elected leader is master@127.0.1.1:49023 with id 20140528-224147-16842879-49023-3296
> I0528 22:41:47.490900 3319 master.cpp:970] Elected as the leading master!
> I0528 22:41:47.490906 3319 master.cpp:788] Recovering from registrar
> I0528 22:41:47.490958 3319 registrar.cpp:313] Recovering registrar
> I0528 22:41:47.491181 3319 log.cpp:656] Attempting to start the writer
> I0528 22:41:47.491462 3319 replica.cpp:474] Replica received implicit promise request with proposal 1
> I0528 22:41:47.492318 3319 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 834657ns
> I0528 22:41:47.492339 3319 replica.cpp:342] Persisted promised to 1
> I0528 22:41:47.492496 3319 coordinator.cpp:230] Coordinator attemping to fill missing position
> I0528 22:41:47.492866 3319 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
> I0528 22:41:47.493752 3317 network.hpp:423] ZooKeeper group memberships changed
> I0528 22:41:47.493835 3317 group.cpp:655] Trying to get '/znode/log_replicas/0000000000' in ZooKeeper
> I0528 22:41:47.494487 3319 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 1.599358ms
> I0528 22:41:47.494829 3319 replica.cpp:676] Persisted action at 0
> I0528 22:41:47.497071 3320 replica.cpp:508] Replica received write request for position 0
> I0528 22:41:47.497105 3320 leveldb.cpp:438] Reading position from leveldb took 14621ns
> I0528 22:41:47.497846 3320 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 722385ns
> I0528 22:41:47.497866 3320 replica.cpp:676] Persisted action at 0
> I0528 22:41:47.498241 3320 replica.cpp:655] Replica received learned notice for position 0
> I0528 22:41:47.498695 3320 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 432612ns
> I0528 22:41:47.498714 3320 replica.cpp:676] Persisted action at 0
> I0528 22:41:47.498723 3320 replica.cpp:661] Replica learned NOP action at position 0
> I0528 22:41:47.498858 3320 log.cpp:672] Writer started with ending position 0
> I0528 22:41:47.499080 3320 leveldb.cpp:438] Reading position from leveldb took 10118ns
> I0528 22:41:47.506505 3320 registrar.cpp:346] Successfully fetched the registry (0B)
> I0528 22:41:47.506539 3320 registrar.cpp:422] Attempting to update the 'registry'
> I0528 22:41:47.508394 3317 network.hpp:461] ZooKeeper group PIDs: { log-replica(223)@127.0.1.1:49023 }
> I0528 22:41:47.508941 3319 log.cpp:680] Attempting to append 117 bytes to the log
> I0528 22:41:47.508991 3319 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
> I0528 22:41:47.509184 3319 replica.cpp:508] Replica received write request for position 1
> I0528 22:41:47.510179 3319 leveldb.cpp:343] Persisting action (134 bytes) to leveldb took 974658ns
> I0528 22:41:47.510200 3319 replica.cpp:676] Persisted action at 1
> I0528 22:41:47.510367 3319 replica.cpp:655] Replica received learned notice for position 1
> I0528 22:41:47.510923 3319 leveldb.cpp:343] Persisting action (136 bytes) to leveldb took 538545ns
> I0528 22:41:47.510942 3319 replica.cpp:676] Persisted action at 1
> I0528 22:41:47.510951 3319 replica.cpp:661] Replica learned APPEND action at position 1
> I0528 22:41:47.511188 3319 registrar.cpp:479] Successfully updated 'registry'
> I0528 22:41:47.511222 3319 registrar.cpp:372] Successfully recovered registrar
> I0528 22:41:47.511257 3319 log.cpp:699] Attempting to truncate the log to 1
> I0528 22:41:47.511317 3319 master.cpp:815] Recovered 0 slaves from the Registry (81B) ; allowing 10mins for slaves to re-register
> I0528 22:41:47.511358 3319 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2
> I0528 22:41:47.511947 3317 replica.cpp:508] Replica received write request for position 2
> I0528 22:41:47.512747 3317 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 776138ns
> I0528 22:41:47.512766 3317 replica.cpp:676] Persisted action at 2
> I0528 22:41:47.513780 3317 slave.cpp:143] Slave started on 77)@127.0.1.1:49023
> I0528 22:41:47.513800 3317 credentials.hpp:35] Loading credentials for authentication from '/tmp/RegistrarZooKeeperTest_TaskRunning_WjrV69/credential'
> I0528 22:41:47.514127 3317 slave.cpp:242] Slave using credential for: test-principal
> I0528 22:41:47.514214 3317 slave.cpp:255] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0528 22:41:47.514284 3317 slave.cpp:283] Slave hostname: saucy
> I0528 22:41:47.514294 3317 slave.cpp:284] Slave checkpoint: false
> 2014-05-28 22:41:47,514:3296(0x2b732760b700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-05-28 22:41:47,514:3296(0x2b732760b700):ZOO_INFO@log_env@716: Client environment:host.name=saucy
> 2014-05-28 22:41:47,514:3296(0x2b732760b700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
> 2014-05-28 22:41:47,514:3296(0x2b732760b700):ZOO_INFO@log_env@724: Client environment:os.arch=3.11.0-22-generic
> 2014-05-28 22:41:47,514:3296(0x2b732760b700):ZOO_INFO@log_env@725: Client environment:os.version=#38-Ubuntu SMP Thu May 15 20:47:00 UTC 2014
> 2014-05-28 22:41:47,514:3296(0x2b732760b700):ZOO_INFO@log_env@733: Client environment:user.name=jenkins
> 2014-05-28 22:41:47,514:3296(0x2b732760b700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
> 2014-05-28 22:41:47,514:3296(0x2b732760b700):ZOO_INFO@log_env@753: Client environment:user.dir=/tmp/RegistrarZooKeeperTest_TaskRunning_kEyNsO
> 2014-05-28 22:41:47,514:3296(0x2b732760b700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:55350 sessionTimeout=10000 watcher=0x2b7324b602b0 sessionId=0 sessionPasswd=<null> context=0x2b7344047940 flags=0
> I0528 22:41:47.516696 3296 sched.cpp:126] Version: 0.19.0
> I0528 22:41:47.517285 3319 state.cpp:33] Recovering state from '/tmp/RegistrarZooKeeperTest_TaskRunning_WjrV69/meta'
> I0528 22:41:47.517401 3322 replica.cpp:655] Replica received learned notice for position 2
> I0528 22:41:47.518190 3323 status_update_manager.cpp:193] Recovering status update manager
> I0528 22:41:47.518443 3322 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 747991ns
> I0528 22:41:47.518528 3322 leveldb.cpp:401] Deleting ~1 keys from leveldb took 18114ns
> I0528 22:41:47.518540 3322 replica.cpp:676] Persisted action at 2
> I0528 22:41:47.518548 3322 replica.cpp:661] Replica learned TRUNCATE action at position 2
> I0528 22:41:47.518996 3321 slave.cpp:3018] Finished recovery
> I0528 22:41:47.519532 3316 sched.cpp:222] New master detected at master@127.0.1.1:49023
> I0528 22:41:47.519556 3316 sched.cpp:273] Authenticating with master master@127.0.1.1:49023
> I0528 22:41:47.519624 3316 authenticatee.hpp:128] Creating new client SASL connection
> I0528 22:41:47.519759 3316 master.cpp:2986] Authenticating scheduler(67)@127.0.1.1:49023
> I0528 22:41:47.519834 3316 authenticator.hpp:156] Creating new server SASL connection
> I0528 22:41:47.519938 3316 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
> I0528 22:41:47.519956 3316 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0528 22:41:47.520262 3316 authenticator.hpp:262] Received SASL authentication start
> I0528 22:41:47.520309 3316 authenticator.hpp:384] Authentication requires more steps
> I0528 22:41:47.520344 3316 authenticatee.hpp:265] Received SASL authentication step
> I0528 22:41:47.520378 3316 authenticator.hpp:290] Received SASL authentication step
> I0528 22:41:47.520393 3316 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'saucy' server FQDN: 'saucy' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0528 22:41:47.520401 3316 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I0528 22:41:47.520409 3316 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0528 22:41:47.520417 3316 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'saucy' server FQDN: 'saucy' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0528 22:41:47.520423 3316 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0528 22:41:47.520428 3316 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0528 22:41:47.520438 3316 authenticator.hpp:376] Authentication success
> I0528 22:41:47.520462 3316 authenticatee.hpp:305] Authentication success
> I0528 22:41:47.520480 3316 master.cpp:3026] Successfully authenticated principal 'test-principal' at scheduler(67)@127.0.1.1:49023
> I0528 22:41:47.520541 3316 sched.cpp:347] Successfully authenticated with master master@127.0.1.1:49023
> I0528 22:41:47.520555 3316 sched.cpp:466] Sending registration request to master@127.0.1.1:49023
> I0528 22:41:47.520594 3316 master.cpp:1041] Received registration request from scheduler(67)@127.0.1.1:49023
> I0528 22:41:47.520625 3316 master.cpp:1059] Registering framework 20140528-224147-16842879-49023-3296-0000 at scheduler(67)@127.0.1.1:49023
> I0528 22:41:47.520676 3316 sched.cpp:397] Framework registered with 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.520694 3316 sched.cpp:411] Scheduler::registered took 7583ns
> I0528 22:41:47.520725 3316 hierarchical_allocator_process.hpp:331] Added framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.520732 3316 hierarchical_allocator_process.hpp:725] No resources available to allocate!
> I0528 22:41:47.520737 3316 hierarchical_allocator_process.hpp:687] Performed allocation for 0 slaves in 5496ns
> 2014-05-28 22:41:47,522:3296(0x2b735438d700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:55350]
> 2014-05-28 22:41:47,526:3296(0x2b735438d700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:55350], sessionId=0x146467f9f250004, negotiated timeout=10000
> I0528 22:41:47.528724 3321 group.cpp:310] Group process ((2804)@127.0.1.1:49023) connected to ZooKeeper
> I0528 22:41:47.528745 3321 group.cpp:784] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
> I0528 22:41:47.528754 3321 group.cpp:382] Trying to create path '/znode' in ZooKeeper
> I0528 22:41:47.538012 3321 group.cpp:711] Found non-sequence node 'log_replicas' at '/znode' in ZooKeeper
> I0528 22:41:47.538086 3321 detector.cpp:135] Detected a new leader: (id='1')
> I0528 22:41:47.538197 3321 group.cpp:655] Trying to get '/znode/info_0000000001' in ZooKeeper
> I0528 22:41:47.539271 3321 detector.cpp:377] A new leading master (UPID=master@127.0.1.1:49023) is detected
> I0528 22:41:47.539335 3321 slave.cpp:536] New master detected at master@127.0.1.1:49023
> I0528 22:41:47.539356 3321 slave.cpp:612] Authenticating with master master@127.0.1.1:49023
> I0528 22:41:47.539396 3321 slave.cpp:585] Detecting new master
> I0528 22:41:47.539433 3321 status_update_manager.cpp:167] New master detected at master@127.0.1.1:49023
> I0528 22:41:47.539468 3321 authenticatee.hpp:128] Creating new client SASL connection
> I0528 22:41:47.539998 3321 master.cpp:2986] Authenticating slave(77)@127.0.1.1:49023
> I0528 22:41:47.540081 3321 authenticator.hpp:156] Creating new server SASL connection
> I0528 22:41:47.540186 3321 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
> I0528 22:41:47.540205 3321 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0528 22:41:47.540226 3321 authenticator.hpp:262] Received SASL authentication start
> I0528 22:41:47.540279 3321 authenticator.hpp:384] Authentication requires more steps
> I0528 22:41:47.540305 3321 authenticatee.hpp:265] Received SASL authentication step
> I0528 22:41:47.540336 3321 authenticator.hpp:290] Received SASL authentication step
> I0528 22:41:47.540352 3321 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'saucy' server FQDN: 'saucy' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0528 22:41:47.540359 3321 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I0528 22:41:47.540369 3321 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0528 22:41:47.540377 3321 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'saucy' server FQDN: 'saucy' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0528 22:41:47.540382 3321 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0528 22:41:47.540387 3321 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0528 22:41:47.540397 3321 authenticator.hpp:376] Authentication success
> I0528 22:41:47.540421 3321 authenticatee.hpp:305] Authentication success
> I0528 22:41:47.540442 3321 master.cpp:3026] Successfully authenticated principal 'test-principal' at slave(77)@127.0.1.1:49023
> I0528 22:41:47.540503 3321 slave.cpp:669] Successfully authenticated with master master@127.0.1.1:49023
> I0528 22:41:47.540546 3321 slave.cpp:902] Will retry registration in 8.29487ms if necessary
> I0528 22:41:47.540654 3318 master.cpp:2302] Registering slave at slave(77)@127.0.1.1:49023 (saucy) with id 20140528-224147-16842879-49023-3296-0
> I0528 22:41:47.540753 3318 registrar.cpp:422] Attempting to update the 'registry'
> I0528 22:41:47.542515 3317 log.cpp:680] Attempting to append 287 bytes to the log
> I0528 22:41:47.542569 3317 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
> I0528 22:41:47.543118 3317 replica.cpp:508] Replica received write request for position 3
> I0528 22:41:47.543685 3317 leveldb.cpp:343] Persisting action (306 bytes) to leveldb took 541746ns
> I0528 22:41:47.543705 3317 replica.cpp:676] Persisted action at 3
> I0528 22:41:47.543872 3317 replica.cpp:655] Replica received learned notice for position 3
> I0528 22:41:47.544726 3317 leveldb.cpp:343] Persisting action (308 bytes) to leveldb took 835349ns
> I0528 22:41:47.544747 3317 replica.cpp:676] Persisted action at 3
> I0528 22:41:47.544755 3317 replica.cpp:661] Replica learned APPEND action at position 3
> I0528 22:41:47.545313 3319 registrar.cpp:479] Successfully updated 'registry'
> I0528 22:41:47.545384 3319 log.cpp:699] Attempting to truncate the log to 3
> I0528 22:41:47.545433 3319 master.cpp:2342] Registered slave 20140528-224147-16842879-49023-3296-0 at slave(77)@127.0.1.1:49023 (saucy)
> I0528 22:41:47.545447 3319 master.cpp:3472] Adding slave 20140528-224147-16842879-49023-3296-0 at slave(77)@127.0.1.1:49023 (saucy) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0528 22:41:47.545541 3319 slave.cpp:703] Registered with master master@127.0.1.1:49023; given slave ID 20140528-224147-16842879-49023-3296-0
> I0528 22:41:47.545600 3319 hierarchical_allocator_process.hpp:444] Added slave 20140528-224147-16842879-49023-3296-0 (saucy) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I0528 22:41:47.545652 3319 hierarchical_allocator_process.hpp:751] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140528-224147-16842879-49023-3296-0 to framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.545732 3319 hierarchical_allocator_process.hpp:707] Performed allocation for slave 20140528-224147-16842879-49023-3296-0 in 102725ns
> I0528 22:41:47.545790 3319 master.hpp:683] Adding offer 20140528-224147-16842879-49023-3296-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140528-224147-16842879-49023-3296-0 (saucy)
> I0528 22:41:47.545828 3319 master.cpp:2933] Sending 1 offers to framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.545929 3319 sched.cpp:534] Scheduler::resourceOffers took 17661ns
> I0528 22:41:47.547498 3320 master.hpp:693] Removing offer 20140528-224147-16842879-49023-3296-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140528-224147-16842879-49023-3296-0 (saucy)
> I0528 22:41:47.547549 3320 master.cpp:1889] Processing reply for offers: [ 20140528-224147-16842879-49023-3296-0 ] on slave 20140528-224147-16842879-49023-3296-0 at slave(77)@127.0.1.1:49023 (saucy) for framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.547643 3320 master.hpp:655] Adding task 2a5b4791-0ec0-4383-9152-b5278d15343f with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140528-224147-16842879-49023-3296-0 (saucy)
> I0528 22:41:47.547685 3320 master.cpp:3111] Launching task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140528-224147-16842879-49023-3296-0 at slave(77)@127.0.1.1:49023 (saucy)
> I0528 22:41:47.547803 3320 slave.cpp:933] Got assigned task 2a5b4791-0ec0-4383-9152-b5278d15343f for framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.547966 3320 slave.cpp:1043] Launching task 2a5b4791-0ec0-4383-9152-b5278d15343f for framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.548945 3322 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
> I0528 22:41:47.549118 3322 replica.cpp:508] Replica received write request for position 4
> I0528 22:41:47.549805 3322 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 667416ns
> I0528 22:41:47.549824 3322 replica.cpp:676] Persisted action at 4
> I0528 22:41:47.549988 3322 replica.cpp:655] Replica received learned notice for position 4
> I0528 22:41:47.550354 3322 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 347351ns
> I0528 22:41:47.550390 3322 leveldb.cpp:401] Deleting ~2 keys from leveldb took 17961ns
> I0528 22:41:47.550422 3322 replica.cpp:676] Persisted action at 4
> I0528 22:41:47.550431 3322 replica.cpp:661] Replica learned TRUNCATE action at position 4
> I0528 22:41:47.553100 3320 exec.cpp:131] Version: 0.19.0
> I0528 22:41:47.553578 3319 exec.cpp:181] Executor started at: executor(11)@127.0.1.1:49023 with pid 3296
> I0528 22:41:47.553868 3320 slave.cpp:1153] Queuing task '2a5b4791-0ec0-4383-9152-b5278d15343f' for executor default of framework '20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.554252 3320 slave.cpp:497] Successfully attached file '/tmp/RegistrarZooKeeperTest_TaskRunning_WjrV69/slaves/20140528-224147-16842879-49023-3296-0/frameworks/20140528-224147-16842879-49023-3296-0000/executors/default/runs/345bd98a-9014-4c69-80a6-abe68a207973'
> I0528 22:41:47.554594 3320 slave.cpp:1664] Got registration for executor 'default' of framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.555064 3321 exec.cpp:205] Executor registered on slave 20140528-224147-16842879-49023-3296-0
> I0528 22:41:47.556344 3321 exec.cpp:217] Executor::registered took 15671ns
> I0528 22:41:47.556663 3320 slave.cpp:1783] Flushing queued task 2a5b4791-0ec0-4383-9152-b5278d15343f for executor 'default' of framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.557102 3322 exec.cpp:292] Executor asked to run task '2a5b4791-0ec0-4383-9152-b5278d15343f'
> I0528 22:41:47.557138 3322 exec.cpp:301] Executor::launchTask took 19087ns
> I0528 22:41:47.558537 3322 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 5fef97f8-ab0f-4b6f-b38e-7ff309af316f) for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.559028 3320 slave.cpp:2355] Monitoring executor 'default' of framework '20140528-224147-16842879-49023-3296-0000' in container '345bd98a-9014-4c69-80a6-abe68a207973'
> I0528 22:41:47.559458 3320 slave.cpp:2018] Handling status update TASK_RUNNING (UUID: 5fef97f8-ab0f-4b6f-b38e-7ff309af316f) for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000 from executor(11)@127.0.1.1:49023
> I0528 22:41:47.559830 3318 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 5fef97f8-ab0f-4b6f-b38e-7ff309af316f) for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.559850 3318 status_update_manager.cpp:499] Creating StatusUpdate stream for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.559901 3318 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 5fef97f8-ab0f-4b6f-b38e-7ff309af316f) for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000 to master@127.0.1.1:49023
> I0528 22:41:47.560009 3318 master.cpp:2628] Status update TASK_RUNNING (UUID: 5fef97f8-ab0f-4b6f-b38e-7ff309af316f) for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000 from slave 20140528-224147-16842879-49023-3296-0 at slave(77)@127.0.1.1:49023 (saucy)
> I0528 22:41:47.560073 3318 sched.cpp:625] Scheduler::statusUpdate took 13859ns
> I0528 22:41:47.560170 3296 master.cpp:574] Master terminating
> I0528 22:41:47.560216 3296 master.hpp:673] Removing task 2a5b4791-0ec0-4383-9152-b5278d15343f with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140528-224147-16842879-49023-3296-0 (saucy)
> W0528 22:41:47.560274 3296 master.cpp:3758] Removing task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000 and slave 20140528-224147-16842879-49023-3296-0 in non-terminal state TASK_RUNNING
> I0528 22:41:47.560762 3317 sched.cpp:730] Stopping framework '20140528-224147-16842879-49023-3296-0000'
> I0528 22:41:47.560909 3317 hierarchical_allocator_process.hpp:636] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 20140528-224147-16842879-49023-3296-0 from framework 20140528-224147-16842879-49023-3296-0000
> 2014-05-28 22:41:47,562:3296(0x2b73241f29c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x146467f9f250003 to [127.0.0.1:55350]
> I0528 22:41:47.564553 3317 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 5fef97f8-ab0f-4b6f-b38e-7ff309af316f) for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.564860 3320 slave.cpp:2224] master@127.0.1.1:49023 exited
> W0528 22:41:47.565160 3320 slave.cpp:2227] Master disconnected! Waiting for a new master to be elected
> I0528 22:41:47.565459 3320 slave.cpp:2139] Status update manager successfully handled status update TASK_RUNNING (UUID: 5fef97f8-ab0f-4b6f-b38e-7ff309af316f) for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.565721 3320 slave.cpp:2145] Sending acknowledgement for status update TASK_RUNNING (UUID: 5fef97f8-ab0f-4b6f-b38e-7ff309af316f) for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000 to executor(11)@127.0.1.1:49023
> I0528 22:41:47.566117 3319 exec.cpp:338] Executor received status update acknowledgement 5fef97f8-ab0f-4b6f-b38e-7ff309af316f for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:41:47.566309 3320 slave.cpp:1604] Status update manager successfully handled status update acknowledgement (UUID: 5fef97f8-ab0f-4b6f-b38e-7ff309af316f) for task 2a5b4791-0ec0-4383-9152-b5278d15343f of framework 20140528-224147-16842879-49023-3296-0000
> I0528 22:42:47.515082 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:43:47.516177 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:44:47.516474 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:45:47.516986 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:46:47.518245 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:47:47.518538 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:48:47.519117 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:49:47.520158 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:50:47.520632 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:51:47.521129 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:52:47.521389 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:53:47.522461 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:54:47.523428 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:55:47.523809 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:56:47.524552 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:57:47.525549 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:58:47.526445 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 22:59:47.527374 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:00:47.527632 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:01:47.528265 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:02:47.529364 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:03:47.530076 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:04:47.530315 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:05:47.531229 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:06:47.532495 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:07:47.533521 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:08:47.533995 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:09:47.534975 3321 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:10:47.535697 3321 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:11:47.536598 3321 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:12:47.537813 3321 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:13:47.539047 3321 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:14:47.540438 3319 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:15:47.540669 3319 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:16:47.541628 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:17:47.541877 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:18:47.542110 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:19:47.543016 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:20:47.544267 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:21:47.545068 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:22:47.545936 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:23:47.546763 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:24:47.548024 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:25:47.548250 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:26:47.549260 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:27:47.550212 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:28:47.551414 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:29:47.551719 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085993285073773days
> I0528 23:30:47.552945 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:31:47.554016 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:32:47.555058 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:33:47.555373 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:34:47.556319 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:35:47.556638 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:36:47.557842 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:37:47.558543 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:38:47.559722 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:39:47.560497 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:40:47.561594 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:41:47.561849 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:42:47.562643 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:43:47.563550 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:44:47.564291 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:45:47.565316 3319 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:46:47.566095 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:47:47.566952 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:48:47.567217 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:49:47.567445 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:50:47.567909 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:51:47.569120 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:52:47.569988 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:53:47.571121 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:54:47.572008 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:55:47.573004 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:56:47.573729 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:57:47.575114 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:58:47.575858 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0528 23:59:47.576071 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:00:47.576402 3317 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:01:47.577908 3321 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:02:47.579148 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:03:47.579403 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:04:47.580749 3319 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:05:47.581066 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:06:47.582089 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:07:47.582308 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:08:47.582749 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:09:47.583755 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:10:47.584045 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:11:47.584509 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:12:47.585274 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:13:47.586570 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:14:47.587605 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:15:47.588119 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:16:47.588582 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:17:47.589850 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:18:47.590785 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:19:47.591136 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:20:47.592016 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:21:47.593204 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:22:47.593507 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:23:47.593678 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:24:47.594652 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:25:47.595880 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:26:47.597148 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:27:47.597497 3323 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:28:47.598561 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:29:47.599367 3319 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:30:47.600210 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:31:47.600616 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:32:47.601379 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:33:47.601578 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:34:47.602579 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:35:47.603210 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:36:47.604251 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:37:47.604964 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:38:47.606109 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:39:47.607224 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:40:47.607769 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:41:47.608319 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:42:47.608773 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:43:47.609014 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:44:47.609333 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:45:47.610642 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:46:47.611942 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:47:47.612846 3322 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:48:47.613365 3321 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:49:47.613826 3321 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:50:47.614302 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:51:47.614568 3316 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:52:47.615404 3320 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:53:47.616474 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:54:47.617643 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> I0529 00:55:47.618311 3318 slave.cpp:2873] Current usage 60.20%. Max allowed age: 2.085992376914965days
> Build timed out (after 240 minutes). Marking the build as failed.
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.2#6252)