You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/03/16 15:34:28 UTC
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1821
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1821/changes>
Changes:
[mpark] Refactor cluster test helpers into self-contained objects.
[mpark] Refactor MesosTest and remove cleanup logic.
[mpark] Fixed formatting issues in `src/tests/mesos.{hpp,cpp}`.
[mpark] Especially updated tests to use the updated MesosTest helpers.
[mpark] Especially updated scheduler tests to use the updated MesosTest helpers.
[mpark] Update test suite to use the reworked MesosTest helpers.
------------------------------------------
[...truncated 171435 lines...]
I0316 14:34:25.693614 1273 master.cpp:378] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/NRNIuf/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui" --work_dir="/tmp/NRNIuf/master" --zk_session_timeout="10secs"
I0316 14:34:25.693967 1273 master.cpp:425] Master allowing unauthenticated frameworks to register
I0316 14:34:25.693984 1273 master.cpp:428] Master only allowing authenticated slaves to register
I0316 14:34:25.693996 1273 credentials.hpp:35] Loading credentials for authentication from '/tmp/NRNIuf/credentials'
I0316 14:34:25.694159 1272 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.266881ms
I0316 14:34:25.694195 1272 replica.cpp:320] Persisted replica status to STARTING
I0316 14:34:25.694439 1272 recover.cpp:473] Replica is in STARTING status
I0316 14:34:25.694468 1273 master.cpp:468] Using default 'crammd5' authenticator
I0316 14:34:25.694679 1273 master.cpp:537] Using default 'basic' HTTP authenticator
I0316 14:34:25.694886 1273 master.cpp:571] Authorization enabled
I0316 14:34:25.695179 1272 hierarchical.cpp:144] Initialized hierarchical allocator process
I0316 14:34:25.695225 1276 whitelist_watcher.cpp:77] No whitelist given
I0316 14:34:25.695478 1270 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15617)@172.17.0.3:45919
I0316 14:34:25.695854 1272 recover.cpp:193] Received a recover response from a replica in STARTING status
I0316 14:34:25.696405 1265 recover.cpp:564] Updating replica status to VOTING
I0316 14:34:25.697202 1261 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 637488ns
I0316 14:34:25.697309 1261 replica.cpp:320] Persisted replica status to VOTING
I0316 14:34:25.697528 1269 recover.cpp:578] Successfully joined the Paxos group
I0316 14:34:25.697957 1269 recover.cpp:462] Recover process terminated
I0316 14:34:25.698029 1273 master.cpp:1806] The newly elected leader is master@172.17.0.3:45919 with id a6d44a5f-2e9f-4245-9655-555ae6663a9e
I0316 14:34:25.698230 1273 master.cpp:1819] Elected as the leading master!
I0316 14:34:25.698257 1273 master.cpp:1508] Recovering from registrar
I0316 14:34:25.698500 1261 registrar.cpp:307] Recovering registrar
I0316 14:34:25.699101 1270 log.cpp:659] Attempting to start the writer
I0316 14:34:25.700238 1269 replica.cpp:493] Replica received implicit promise request from (15618)@172.17.0.3:45919 with proposal 1
I0316 14:34:25.700956 1269 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 618043ns
I0316 14:34:25.701006 1269 replica.cpp:342] Persisted promised to 1
I0316 14:34:25.701830 1269 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0316 14:34:25.703053 1273 replica.cpp:388] Replica received explicit promise request from (15619)@172.17.0.3:45919 for position 0 with proposal 2
I0316 14:34:25.703554 1273 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 457906ns
I0316 14:34:25.703579 1273 replica.cpp:712] Persisted action at 0
I0316 14:34:25.704733 1262 replica.cpp:537] Replica received write request for position 0 from (15620)@172.17.0.3:45919
I0316 14:34:25.704793 1262 leveldb.cpp:436] Reading position from leveldb took 28766ns
I0316 14:34:25.705266 1262 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 423966ns
I0316 14:34:25.705289 1262 replica.cpp:712] Persisted action at 0
I0316 14:34:25.705811 1268 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0316 14:34:25.706243 1268 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 403467ns
I0316 14:34:25.706269 1268 replica.cpp:712] Persisted action at 0
I0316 14:34:25.706305 1268 replica.cpp:697] Replica learned NOP action at position 0
I0316 14:34:25.706846 1268 log.cpp:675] Writer started with ending position 0
I0316 14:34:25.707998 1269 leveldb.cpp:436] Reading position from leveldb took 49372ns
I0316 14:34:25.709146 1274 registrar.cpp:340] Successfully fetched the registry (0B) in 10.578176ms
I0316 14:34:25.709329 1274 registrar.cpp:439] Applied 1 operations in 78812ns; attempting to update the 'registry'
I0316 14:34:25.710098 1276 log.cpp:683] Attempting to append 170 bytes to the log
I0316 14:34:25.710239 1275 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0316 14:34:25.710973 1269 replica.cpp:537] Replica received write request for position 1 from (15621)@172.17.0.3:45919
I0316 14:34:25.711562 1269 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 544267ns
I0316 14:34:25.711596 1269 replica.cpp:712] Persisted action at 1
I0316 14:34:25.712240 1273 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0316 14:34:25.712647 1273 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 378523ns
I0316 14:34:25.712674 1273 replica.cpp:712] Persisted action at 1
I0316 14:34:25.712698 1273 replica.cpp:697] Replica learned APPEND action at position 1
I0316 14:34:25.713765 1274 registrar.cpp:484] Successfully updated the 'registry' in 4.36992ms
I0316 14:34:25.713903 1274 registrar.cpp:370] Successfully recovered registrar
I0316 14:34:25.714059 1272 log.cpp:702] Attempting to truncate the log to 1
I0316 14:34:25.714329 1270 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0316 14:34:25.714527 1262 master.cpp:1616] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0316 14:34:25.714555 1276 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0316 14:34:25.715176 1274 replica.cpp:537] Replica received write request for position 2 from (15622)@172.17.0.3:45919
I0316 14:34:25.715608 1274 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 398648ns
I0316 14:34:25.715632 1274 replica.cpp:712] Persisted action at 2
I0316 14:34:25.716334 1268 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0316 14:34:25.716732 1268 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 365171ns
I0316 14:34:25.716780 1268 leveldb.cpp:399] Deleting ~1 keys from leveldb took 25514ns
I0316 14:34:25.716799 1268 replica.cpp:712] Persisted action at 2
I0316 14:34:25.716815 1268 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0316 14:34:25.725514 1242 scheduler.cpp:172] Version: 0.29.0
I0316 14:34:25.726346 1271 scheduler.cpp:437] New master detected at master@172.17.0.3:45919
I0316 14:34:25.728546 1272 scheduler.cpp:337] Connected with the master at http://172.17.0.3:45919/master/api/v1/scheduler
I0316 14:34:25.730216 1267 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.3:45919/master/api/v1/scheduler
I0316 14:34:25.731333 1271 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0316 14:34:25.731999 1272 http.cpp:312] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54719
I0316 14:34:25.732342 1272 master.cpp:2068] Received subscription request for HTTP framework 'default'
I0316 14:34:25.732416 1272 master.cpp:1845] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0316 14:34:25.732769 1269 master.cpp:2159] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0316 14:34:25.733283 1267 hierarchical.cpp:265] Added framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000
I0316 14:34:25.733393 1267 hierarchical.cpp:1453] No resources available to allocate!
I0316 14:34:25.733399 1273 master.hpp:1715] Sending heartbeat to a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000
I0316 14:34:25.733446 1267 hierarchical.cpp:1548] No inverse offers to send out!
I0316 14:34:25.733490 1267 hierarchical.cpp:1130] Performed allocation for 0 slaves in 169672ns
I0316 14:34:25.734273 1269 scheduler.cpp:612] Enqueuing event SUBSCRIBED received from http://172.17.0.3:45919/master/api/v1/scheduler
I0316 14:34:25.734899 1269 scheduler.cpp:612] Enqueuing event HEARTBEAT received from http://172.17.0.3:45919/master/api/v1/scheduler
I0316 14:34:25.735852 1261 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.3:45919/master/api/v1/scheduler
I0316 14:34:25.737081 1263 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0316 14:34:25.737521 1271 http.cpp:312] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54720
I0316 14:34:25.737709 1271 master.cpp:2765] Processing REQUEST call for framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default)
I0316 14:34:25.737917 1272 hierarchical.cpp:589] Received resource request from framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000
I0316 14:34:25.740458 1269 master.cpp:1251] Framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default) disconnected
I0316 14:34:25.740497 1269 master.cpp:2622] Disconnecting framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default)
I0316 14:34:25.740535 1269 master.cpp:2646] Deactivating framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default)
I0316 14:34:25.740736 1271 hierarchical.cpp:375] Deactivated framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000
I0316 14:34:25.740695 1269 master.cpp:1275] Giving framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default) 0ns to failover
I0316 14:34:25.742264 1274 master.cpp:5340] Framework failover timeout, removing framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default)
I0316 14:34:25.742372 1274 master.cpp:6073] Removing framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default)
I0316 14:34:25.742709 1275 hierarchical.cpp:326] Removed framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000
I0316 14:34:25.750900 1242 master.cpp:1065] Master terminating
[ OK ] ContentType/SchedulerTest.Request/0 (75 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0316 14:34:25.760467 1242 cluster.cpp:139] Creating default 'local' authorizer
I0316 14:34:25.763375 1242 leveldb.cpp:174] Opened db in 2.631728ms
I0316 14:34:25.764204 1242 leveldb.cpp:181] Compacted db in 786101ns
I0316 14:34:25.764262 1242 leveldb.cpp:196] Created db iterator in 23268ns
I0316 14:34:25.764389 1242 leveldb.cpp:202] Seeked to beginning of db in 2358ns
I0316 14:34:25.764498 1242 leveldb.cpp:271] Iterated through 0 keys in the db in 585ns
I0316 14:34:25.764565 1242 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0316 14:34:25.765300 1274 recover.cpp:447] Starting replica recovery
I0316 14:34:25.765755 1274 recover.cpp:473] Replica is in EMPTY status
I0316 14:34:25.767058 1265 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (15630)@172.17.0.3:45919
I0316 14:34:25.767719 1263 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0316 14:34:25.768309 1265 recover.cpp:564] Updating replica status to STARTING
I0316 14:34:25.769213 1275 master.cpp:376] Master 8a03f08d-bf92-44a0-9aae-e601dabec71c (2cbb23302fe5) started on 172.17.0.3:45919
I0316 14:34:25.769423 1268 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 802608ns
I0316 14:34:25.769467 1268 replica.cpp:320] Persisted replica status to STARTING
I0316 14:34:25.769240 1275 master.cpp:378] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/v8ttt3/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui" --work_dir="/tmp/v8ttt3/master" --zk_session_timeout="10secs"
I0316 14:34:25.769635 1275 master.cpp:425] Master allowing unauthenticated frameworks to register
I0316 14:34:25.769645 1275 master.cpp:428] Master only allowing authenticated slaves to register
I0316 14:34:25.769652 1275 credentials.hpp:35] Loading credentials for authentication from '/tmp/v8ttt3/credentials'
I0316 14:34:25.770046 1275 master.cpp:468] Using default 'crammd5' authenticator
I0316 14:34:25.770040 1268 recover.cpp:473] Replica is in STARTING status
I0316 14:34:25.770254 1275 master.cpp:537] Using default 'basic' HTTP authenticator
I0316 14:34:25.770455 1275 master.cpp:571] Authorization enabled
I0316 14:34:25.770663 1267 whitelist_watcher.cpp:77] No whitelist given
I0316 14:34:25.770763 1264 hierarchical.cpp:144] Initialized hierarchical allocator process
I0316 14:34:25.771503 1269 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15632)@172.17.0.3:45919
I0316 14:34:25.772037 1261 recover.cpp:193] Received a recover response from a replica in STARTING status
I0316 14:34:25.772578 1265 recover.cpp:564] Updating replica status to VOTING
I0316 14:34:25.773263 1261 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 504125ns
I0316 14:34:25.773294 1261 replica.cpp:320] Persisted replica status to VOTING
I0316 14:34:25.773406 1275 recover.cpp:578] Successfully joined the Paxos group
I0316 14:34:25.773576 1261 master.cpp:1806] The newly elected leader is master@172.17.0.3:45919 with id 8a03f08d-bf92-44a0-9aae-e601dabec71c
I0316 14:34:25.773736 1261 master.cpp:1819] Elected as the leading master!
I0316 14:34:25.773746 1275 recover.cpp:462] Recover process terminated
I0316 14:34:25.773774 1261 master.cpp:1508] Recovering from registrar
I0316 14:34:25.774015 1276 registrar.cpp:307] Recovering registrar
I0316 14:34:25.774781 1261 log.cpp:659] Attempting to start the writer
I0316 14:34:25.776232 1262 replica.cpp:493] Replica received implicit promise request from (15633)@172.17.0.3:45919 with proposal 1
I0316 14:34:25.776703 1262 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 426458ns
I0316 14:34:25.776729 1262 replica.cpp:342] Persisted promised to 1
I0316 14:34:25.777372 1263 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0316 14:34:25.778818 1266 replica.cpp:388] Replica received explicit promise request from (15634)@172.17.0.3:45919 for position 0 with proposal 2
I0316 14:34:25.779248 1266 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 374975ns
I0316 14:34:25.779283 1266 replica.cpp:712] Persisted action at 0
I0316 14:34:25.780740 1268 replica.cpp:537] Replica received write request for position 0 from (15635)@172.17.0.3:45919
I0316 14:34:25.780838 1268 leveldb.cpp:436] Reading position from leveldb took 46911ns
I0316 14:34:25.781334 1268 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 429536ns
I0316 14:34:25.781366 1268 replica.cpp:712] Persisted action at 0
I0316 14:34:25.782116 1267 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0316 14:34:25.782632 1267 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 454952ns
I0316 14:34:25.782660 1267 replica.cpp:712] Persisted action at 0
I0316 14:34:25.782692 1267 replica.cpp:697] Replica learned NOP action at position 0
I0316 14:34:25.783316 1262 log.cpp:675] Writer started with ending position 0
I0316 14:34:25.784416 1266 leveldb.cpp:436] Reading position from leveldb took 40346ns
I0316 14:34:25.785414 1275 registrar.cpp:340] Successfully fetched the registry (0B) in 11.233024ms
I0316 14:34:25.785598 1275 registrar.cpp:439] Applied 1 operations in 33290ns; attempting to update the 'registry'
I0316 14:34:25.786360 1261 log.cpp:683] Attempting to append 170 bytes to the log
I0316 14:34:25.786527 1271 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0316 14:34:25.787273 1273 replica.cpp:537] Replica received write request for position 1 from (15636)@172.17.0.3:45919
I0316 14:34:25.787727 1273 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 415025ns
I0316 14:34:25.787755 1273 replica.cpp:712] Persisted action at 1
I0316 14:34:25.788522 1268 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0316 14:34:25.788976 1268 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 424139ns
I0316 14:34:25.789003 1268 replica.cpp:712] Persisted action at 1
I0316 14:34:25.789046 1268 replica.cpp:697] Replica learned APPEND action at position 1
I0316 14:34:25.790257 1267 registrar.cpp:484] Successfully updated the 'registry' in 4.585984ms
I0316 14:34:25.790406 1267 registrar.cpp:370] Successfully recovered registrar
I0316 14:34:25.790956 1270 master.cpp:1616] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0316 14:34:25.791084 1272 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0316 14:34:25.791589 1269 log.cpp:702] Attempting to truncate the log to 1
I0316 14:34:25.791817 1276 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0316 14:34:25.792682 1273 replica.cpp:537] Replica received write request for position 2 from (15637)@172.17.0.3:45919
I0316 14:34:25.793195 1273 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 467536ns
I0316 14:34:25.793329 1273 replica.cpp:712] Persisted action at 2
I0316 14:34:25.794317 1267 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0316 14:34:25.794713 1267 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 364635ns
I0316 14:34:25.794809 1267 leveldb.cpp:399] Deleting ~1 keys from leveldb took 70837ns
I0316 14:34:25.794836 1267 replica.cpp:712] Persisted action at 2
I0316 14:34:25.794864 1267 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0316 14:34:25.802239 1242 scheduler.cpp:172] Version: 0.29.0
I0316 14:34:25.803004 1265 scheduler.cpp:437] New master detected at master@172.17.0.3:45919
I0316 14:34:25.804595 1263 scheduler.cpp:337] Connected with the master at http://172.17.0.3:45919/master/api/v1/scheduler
I0316 14:34:25.805811 1268 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.3:45919/master/api/v1/scheduler
I0316 14:34:25.806689 1273 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0316 14:34:25.807131 1270 http.cpp:312] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54741
I0316 14:34:25.807474 1270 master.cpp:2068] Received subscription request for HTTP framework 'default'
I0316 14:34:25.807533 1270 master.cpp:1845] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0316 14:34:25.807785 1270 master.cpp:2159] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0316 14:34:25.808226 1261 hierarchical.cpp:265] Added framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000
I0316 14:34:25.808317 1270 master.hpp:1715] Sending heartbeat to 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000
I0316 14:34:25.808353 1261 hierarchical.cpp:1453] No resources available to allocate!
I0316 14:34:25.808404 1261 hierarchical.cpp:1548] No inverse offers to send out!
I0316 14:34:25.808434 1261 hierarchical.cpp:1130] Performed allocation for 0 slaves in 169581ns
I0316 14:34:25.809084 1265 scheduler.cpp:612] Enqueuing event SUBSCRIBED received from http://172.17.0.3:45919/master/api/v1/scheduler
I0316 14:34:25.809528 1265 scheduler.cpp:612] Enqueuing event HEARTBEAT received from http://172.17.0.3:45919/master/api/v1/scheduler
I0316 14:34:25.810348 1271 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.3:45919/master/api/v1/scheduler
I0316 14:34:25.811244 1269 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0316 14:34:25.812198 1262 http.cpp:312] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54742
I0316 14:34:25.812505 1262 master.cpp:2765] Processing REQUEST call for framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default)
I0316 14:34:25.812748 1266 hierarchical.cpp:589] Received resource request from framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000
I0316 14:34:25.815428 1265 master.cpp:1251] Framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default) disconnected
I0316 14:34:25.815477 1265 master.cpp:2622] Disconnecting framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default)
I0316 14:34:25.815506 1265 master.cpp:2646] Deactivating framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default)
I0316 14:34:25.815649 1265 master.cpp:1275] Giving framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default) 0ns to failover
I0316 14:34:25.815690 1267 hierarchical.cpp:375] Deactivated framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000
I0316 14:34:25.817137 1275 master.cpp:5340] Framework failover timeout, removing framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default)
I0316 14:34:25.817170 1275 master.cpp:6073] Removing framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default)
I0316 14:34:25.817497 1262 hierarchical.cpp:326] Removed framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000
I0316 14:34:25.825148 1242 master.cpp:1065] Master terminating
[ OK ] ContentType/SchedulerTest.Request/1 (73 ms)
[----------] 26 tests from ContentType/SchedulerTest (5096 ms total)
[----------] Global test environment tear-down
E0316 14:34:25.962769 1242 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_WriteRead_eUjj2c': No such file or directory
E0316 14:34:25.962831 1242 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_LostZooKeeper_6Sngur': No such file or directory
[==========] 1026 tests from 130 test cases ran. (342527 ms total)
[ PASSED ] 1025 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ContainerLoggerTest.LOGROTATE_RotateInSandbox
1 FAILED TEST
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.29.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1458136958-22834
Untagged: mesos-1458136958-22834:latest
Deleted: 3da4ae2e59e018cb2c8ebc2605f8c8d92e1412b03506ae36b5a5757bcfb19182
Deleted: a7210d6f5bf7e68b9110ba16258a5a7b25cc68ff360ef736dbfda3c4e2f1dde8
Deleted: 1dc586915bc033c4f18e4840e9dde93b159a3790619d7fa9d35b9f9e55c7eb8e
Deleted: 63a748f876b05ef362586ab94fcdcb9c2fa19bede9efd82235f53728388b883c
Deleted: 85c905dc5e1f8c7037cb121096bd64edb92b5691712e730711c86ef2078eb830
Deleted: 6fc18598941bcc8ae9fb7c18a5036b94179e2c221d04ab05517a882bf06254a0
Deleted: 6239a866e3495ccc56968aa5bb682a5546b7cbce45e0d92149d814b2023020d8
Deleted: 773d8a4b0c21cd1569922daf6c13ee4ba84badbf7db1935c8b0881b74f741320
Deleted: 530879693fe158ee1f3f0f926e7196a93130d53b5a9b87be465da0a96ee85d07
Deleted: 6936675e29b8e66ad5ca911e98034561107323bd10e88ded0bb6f263e06ee137
Deleted: 8dd47b7c59e866b88e8e7ff6d69d27c87be515ff71f00a15db27d42ac7499390
Deleted: 4ed5e46657f3b8f1cf12eba76fffcd51675e063ccd8da83e6693cdb491998b71
Deleted: c82b02e42b44825d2c771eb427939ffc64ffd79817ad72dfe718d24f2ed533c6
Deleted: 76730af2886146056c6c9d93600e93b938455ff19653ab7f6ffbd40002de1ff9
Deleted: 233079ce44e433f00b79f8c2aca140b31dce0310c3897721ce5a4c11b0608913
Deleted: 857ac85df7cae026d46eda305769f1ed35f763d1f724fb2d2001f3faf4ed32df
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1822
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1822/changes>
Re: Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1821
Posted by Joseph Wu <jo...@mesosphere.io>.
This isn't related to the test refactor. Looks like this was flaky before
:( The problem is fairly trivial though.
Filed: https://issues.apache.org/jira/browse/MESOS-4961
On Wed, Mar 16, 2016 at 7:34 AM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1821/changes
> >
>
> Changes:
>
> [mpark] Refactor cluster test helpers into self-contained objects.
>
> [mpark] Refactor MesosTest and remove cleanup logic.
>
> [mpark] Fixed formatting issues in `src/tests/mesos.{hpp,cpp}`.
>
> [mpark] Especially updated tests to use the updated MesosTest helpers.
>
> [mpark] Especially updated scheduler tests to use the updated MesosTest
> helpers.
>
> [mpark] Update test suite to use the reworked MesosTest helpers.
>
> ------------------------------------------
> [...truncated 171435 lines...]
> I0316 14:34:25.693614 1273 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/NRNIuf/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui"
> --work_dir="/tmp/NRNIuf/master" --zk_session_timeout="10secs"
> I0316 14:34:25.693967 1273 master.cpp:425] Master allowing
> unauthenticated frameworks to register
> I0316 14:34:25.693984 1273 master.cpp:428] Master only allowing
> authenticated slaves to register
> I0316 14:34:25.693996 1273 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/NRNIuf/credentials'
> I0316 14:34:25.694159 1272 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 1.266881ms
> I0316 14:34:25.694195 1272 replica.cpp:320] Persisted replica status to
> STARTING
> I0316 14:34:25.694439 1272 recover.cpp:473] Replica is in STARTING status
> I0316 14:34:25.694468 1273 master.cpp:468] Using default 'crammd5'
> authenticator
> I0316 14:34:25.694679 1273 master.cpp:537] Using default 'basic' HTTP
> authenticator
> I0316 14:34:25.694886 1273 master.cpp:571] Authorization enabled
> I0316 14:34:25.695179 1272 hierarchical.cpp:144] Initialized hierarchical
> allocator process
> I0316 14:34:25.695225 1276 whitelist_watcher.cpp:77] No whitelist given
> I0316 14:34:25.695478 1270 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (15617)@172.17.0.3:45919
> I0316 14:34:25.695854 1272 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0316 14:34:25.696405 1265 recover.cpp:564] Updating replica status to
> VOTING
> I0316 14:34:25.697202 1261 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 637488ns
> I0316 14:34:25.697309 1261 replica.cpp:320] Persisted replica status to
> VOTING
> I0316 14:34:25.697528 1269 recover.cpp:578] Successfully joined the Paxos
> group
> I0316 14:34:25.697957 1269 recover.cpp:462] Recover process terminated
> I0316 14:34:25.698029 1273 master.cpp:1806] The newly elected leader is
> master@172.17.0.3:45919 with id a6d44a5f-2e9f-4245-9655-555ae6663a9e
> I0316 14:34:25.698230 1273 master.cpp:1819] Elected as the leading master!
> I0316 14:34:25.698257 1273 master.cpp:1508] Recovering from registrar
> I0316 14:34:25.698500 1261 registrar.cpp:307] Recovering registrar
> I0316 14:34:25.699101 1270 log.cpp:659] Attempting to start the writer
> I0316 14:34:25.700238 1269 replica.cpp:493] Replica received implicit
> promise request from (15618)@172.17.0.3:45919 with proposal 1
> I0316 14:34:25.700956 1269 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 618043ns
> I0316 14:34:25.701006 1269 replica.cpp:342] Persisted promised to 1
> I0316 14:34:25.701830 1269 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0316 14:34:25.703053 1273 replica.cpp:388] Replica received explicit
> promise request from (15619)@172.17.0.3:45919 for position 0 with
> proposal 2
> I0316 14:34:25.703554 1273 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 457906ns
> I0316 14:34:25.703579 1273 replica.cpp:712] Persisted action at 0
> I0316 14:34:25.704733 1262 replica.cpp:537] Replica received write
> request for position 0 from (15620)@172.17.0.3:45919
> I0316 14:34:25.704793 1262 leveldb.cpp:436] Reading position from leveldb
> took 28766ns
> I0316 14:34:25.705266 1262 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 423966ns
> I0316 14:34:25.705289 1262 replica.cpp:712] Persisted action at 0
> I0316 14:34:25.705811 1268 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0316 14:34:25.706243 1268 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 403467ns
> I0316 14:34:25.706269 1268 replica.cpp:712] Persisted action at 0
> I0316 14:34:25.706305 1268 replica.cpp:697] Replica learned NOP action at
> position 0
> I0316 14:34:25.706846 1268 log.cpp:675] Writer started with ending
> position 0
> I0316 14:34:25.707998 1269 leveldb.cpp:436] Reading position from leveldb
> took 49372ns
> I0316 14:34:25.709146 1274 registrar.cpp:340] Successfully fetched the
> registry (0B) in 10.578176ms
> I0316 14:34:25.709329 1274 registrar.cpp:439] Applied 1 operations in
> 78812ns; attempting to update the 'registry'
> I0316 14:34:25.710098 1276 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0316 14:34:25.710239 1275 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0316 14:34:25.710973 1269 replica.cpp:537] Replica received write
> request for position 1 from (15621)@172.17.0.3:45919
> I0316 14:34:25.711562 1269 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 544267ns
> I0316 14:34:25.711596 1269 replica.cpp:712] Persisted action at 1
> I0316 14:34:25.712240 1273 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0316 14:34:25.712647 1273 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 378523ns
> I0316 14:34:25.712674 1273 replica.cpp:712] Persisted action at 1
> I0316 14:34:25.712698 1273 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0316 14:34:25.713765 1274 registrar.cpp:484] Successfully updated the
> 'registry' in 4.36992ms
> I0316 14:34:25.713903 1274 registrar.cpp:370] Successfully recovered
> registrar
> I0316 14:34:25.714059 1272 log.cpp:702] Attempting to truncate the log to
> 1
> I0316 14:34:25.714329 1270 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0316 14:34:25.714527 1262 master.cpp:1616] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0316 14:34:25.714555 1276 hierarchical.cpp:171] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0316 14:34:25.715176 1274 replica.cpp:537] Replica received write
> request for position 2 from (15622)@172.17.0.3:45919
> I0316 14:34:25.715608 1274 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 398648ns
> I0316 14:34:25.715632 1274 replica.cpp:712] Persisted action at 2
> I0316 14:34:25.716334 1268 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0316 14:34:25.716732 1268 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 365171ns
> I0316 14:34:25.716780 1268 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 25514ns
> I0316 14:34:25.716799 1268 replica.cpp:712] Persisted action at 2
> I0316 14:34:25.716815 1268 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0316 14:34:25.725514 1242 scheduler.cpp:172] Version: 0.29.0
> I0316 14:34:25.726346 1271 scheduler.cpp:437] New master detected at
> master@172.17.0.3:45919
> I0316 14:34:25.728546 1272 scheduler.cpp:337] Connected with the master
> at http://172.17.0.3:45919/master/api/v1/scheduler
> I0316 14:34:25.730216 1267 scheduler.cpp:230] Sending SUBSCRIBE call to
> http://172.17.0.3:45919/master/api/v1/scheduler
> I0316 14:34:25.731333 1271 process.cpp:3136] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0316 14:34:25.731999 1272 http.cpp:312] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.3:54719
> I0316 14:34:25.732342 1272 master.cpp:2068] Received subscription request
> for HTTP framework 'default'
> I0316 14:34:25.732416 1272 master.cpp:1845] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0316 14:34:25.732769 1269 master.cpp:2159] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0316 14:34:25.733283 1267 hierarchical.cpp:265] Added framework
> a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000
> I0316 14:34:25.733393 1267 hierarchical.cpp:1453] No resources available
> to allocate!
> I0316 14:34:25.733399 1273 master.hpp:1715] Sending heartbeat to
> a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000
> I0316 14:34:25.733446 1267 hierarchical.cpp:1548] No inverse offers to
> send out!
> I0316 14:34:25.733490 1267 hierarchical.cpp:1130] Performed allocation
> for 0 slaves in 169672ns
> I0316 14:34:25.734273 1269 scheduler.cpp:612] Enqueuing event SUBSCRIBED
> received from http://172.17.0.3:45919/master/api/v1/scheduler
> I0316 14:34:25.734899 1269 scheduler.cpp:612] Enqueuing event HEARTBEAT
> received from http://172.17.0.3:45919/master/api/v1/scheduler
> I0316 14:34:25.735852 1261 scheduler.cpp:230] Sending REQUEST call to
> http://172.17.0.3:45919/master/api/v1/scheduler
> I0316 14:34:25.737081 1263 process.cpp:3136] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0316 14:34:25.737521 1271 http.cpp:312] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.3:54720
> I0316 14:34:25.737709 1271 master.cpp:2765] Processing REQUEST call for
> framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default)
> I0316 14:34:25.737917 1272 hierarchical.cpp:589] Received resource
> request from framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000
> I0316 14:34:25.740458 1269 master.cpp:1251] Framework
> a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default) disconnected
> I0316 14:34:25.740497 1269 master.cpp:2622] Disconnecting framework
> a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default)
> I0316 14:34:25.740535 1269 master.cpp:2646] Deactivating framework
> a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default)
> I0316 14:34:25.740736 1271 hierarchical.cpp:375] Deactivated framework
> a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000
> I0316 14:34:25.740695 1269 master.cpp:1275] Giving framework
> a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default) 0ns to failover
> I0316 14:34:25.742264 1274 master.cpp:5340] Framework failover timeout,
> removing framework a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default)
> I0316 14:34:25.742372 1274 master.cpp:6073] Removing framework
> a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000 (default)
> I0316 14:34:25.742709 1275 hierarchical.cpp:326] Removed framework
> a6d44a5f-2e9f-4245-9655-555ae6663a9e-0000
> I0316 14:34:25.750900 1242 master.cpp:1065] Master terminating
> [ OK ] ContentType/SchedulerTest.Request/0 (75 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I0316 14:34:25.760467 1242 cluster.cpp:139] Creating default 'local'
> authorizer
> I0316 14:34:25.763375 1242 leveldb.cpp:174] Opened db in 2.631728ms
> I0316 14:34:25.764204 1242 leveldb.cpp:181] Compacted db in 786101ns
> I0316 14:34:25.764262 1242 leveldb.cpp:196] Created db iterator in 23268ns
> I0316 14:34:25.764389 1242 leveldb.cpp:202] Seeked to beginning of db in
> 2358ns
> I0316 14:34:25.764498 1242 leveldb.cpp:271] Iterated through 0 keys in
> the db in 585ns
> I0316 14:34:25.764565 1242 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0316 14:34:25.765300 1274 recover.cpp:447] Starting replica recovery
> I0316 14:34:25.765755 1274 recover.cpp:473] Replica is in EMPTY status
> I0316 14:34:25.767058 1265 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (15630)@172.17.0.3:45919
> I0316 14:34:25.767719 1263 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0316 14:34:25.768309 1265 recover.cpp:564] Updating replica status to
> STARTING
> I0316 14:34:25.769213 1275 master.cpp:376] Master
> 8a03f08d-bf92-44a0-9aae-e601dabec71c (2cbb23302fe5) started on
> 172.17.0.3:45919
> I0316 14:34:25.769423 1268 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 802608ns
> I0316 14:34:25.769467 1268 replica.cpp:320] Persisted replica status to
> STARTING
> I0316 14:34:25.769240 1275 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/v8ttt3/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui"
> --work_dir="/tmp/v8ttt3/master" --zk_session_timeout="10secs"
> I0316 14:34:25.769635 1275 master.cpp:425] Master allowing
> unauthenticated frameworks to register
> I0316 14:34:25.769645 1275 master.cpp:428] Master only allowing
> authenticated slaves to register
> I0316 14:34:25.769652 1275 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/v8ttt3/credentials'
> I0316 14:34:25.770046 1275 master.cpp:468] Using default 'crammd5'
> authenticator
> I0316 14:34:25.770040 1268 recover.cpp:473] Replica is in STARTING status
> I0316 14:34:25.770254 1275 master.cpp:537] Using default 'basic' HTTP
> authenticator
> I0316 14:34:25.770455 1275 master.cpp:571] Authorization enabled
> I0316 14:34:25.770663 1267 whitelist_watcher.cpp:77] No whitelist given
> I0316 14:34:25.770763 1264 hierarchical.cpp:144] Initialized hierarchical
> allocator process
> I0316 14:34:25.771503 1269 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (15632)@172.17.0.3:45919
> I0316 14:34:25.772037 1261 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0316 14:34:25.772578 1265 recover.cpp:564] Updating replica status to
> VOTING
> I0316 14:34:25.773263 1261 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 504125ns
> I0316 14:34:25.773294 1261 replica.cpp:320] Persisted replica status to
> VOTING
> I0316 14:34:25.773406 1275 recover.cpp:578] Successfully joined the Paxos
> group
> I0316 14:34:25.773576 1261 master.cpp:1806] The newly elected leader is
> master@172.17.0.3:45919 with id 8a03f08d-bf92-44a0-9aae-e601dabec71c
> I0316 14:34:25.773736 1261 master.cpp:1819] Elected as the leading master!
> I0316 14:34:25.773746 1275 recover.cpp:462] Recover process terminated
> I0316 14:34:25.773774 1261 master.cpp:1508] Recovering from registrar
> I0316 14:34:25.774015 1276 registrar.cpp:307] Recovering registrar
> I0316 14:34:25.774781 1261 log.cpp:659] Attempting to start the writer
> I0316 14:34:25.776232 1262 replica.cpp:493] Replica received implicit
> promise request from (15633)@172.17.0.3:45919 with proposal 1
> I0316 14:34:25.776703 1262 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 426458ns
> I0316 14:34:25.776729 1262 replica.cpp:342] Persisted promised to 1
> I0316 14:34:25.777372 1263 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0316 14:34:25.778818 1266 replica.cpp:388] Replica received explicit
> promise request from (15634)@172.17.0.3:45919 for position 0 with
> proposal 2
> I0316 14:34:25.779248 1266 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 374975ns
> I0316 14:34:25.779283 1266 replica.cpp:712] Persisted action at 0
> I0316 14:34:25.780740 1268 replica.cpp:537] Replica received write
> request for position 0 from (15635)@172.17.0.3:45919
> I0316 14:34:25.780838 1268 leveldb.cpp:436] Reading position from leveldb
> took 46911ns
> I0316 14:34:25.781334 1268 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 429536ns
> I0316 14:34:25.781366 1268 replica.cpp:712] Persisted action at 0
> I0316 14:34:25.782116 1267 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0316 14:34:25.782632 1267 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 454952ns
> I0316 14:34:25.782660 1267 replica.cpp:712] Persisted action at 0
> I0316 14:34:25.782692 1267 replica.cpp:697] Replica learned NOP action at
> position 0
> I0316 14:34:25.783316 1262 log.cpp:675] Writer started with ending
> position 0
> I0316 14:34:25.784416 1266 leveldb.cpp:436] Reading position from leveldb
> took 40346ns
> I0316 14:34:25.785414 1275 registrar.cpp:340] Successfully fetched the
> registry (0B) in 11.233024ms
> I0316 14:34:25.785598 1275 registrar.cpp:439] Applied 1 operations in
> 33290ns; attempting to update the 'registry'
> I0316 14:34:25.786360 1261 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0316 14:34:25.786527 1271 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0316 14:34:25.787273 1273 replica.cpp:537] Replica received write
> request for position 1 from (15636)@172.17.0.3:45919
> I0316 14:34:25.787727 1273 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 415025ns
> I0316 14:34:25.787755 1273 replica.cpp:712] Persisted action at 1
> I0316 14:34:25.788522 1268 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0316 14:34:25.788976 1268 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 424139ns
> I0316 14:34:25.789003 1268 replica.cpp:712] Persisted action at 1
> I0316 14:34:25.789046 1268 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0316 14:34:25.790257 1267 registrar.cpp:484] Successfully updated the
> 'registry' in 4.585984ms
> I0316 14:34:25.790406 1267 registrar.cpp:370] Successfully recovered
> registrar
> I0316 14:34:25.790956 1270 master.cpp:1616] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0316 14:34:25.791084 1272 hierarchical.cpp:171] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0316 14:34:25.791589 1269 log.cpp:702] Attempting to truncate the log to
> 1
> I0316 14:34:25.791817 1276 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0316 14:34:25.792682 1273 replica.cpp:537] Replica received write
> request for position 2 from (15637)@172.17.0.3:45919
> I0316 14:34:25.793195 1273 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 467536ns
> I0316 14:34:25.793329 1273 replica.cpp:712] Persisted action at 2
> I0316 14:34:25.794317 1267 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0316 14:34:25.794713 1267 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 364635ns
> I0316 14:34:25.794809 1267 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 70837ns
> I0316 14:34:25.794836 1267 replica.cpp:712] Persisted action at 2
> I0316 14:34:25.794864 1267 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0316 14:34:25.802239 1242 scheduler.cpp:172] Version: 0.29.0
> I0316 14:34:25.803004 1265 scheduler.cpp:437] New master detected at
> master@172.17.0.3:45919
> I0316 14:34:25.804595 1263 scheduler.cpp:337] Connected with the master
> at http://172.17.0.3:45919/master/api/v1/scheduler
> I0316 14:34:25.805811 1268 scheduler.cpp:230] Sending SUBSCRIBE call to
> http://172.17.0.3:45919/master/api/v1/scheduler
> I0316 14:34:25.806689 1273 process.cpp:3136] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0316 14:34:25.807131 1270 http.cpp:312] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.3:54741
> I0316 14:34:25.807474 1270 master.cpp:2068] Received subscription request
> for HTTP framework 'default'
> I0316 14:34:25.807533 1270 master.cpp:1845] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0316 14:34:25.807785 1270 master.cpp:2159] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0316 14:34:25.808226 1261 hierarchical.cpp:265] Added framework
> 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000
> I0316 14:34:25.808317 1270 master.hpp:1715] Sending heartbeat to
> 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000
> I0316 14:34:25.808353 1261 hierarchical.cpp:1453] No resources available
> to allocate!
> I0316 14:34:25.808404 1261 hierarchical.cpp:1548] No inverse offers to
> send out!
> I0316 14:34:25.808434 1261 hierarchical.cpp:1130] Performed allocation
> for 0 slaves in 169581ns
> I0316 14:34:25.809084 1265 scheduler.cpp:612] Enqueuing event SUBSCRIBED
> received from http://172.17.0.3:45919/master/api/v1/scheduler
> I0316 14:34:25.809528 1265 scheduler.cpp:612] Enqueuing event HEARTBEAT
> received from http://172.17.0.3:45919/master/api/v1/scheduler
> I0316 14:34:25.810348 1271 scheduler.cpp:230] Sending REQUEST call to
> http://172.17.0.3:45919/master/api/v1/scheduler
> I0316 14:34:25.811244 1269 process.cpp:3136] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0316 14:34:25.812198 1262 http.cpp:312] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.3:54742
> I0316 14:34:25.812505 1262 master.cpp:2765] Processing REQUEST call for
> framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default)
> I0316 14:34:25.812748 1266 hierarchical.cpp:589] Received resource
> request from framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000
> I0316 14:34:25.815428 1265 master.cpp:1251] Framework
> 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default) disconnected
> I0316 14:34:25.815477 1265 master.cpp:2622] Disconnecting framework
> 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default)
> I0316 14:34:25.815506 1265 master.cpp:2646] Deactivating framework
> 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default)
> I0316 14:34:25.815649 1265 master.cpp:1275] Giving framework
> 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default) 0ns to failover
> I0316 14:34:25.815690 1267 hierarchical.cpp:375] Deactivated framework
> 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000
> I0316 14:34:25.817137 1275 master.cpp:5340] Framework failover timeout,
> removing framework 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default)
> I0316 14:34:25.817170 1275 master.cpp:6073] Removing framework
> 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000 (default)
> I0316 14:34:25.817497 1262 hierarchical.cpp:326] Removed framework
> 8a03f08d-bf92-44a0-9aae-e601dabec71c-0000
> I0316 14:34:25.825148 1242 master.cpp:1065] Master terminating
> [ OK ] ContentType/SchedulerTest.Request/1 (73 ms)
> [----------] 26 tests from ContentType/SchedulerTest (5096 ms total)
>
> [----------] Global test environment tear-down
> E0316 14:34:25.962769 1242 environment.cpp:752] Failed to remove
> '/tmp/LogZooKeeperTest_WriteRead_eUjj2c': No such file or directory
> E0316 14:34:25.962831 1242 environment.cpp:752] Failed to remove
> '/tmp/LogZooKeeperTest_LostZooKeeper_6Sngur': No such file or directory
> [==========] 1026 tests from 130 test cases ran. (342527 ms total)
> [ PASSED ] 1025 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] ContainerLoggerTest.LOGROTATE_RotateInSandbox
>
> 1 FAILED TEST
> YOU HAVE 6 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> make[4]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.29.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1458136958-22834
> Untagged: mesos-1458136958-22834:latest
> Deleted: 3da4ae2e59e018cb2c8ebc2605f8c8d92e1412b03506ae36b5a5757bcfb19182
> Deleted: a7210d6f5bf7e68b9110ba16258a5a7b25cc68ff360ef736dbfda3c4e2f1dde8
> Deleted: 1dc586915bc033c4f18e4840e9dde93b159a3790619d7fa9d35b9f9e55c7eb8e
> Deleted: 63a748f876b05ef362586ab94fcdcb9c2fa19bede9efd82235f53728388b883c
> Deleted: 85c905dc5e1f8c7037cb121096bd64edb92b5691712e730711c86ef2078eb830
> Deleted: 6fc18598941bcc8ae9fb7c18a5036b94179e2c221d04ab05517a882bf06254a0
> Deleted: 6239a866e3495ccc56968aa5bb682a5546b7cbce45e0d92149d814b2023020d8
> Deleted: 773d8a4b0c21cd1569922daf6c13ee4ba84badbf7db1935c8b0881b74f741320
> Deleted: 530879693fe158ee1f3f0f926e7196a93130d53b5a9b87be465da0a96ee85d07
> Deleted: 6936675e29b8e66ad5ca911e98034561107323bd10e88ded0bb6f263e06ee137
> Deleted: 8dd47b7c59e866b88e8e7ff6d69d27c87be515ff71f00a15db27d42ac7499390
> Deleted: 4ed5e46657f3b8f1cf12eba76fffcd51675e063ccd8da83e6693cdb491998b71
> Deleted: c82b02e42b44825d2c771eb427939ffc64ffd79817ad72dfe718d24f2ed533c6
> Deleted: 76730af2886146056c6c9d93600e93b938455ff19653ab7f6ffbd40002de1ff9
> Deleted: 233079ce44e433f00b79f8c2aca140b31dce0310c3897721ce5a4c11b0608913
> Deleted: 857ac85df7cae026d46eda305769f1ed35f763d1f724fb2d2001f3faf4ed32df
> Build step 'Execute shell' marked build as failure
>