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/01/29 06:41:49 UTC
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1582
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1582/>
------------------------------------------
[...truncated 159938 lines...]
I0129 05:41:45.448012 2447 status_update_manager.cpp:282] Closing status update streams for framework 334d2f87-82d2-4268-bc1d-af0b060ce7d9-0000
I0129 05:41:45.448071 2447 status_update_manager.cpp:528] Cleaning up status update stream for task fd9f61f3-6c5d-47ca-8167-c3a482bbf2e5 of framework 334d2f87-82d2-4268-bc1d-af0b060ce7d9-0000
I0129 05:41:45.448104 2439 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_F7EYD1/slaves/334d2f87-82d2-4268-bc1d-af0b060ce7d9-S0/frameworks/334d2f87-82d2-4268-bc1d-af0b060ce7d9-0000' for gc 6.99999481482667days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (147 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0129 05:41:45.455202 2413 leveldb.cpp:174] Opened db in 2.678483ms
I0129 05:41:45.456105 2413 leveldb.cpp:181] Compacted db in 845647ns
I0129 05:41:45.456161 2413 leveldb.cpp:196] Created db iterator in 24095ns
I0129 05:41:45.456177 2413 leveldb.cpp:202] Seeked to beginning of db in 1935ns
I0129 05:41:45.456185 2413 leveldb.cpp:271] Iterated through 0 keys in the db in 317ns
I0129 05:41:45.456230 2413 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 05:41:45.456806 2444 recover.cpp:447] Starting replica recovery
I0129 05:41:45.457144 2444 recover.cpp:473] Replica is in EMPTY status
I0129 05:41:45.458243 2437 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14167)@172.17.0.5:54358
I0129 05:41:45.459022 2442 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 05:41:45.459653 2441 recover.cpp:564] Updating replica status to STARTING
I0129 05:41:45.460526 2444 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 665413ns
I0129 05:41:45.460554 2440 master.cpp:374] Master bcd17732-5bbb-4b09-9297-2dab9f60de0e (128efcb1d8c6) started on 172.17.0.5:54358
I0129 05:41:45.460562 2444 replica.cpp:320] Persisted replica status to STARTING
I0129 05:41:45.460803 2447 recover.cpp:473] Replica is in STARTING status
I0129 05:41:45.460575 2440 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/MfM8wK/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="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/MfM8wK/master" --zk_session_timeout="10secs"
I0129 05:41:45.460912 2440 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 05:41:45.460927 2440 master.cpp:426] Master only allowing authenticated slaves to register
I0129 05:41:45.460939 2440 credentials.hpp:35] Loading credentials for authentication from '/tmp/MfM8wK/credentials'
I0129 05:41:45.461293 2440 master.cpp:466] Using default 'crammd5' authenticator
I0129 05:41:45.461432 2440 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 05:41:45.461544 2440 master.cpp:569] Authorization enabled
I0129 05:41:45.462045 2436 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 05:41:45.462054 2445 whitelist_watcher.cpp:77] No whitelist given
I0129 05:41:45.462244 2436 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14169)@172.17.0.5:54358
I0129 05:41:45.462489 2445 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 05:41:45.463052 2435 recover.cpp:564] Updating replica status to VOTING
I0129 05:41:45.463595 2445 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 414264ns
I0129 05:41:45.463624 2445 replica.cpp:320] Persisted replica status to VOTING
I0129 05:41:45.463747 2445 recover.cpp:578] Successfully joined the Paxos group
I0129 05:41:45.464149 2445 recover.cpp:462] Recover process terminated
I0129 05:41:45.464490 2440 master.cpp:1710] The newly elected leader is master@172.17.0.5:54358 with id bcd17732-5bbb-4b09-9297-2dab9f60de0e
I0129 05:41:45.464651 2440 master.cpp:1723] Elected as the leading master!
I0129 05:41:45.464684 2440 master.cpp:1468] Recovering from registrar
I0129 05:41:45.464867 2438 registrar.cpp:307] Recovering registrar
I0129 05:41:45.465641 2447 log.cpp:659] Attempting to start the writer
I0129 05:41:45.466960 2445 replica.cpp:493] Replica received implicit promise request from (14170)@172.17.0.5:54358 with proposal 1
I0129 05:41:45.467397 2445 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 401821ns
I0129 05:41:45.467427 2445 replica.cpp:342] Persisted promised to 1
I0129 05:41:45.468021 2443 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 05:41:45.469147 2439 replica.cpp:388] Replica received explicit promise request from (14171)@172.17.0.5:54358 for position 0 with proposal 2
I0129 05:41:45.469594 2439 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 407223ns
I0129 05:41:45.469619 2439 replica.cpp:712] Persisted action at 0
I0129 05:41:45.470680 2445 replica.cpp:537] Replica received write request for position 0 from (14172)@172.17.0.5:54358
I0129 05:41:45.470800 2445 leveldb.cpp:436] Reading position from leveldb took 37876ns
I0129 05:41:45.471262 2445 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 386298ns
I0129 05:41:45.471287 2445 replica.cpp:712] Persisted action at 0
I0129 05:41:45.471882 2445 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 05:41:45.472342 2445 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 427005ns
I0129 05:41:45.472365 2445 replica.cpp:712] Persisted action at 0
I0129 05:41:45.472383 2445 replica.cpp:697] Replica learned NOP action at position 0
I0129 05:41:45.473007 2442 log.cpp:675] Writer started with ending position 0
I0129 05:41:45.474159 2443 leveldb.cpp:436] Reading position from leveldb took 40509ns
I0129 05:41:45.475546 2442 registrar.cpp:340] Successfully fetched the registry (0B) in 10.628864ms
I0129 05:41:45.475713 2442 registrar.cpp:439] Applied 1 operations in 47784ns; attempting to update the 'registry'
I0129 05:41:45.476523 2441 log.cpp:683] Attempting to append 170 bytes to the log
I0129 05:41:45.476654 2435 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 05:41:45.477438 2435 replica.cpp:537] Replica received write request for position 1 from (14173)@172.17.0.5:54358
I0129 05:41:45.478032 2435 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 539922ns
I0129 05:41:45.478057 2435 replica.cpp:712] Persisted action at 1
I0129 05:41:45.478719 2435 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 05:41:45.479123 2435 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 371019ns
I0129 05:41:45.479147 2435 replica.cpp:712] Persisted action at 1
I0129 05:41:45.479166 2435 replica.cpp:697] Replica learned APPEND action at position 1
I0129 05:41:45.480240 2435 registrar.cpp:484] Successfully updated the 'registry' in 4.449792ms
I0129 05:41:45.480392 2435 registrar.cpp:370] Successfully recovered registrar
I0129 05:41:45.480453 2443 log.cpp:702] Attempting to truncate the log to 1
I0129 05:41:45.480684 2433 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 05:41:45.481292 2441 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 05:41:45.481415 2432 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 05:41:45.481667 2442 replica.cpp:537] Replica received write request for position 2 from (14174)@172.17.0.5:54358
I0129 05:41:45.482101 2442 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 397579ns
I0129 05:41:45.482125 2442 replica.cpp:712] Persisted action at 2
I0129 05:41:45.482697 2433 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 05:41:45.483104 2433 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 375662ns
I0129 05:41:45.483171 2433 leveldb.cpp:399] Deleting ~1 keys from leveldb took 41204ns
I0129 05:41:45.483196 2433 replica.cpp:712] Persisted action at 2
I0129 05:41:45.483224 2433 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 05:41:45.492209 2413 scheduler.cpp:154] Version: 0.28.0
I0129 05:41:45.492980 2442 scheduler.cpp:236] New master detected at master@172.17.0.5:54358
I0129 05:41:45.494109 2442 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:54358
I0129 05:41:45.495765 2439 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 05:41:45.496255 2434 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:46223
I0129 05:41:45.496434 2434 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 05:41:45.496505 2434 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 05:41:45.496778 2434 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 05:41:45.497230 2445 hierarchical.cpp:265] Added framework bcd17732-5bbb-4b09-9297-2dab9f60de0e-0000
I0129 05:41:45.497398 2445 hierarchical.cpp:1403] No resources available to allocate!
I0129 05:41:45.497459 2445 hierarchical.cpp:1498] No inverse offers to send out!
I0129 05:41:45.497490 2445 hierarchical.cpp:1096] Performed allocation for 0 slaves in 164664ns
I0129 05:41:45.497265 2435 master.hpp:1658] Sending heartbeat to bcd17732-5bbb-4b09-9297-2dab9f60de0e-0000
I0129 05:41:45.497812 2434 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:54358
I0129 05:41:45.498229 2434 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:54358
I0129 05:41:45.498787 2438 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 05:41:45.499125 2436 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:54358
I0129 05:41:45.500434 2439 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 05:41:45.500833 2437 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:46224
I0129 05:41:45.500941 2437 master.cpp:2717] Processing REQUEST call for framework bcd17732-5bbb-4b09-9297-2dab9f60de0e-0000 (default)
I0129 05:41:45.501175 2432 hierarchical.cpp:589] Received resource request from framework bcd17732-5bbb-4b09-9297-2dab9f60de0e-0000
I0129 05:41:45.501559 2437 master.cpp:1025] Master terminating
I0129 05:41:45.501747 2441 hierarchical.cpp:326] Removed framework bcd17732-5bbb-4b09-9297-2dab9f60de0e-0000
E0129 05:41:45.502437 2445 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (56 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0129 05:41:45.511112 2413 leveldb.cpp:174] Opened db in 2.55178ms
I0129 05:41:45.512006 2413 leveldb.cpp:181] Compacted db in 846145ns
I0129 05:41:45.512055 2413 leveldb.cpp:196] Created db iterator in 24608ns
I0129 05:41:45.512070 2413 leveldb.cpp:202] Seeked to beginning of db in 1830ns
I0129 05:41:45.512079 2413 leveldb.cpp:271] Iterated through 0 keys in the db in 303ns
I0129 05:41:45.512130 2413 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 05:41:45.512637 2437 recover.cpp:447] Starting replica recovery
I0129 05:41:45.512989 2437 recover.cpp:473] Replica is in EMPTY status
I0129 05:41:45.514049 2437 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14182)@172.17.0.5:54358
I0129 05:41:45.515216 2438 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 05:41:45.515745 2432 master.cpp:374] Master 6ec6ba84-5d50-4bdb-9f55-7717869692a8 (128efcb1d8c6) started on 172.17.0.5:54358
I0129 05:41:45.515769 2434 recover.cpp:564] Updating replica status to STARTING
I0129 05:41:45.515770 2432 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/JzAHpk/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="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/JzAHpk/master" --zk_session_timeout="10secs"
I0129 05:41:45.516098 2432 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 05:41:45.516108 2432 master.cpp:426] Master only allowing authenticated slaves to register
I0129 05:41:45.516115 2432 credentials.hpp:35] Loading credentials for authentication from '/tmp/JzAHpk/credentials'
I0129 05:41:45.516463 2432 master.cpp:466] Using default 'crammd5' authenticator
I0129 05:41:45.516594 2432 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 05:41:45.516715 2432 master.cpp:569] Authorization enabled
I0129 05:41:45.516894 2446 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 05:41:45.516963 2445 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 922627ns
I0129 05:41:45.516988 2445 replica.cpp:320] Persisted replica status to STARTING
I0129 05:41:45.516937 2435 whitelist_watcher.cpp:77] No whitelist given
I0129 05:41:45.517272 2435 recover.cpp:473] Replica is in STARTING status
I0129 05:41:45.518276 2446 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14184)@172.17.0.5:54358
I0129 05:41:45.518910 2436 master.cpp:1710] The newly elected leader is master@172.17.0.5:54358 with id 6ec6ba84-5d50-4bdb-9f55-7717869692a8
I0129 05:41:45.518947 2436 master.cpp:1723] Elected as the leading master!
I0129 05:41:45.518966 2436 master.cpp:1468] Recovering from registrar
I0129 05:41:45.519110 2441 registrar.cpp:307] Recovering registrar
I0129 05:41:45.519146 2443 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 05:41:45.519646 2444 recover.cpp:564] Updating replica status to VOTING
I0129 05:41:45.520450 2440 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 355917ns
I0129 05:41:45.520478 2440 replica.cpp:320] Persisted replica status to VOTING
I0129 05:41:45.520611 2440 recover.cpp:578] Successfully joined the Paxos group
I0129 05:41:45.520864 2440 recover.cpp:462] Recover process terminated
I0129 05:41:45.521374 2447 log.cpp:659] Attempting to start the writer
I0129 05:41:45.522727 2436 replica.cpp:493] Replica received implicit promise request from (14185)@172.17.0.5:54358 with proposal 1
I0129 05:41:45.523138 2436 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 371546ns
I0129 05:41:45.523161 2436 replica.cpp:342] Persisted promised to 1
I0129 05:41:45.523700 2433 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 05:41:45.524977 2443 replica.cpp:388] Replica received explicit promise request from (14186)@172.17.0.5:54358 for position 0 with proposal 2
I0129 05:41:45.525470 2443 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 434779ns
I0129 05:41:45.525521 2443 replica.cpp:712] Persisted action at 0
I0129 05:41:45.526669 2433 replica.cpp:537] Replica received write request for position 0 from (14187)@172.17.0.5:54358
I0129 05:41:45.526743 2433 leveldb.cpp:436] Reading position from leveldb took 36849ns
I0129 05:41:45.527196 2433 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 402493ns
I0129 05:41:45.527226 2433 replica.cpp:712] Persisted action at 0
I0129 05:41:45.527958 2437 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 05:41:45.528339 2437 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 352431ns
I0129 05:41:45.528364 2437 replica.cpp:712] Persisted action at 0
I0129 05:41:45.528388 2437 replica.cpp:697] Replica learned NOP action at position 0
I0129 05:41:45.529670 2434 log.cpp:675] Writer started with ending position 0
I0129 05:41:45.530915 2441 leveldb.cpp:436] Reading position from leveldb took 47482ns
I0129 05:41:45.531970 2441 registrar.cpp:340] Successfully fetched the registry (0B) in 12.815104ms
I0129 05:41:45.532099 2441 registrar.cpp:439] Applied 1 operations in 36626ns; attempting to update the 'registry'
I0129 05:41:45.532938 2434 log.cpp:683] Attempting to append 170 bytes to the log
I0129 05:41:45.533083 2435 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 05:41:45.533973 2434 replica.cpp:537] Replica received write request for position 1 from (14188)@172.17.0.5:54358
I0129 05:41:45.534420 2434 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 407728ns
I0129 05:41:45.534445 2434 replica.cpp:712] Persisted action at 1
I0129 05:41:45.534996 2446 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 05:41:45.535461 2446 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 435841ns
I0129 05:41:45.535485 2446 replica.cpp:712] Persisted action at 1
I0129 05:41:45.535501 2446 replica.cpp:697] Replica learned APPEND action at position 1
I0129 05:41:45.536499 2435 registrar.cpp:484] Successfully updated the 'registry' in 4.337152ms
I0129 05:41:45.536653 2435 registrar.cpp:370] Successfully recovered registrar
I0129 05:41:45.536741 2437 log.cpp:702] Attempting to truncate the log to 1
I0129 05:41:45.536924 2440 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 05:41:45.537196 2438 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 05:41:45.537391 2441 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 05:41:45.537967 2433 replica.cpp:537] Replica received write request for position 2 from (14189)@172.17.0.5:54358
I0129 05:41:45.538399 2433 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 390473ns
I0129 05:41:45.538425 2433 replica.cpp:712] Persisted action at 2
I0129 05:41:45.539068 2437 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 05:41:45.539404 2437 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 308420ns
I0129 05:41:45.539465 2437 leveldb.cpp:399] Deleting ~1 keys from leveldb took 35289ns
I0129 05:41:45.539490 2437 replica.cpp:712] Persisted action at 2
I0129 05:41:45.539517 2437 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 05:41:45.548130 2413 scheduler.cpp:154] Version: 0.28.0
I0129 05:41:45.549430 2444 scheduler.cpp:236] New master detected at master@172.17.0.5:54358
I0129 05:41:45.550685 2439 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:54358
I0129 05:41:45.552781 2434 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 05:41:45.553591 2444 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:46225
I0129 05:41:45.554047 2444 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 05:41:45.554136 2444 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 05:41:45.554563 2444 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 05:41:45.555366 2436 master.hpp:1658] Sending heartbeat to 6ec6ba84-5d50-4bdb-9f55-7717869692a8-0000
I0129 05:41:45.555403 2444 hierarchical.cpp:265] Added framework 6ec6ba84-5d50-4bdb-9f55-7717869692a8-0000
I0129 05:41:45.555502 2444 hierarchical.cpp:1403] No resources available to allocate!
I0129 05:41:45.555548 2444 hierarchical.cpp:1498] No inverse offers to send out!
I0129 05:41:45.555579 2444 hierarchical.cpp:1096] Performed allocation for 0 slaves in 152269ns
I0129 05:41:45.556478 2446 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:54358
I0129 05:41:45.557071 2446 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:54358
I0129 05:41:45.557896 2434 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 05:41:45.557982 2441 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:54358
I0129 05:41:45.559489 2438 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 05:41:45.560114 2434 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:46226
I0129 05:41:45.560410 2434 master.cpp:2717] Processing REQUEST call for framework 6ec6ba84-5d50-4bdb-9f55-7717869692a8-0000 (default)
I0129 05:41:45.560585 2437 hierarchical.cpp:589] Received resource request from framework 6ec6ba84-5d50-4bdb-9f55-7717869692a8-0000
I0129 05:41:45.560952 2447 master.cpp:1025] Master terminating
I0129 05:41:45.561210 2441 hierarchical.cpp:326] Removed framework 6ec6ba84-5d50-4bdb-9f55-7717869692a8-0000
E0129 05:41:45.562364 2440 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (60 ms)
[----------] 22 tests from ContentType/SchedulerTest (4353 ms total)
[----------] Global test environment tear-down
[==========] 968 tests from 127 test cases ran. (352751 ms total)
[ PASSED ] 967 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ShasumTest.SHA512SimpleFile
1 FAILED TEST
YOU HAVE 9 DISABLED TESTS
2016-01-29 05:41:46,395:2413(0x7f6d210a8700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:55014] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1454043998-26071
Untagged: mesos-1454043998-26071:latest
Deleted: 7b3f006f97279f9558853ce9bf778d7e40ff11ded09d2ff9d173976aed6ac74f
Deleted: fe7cfaf248e2bca9622404117a415f6b3cc0e49c7e1d04a0f734abc7a2deb907
Deleted: bdc2ea2ca2b2e2587c7f6413896c21e50c29cd3fa8be9670bda20fd690a2e404
Deleted: 514e4c920d31ad3b6fd8ec1b33ad7171b641020e5a8ed5a9efef552c3d577eac
Deleted: 6e5f1ecd455c15c995359e0d112823317e4252c50ce0c1899d9fc45ec5438182
Deleted: 5c44c5f937ab775d2c199c74b5835167b417617b5d7e6c29236893a2404cee93
Deleted: 84d3a54cdad43e712ec9b8ac82895f60ef322fd6d8d9440ecc044e0404549a69
Deleted: 0167db71ffbc539e0cf4b61d3974e5e84a8f928b3056a145d299d73711232e73
Deleted: 5d6dfbb16d9e78c1321a4bca0ded8a3d558dcb8b079dba3661beb76d343d1387
Deleted: 33d39016cdbdb6a35c6a20a184190bc90f0783d8d4162667fe205f9727dc96bc
Deleted: f8f269e31723a7f8fd69e2bde97450872f9402c6ef5ddd4ee6b61792905738c7
Deleted: 02d05c265a21128b9a47b91159d2f9bb4088306c3ce54401277911e5fb82145a
Deleted: 10298ac745f961b5f177e07d811ce985c713937b9bcc52e66aa2a0bdd3216d27
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1589
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1589/changes>
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1588
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1588/>
------------------------------------------
[...truncated 162388 lines...]
rm -f slave/.deps/.dirstamp
rm -f slave/.dirstamp
rm -f slave/container_loggers/.deps/.dirstamp
rm -f examples/*.lo
rm -f slave/container_loggers/.dirstamp
rm -f slave/containerizer/.deps/.dirstamp
rm -f slave/containerizer/.dirstamp
rm -f exec/*.o
rm -f slave/containerizer/mesos/.deps/.dirstamp
rm -f exec/*.lo
rm -f slave/containerizer/mesos/.dirstamp
rm -f slave/containerizer/mesos/isolators/cgroups/.deps/.dirstamp
rm -f slave/containerizer/mesos/isolators/cgroups/.dirstamp
rm -f executor/*.o
rm -f slave/containerizer/mesos/isolators/filesystem/.deps/.dirstamp
rm -f slave/containerizer/mesos/isolators/filesystem/.dirstamp
rm -f slave/containerizer/mesos/isolators/namespaces/.deps/.dirstamp
rm -f slave/containerizer/mesos/isolators/namespaces/.dirstamp
rm -f executor/*.lo
rm -f slave/containerizer/mesos/isolators/network/.deps/.dirstamp
rm -f slave/containerizer/mesos/isolators/network/.dirstamp
rm -f slave/containerizer/mesos/isolators/posix/.deps/.dirstamp
rm -f files/*.o
rm -f slave/containerizer/mesos/isolators/posix/.dirstamp
rm -f slave/containerizer/mesos/provisioner/.deps/.dirstamp
rm -f slave/containerizer/mesos/provisioner/.dirstamp
rm -f files/*.lo
rm -f slave/containerizer/mesos/provisioner/appc/.deps/.dirstamp
rm -f slave/containerizer/mesos/provisioner/appc/.dirstamp
rm -f slave/containerizer/mesos/provisioner/backends/.deps/.dirstamp
rm -f hdfs/*.o
rm -f slave/containerizer/mesos/provisioner/backends/.dirstamp
rm -f slave/containerizer/mesos/provisioner/docker/.deps/.dirstamp
rm -f slave/containerizer/mesos/provisioner/docker/.dirstamp
rm -f hdfs/*.lo
rm -f slave/qos_controllers/.deps/.dirstamp
rm -f slave/qos_controllers/.dirstamp
rm -f slave/resource_estimators/.deps/.dirstamp
rm -f slave/resource_estimators/.dirstamp
rm -f health-check/*.o
rm -f state/.deps/.dirstamp
rm -f state/.dirstamp
rm -f tests/.deps/.dirstamp
rm -f hook/*.o
rm -f tests/.dirstamp
rm -f tests/common/.deps/.dirstamp
rm -f tests/common/.dirstamp
rm -f tests/containerizer/.deps/.dirstamp
rm -f hook/*.lo
rm -f tests/containerizer/.dirstamp
rm -f uri/.deps/.dirstamp
rm -f uri/.dirstamp
rm -rf ../include/mesos/.libs ../include/mesos/_libs
rm -f uri/fetchers/.deps/.dirstamp
rm -f internal/*.o
rm -f uri/fetchers/.dirstamp
rm -f usage/.deps/.dirstamp
rm -f usage/.dirstamp
rm -f v1/.deps/.dirstamp
rm -f internal/*.lo
rm -f v1/.dirstamp
rm -f version/.deps/.dirstamp
rm -f version/.dirstamp
rm -f java/jni/*.o
rm -f java/jni/*.lo
rm -rf ../include/mesos/authentication/.libs ../include/mesos/authentication/_libs
rm -f jvm/*.o
rm -rf ../include/mesos/authorizer/.libs ../include/mesos/authorizer/_libs
rm -rf ../include/mesos/containerizer/.libs ../include/mesos/containerizer/_libs
rm -f jvm/*.lo
rm -f examples/java/*.class
rm -rf ../include/mesos/docker/.libs ../include/mesos/docker/_libs
rm -f watcher/.deps/.dirstamp
rm -f jvm/org/apache/*.o
rm -f watcher/.dirstamp
rm -f java/jni/org_apache_mesos*.h
rm -rf ../include/mesos/executor/.libs ../include/mesos/executor/_libs
rm -f jvm/org/apache/*.lo
rm -f zookeeper/.deps/.dirstamp
rm -rf ../include/mesos/fetcher/.libs ../include/mesos/fetcher/_libs
rm -f zookeeper/.dirstamp
rm -rf ../include/mesos/maintenance/.libs ../include/mesos/maintenance/_libs
rm -f launcher/*.o
rm -rf ../include/mesos/master/.libs ../include/mesos/master/_libs
rm -rf ../include/mesos/module/.libs ../include/mesos/module/_libs
rm -f linux/*.o
rm -rf ../include/mesos/quota/.libs ../include/mesos/quota/_libs
rm -rf ../include/mesos/scheduler/.libs ../include/mesos/scheduler/_libs
rm -rf ../include/mesos/slave/.libs ../include/mesos/slave/_libs
rm -f linux/*.lo
rm -rf ../include/mesos/uri/.libs ../include/mesos/uri/_libs
rm -rf ../include/mesos/v1/.libs ../include/mesos/v1/_libs
rm -rf ../include/mesos/v1/executor/.libs ../include/mesos/v1/executor/_libs
rm -f linux/routing/*.o
rm -rf ../include/mesos/v1/scheduler/.libs ../include/mesos/v1/scheduler/_libs
rm -f linux/routing/*.lo
rm -rf authentication/cram_md5/.libs authentication/cram_md5/_libs
rm -f linux/routing/diagnosis/*.o
rm -rf authentication/http/.libs authentication/http/_libs
rm -f linux/routing/diagnosis/*.lo
rm -f linux/routing/filter/*.o
rm -f linux/routing/filter/*.lo
rm -rf authorizer/.libs authorizer/_libs
rm -f linux/routing/link/*.o
rm -rf authorizer/local/.libs authorizer/local/_libs
rm -rf common/.libs common/_libs
rm -f linux/routing/link/*.lo
rm -f linux/routing/queueing/*.o
rm -f linux/routing/queueing/*.lo
rm -f local/*.o
rm -rf docker/.libs docker/_libs
rm -f local/*.lo
rm -f log/*.o
rm -rf examples/.libs examples/_libs
rm -rf exec/.libs exec/_libs
rm -f log/*.lo
rm -f log/tool/*.o
rm -f log/tool/*.lo
rm -f logging/*.o
rm -rf executor/.libs executor/_libs
rm -f logging/*.lo
rm -rf files/.libs files/_libs
rm -rf hdfs/.libs hdfs/_libs
rm -f master/*.o
rm -f master/*.lo
rm -f master/allocator/*.o
rm -rf hook/.libs hook/_libs
rm -f master/allocator/*.lo
rm -rf internal/.libs internal/_libs
rm -rf java/jni/.libs java/jni/_libs
rm -f master/allocator/mesos/*.o
rm -rf jvm/.libs jvm/_libs
rm -rf jvm/org/apache/.libs jvm/org/apache/_libs
rm -f master/allocator/mesos/*.lo
rm -rf linux/.libs linux/_libs
rm -f master/allocator/sorter/drf/*.o
rm -f master/allocator/sorter/drf/*.lo
rm -rf linux/routing/.libs linux/routing/_libs
rm -f messages/*.o
rm -rf linux/routing/diagnosis/.libs linux/routing/diagnosis/_libs
rm -rf linux/routing/filter/.libs linux/routing/filter/_libs
rm -rf linux/routing/link/.libs linux/routing/link/_libs
rm -f messages/*.lo
rm -rf linux/routing/queueing/.libs linux/routing/queueing/_libs
rm -f module/*.o
rm -rf local/.libs local/_libs
rm -f module/*.lo
rm -rf log/.libs log/_libs
rm -f sched/*.o
rm -rf log/tool/.libs log/tool/_libs
rm -f sched/*.lo
rm -rf logging/.libs logging/_libs
rm -rf master/.libs master/_libs
rm -f scheduler/*.o
rm -f scheduler/*.lo
rm -f slave/*.o
rm -f slave/*.lo
rm -f slave/container_loggers/*.o
rm -f slave/container_loggers/*.lo
rm -f slave/containerizer/*.o
rm -f slave/containerizer/*.lo
rm -f slave/containerizer/mesos/*.o
rm -f slave/containerizer/mesos/*.lo
rm -f slave/containerizer/mesos/isolators/cgroups/*.o
rm -rf master/allocator/.libs master/allocator/_libs
rm -f slave/containerizer/mesos/isolators/cgroups/*.lo
rm -rf master/allocator/mesos/.libs master/allocator/mesos/_libs
rm -rf master/allocator/sorter/drf/.libs master/allocator/sorter/drf/_libs
rm -f slave/containerizer/mesos/isolators/filesystem/*.o
rm -rf messages/.libs messages/_libs
rm -f slave/containerizer/mesos/isolators/filesystem/*.lo
rm -rf module/.libs module/_libs
rm -rf sched/.libs sched/_libs
rm -f slave/containerizer/mesos/isolators/namespaces/*.o
rm -rf scheduler/.libs scheduler/_libs
rm -rf slave/.libs slave/_libs
rm -f slave/containerizer/mesos/isolators/namespaces/*.lo
rm -f slave/containerizer/mesos/isolators/network/*.o
rm -f slave/containerizer/mesos/isolators/network/*.lo
rm -f slave/containerizer/mesos/isolators/posix/*.o
rm -f slave/containerizer/mesos/isolators/posix/*.lo
rm -f slave/containerizer/mesos/provisioner/*.o
rm -f slave/containerizer/mesos/provisioner/*.lo
rm -f slave/containerizer/mesos/provisioner/appc/*.o
rm -f slave/containerizer/mesos/provisioner/appc/*.lo
rm -rf slave/container_loggers/.libs slave/container_loggers/_libs
rm -f slave/containerizer/mesos/provisioner/backends/*.o
rm -f slave/containerizer/mesos/provisioner/backends/*.lo
rm -f slave/containerizer/mesos/provisioner/docker/*.o
rm -rf slave/containerizer/.libs slave/containerizer/_libs
rm -f slave/containerizer/mesos/provisioner/docker/*.lo
rm -f slave/qos_controllers/*.o
rm -f slave/qos_controllers/*.lo
rm -rf slave/containerizer/mesos/.libs slave/containerizer/mesos/_libs
rm -f slave/resource_estimators/*.o
rm -f slave/resource_estimators/*.lo
rm -rf slave/containerizer/mesos/isolators/cgroups/.libs slave/containerizer/mesos/isolators/cgroups/_libs
rm -f state/*.o
rm -rf slave/containerizer/mesos/isolators/filesystem/.libs slave/containerizer/mesos/isolators/filesystem/_libs
rm -rf slave/containerizer/mesos/isolators/namespaces/.libs slave/containerizer/mesos/isolators/namespaces/_libs
rm -f state/*.lo
rm -rf slave/containerizer/mesos/isolators/network/.libs slave/containerizer/mesos/isolators/network/_libs
rm -rf slave/containerizer/mesos/isolators/posix/.libs slave/containerizer/mesos/isolators/posix/_libs
rm -rf slave/containerizer/mesos/provisioner/.libs slave/containerizer/mesos/provisioner/_libs
rm -f tests/*.o
rm -rf slave/containerizer/mesos/provisioner/appc/.libs slave/containerizer/mesos/provisioner/appc/_libs
rm -rf slave/containerizer/mesos/provisioner/backends/.libs slave/containerizer/mesos/provisioner/backends/_libs
rm -rf slave/containerizer/mesos/provisioner/docker/.libs slave/containerizer/mesos/provisioner/docker/_libs
rm -rf slave/qos_controllers/.libs slave/qos_controllers/_libs
rm -rf slave/resource_estimators/.libs slave/resource_estimators/_libs
rm -rf state/.libs state/_libs
rm -rf uri/.libs uri/_libs
rm -rf uri/fetchers/.libs uri/fetchers/_libs
rm -rf usage/.libs usage/_libs
rm -rf v1/.libs v1/_libs
rm -rf version/.libs version/_libs
rm -rf watcher/.libs watcher/_libs
rm -rf zookeeper/.libs zookeeper/_libs
rm -f tests/common/*.o
rm -f tests/containerizer/*.o
rm -f uri/*.o
rm -f uri/*.lo
rm -f uri/fetchers/*.o
rm -f uri/fetchers/*.lo
rm -f usage/*.o
rm -f usage/*.lo
rm -f v1/*.o
rm -f v1/*.lo
rm -f version/*.o
rm -f version/*.lo
rm -f watcher/*.o
rm -f watcher/*.lo
rm -f zookeeper/*.o
rm -f zookeeper/*.lo
rm -rf ../include/mesos/.deps ../include/mesos/authentication/.deps ../include/mesos/authorizer/.deps ../include/mesos/containerizer/.deps ../include/mesos/docker/.deps ../include/mesos/executor/.deps ../include/mesos/fetcher/.deps ../include/mesos/maintenance/.deps ../include/mesos/master/.deps ../include/mesos/module/.deps ../include/mesos/quota/.deps ../include/mesos/scheduler/.deps ../include/mesos/slave/.deps ../include/mesos/uri/.deps ../include/mesos/v1/.deps ../include/mesos/v1/executor/.deps ../include/mesos/v1/scheduler/.deps authentication/cram_md5/.deps authentication/http/.deps authorizer/.deps authorizer/local/.deps cli/.deps common/.deps docker/.deps examples/.deps exec/.deps executor/.deps files/.deps hdfs/.deps health-check/.deps hook/.deps internal/.deps java/jni/.deps jvm/.deps jvm/org/apache/.deps launcher/.deps linux/.deps linux/routing/.deps linux/routing/diagnosis/.deps linux/routing/filter/.deps linux/routing/link/.deps linux/routing/queueing/.deps local/.deps log/.deps log/tool/.deps logging/.deps master/.deps master/allocator/.deps master/allocator/mesos/.deps master/allocator/sorter/drf/.deps messages/.deps module/.deps sched/.deps scheduler/.deps slave/.deps slave/container_loggers/.deps slave/containerizer/.deps slave/containerizer/mesos/.deps slave/containerizer/mesos/isolators/cgroups/.deps slave/containerizer/mesos/isolators/filesystem/.deps slave/containerizer/mesos/isolators/namespaces/.deps slave/containerizer/mesos/isolators/network/.deps slave/containerizer/mesos/isolators/posix/.deps slave/containerizer/mesos/provisioner/.deps slave/containerizer/mesos/provisioner/appc/.deps slave/containerizer/mesos/provisioner/backends/.deps slave/containerizer/mesos/provisioner/docker/.deps slave/qos_controllers/.deps slave/resource_estimators/.deps state/.deps tests/.deps tests/common/.deps tests/containerizer/.deps uri/.deps uri/fetchers/.deps usage/.deps v1/.deps version/.deps watcher/.deps zookeeper/.deps
rm -f Makefile
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
rm -f config.status config.cache config.log configure.lineno config.status.lineno
rm -f Makefile
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
if test -d "mesos-0.28.0"; then find "mesos-0.28.0" -type d ! -perm -200 -exec chmod u+w {} ';' && rm -rf "mesos-0.28.0" || { sleep 5 && rm -rf "mesos-0.28.0"; }; else :; fi
==============================================
mesos-0.28.0 archives ready for distribution:
mesos-0.28.0.tar.gz
==============================================
+ docker rmi mesos-1454104055-28274
Error response from daemon: conflict: unable to delete ee3e49bbf0d4 (must be forced) - image is being used by stopped container 007a621048ef
Error: failed to remove images: [mesos-1454104055-28274]
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1587
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1587/>
------------------------------------------
[...truncated 160338 lines...]
I0129 21:25:03.723858 2437 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_Lzy3mL/slaves/8a701c8d-f1ae-4771-8035-fb31ee473eb0-S0/frameworks/8a701c8d-f1ae-4771-8035-fb31ee473eb0-0000/executors/default' for gc 6.99999162292741days in the future
I0129 21:25:03.723948 2445 status_update_manager.cpp:282] Closing status update streams for framework 8a701c8d-f1ae-4771-8035-fb31ee473eb0-0000
I0129 21:25:03.724000 2445 status_update_manager.cpp:528] Cleaning up status update stream for task e970a59a-ec88-4e4d-8556-976f77aaf408 of framework 8a701c8d-f1ae-4771-8035-fb31ee473eb0-0000
I0129 21:25:03.724017 2449 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_Lzy3mL/slaves/8a701c8d-f1ae-4771-8035-fb31ee473eb0-S0/frameworks/8a701c8d-f1ae-4771-8035-fb31ee473eb0-0000' for gc 6.99999162097185days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (105 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0129 21:25:03.732007 2415 leveldb.cpp:174] Opened db in 3.325621ms
I0129 21:25:03.732858 2415 leveldb.cpp:181] Compacted db in 793277ns
I0129 21:25:03.732902 2415 leveldb.cpp:196] Created db iterator in 18269ns
I0129 21:25:03.732925 2415 leveldb.cpp:202] Seeked to beginning of db in 1869ns
I0129 21:25:03.733099 2415 leveldb.cpp:271] Iterated through 0 keys in the db in 520ns
I0129 21:25:03.733157 2415 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 21:25:03.733574 2438 recover.cpp:447] Starting replica recovery
I0129 21:25:03.733788 2438 recover.cpp:473] Replica is in EMPTY status
I0129 21:25:03.735548 2446 master.cpp:374] Master a85fe6ef-2243-41e6-b7a1-3eaf2b1b2c2e (c17944d9f94b) started on 172.17.0.4:47940
I0129 21:25:03.735993 2440 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14168)@172.17.0.4:47940
I0129 21:25:03.736377 2446 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/DNRJ3F/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="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/DNRJ3F/master" --zk_session_timeout="10secs"
I0129 21:25:03.736716 2436 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 21:25:03.737700 2446 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 21:25:03.737716 2446 master.cpp:426] Master only allowing authenticated slaves to register
I0129 21:25:03.737726 2446 credentials.hpp:35] Loading credentials for authentication from '/tmp/DNRJ3F/credentials'
I0129 21:25:03.738097 2446 master.cpp:466] Using default 'crammd5' authenticator
I0129 21:25:03.738242 2436 recover.cpp:564] Updating replica status to STARTING
I0129 21:25:03.738252 2446 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 21:25:03.738392 2446 master.cpp:569] Authorization enabled
I0129 21:25:03.738894 2441 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 21:25:03.738963 2441 whitelist_watcher.cpp:77] No whitelist given
I0129 21:25:03.739233 2436 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 695883ns
I0129 21:25:03.739264 2436 replica.cpp:320] Persisted replica status to STARTING
I0129 21:25:03.739522 2436 recover.cpp:473] Replica is in STARTING status
I0129 21:25:03.740592 2449 master.cpp:1710] The newly elected leader is master@172.17.0.4:47940 with id a85fe6ef-2243-41e6-b7a1-3eaf2b1b2c2e
I0129 21:25:03.740624 2449 master.cpp:1723] Elected as the leading master!
I0129 21:25:03.740644 2449 master.cpp:1468] Recovering from registrar
I0129 21:25:03.741812 2434 registrar.cpp:307] Recovering registrar
I0129 21:25:03.742508 2439 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14170)@172.17.0.4:47940
I0129 21:25:03.742787 2434 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 21:25:03.743249 2438 recover.cpp:564] Updating replica status to VOTING
I0129 21:25:03.744009 2438 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 564080ns
I0129 21:25:03.744042 2438 replica.cpp:320] Persisted replica status to VOTING
I0129 21:25:03.744277 2435 recover.cpp:578] Successfully joined the Paxos group
I0129 21:25:03.744607 2435 recover.cpp:462] Recover process terminated
I0129 21:25:03.745507 2435 log.cpp:659] Attempting to start the writer
I0129 21:25:03.747033 2438 replica.cpp:493] Replica received implicit promise request from (14171)@172.17.0.4:47940 with proposal 1
I0129 21:25:03.747503 2438 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 429775ns
I0129 21:25:03.747532 2438 replica.cpp:342] Persisted promised to 1
I0129 21:25:03.748580 2438 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 21:25:03.750001 2449 replica.cpp:388] Replica received explicit promise request from (14172)@172.17.0.4:47940 for position 0 with proposal 2
I0129 21:25:03.750668 2449 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 621770ns
I0129 21:25:03.750708 2449 replica.cpp:712] Persisted action at 0
I0129 21:25:03.752346 2438 replica.cpp:537] Replica received write request for position 0 from (14173)@172.17.0.4:47940
I0129 21:25:03.752424 2438 leveldb.cpp:436] Reading position from leveldb took 45286ns
I0129 21:25:03.752825 2438 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 355265ns
I0129 21:25:03.752849 2438 replica.cpp:712] Persisted action at 0
I0129 21:25:03.753584 2438 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 21:25:03.754206 2438 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 593179ns
I0129 21:25:03.754232 2438 replica.cpp:712] Persisted action at 0
I0129 21:25:03.754251 2438 replica.cpp:697] Replica learned NOP action at position 0
I0129 21:25:03.755219 2436 log.cpp:675] Writer started with ending position 0
I0129 21:25:03.756616 2435 leveldb.cpp:436] Reading position from leveldb took 27251ns
I0129 21:25:03.757902 2439 registrar.cpp:340] Successfully fetched the registry (0B) in 16.039936ms
I0129 21:25:03.758038 2439 registrar.cpp:439] Applied 1 operations in 34861ns; attempting to update the 'registry'
I0129 21:25:03.759372 2439 log.cpp:683] Attempting to append 170 bytes to the log
I0129 21:25:03.759659 2447 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 21:25:03.760488 2446 replica.cpp:537] Replica received write request for position 1 from (14174)@172.17.0.4:47940
I0129 21:25:03.761023 2446 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 491354ns
I0129 21:25:03.761112 2446 replica.cpp:712] Persisted action at 1
I0129 21:25:03.762333 2448 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 21:25:03.762855 2448 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 431449ns
I0129 21:25:03.762943 2448 replica.cpp:712] Persisted action at 1
I0129 21:25:03.763062 2448 replica.cpp:697] Replica learned APPEND action at position 1
I0129 21:25:03.764732 2445 log.cpp:702] Attempting to truncate the log to 1
I0129 21:25:03.765103 2445 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 21:25:03.766185 2445 replica.cpp:537] Replica received write request for position 2 from (14175)@172.17.0.4:47940
I0129 21:25:03.766418 2448 registrar.cpp:484] Successfully updated the 'registry' in 8.279808ms
I0129 21:25:03.766618 2448 registrar.cpp:370] Successfully recovered registrar
I0129 21:25:03.767092 2448 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 21:25:03.767318 2442 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 21:25:03.767412 2445 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.110188ms
I0129 21:25:03.767726 2445 replica.cpp:712] Persisted action at 2
I0129 21:25:03.768554 2443 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 21:25:03.768949 2443 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 362877ns
I0129 21:25:03.769006 2443 leveldb.cpp:399] Deleting ~1 keys from leveldb took 31442ns
I0129 21:25:03.769040 2443 replica.cpp:712] Persisted action at 2
I0129 21:25:03.769062 2443 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 21:25:03.778211 2415 scheduler.cpp:154] Version: 0.28.0
I0129 21:25:03.779119 2443 scheduler.cpp:236] New master detected at master@172.17.0.4:47940
I0129 21:25:03.780131 2443 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:47940
I0129 21:25:03.781904 2436 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 21:25:03.782382 2449 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:40320
I0129 21:25:03.782588 2449 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 21:25:03.782658 2449 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 21:25:03.782938 2449 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 21:25:03.783398 2449 master.hpp:1658] Sending heartbeat to a85fe6ef-2243-41e6-b7a1-3eaf2b1b2c2e-0000
I0129 21:25:03.783416 2436 hierarchical.cpp:265] Added framework a85fe6ef-2243-41e6-b7a1-3eaf2b1b2c2e-0000
I0129 21:25:03.783502 2436 hierarchical.cpp:1403] No resources available to allocate!
I0129 21:25:03.783565 2436 hierarchical.cpp:1498] No inverse offers to send out!
I0129 21:25:03.783604 2436 hierarchical.cpp:1096] Performed allocation for 0 slaves in 164959ns
I0129 21:25:03.784330 2434 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:47940
I0129 21:25:03.784822 2434 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:47940
I0129 21:25:03.785562 2434 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:47940
I0129 21:25:03.785827 2441 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 21:25:03.786998 2436 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 21:25:03.787304 2443 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:40321
I0129 21:25:03.787402 2443 master.cpp:2717] Processing REQUEST call for framework a85fe6ef-2243-41e6-b7a1-3eaf2b1b2c2e-0000 (default)
I0129 21:25:03.787556 2447 hierarchical.cpp:589] Received resource request from framework a85fe6ef-2243-41e6-b7a1-3eaf2b1b2c2e-0000
I0129 21:25:03.788048 2447 master.cpp:1025] Master terminating
I0129 21:25:03.788244 2443 hierarchical.cpp:326] Removed framework a85fe6ef-2243-41e6-b7a1-3eaf2b1b2c2e-0000
E0129 21:25:03.788923 2435 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (66 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0129 21:25:03.797405 2415 leveldb.cpp:174] Opened db in 2.647289ms
I0129 21:25:03.798316 2415 leveldb.cpp:181] Compacted db in 864503ns
I0129 21:25:03.798377 2415 leveldb.cpp:196] Created db iterator in 33699ns
I0129 21:25:03.798398 2415 leveldb.cpp:202] Seeked to beginning of db in 2166ns
I0129 21:25:03.798429 2415 leveldb.cpp:271] Iterated through 0 keys in the db in 492ns
I0129 21:25:03.798490 2415 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 21:25:03.799962 2441 recover.cpp:447] Starting replica recovery
I0129 21:25:03.800261 2441 recover.cpp:473] Replica is in EMPTY status
I0129 21:25:03.801952 2440 master.cpp:374] Master d93c864a-57de-4656-a59a-e9944586c2f0 (c17944d9f94b) started on 172.17.0.4:47940
I0129 21:25:03.802278 2440 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/3aFYSj/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="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/3aFYSj/master" --zk_session_timeout="10secs"
I0129 21:25:03.803225 2440 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 21:25:03.803243 2440 master.cpp:426] Master only allowing authenticated slaves to register
I0129 21:25:03.803253 2440 credentials.hpp:35] Loading credentials for authentication from '/tmp/3aFYSj/credentials'
I0129 21:25:03.803625 2440 master.cpp:466] Using default 'crammd5' authenticator
I0129 21:25:03.804235 2449 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14183)@172.17.0.4:47940
I0129 21:25:03.804321 2440 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 21:25:03.804522 2440 master.cpp:569] Authorization enabled
I0129 21:25:03.805060 2449 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 21:25:03.805647 2434 whitelist_watcher.cpp:77] No whitelist given
I0129 21:25:03.805762 2441 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 21:25:03.806457 2449 recover.cpp:564] Updating replica status to STARTING
I0129 21:25:03.807387 2435 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 544429ns
I0129 21:25:03.807497 2435 replica.cpp:320] Persisted replica status to STARTING
I0129 21:25:03.807857 2435 recover.cpp:473] Replica is in STARTING status
I0129 21:25:03.808290 2440 master.cpp:1710] The newly elected leader is master@172.17.0.4:47940 with id d93c864a-57de-4656-a59a-e9944586c2f0
I0129 21:25:03.808323 2440 master.cpp:1723] Elected as the leading master!
I0129 21:25:03.808348 2440 master.cpp:1468] Recovering from registrar
I0129 21:25:03.808653 2440 registrar.cpp:307] Recovering registrar
I0129 21:25:03.809598 2440 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14185)@172.17.0.4:47940
I0129 21:25:03.810201 2449 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 21:25:03.810657 2442 recover.cpp:564] Updating replica status to VOTING
I0129 21:25:03.811329 2449 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 450684ns
I0129 21:25:03.811357 2449 replica.cpp:320] Persisted replica status to VOTING
I0129 21:25:03.811466 2442 recover.cpp:578] Successfully joined the Paxos group
I0129 21:25:03.811827 2442 recover.cpp:462] Recover process terminated
I0129 21:25:03.812357 2434 log.cpp:659] Attempting to start the writer
I0129 21:25:03.813952 2434 replica.cpp:493] Replica received implicit promise request from (14186)@172.17.0.4:47940 with proposal 1
I0129 21:25:03.814558 2434 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 544854ns
I0129 21:25:03.814599 2434 replica.cpp:342] Persisted promised to 1
I0129 21:25:03.816249 2444 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 21:25:03.817891 2439 replica.cpp:388] Replica received explicit promise request from (14187)@172.17.0.4:47940 for position 0 with proposal 2
I0129 21:25:03.818724 2439 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 519660ns
I0129 21:25:03.818770 2439 replica.cpp:712] Persisted action at 0
I0129 21:25:03.820261 2439 replica.cpp:537] Replica received write request for position 0 from (14188)@172.17.0.4:47940
I0129 21:25:03.820348 2439 leveldb.cpp:436] Reading position from leveldb took 39568ns
I0129 21:25:03.820988 2439 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 469728ns
I0129 21:25:03.821030 2439 replica.cpp:712] Persisted action at 0
I0129 21:25:03.822151 2442 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 21:25:03.823731 2442 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 1.388275ms
I0129 21:25:03.823778 2442 replica.cpp:712] Persisted action at 0
I0129 21:25:03.823810 2442 replica.cpp:697] Replica learned NOP action at position 0
I0129 21:25:03.824764 2441 log.cpp:675] Writer started with ending position 0
I0129 21:25:03.826340 2442 leveldb.cpp:436] Reading position from leveldb took 59283ns
I0129 21:25:03.829782 2436 registrar.cpp:340] Successfully fetched the registry (0B) in 20.98304ms
I0129 21:25:03.829948 2436 registrar.cpp:439] Applied 1 operations in 41763ns; attempting to update the 'registry'
I0129 21:25:03.834053 2436 log.cpp:683] Attempting to append 170 bytes to the log
I0129 21:25:03.834347 2436 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 21:25:03.835553 2438 replica.cpp:537] Replica received write request for position 1 from (14189)@172.17.0.4:47940
I0129 21:25:03.836732 2438 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 1.124096ms
I0129 21:25:03.836778 2438 replica.cpp:712] Persisted action at 1
I0129 21:25:03.837939 2438 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 21:25:03.838721 2438 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 746304ns
I0129 21:25:03.838752 2438 replica.cpp:712] Persisted action at 1
I0129 21:25:03.838781 2438 replica.cpp:697] Replica learned APPEND action at position 1
I0129 21:25:03.841599 2444 registrar.cpp:484] Successfully updated the 'registry' in 11.56608ms
I0129 21:25:03.841804 2444 registrar.cpp:370] Successfully recovered registrar
I0129 21:25:03.842021 2438 log.cpp:702] Attempting to truncate the log to 1
I0129 21:25:03.842356 2438 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 21:25:03.842808 2444 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 21:25:03.842923 2436 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 21:25:03.843724 2442 replica.cpp:537] Replica received write request for position 2 from (14190)@172.17.0.4:47940
I0129 21:25:03.844264 2442 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 494001ns
I0129 21:25:03.844293 2442 replica.cpp:712] Persisted action at 2
I0129 21:25:03.845108 2442 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 21:25:03.845626 2442 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 483285ns
I0129 21:25:03.845839 2442 leveldb.cpp:399] Deleting ~1 keys from leveldb took 60038ns
I0129 21:25:03.845953 2442 replica.cpp:712] Persisted action at 2
I0129 21:25:03.846070 2442 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 21:25:03.853407 2415 scheduler.cpp:154] Version: 0.28.0
I0129 21:25:03.854439 2438 scheduler.cpp:236] New master detected at master@172.17.0.4:47940
I0129 21:25:03.858309 2434 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:47940
I0129 21:25:03.860339 2440 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 21:25:03.860879 2449 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:40322
I0129 21:25:03.861227 2449 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 21:25:03.861292 2449 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 21:25:03.861618 2442 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 21:25:03.862102 2437 hierarchical.cpp:265] Added framework d93c864a-57de-4656-a59a-e9944586c2f0-0000
I0129 21:25:03.862190 2437 hierarchical.cpp:1403] No resources available to allocate!
I0129 21:25:03.862216 2442 master.hpp:1658] Sending heartbeat to d93c864a-57de-4656-a59a-e9944586c2f0-0000
I0129 21:25:03.862340 2437 hierarchical.cpp:1498] No inverse offers to send out!
I0129 21:25:03.862551 2437 hierarchical.cpp:1096] Performed allocation for 0 slaves in 421278ns
I0129 21:25:03.862977 2442 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:47940
I0129 21:25:03.863443 2437 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:47940
I0129 21:25:03.864063 2437 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:47940
I0129 21:25:03.864563 2438 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 21:25:03.865859 2440 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 21:25:03.866154 2445 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:40323
I0129 21:25:03.866361 2445 master.cpp:2717] Processing REQUEST call for framework d93c864a-57de-4656-a59a-e9944586c2f0-0000 (default)
I0129 21:25:03.866485 2447 hierarchical.cpp:589] Received resource request from framework d93c864a-57de-4656-a59a-e9944586c2f0-0000
I0129 21:25:03.866775 2449 master.cpp:1025] Master terminating
I0129 21:25:03.867036 2446 hierarchical.cpp:326] Removed framework d93c864a-57de-4656-a59a-e9944586c2f0-0000
E0129 21:25:03.868137 2445 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (80 ms)
[----------] 22 tests from ContentType/SchedulerTest (4204 ms total)
[----------] Global test environment tear-down
[==========] 969 tests from 127 test cases ran. (371788 ms total)
[ PASSED ] 968 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ShasumTest.SHA512SimpleFile
1 FAILED TEST
YOU HAVE 9 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1454100653-8437
Untagged: mesos-1454100653-8437:latest
Deleted: 56843bcb8431aa6e75fd2c16b1cfeb04bf95aef590312e078c08f83d268873eb
Deleted: e2eb495ca9730facba159ae1e866d696808085bfbca87081667f35a7e31cf83a
Deleted: 1d67ef86c0ee98bdf7448b565b493a044b282b1551f05ea35441a70d51d89f90
Deleted: 0f534fc80e12edf0f2a091778376854bb45208c5116018fc1eaf67b819efcd00
Deleted: 8b8e476ed78b8080de130c0c2624d39fd2c1139ca44673cfbceeb998f3b5a139
Deleted: 644b3a25c2067fd37e9b133cc68fa23079eec3f3867e7795796cdb0970fa47a0
Deleted: dbce68e3f2a604976b09e6b73c6156738387e6fcd023f4de52eee2738277e9f0
Deleted: 0b200bb95bc5bba10c1d02edae3c14733d81941da6343ccc9ddc54408a8cb5e8
Deleted: b8c7e83314f28b99c1f55d160fe213b15b9a875ed95e3ec19701be9a0ba142d0
Deleted: 70905922a9ee342ab7071031ff9b8d3d0115c491a4c1e1b97b482442af6a09ec
Deleted: d5ade59ba765852960ce8e86630d3da50e6c52870bfe9912a132ebfeade9f867
Deleted: 5765ab690810c6589ef805dda56d004b12a92db8d52a53ea8ba79d7ce52a4a82
Deleted: dbb765ce6aaf6ebc6fb5e42216dc16ca2f0278b8bfad3e80373571a2e5a1aca0
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1586
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1586/changes>
Changes:
[yujie.jay] Fixed broken build due to signed comparison warning with GCC 5.3.0.
------------------------------------------
[...truncated 165943 lines...]
I0129 20:09:27.635005 2447 status_update_manager.cpp:528] Cleaning up status update stream for task 6535bb00-1ad5-4a64-8be3-13ef035db88b of framework ce6f396c-5f82-4877-95ab-2558a2662e57-0000
I0129 20:09:27.635113 2450 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_gqormZ/slaves/ce6f396c-5f82-4877-95ab-2558a2662e57-S0/frameworks/ce6f396c-5f82-4877-95ab-2558a2662e57-0000/executors/default' for gc 6.99999265326518days in the future
I0129 20:09:27.635244 2450 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_gqormZ/slaves/ce6f396c-5f82-4877-95ab-2558a2662e57-S0/frameworks/ce6f396c-5f82-4877-95ab-2558a2662e57-0000' for gc 6.99999265148148days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (901 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0129 20:09:27.826479 2422 leveldb.cpp:174] Opened db in 185.524437ms
I0129 20:09:27.894345 2422 leveldb.cpp:181] Compacted db in 67.750192ms
I0129 20:09:27.894464 2422 leveldb.cpp:196] Created db iterator in 32452ns
I0129 20:09:27.894486 2422 leveldb.cpp:202] Seeked to beginning of db in 3648ns
I0129 20:09:27.894498 2422 leveldb.cpp:271] Iterated through 0 keys in the db in 258ns
I0129 20:09:27.894562 2422 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 20:09:27.895498 2453 recover.cpp:447] Starting replica recovery
I0129 20:09:27.895736 2453 recover.cpp:473] Replica is in EMPTY status
I0129 20:09:27.896998 2443 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14194)@172.17.15.226:42559
I0129 20:09:27.897706 2454 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 20:09:27.898114 2456 recover.cpp:564] Updating replica status to STARTING
I0129 20:09:27.899060 2450 master.cpp:374] Master 2f22e602-a07f-4537-8424-38af55d68b16 (486be6d149d4) started on 172.17.15.226:42559
I0129 20:09:27.899085 2450 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ZXez0g/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="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/ZXez0g/master" --zk_session_timeout="10secs"
I0129 20:09:27.899636 2450 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 20:09:27.899652 2450 master.cpp:426] Master only allowing authenticated slaves to register
I0129 20:09:27.899664 2450 credentials.hpp:35] Loading credentials for authentication from '/tmp/ZXez0g/credentials'
I0129 20:09:27.900104 2450 master.cpp:466] Using default 'crammd5' authenticator
I0129 20:09:27.900328 2450 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 20:09:27.900501 2450 master.cpp:569] Authorization enabled
I0129 20:09:27.900710 2446 whitelist_watcher.cpp:77] No whitelist given
I0129 20:09:27.900723 2449 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 20:09:27.903126 2456 master.cpp:1710] The newly elected leader is master@172.17.15.226:42559 with id 2f22e602-a07f-4537-8424-38af55d68b16
I0129 20:09:27.903187 2456 master.cpp:1723] Elected as the leading master!
I0129 20:09:27.903213 2456 master.cpp:1468] Recovering from registrar
I0129 20:09:27.903409 2446 registrar.cpp:307] Recovering registrar
I0129 20:09:27.970937 2442 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 72.491073ms
I0129 20:09:27.971035 2442 replica.cpp:320] Persisted replica status to STARTING
I0129 20:09:27.971415 2442 recover.cpp:473] Replica is in STARTING status
I0129 20:09:27.972910 2450 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14196)@172.17.15.226:42559
I0129 20:09:27.973352 2452 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 20:09:27.973958 2446 recover.cpp:564] Updating replica status to VOTING
I0129 20:09:28.046516 2452 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 72.390484ms
I0129 20:09:28.046792 2452 replica.cpp:320] Persisted replica status to VOTING
I0129 20:09:28.047106 2444 recover.cpp:578] Successfully joined the Paxos group
I0129 20:09:28.047631 2444 recover.cpp:462] Recover process terminated
I0129 20:09:28.048359 2451 log.cpp:659] Attempting to start the writer
I0129 20:09:28.050062 2447 replica.cpp:493] Replica received implicit promise request from (14197)@172.17.15.226:42559 with proposal 1
I0129 20:09:28.104744 2447 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 54.606495ms
I0129 20:09:28.104847 2447 replica.cpp:342] Persisted promised to 1
I0129 20:09:28.105998 2451 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 20:09:28.107841 2443 replica.cpp:388] Replica received explicit promise request from (14198)@172.17.15.226:42559 for position 0 with proposal 2
I0129 20:09:28.142185 2443 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 34.264441ms
I0129 20:09:28.142261 2443 replica.cpp:712] Persisted action at 0
I0129 20:09:28.143817 2455 replica.cpp:537] Replica received write request for position 0 from (14199)@172.17.15.226:42559
I0129 20:09:28.143936 2455 leveldb.cpp:436] Reading position from leveldb took 53999ns
I0129 20:09:28.187837 2455 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 43.700345ms
I0129 20:09:28.187947 2455 replica.cpp:712] Persisted action at 0
I0129 20:09:28.188987 2455 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 20:09:28.248370 2455 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 59.324021ms
I0129 20:09:28.248463 2455 replica.cpp:712] Persisted action at 0
I0129 20:09:28.248500 2455 replica.cpp:697] Replica learned NOP action at position 0
I0129 20:09:28.249788 2443 log.cpp:675] Writer started with ending position 0
I0129 20:09:28.251401 2444 leveldb.cpp:436] Reading position from leveldb took 55810ns
I0129 20:09:28.252504 2450 registrar.cpp:340] Successfully fetched the registry (0B) in 348.880896ms
I0129 20:09:28.252696 2450 registrar.cpp:439] Applied 1 operations in 38188ns; attempting to update the 'registry'
I0129 20:09:28.253832 2452 log.cpp:683] Attempting to append 178 bytes to the log
I0129 20:09:28.254164 2444 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 20:09:28.255080 2456 replica.cpp:537] Replica received write request for position 1 from (14200)@172.17.15.226:42559
I0129 20:09:28.314440 2456 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 59.298923ms
I0129 20:09:28.314605 2456 replica.cpp:712] Persisted action at 1
I0129 20:09:28.315822 2456 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 20:09:28.386092 2456 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 70.181919ms
I0129 20:09:28.386562 2456 replica.cpp:712] Persisted action at 1
I0129 20:09:28.386936 2456 replica.cpp:697] Replica learned APPEND action at position 1
I0129 20:09:28.389300 2450 log.cpp:702] Attempting to truncate the log to 1
I0129 20:09:28.389344 2448 registrar.cpp:484] Successfully updated the 'registry' in 136.510976ms
I0129 20:09:28.389921 2448 registrar.cpp:370] Successfully recovered registrar
I0129 20:09:28.390285 2450 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 20:09:28.390563 2448 master.cpp:1520] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I0129 20:09:28.390898 2448 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 20:09:28.391937 2453 replica.cpp:537] Replica received write request for position 2 from (14201)@172.17.15.226:42559
I0129 20:09:28.456441 2453 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 64.440182ms
I0129 20:09:28.456516 2453 replica.cpp:712] Persisted action at 2
I0129 20:09:28.457381 2452 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 20:09:28.524127 2452 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 66.581029ms
I0129 20:09:28.524289 2452 leveldb.cpp:399] Deleting ~1 keys from leveldb took 65448ns
I0129 20:09:28.524322 2452 replica.cpp:712] Persisted action at 2
I0129 20:09:28.524361 2452 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 20:09:28.533155 2422 scheduler.cpp:154] Version: 0.28.0
I0129 20:09:28.533903 2441 scheduler.cpp:236] New master detected at master@172.17.15.226:42559
I0129 20:09:28.534950 2452 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.15.226:42559
I0129 20:09:28.537209 2442 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 20:09:28.537752 2445 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.15.226:34886
I0129 20:09:28.538061 2445 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 20:09:28.538152 2445 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 20:09:28.538564 2445 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 20:09:28.539109 2453 hierarchical.cpp:265] Added framework 2f22e602-a07f-4537-8424-38af55d68b16-0000
I0129 20:09:28.539111 2446 master.hpp:1658] Sending heartbeat to 2f22e602-a07f-4537-8424-38af55d68b16-0000
I0129 20:09:28.539255 2453 hierarchical.cpp:1403] No resources available to allocate!
I0129 20:09:28.539311 2453 hierarchical.cpp:1498] No inverse offers to send out!
I0129 20:09:28.539350 2453 hierarchical.cpp:1096] Performed allocation for 0 slaves in 200421ns
I0129 20:09:28.539975 2445 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.15.226:42559
I0129 20:09:28.540596 2445 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.15.226:42559
I0129 20:09:28.541113 2445 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 20:09:28.541678 2445 scheduler.cpp:298] Sending REQUEST call to master@172.17.15.226:42559
I0129 20:09:28.543318 2451 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 20:09:28.543771 2456 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.15.226:34887
I0129 20:09:28.543895 2456 master.cpp:2717] Processing REQUEST call for framework 2f22e602-a07f-4537-8424-38af55d68b16-0000 (default)
I0129 20:09:28.544101 2453 hierarchical.cpp:589] Received resource request from framework 2f22e602-a07f-4537-8424-38af55d68b16-0000
I0129 20:09:28.544538 2456 master.cpp:1025] Master terminating
I0129 20:09:28.544903 2453 hierarchical.cpp:326] Removed framework 2f22e602-a07f-4537-8424-38af55d68b16-0000
E0129 20:09:28.545860 2449 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (911 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0129 20:09:28.734719 2422 leveldb.cpp:174] Opened db in 182.558264ms
I0129 20:09:28.779439 2422 leveldb.cpp:181] Compacted db in 44.624331ms
I0129 20:09:28.779558 2422 leveldb.cpp:196] Created db iterator in 28889ns
I0129 20:09:28.779583 2422 leveldb.cpp:202] Seeked to beginning of db in 3672ns
I0129 20:09:28.779598 2422 leveldb.cpp:271] Iterated through 0 keys in the db in 298ns
I0129 20:09:28.779660 2422 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 20:09:28.781250 2455 recover.cpp:447] Starting replica recovery
I0129 20:09:28.781538 2455 recover.cpp:473] Replica is in EMPTY status
I0129 20:09:28.782886 2448 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14209)@172.17.15.226:42559
I0129 20:09:28.783419 2452 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 20:09:28.783982 2447 master.cpp:374] Master 40e6eb18-f962-4bba-8535-3816263bbe1d (486be6d149d4) started on 172.17.15.226:42559
I0129 20:09:28.784010 2442 recover.cpp:564] Updating replica status to STARTING
I0129 20:09:28.784011 2447 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/BNVKxp/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="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/BNVKxp/master" --zk_session_timeout="10secs"
I0129 20:09:28.784564 2447 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 20:09:28.784584 2447 master.cpp:426] Master only allowing authenticated slaves to register
I0129 20:09:28.784595 2447 credentials.hpp:35] Loading credentials for authentication from '/tmp/BNVKxp/credentials'
I0129 20:09:28.785166 2447 master.cpp:466] Using default 'crammd5' authenticator
I0129 20:09:28.785420 2447 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 20:09:28.785578 2447 master.cpp:569] Authorization enabled
I0129 20:09:28.786242 2441 whitelist_watcher.cpp:77] No whitelist given
I0129 20:09:28.786337 2448 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 20:09:28.788564 2455 master.cpp:1710] The newly elected leader is master@172.17.15.226:42559 with id 40e6eb18-f962-4bba-8535-3816263bbe1d
I0129 20:09:28.788622 2455 master.cpp:1723] Elected as the leading master!
I0129 20:09:28.788657 2455 master.cpp:1468] Recovering from registrar
I0129 20:09:28.788853 2444 registrar.cpp:307] Recovering registrar
I0129 20:09:28.817458 2442 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 32.961329ms
I0129 20:09:28.817540 2442 replica.cpp:320] Persisted replica status to STARTING
I0129 20:09:28.817929 2450 recover.cpp:473] Replica is in STARTING status
I0129 20:09:28.820273 2453 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14211)@172.17.15.226:42559
I0129 20:09:28.820691 2455 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 20:09:28.821431 2442 recover.cpp:564] Updating replica status to VOTING
I0129 20:09:28.899924 2455 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 77.895605ms
I0129 20:09:28.900007 2455 replica.cpp:320] Persisted replica status to VOTING
I0129 20:09:28.900292 2442 recover.cpp:578] Successfully joined the Paxos group
I0129 20:09:28.900545 2442 recover.cpp:462] Recover process terminated
I0129 20:09:28.901463 2456 log.cpp:659] Attempting to start the writer
I0129 20:09:28.903018 2450 replica.cpp:493] Replica received implicit promise request from (14212)@172.17.15.226:42559 with proposal 1
I0129 20:09:28.960813 2450 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 57.727524ms
I0129 20:09:28.960917 2450 replica.cpp:342] Persisted promised to 1
I0129 20:09:28.961859 2454 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 20:09:28.963132 2451 replica.cpp:388] Replica received explicit promise request from (14213)@172.17.15.226:42559 for position 0 with proposal 2
I0129 20:09:29.002959 2451 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.743096ms
I0129 20:09:29.003057 2451 replica.cpp:712] Persisted action at 0
I0129 20:09:29.004396 2448 replica.cpp:537] Replica received write request for position 0 from (14214)@172.17.15.226:42559
I0129 20:09:29.004508 2448 leveldb.cpp:436] Reading position from leveldb took 42741ns
I0129 20:09:29.045059 2448 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.482347ms
I0129 20:09:29.045150 2448 replica.cpp:712] Persisted action at 0
I0129 20:09:29.046000 2452 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 20:09:29.070487 2452 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.126533ms
I0129 20:09:29.070580 2452 replica.cpp:712] Persisted action at 0
I0129 20:09:29.070615 2452 replica.cpp:697] Replica learned NOP action at position 0
I0129 20:09:29.071434 2450 log.cpp:675] Writer started with ending position 0
I0129 20:09:29.072764 2447 leveldb.cpp:436] Reading position from leveldb took 55253ns
I0129 20:09:29.073927 2452 registrar.cpp:340] Successfully fetched the registry (0B) in 285.000192ms
I0129 20:09:29.074075 2452 registrar.cpp:439] Applied 1 operations in 43553ns; attempting to update the 'registry'
I0129 20:09:29.074868 2443 log.cpp:683] Attempting to append 178 bytes to the log
I0129 20:09:29.075012 2449 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 20:09:29.075799 2442 replica.cpp:537] Replica received write request for position 1 from (14215)@172.17.15.226:42559
I0129 20:09:29.111484 2442 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 35.616823ms
I0129 20:09:29.111582 2442 replica.cpp:712] Persisted action at 1
I0129 20:09:29.112562 2449 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 20:09:29.153830 2449 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 41.214931ms
I0129 20:09:29.153924 2449 replica.cpp:712] Persisted action at 1
I0129 20:09:29.153964 2449 replica.cpp:697] Replica learned APPEND action at position 1
I0129 20:09:29.155315 2444 registrar.cpp:484] Successfully updated the 'registry' in 81.153024ms
I0129 20:09:29.155484 2444 registrar.cpp:370] Successfully recovered registrar
I0129 20:09:29.155550 2442 log.cpp:702] Attempting to truncate the log to 1
I0129 20:09:29.155711 2449 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 20:09:29.156407 2444 master.cpp:1520] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I0129 20:09:29.156432 2456 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 20:09:29.156846 2454 replica.cpp:537] Replica received write request for position 2 from (14216)@172.17.15.226:42559
I0129 20:09:29.210053 2454 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 53.141418ms
I0129 20:09:29.210151 2454 replica.cpp:712] Persisted action at 2
I0129 20:09:29.211432 2446 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 20:09:29.248630 2446 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 37.002957ms
I0129 20:09:29.248800 2446 leveldb.cpp:399] Deleting ~1 keys from leveldb took 76092ns
I0129 20:09:29.248957 2446 replica.cpp:712] Persisted action at 2
I0129 20:09:29.249094 2446 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 20:09:29.257709 2422 scheduler.cpp:154] Version: 0.28.0
I0129 20:09:29.258397 2447 scheduler.cpp:236] New master detected at master@172.17.15.226:42559
I0129 20:09:29.259441 2441 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.15.226:42559
I0129 20:09:29.261940 2445 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 20:09:29.263062 2445 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.15.226:34888
I0129 20:09:29.263733 2445 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 20:09:29.263830 2445 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 20:09:29.264267 2445 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 20:09:29.264854 2453 hierarchical.cpp:265] Added framework 40e6eb18-f962-4bba-8535-3816263bbe1d-0000
I0129 20:09:29.265058 2456 master.hpp:1658] Sending heartbeat to 40e6eb18-f962-4bba-8535-3816263bbe1d-0000
I0129 20:09:29.265429 2453 hierarchical.cpp:1403] No resources available to allocate!
I0129 20:09:29.265470 2453 hierarchical.cpp:1498] No inverse offers to send out!
I0129 20:09:29.265501 2453 hierarchical.cpp:1096] Performed allocation for 0 slaves in 189042ns
I0129 20:09:29.265943 2453 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.15.226:42559
I0129 20:09:29.266656 2453 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.15.226:42559
I0129 20:09:29.267539 2453 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 20:09:29.267554 2448 scheduler.cpp:298] Sending REQUEST call to master@172.17.15.226:42559
I0129 20:09:29.269647 2444 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 20:09:29.270269 2452 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.15.226:34889
I0129 20:09:29.270613 2452 master.cpp:2717] Processing REQUEST call for framework 40e6eb18-f962-4bba-8535-3816263bbe1d-0000 (default)
I0129 20:09:29.270884 2447 hierarchical.cpp:589] Received resource request from framework 40e6eb18-f962-4bba-8535-3816263bbe1d-0000
I0129 20:09:29.271294 2450 master.cpp:1025] Master terminating
I0129 20:09:29.271611 2452 hierarchical.cpp:326] Removed framework 40e6eb18-f962-4bba-8535-3816263bbe1d-0000
E0129 20:09:29.272833 2449 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (734 ms)
[----------] 22 tests from ContentType/SchedulerTest (20295 ms total)
[----------] Global test environment tear-down
2016-01-29 20:09:30,337:2422(0x7f25e0857700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:60077] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
[==========] 968 tests from 127 test cases ran. (919767 ms total)
[ PASSED ] 967 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ShasumTest.SHA512SimpleFile
1 FAILED TEST
YOU HAVE 9 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1454095696-8448
Untagged: mesos-1454095696-8448:latest
Deleted: b0786fd604545e90a12f917add29455410a048c535a4d4003c0402ae7535197f
Deleted: 162ff20d0c28c08d2a5f8479a96369de54ed004fb13948277e2037badf5f380a
Deleted: 9f17ceb293b72b3a1564a445bf6b22fc6556ab5dd01ccc860c8664ff97f6355f
Deleted: 246ceb72494e088e54aba67338a8ca500d423a146526f9eb6d8f31ad505902f6
Deleted: 91ad425b599bb60264977d5d4f7dd8d6ea056476e9997bf329686504973150df
Deleted: c95437e8b93a0e73e6191d397ee4326ff36eae2cda8eb84a5d28a05ef24cde65
Deleted: af25a58301b80a0598d7d189da5af57e339f51bc9734c2adfbe32a014ec6d41b
Deleted: 8cb117b48b8ef3af17064ca260604fe8f54f9d302f8c055298b80d3db5501e31
Deleted: 99ce1b5b298d8a44cb173be600af376ca358f9e9841942ad759d3e6e035117ba
Deleted: 2f5e5060d0c092261a13cf00e0f79f199e718c7c9b2fc70cec2ad2b903b15666
Deleted: 50a30206736ccaa1467165ef964b093e762eedb3b076ba34fa81e9e0f51a5052
Deleted: 89b0a247f0fee26f357cb5a1fe0dff3e7cdcf8cb9e1c7b8e1273ca27f868a713
Deleted: 73b75bd49f1e49fc06dfc1247324711e84d6341662ac2b8f3928f5b5a87af7e8
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1585
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1585/>
------------------------------------------
Started by upstream project "Mesos" build number 1585
originally caused by:
Started by an SCM change
[EnvInject] - Loading node environment variables.
Building remotely on H3 (Mapreduce Hadoop Zookeeper Hdfs yahoo-not-h2) in workspace <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/ws/>
Cloning the remote Git repository
Using shallow clone
Cloning repository https://git-wip-us.apache.org/repos/asf/mesos.git
> git init <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/ws/> # timeout=10
Fetching upstream changes from https://git-wip-us.apache.org/repos/asf/mesos.git
> git --version # timeout=10
> git -c core.askpass=true fetch --tags --progress https://git-wip-us.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/* --depth=1 # timeout=60
> git config remote.origin.url https://git-wip-us.apache.org/repos/asf/mesos.git # timeout=10
> git config --add remote.origin.fetch +refs/heads/*:refs/remotes/origin/* # timeout=10
> git config remote.origin.url https://git-wip-us.apache.org/repos/asf/mesos.git # timeout=10
Fetching upstream changes from https://git-wip-us.apache.org/repos/asf/mesos.git
> git -c core.askpass=true fetch --tags --progress https://git-wip-us.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/* # timeout=60
Checking out Revision fac024fda0897a62377f17549e61b8ac8e531e2e (origin/master)
> git config core.sparsecheckout # timeout=10
> git checkout -f fac024fda0897a62377f17549e61b8ac8e531e2e
FATAL: Could not checkout fac024fda0897a62377f17549e61b8ac8e531e2e
hudson.plugins.git.GitException: Could not checkout fac024fda0897a62377f17549e61b8ac8e531e2e
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl$9.execute(CliGitAPIImpl.java:1964)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:152)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:145)
at hudson.remoting.UserRequest.perform(UserRequest.java:121)
at hudson.remoting.UserRequest.perform(UserRequest.java:49)
at hudson.remoting.Request$2.run(Request.java:326)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:68)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
at ......remote call to H3(Native Method)
at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1413)
at hudson.remoting.UserResponse.retrieve(UserRequest.java:221)
at hudson.remoting.Channel.call(Channel.java:778)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler.execute(RemoteGitImpl.java:145)
at sun.reflect.GeneratedMethodAccessor533.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler.invoke(RemoteGitImpl.java:131)
at com.sun.proxy.$Proxy75.execute(Unknown Source)
at hudson.plugins.git.GitSCM.checkout(GitSCM.java:1081)
at hudson.scm.SCM.checkout(SCM.java:484)
at hudson.model.AbstractProject.checkout(AbstractProject.java:1274)
at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:609)
at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:531)
at hudson.model.Run.execute(Run.java:1738)
at hudson.matrix.MatrixRun.run(MatrixRun.java:146)
at hudson.model.ResourceController.execute(ResourceController.java:98)
at hudson.model.Executor.run(Executor.java:381)
Caused by: hudson.plugins.git.GitException: Command "git checkout -f fac024fda0897a62377f17549e61b8ac8e531e2e" returned status code 128:
stdout:
stderr: fatal: reference is not a tree: fac024fda0897a62377f17549e61b8ac8e531e2e
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl.launchCommandIn(CliGitAPIImpl.java:1693)
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl.access$500(CliGitAPIImpl.java:62)
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl$9.execute(CliGitAPIImpl.java:1956)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:152)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:145)
at hudson.remoting.UserRequest.perform(UserRequest.java:121)
at hudson.remoting.UserRequest.perform(UserRequest.java:49)
at hudson.remoting.Request$2.run(Request.java:326)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:68)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1584
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1584/>
------------------------------------------
[...truncated 163780 lines...]
I0129 08:34:10.752039 2445 status_update_manager.cpp:282] Closing status update streams for framework 0daa92b4-1ccd-42fc-97b6-8fa74355f9bf-0000
I0129 08:34:10.752109 2445 status_update_manager.cpp:528] Cleaning up status update stream for task 1b5c25c0-b5f0-45ab-8374-aff3c845ce71 of framework 0daa92b4-1ccd-42fc-97b6-8fa74355f9bf-0000
I0129 08:34:10.752151 2436 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_Qjch9j/slaves/0daa92b4-1ccd-42fc-97b6-8fa74355f9bf-S0/frameworks/0daa92b4-1ccd-42fc-97b6-8fa74355f9bf-0000' for gc 6.99999129600593days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (623 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0129 08:34:10.864192 2417 leveldb.cpp:174] Opened db in 106.672211ms
I0129 08:34:10.906321 2417 leveldb.cpp:181] Compacted db in 42.064958ms
I0129 08:34:10.906396 2417 leveldb.cpp:196] Created db iterator in 26507ns
I0129 08:34:10.906417 2417 leveldb.cpp:202] Seeked to beginning of db in 2328ns
I0129 08:34:10.906430 2417 leveldb.cpp:271] Iterated through 0 keys in the db in 410ns
I0129 08:34:10.906491 2417 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 08:34:10.907312 2440 recover.cpp:447] Starting replica recovery
I0129 08:34:10.907670 2440 recover.cpp:473] Replica is in EMPTY status
I0129 08:34:10.909075 2449 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14200)@172.17.15.185:59503
I0129 08:34:10.909600 2442 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 08:34:10.910158 2449 recover.cpp:564] Updating replica status to STARTING
I0129 08:34:10.911136 2447 master.cpp:374] Master b3a51456-6854-44e7-81c6-2803308f0241 (5942373daf52) started on 172.17.15.185:59503
I0129 08:34:10.911165 2447 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/yilTSn/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="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/yilTSn/master" --zk_session_timeout="10secs"
I0129 08:34:10.911586 2447 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 08:34:10.911602 2447 master.cpp:426] Master only allowing authenticated slaves to register
I0129 08:34:10.911612 2447 credentials.hpp:35] Loading credentials for authentication from '/tmp/yilTSn/credentials'
I0129 08:34:10.912015 2447 master.cpp:466] Using default 'crammd5' authenticator
I0129 08:34:10.912206 2447 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 08:34:10.912400 2447 master.cpp:569] Authorization enabled
I0129 08:34:10.912657 2436 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 08:34:10.912663 2451 whitelist_watcher.cpp:77] No whitelist given
I0129 08:34:10.915237 2448 master.cpp:1710] The newly elected leader is master@172.17.15.185:59503 with id b3a51456-6854-44e7-81c6-2803308f0241
I0129 08:34:10.915271 2448 master.cpp:1723] Elected as the leading master!
I0129 08:34:10.915292 2448 master.cpp:1468] Recovering from registrar
I0129 08:34:10.915459 2442 registrar.cpp:307] Recovering registrar
I0129 08:34:10.949198 2438 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.815888ms
I0129 08:34:10.949234 2438 replica.cpp:320] Persisted replica status to STARTING
I0129 08:34:10.949503 2439 recover.cpp:473] Replica is in STARTING status
I0129 08:34:10.950477 2437 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14202)@172.17.15.185:59503
I0129 08:34:10.950883 2449 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 08:34:10.951365 2440 recover.cpp:564] Updating replica status to VOTING
I0129 08:34:10.982583 2449 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.980005ms
I0129 08:34:10.982622 2449 replica.cpp:320] Persisted replica status to VOTING
I0129 08:34:10.982748 2445 recover.cpp:578] Successfully joined the Paxos group
I0129 08:34:10.983403 2445 recover.cpp:462] Recover process terminated
I0129 08:34:10.983640 2449 log.cpp:659] Attempting to start the writer
I0129 08:34:10.984799 2442 replica.cpp:493] Replica received implicit promise request from (14203)@172.17.15.185:59503 with proposal 1
I0129 08:34:11.016059 2442 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.223623ms
I0129 08:34:11.016098 2442 replica.cpp:342] Persisted promised to 1
I0129 08:34:11.016965 2440 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 08:34:11.018302 2438 replica.cpp:388] Replica received explicit promise request from (14204)@172.17.15.185:59503 for position 0 with proposal 2
I0129 08:34:11.049605 2438 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 31.260201ms
I0129 08:34:11.049643 2438 replica.cpp:712] Persisted action at 0
I0129 08:34:11.050686 2451 replica.cpp:537] Replica received write request for position 0 from (14205)@172.17.15.185:59503
I0129 08:34:11.050748 2451 leveldb.cpp:436] Reading position from leveldb took 28617ns
I0129 08:34:11.083077 2451 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 32.285991ms
I0129 08:34:11.083119 2451 replica.cpp:712] Persisted action at 0
I0129 08:34:11.083936 2438 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 08:34:11.116917 2438 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.914962ms
I0129 08:34:11.116998 2438 replica.cpp:712] Persisted action at 0
I0129 08:34:11.117033 2438 replica.cpp:697] Replica learned NOP action at position 0
I0129 08:34:11.117869 2451 log.cpp:675] Writer started with ending position 0
I0129 08:34:11.119047 2441 leveldb.cpp:436] Reading position from leveldb took 52198ns
I0129 08:34:11.119992 2445 registrar.cpp:340] Successfully fetched the registry (0B) in 204.385024ms
I0129 08:34:11.120112 2445 registrar.cpp:439] Applied 1 operations in 34721ns; attempting to update the 'registry'
I0129 08:34:11.120853 2447 log.cpp:683] Attempting to append 178 bytes to the log
I0129 08:34:11.120965 2440 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 08:34:11.121657 2438 replica.cpp:537] Replica received write request for position 1 from (14206)@172.17.15.185:59503
I0129 08:34:11.159574 2438 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 37.877254ms
I0129 08:34:11.159610 2438 replica.cpp:712] Persisted action at 1
I0129 08:34:11.160361 2447 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 08:34:11.193033 2447 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 32.634725ms
I0129 08:34:11.193083 2447 replica.cpp:712] Persisted action at 1
I0129 08:34:11.193106 2447 replica.cpp:697] Replica learned APPEND action at position 1
I0129 08:34:11.194407 2450 registrar.cpp:484] Successfully updated the 'registry' in 74.203904ms
I0129 08:34:11.194563 2450 registrar.cpp:370] Successfully recovered registrar
I0129 08:34:11.194622 2444 log.cpp:702] Attempting to truncate the log to 1
I0129 08:34:11.194792 2443 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 08:34:11.195312 2449 master.cpp:1520] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I0129 08:34:11.195358 2437 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 08:34:11.195720 2439 replica.cpp:537] Replica received write request for position 2 from (14207)@172.17.15.185:59503
I0129 08:34:11.234916 2439 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 39.157004ms
I0129 08:34:11.234953 2439 replica.cpp:712] Persisted action at 2
I0129 08:34:11.235651 2438 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 08:34:11.264420 2438 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 28.73605ms
I0129 08:34:11.264492 2438 leveldb.cpp:399] Deleting ~1 keys from leveldb took 38514ns
I0129 08:34:11.264514 2438 replica.cpp:712] Persisted action at 2
I0129 08:34:11.264538 2438 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 08:34:11.266762 2417 scheduler.cpp:154] Version: 0.28.0
I0129 08:34:11.267458 2437 scheduler.cpp:236] New master detected at master@172.17.15.185:59503
I0129 08:34:11.268553 2440 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.15.185:59503
I0129 08:34:11.270102 2439 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 08:34:11.270658 2444 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.15.185:60734
I0129 08:34:11.270906 2444 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 08:34:11.270982 2444 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 08:34:11.271334 2444 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 08:34:11.271780 2448 hierarchical.cpp:265] Added framework b3a51456-6854-44e7-81c6-2803308f0241-0000
I0129 08:34:11.271863 2448 hierarchical.cpp:1403] No resources available to allocate!
I0129 08:34:11.271898 2448 hierarchical.cpp:1498] No inverse offers to send out!
I0129 08:34:11.271924 2448 hierarchical.cpp:1096] Performed allocation for 0 slaves in 117563ns
I0129 08:34:11.271951 2448 master.hpp:1658] Sending heartbeat to b3a51456-6854-44e7-81c6-2803308f0241-0000
I0129 08:34:11.272512 2441 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.15.185:59503
I0129 08:34:11.273708 2444 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.15.185:59503
I0129 08:34:11.274106 2444 scheduler.cpp:298] Sending REQUEST call to master@172.17.15.185:59503
I0129 08:34:11.275060 2445 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 08:34:11.275518 2439 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 08:34:11.276037 2437 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.15.185:60735
I0129 08:34:11.276198 2437 master.cpp:2717] Processing REQUEST call for framework b3a51456-6854-44e7-81c6-2803308f0241-0000 (default)
I0129 08:34:11.276388 2449 hierarchical.cpp:589] Received resource request from framework b3a51456-6854-44e7-81c6-2803308f0241-0000
I0129 08:34:11.276821 2443 master.cpp:1025] Master terminating
I0129 08:34:11.277096 2451 hierarchical.cpp:326] Removed framework b3a51456-6854-44e7-81c6-2803308f0241-0000
E0129 08:34:11.278005 2448 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (528 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0129 08:34:11.400167 2417 leveldb.cpp:174] Opened db in 115.064517ms
I0129 08:34:11.460362 2417 leveldb.cpp:181] Compacted db in 60.123659ms
I0129 08:34:11.460430 2417 leveldb.cpp:196] Created db iterator in 21404ns
I0129 08:34:11.460453 2417 leveldb.cpp:202] Seeked to beginning of db in 2348ns
I0129 08:34:11.460464 2417 leveldb.cpp:271] Iterated through 0 keys in the db in 415ns
I0129 08:34:11.460505 2417 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 08:34:11.461024 2449 recover.cpp:447] Starting replica recovery
I0129 08:34:11.461659 2448 recover.cpp:473] Replica is in EMPTY status
I0129 08:34:11.462765 2441 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14215)@172.17.15.185:59503
I0129 08:34:11.463460 2450 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 08:34:11.464073 2443 recover.cpp:564] Updating replica status to STARTING
I0129 08:34:11.464299 2448 master.cpp:374] Master 889db711-b151-43d9-aef3-7c3fa443461a (5942373daf52) started on 172.17.15.185:59503
I0129 08:34:11.464442 2448 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/j1NeqL/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="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/j1NeqL/master" --zk_session_timeout="10secs"
I0129 08:34:11.464750 2448 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 08:34:11.464761 2448 master.cpp:426] Master only allowing authenticated slaves to register
I0129 08:34:11.464767 2448 credentials.hpp:35] Loading credentials for authentication from '/tmp/j1NeqL/credentials'
I0129 08:34:11.465068 2448 master.cpp:466] Using default 'crammd5' authenticator
I0129 08:34:11.465240 2448 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 08:34:11.465389 2448 master.cpp:569] Authorization enabled
I0129 08:34:11.465615 2442 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 08:34:11.465636 2444 whitelist_watcher.cpp:77] No whitelist given
I0129 08:34:11.467123 2451 master.cpp:1710] The newly elected leader is master@172.17.15.185:59503 with id 889db711-b151-43d9-aef3-7c3fa443461a
I0129 08:34:11.467218 2451 master.cpp:1723] Elected as the leading master!
I0129 08:34:11.467321 2451 master.cpp:1468] Recovering from registrar
I0129 08:34:11.467478 2449 registrar.cpp:307] Recovering registrar
I0129 08:34:11.493551 2440 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 28.983179ms
I0129 08:34:11.493592 2440 replica.cpp:320] Persisted replica status to STARTING
I0129 08:34:11.493890 2441 recover.cpp:473] Replica is in STARTING status
I0129 08:34:11.494956 2437 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14217)@172.17.15.185:59503
I0129 08:34:11.495503 2443 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 08:34:11.495875 2441 recover.cpp:564] Updating replica status to VOTING
2016-01-29 08:34:11,511:2417(0x7f15adfdb700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:59757] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0129 08:34:11.518785 2440 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.773061ms
I0129 08:34:11.518826 2440 replica.cpp:320] Persisted replica status to VOTING
I0129 08:34:11.518955 2438 recover.cpp:578] Successfully joined the Paxos group
I0129 08:34:11.519183 2438 recover.cpp:462] Recover process terminated
I0129 08:34:11.519639 2449 log.cpp:659] Attempting to start the writer
I0129 08:34:11.520787 2448 replica.cpp:493] Replica received implicit promise request from (14218)@172.17.15.185:59503 with proposal 1
I0129 08:34:11.543902 2448 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.084349ms
I0129 08:34:11.543933 2448 replica.cpp:342] Persisted promised to 1
I0129 08:34:11.544731 2446 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 08:34:11.546231 2443 replica.cpp:388] Replica received explicit promise request from (14219)@172.17.15.185:59503 for position 0 with proposal 2
I0129 08:34:11.569000 2443 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.726396ms
I0129 08:34:11.569036 2443 replica.cpp:712] Persisted action at 0
I0129 08:34:11.570559 2448 replica.cpp:537] Replica received write request for position 0 from (14220)@172.17.15.185:59503
I0129 08:34:11.570660 2448 leveldb.cpp:436] Reading position from leveldb took 54245ns
I0129 08:34:11.592545 2448 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 21.831432ms
I0129 08:34:11.592586 2448 replica.cpp:712] Persisted action at 0
I0129 08:34:11.593279 2451 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 08:34:11.617727 2451 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.316299ms
I0129 08:34:11.617770 2451 replica.cpp:712] Persisted action at 0
I0129 08:34:11.617794 2451 replica.cpp:697] Replica learned NOP action at position 0
I0129 08:34:11.618448 2440 log.cpp:675] Writer started with ending position 0
I0129 08:34:11.619772 2450 leveldb.cpp:436] Reading position from leveldb took 37569ns
I0129 08:34:11.620816 2438 registrar.cpp:340] Successfully fetched the registry (0B) in 153.291008ms
I0129 08:34:11.621001 2438 registrar.cpp:439] Applied 1 operations in 39099ns; attempting to update the 'registry'
I0129 08:34:11.621888 2451 log.cpp:683] Attempting to append 178 bytes to the log
I0129 08:34:11.622069 2447 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 08:34:11.622944 2450 replica.cpp:537] Replica received write request for position 1 from (14221)@172.17.15.185:59503
I0129 08:34:11.642709 2450 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 19.712477ms
I0129 08:34:11.642751 2450 replica.cpp:712] Persisted action at 1
I0129 08:34:11.643564 2439 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 08:34:11.667953 2439 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 24.345645ms
I0129 08:34:11.667992 2439 replica.cpp:712] Persisted action at 1
I0129 08:34:11.668015 2439 replica.cpp:697] Replica learned APPEND action at position 1
I0129 08:34:11.669216 2441 registrar.cpp:484] Successfully updated the 'registry' in 48.112896ms
I0129 08:34:11.669378 2441 registrar.cpp:370] Successfully recovered registrar
I0129 08:34:11.669534 2439 log.cpp:702] Attempting to truncate the log to 1
I0129 08:34:11.669967 2451 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 08:34:11.669996 2440 master.cpp:1520] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I0129 08:34:11.670023 2446 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 08:34:11.670938 2443 replica.cpp:537] Replica received write request for position 2 from (14222)@172.17.15.185:59503
I0129 08:34:11.692996 2443 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.013596ms
I0129 08:34:11.693035 2443 replica.cpp:712] Persisted action at 2
I0129 08:34:11.693749 2445 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 08:34:11.718096 2445 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.30634ms
I0129 08:34:11.718217 2445 leveldb.cpp:399] Deleting ~1 keys from leveldb took 76182ns
I0129 08:34:11.718261 2445 replica.cpp:712] Persisted action at 2
I0129 08:34:11.718298 2445 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 08:34:11.720932 2417 scheduler.cpp:154] Version: 0.28.0
I0129 08:34:11.721592 2445 scheduler.cpp:236] New master detected at master@172.17.15.185:59503
I0129 08:34:11.722816 2436 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.15.185:59503
I0129 08:34:11.725059 2437 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 08:34:11.725611 2448 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.15.185:60738
I0129 08:34:11.726022 2448 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 08:34:11.726099 2448 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 08:34:11.726377 2448 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 08:34:11.726831 2441 hierarchical.cpp:265] Added framework 889db711-b151-43d9-aef3-7c3fa443461a-0000
I0129 08:34:11.726907 2441 hierarchical.cpp:1403] No resources available to allocate!
I0129 08:34:11.726938 2441 hierarchical.cpp:1498] No inverse offers to send out!
I0129 08:34:11.726958 2441 hierarchical.cpp:1096] Performed allocation for 0 slaves in 104390ns
I0129 08:34:11.726974 2437 master.hpp:1658] Sending heartbeat to 889db711-b151-43d9-aef3-7c3fa443461a-0000
I0129 08:34:11.727799 2437 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.15.185:59503
I0129 08:34:11.728199 2437 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.15.185:59503
I0129 08:34:11.728857 2449 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 08:34:11.728895 2437 scheduler.cpp:298] Sending REQUEST call to master@172.17.15.185:59503
I0129 08:34:11.730132 2447 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 08:34:11.730590 2440 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.15.185:60739
I0129 08:34:11.730877 2440 master.cpp:2717] Processing REQUEST call for framework 889db711-b151-43d9-aef3-7c3fa443461a-0000 (default)
I0129 08:34:11.731097 2439 hierarchical.cpp:589] Received resource request from framework 889db711-b151-43d9-aef3-7c3fa443461a-0000
I0129 08:34:11.731544 2442 master.cpp:1025] Master terminating
I0129 08:34:11.732125 2447 hierarchical.cpp:326] Removed framework 889db711-b151-43d9-aef3-7c3fa443461a-0000
E0129 08:34:11.733640 2445 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (454 ms)
[----------] 22 tests from ContentType/SchedulerTest (15557 ms total)
[----------] Global test environment tear-down
[==========] 968 tests from 127 test cases ran. (754127 ms total)
[ PASSED ] 967 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ShasumTest.SHA512SimpleFile
1 FAILED TEST
YOU HAVE 9 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1454054165-14229
Untagged: mesos-1454054165-14229:latest
Deleted: 60fd4f026fbbf826189a13d4ef28b3c69e931406e11025d661d4dbf31a2ff1cc
Deleted: a97cb91cd53ac6f2fcc21aab3a3612d67242efe726a4a9ed7ff7bd5ca32bf35c
Deleted: ff1d9a78e9e2b25efaa60c320c8f1df11d15e61db6269f6d5208d7caade07900
Deleted: 5dd3eff67e1e7f95d23958715f6308987d984d1f75e4f800ef20bd0c44bbde71
Deleted: 21c2c8ee7a520d956468acaf01f4f2179f4117342aa715d891a2e80daecca221
Deleted: 564f6ce58bbe6c1275da040998584b3b6ec031ce538038342f9e6ab98c1cf0fd
Deleted: 333adc8054b3460d34c7b212ca147392854a3186239295b156c6c35c4c82182c
Deleted: 022215d3d7f14a0b8ef345efa4f6b5f0f919076834f81d50c3b06ce765960d75
Deleted: 1c302089ae36dfb3fa12097928636ab48bd2f2c7346185a3e2b7609a3f99c639
Deleted: 5e79a4dc9261c174378fdfac855b0f30b92d18843abf45c8bcef8ecd7f3dcb8e
Deleted: e2a1d25777185b86fea89ec254530bef8b531ab0a3f9eb5ff6517520449deaa3
Deleted: 08ec3722f83e0b8c2e0ead484ae25ba7495e6dc989023218554d0590e681e699
Deleted: 5212fa5be2c077d07df527c7191f94f65a54e35ada34ca92546732870fd1182a
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,docker||Hadoop #1583
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1583/>
------------------------------------------
[...truncated 160050 lines...]
I0129 06:45:31.524857 2453 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_2IsWVp/slaves/dcb87e28-31da-463c-8d55-1626bb5826bf-S0/frameworks/dcb87e28-31da-463c-8d55-1626bb5826bf-0000/executors/default' for gc 6.99999392708444days in the future
I0129 06:45:31.524917 2455 status_update_manager.cpp:282] Closing status update streams for framework dcb87e28-31da-463c-8d55-1626bb5826bf-0000
I0129 06:45:31.525007 2455 status_update_manager.cpp:528] Cleaning up status update stream for task deada242-42c6-4d32-8853-cd217a91440c of framework dcb87e28-31da-463c-8d55-1626bb5826bf-0000
I0129 06:45:31.525053 2453 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_2IsWVp/slaves/dcb87e28-31da-463c-8d55-1626bb5826bf-S0/frameworks/dcb87e28-31da-463c-8d55-1626bb5826bf-0000' for gc 6.99999392393481days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (121 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0129 06:45:31.534073 2421 leveldb.cpp:174] Opened db in 3.588099ms
I0129 06:45:31.534984 2421 leveldb.cpp:181] Compacted db in 871046ns
I0129 06:45:31.535034 2421 leveldb.cpp:196] Created db iterator in 19187ns
I0129 06:45:31.535053 2421 leveldb.cpp:202] Seeked to beginning of db in 1980ns
I0129 06:45:31.535064 2421 leveldb.cpp:271] Iterated through 0 keys in the db in 342ns
I0129 06:45:31.535107 2421 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 06:45:31.535593 2453 recover.cpp:447] Starting replica recovery
I0129 06:45:31.535990 2453 recover.cpp:473] Replica is in EMPTY status
I0129 06:45:31.537348 2451 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14174)@172.17.0.4:54981
I0129 06:45:31.537550 2452 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 06:45:31.538147 2440 recover.cpp:564] Updating replica status to STARTING
I0129 06:45:31.538611 2442 master.cpp:374] Master f4bf7192-609e-43cd-a4f3-c23f99b600c4 (9f1fa7546a87) started on 172.17.0.4:54981
I0129 06:45:31.538822 2447 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 512437ns
I0129 06:45:31.538857 2447 replica.cpp:320] Persisted replica status to STARTING
I0129 06:45:31.538637 2442 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/DoSPDJ/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="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/DoSPDJ/master" --zk_session_timeout="10secs"
I0129 06:45:31.538967 2442 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 06:45:31.538988 2442 master.cpp:426] Master only allowing authenticated slaves to register
I0129 06:45:31.539000 2442 credentials.hpp:35] Loading credentials for authentication from '/tmp/DoSPDJ/credentials'
I0129 06:45:31.539149 2444 recover.cpp:473] Replica is in STARTING status
I0129 06:45:31.539365 2442 master.cpp:466] Using default 'crammd5' authenticator
I0129 06:45:31.539523 2442 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 06:45:31.539841 2442 master.cpp:569] Authorization enabled
I0129 06:45:31.540081 2455 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 06:45:31.540102 2441 whitelist_watcher.cpp:77] No whitelist given
I0129 06:45:31.540313 2452 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14176)@172.17.0.4:54981
I0129 06:45:31.540737 2441 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 06:45:31.541329 2440 recover.cpp:564] Updating replica status to VOTING
I0129 06:45:31.542078 2443 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 435266ns
I0129 06:45:31.542114 2443 replica.cpp:320] Persisted replica status to VOTING
I0129 06:45:31.542280 2448 recover.cpp:578] Successfully joined the Paxos group
I0129 06:45:31.542546 2448 recover.cpp:462] Recover process terminated
I0129 06:45:31.542578 2445 master.cpp:1710] The newly elected leader is master@172.17.0.4:54981 with id f4bf7192-609e-43cd-a4f3-c23f99b600c4
I0129 06:45:31.542687 2445 master.cpp:1723] Elected as the leading master!
I0129 06:45:31.542726 2445 master.cpp:1468] Recovering from registrar
I0129 06:45:31.542924 2444 registrar.cpp:307] Recovering registrar
I0129 06:45:31.543689 2452 log.cpp:659] Attempting to start the writer
I0129 06:45:31.545243 2448 replica.cpp:493] Replica received implicit promise request from (14177)@172.17.0.4:54981 with proposal 1
I0129 06:45:31.545600 2448 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 322037ns
I0129 06:45:31.545626 2448 replica.cpp:342] Persisted promised to 1
I0129 06:45:31.546396 2446 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 06:45:31.547868 2446 replica.cpp:388] Replica received explicit promise request from (14178)@172.17.0.4:54981 for position 0 with proposal 2
I0129 06:45:31.548367 2446 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 443176ns
I0129 06:45:31.548403 2446 replica.cpp:712] Persisted action at 0
I0129 06:45:31.549893 2453 replica.cpp:537] Replica received write request for position 0 from (14179)@172.17.0.4:54981
I0129 06:45:31.549990 2453 leveldb.cpp:436] Reading position from leveldb took 54363ns
I0129 06:45:31.550448 2453 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 410203ns
I0129 06:45:31.550475 2453 replica.cpp:712] Persisted action at 0
I0129 06:45:31.551086 2442 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 06:45:31.551550 2442 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 318174ns
I0129 06:45:31.551578 2442 replica.cpp:712] Persisted action at 0
I0129 06:45:31.551599 2442 replica.cpp:697] Replica learned NOP action at position 0
I0129 06:45:31.552237 2454 log.cpp:675] Writer started with ending position 0
I0129 06:45:31.553341 2443 leveldb.cpp:436] Reading position from leveldb took 31600ns
I0129 06:45:31.554263 2449 registrar.cpp:340] Successfully fetched the registry (0B) in 11.256064ms
I0129 06:45:31.554379 2449 registrar.cpp:439] Applied 1 operations in 28307ns; attempting to update the 'registry'
I0129 06:45:31.555209 2444 log.cpp:683] Attempting to append 170 bytes to the log
I0129 06:45:31.555352 2453 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 06:45:31.556087 2440 replica.cpp:537] Replica received write request for position 1 from (14180)@172.17.0.4:54981
I0129 06:45:31.556483 2440 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 349119ns
I0129 06:45:31.556514 2440 replica.cpp:712] Persisted action at 1
I0129 06:45:31.557276 2446 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 06:45:31.557679 2446 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 359708ns
I0129 06:45:31.557710 2446 replica.cpp:712] Persisted action at 1
I0129 06:45:31.557734 2446 replica.cpp:697] Replica learned APPEND action at position 1
I0129 06:45:31.558900 2449 registrar.cpp:484] Successfully updated the 'registry' in 4.446976ms
I0129 06:45:31.559100 2449 registrar.cpp:370] Successfully recovered registrar
I0129 06:45:31.559190 2452 log.cpp:702] Attempting to truncate the log to 1
I0129 06:45:31.559329 2450 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 06:45:31.559656 2452 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 06:45:31.559687 2441 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 06:45:31.560443 2446 replica.cpp:537] Replica received write request for position 2 from (14181)@172.17.0.4:54981
I0129 06:45:31.560837 2446 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 349068ns
I0129 06:45:31.560868 2446 replica.cpp:712] Persisted action at 2
I0129 06:45:31.561866 2442 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 06:45:31.562280 2442 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 378592ns
I0129 06:45:31.562352 2442 leveldb.cpp:399] Deleting ~1 keys from leveldb took 39842ns
I0129 06:45:31.562376 2442 replica.cpp:712] Persisted action at 2
I0129 06:45:31.562399 2442 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 06:45:31.570515 2421 scheduler.cpp:154] Version: 0.28.0
I0129 06:45:31.571478 2449 scheduler.cpp:236] New master detected at master@172.17.0.4:54981
I0129 06:45:31.573362 2447 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:54981
I0129 06:45:31.575060 2446 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 06:45:31.575690 2451 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:50809
I0129 06:45:31.575983 2451 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 06:45:31.576063 2451 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 06:45:31.576393 2451 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 06:45:31.576839 2455 master.hpp:1658] Sending heartbeat to f4bf7192-609e-43cd-a4f3-c23f99b600c4-0000
I0129 06:45:31.576890 2441 hierarchical.cpp:265] Added framework f4bf7192-609e-43cd-a4f3-c23f99b600c4-0000
I0129 06:45:31.577039 2441 hierarchical.cpp:1403] No resources available to allocate!
I0129 06:45:31.577195 2441 hierarchical.cpp:1498] No inverse offers to send out!
I0129 06:45:31.577234 2441 hierarchical.cpp:1096] Performed allocation for 0 slaves in 307374ns
I0129 06:45:31.577754 2445 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:54981
I0129 06:45:31.578377 2445 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:54981
I0129 06:45:31.579221 2446 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 06:45:31.579313 2445 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:54981
I0129 06:45:31.581310 2451 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 06:45:31.581727 2444 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:50810
I0129 06:45:31.581874 2444 master.cpp:2717] Processing REQUEST call for framework f4bf7192-609e-43cd-a4f3-c23f99b600c4-0000 (default)
I0129 06:45:31.582396 2454 hierarchical.cpp:589] Received resource request from framework f4bf7192-609e-43cd-a4f3-c23f99b600c4-0000
I0129 06:45:31.582761 2421 master.cpp:1025] Master terminating
I0129 06:45:31.583336 2440 hierarchical.cpp:326] Removed framework f4bf7192-609e-43cd-a4f3-c23f99b600c4-0000
E0129 06:45:31.584067 2444 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (61 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0129 06:45:31.594123 2421 leveldb.cpp:174] Opened db in 2.879982ms
I0129 06:45:31.595024 2421 leveldb.cpp:181] Compacted db in 861171ns
I0129 06:45:31.595079 2421 leveldb.cpp:196] Created db iterator in 17472ns
I0129 06:45:31.595103 2421 leveldb.cpp:202] Seeked to beginning of db in 2358ns
I0129 06:45:31.595123 2421 leveldb.cpp:271] Iterated through 0 keys in the db in 452ns
I0129 06:45:31.595180 2421 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0129 06:45:31.595667 2452 recover.cpp:447] Starting replica recovery
I0129 06:45:31.595937 2452 recover.cpp:473] Replica is in EMPTY status
I0129 06:45:31.597965 2443 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (14189)@172.17.0.4:54981
I0129 06:45:31.598259 2441 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0129 06:45:31.598834 2446 recover.cpp:564] Updating replica status to STARTING
I0129 06:45:31.599524 2451 master.cpp:374] Master 65d0861b-b1ff-4e08-a5f7-1253e2017263 (9f1fa7546a87) started on 172.17.0.4:54981
I0129 06:45:31.599586 2447 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 536102ns
I0129 06:45:31.599882 2447 replica.cpp:320] Persisted replica status to STARTING
I0129 06:45:31.599557 2451 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/02sb9a/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="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/02sb9a/master" --zk_session_timeout="10secs"
I0129 06:45:31.600081 2451 master.cpp:423] Master allowing unauthenticated frameworks to register
I0129 06:45:31.600096 2451 master.cpp:426] Master only allowing authenticated slaves to register
I0129 06:45:31.600106 2451 credentials.hpp:35] Loading credentials for authentication from '/tmp/02sb9a/credentials'
I0129 06:45:31.600186 2442 recover.cpp:473] Replica is in STARTING status
I0129 06:45:31.600428 2451 master.cpp:466] Using default 'crammd5' authenticator
I0129 06:45:31.600607 2451 master.cpp:535] Using default 'basic' HTTP authenticator
I0129 06:45:31.600816 2451 master.cpp:569] Authorization enabled
I0129 06:45:31.601099 2442 whitelist_watcher.cpp:77] No whitelist given
I0129 06:45:31.601099 2443 hierarchical.cpp:144] Initialized hierarchical allocator process
I0129 06:45:31.601364 2455 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (14191)@172.17.0.4:54981
I0129 06:45:31.601852 2453 recover.cpp:193] Received a recover response from a replica in STARTING status
I0129 06:45:31.602448 2444 recover.cpp:564] Updating replica status to VOTING
I0129 06:45:31.603121 2455 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 421540ns
I0129 06:45:31.603159 2455 replica.cpp:320] Persisted replica status to VOTING
I0129 06:45:31.603286 2441 recover.cpp:578] Successfully joined the Paxos group
I0129 06:45:31.603574 2441 recover.cpp:462] Recover process terminated
I0129 06:45:31.603818 2452 master.cpp:1710] The newly elected leader is master@172.17.0.4:54981 with id 65d0861b-b1ff-4e08-a5f7-1253e2017263
I0129 06:45:31.603864 2452 master.cpp:1723] Elected as the leading master!
I0129 06:45:31.603893 2452 master.cpp:1468] Recovering from registrar
I0129 06:45:31.604113 2445 registrar.cpp:307] Recovering registrar
I0129 06:45:31.604739 2453 log.cpp:659] Attempting to start the writer
I0129 06:45:31.606150 2447 replica.cpp:493] Replica received implicit promise request from (14192)@172.17.0.4:54981 with proposal 1
I0129 06:45:31.606580 2447 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 392261ns
I0129 06:45:31.606607 2447 replica.cpp:342] Persisted promised to 1
I0129 06:45:31.607276 2441 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0129 06:45:31.608547 2442 replica.cpp:388] Replica received explicit promise request from (14193)@172.17.0.4:54981 for position 0 with proposal 2
I0129 06:45:31.608971 2442 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 377193ns
I0129 06:45:31.609002 2442 replica.cpp:712] Persisted action at 0
I0129 06:45:31.610175 2450 replica.cpp:537] Replica received write request for position 0 from (14194)@172.17.0.4:54981
I0129 06:45:31.610240 2450 leveldb.cpp:436] Reading position from leveldb took 28542ns
I0129 06:45:31.610688 2450 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 404063ns
I0129 06:45:31.610718 2450 replica.cpp:712] Persisted action at 0
I0129 06:45:31.611408 2444 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0129 06:45:31.611845 2444 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 394544ns
I0129 06:45:31.611873 2444 replica.cpp:712] Persisted action at 0
I0129 06:45:31.611894 2444 replica.cpp:697] Replica learned NOP action at position 0
I0129 06:45:31.612547 2454 log.cpp:675] Writer started with ending position 0
I0129 06:45:31.613714 2455 leveldb.cpp:436] Reading position from leveldb took 35372ns
I0129 06:45:31.614754 2450 registrar.cpp:340] Successfully fetched the registry (0B) in 10.580992ms
I0129 06:45:31.614874 2450 registrar.cpp:439] Applied 1 operations in 24500ns; attempting to update the 'registry'
I0129 06:45:31.615629 2445 log.cpp:683] Attempting to append 170 bytes to the log
I0129 06:45:31.615777 2444 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0129 06:45:31.616771 2447 replica.cpp:537] Replica received write request for position 1 from (14195)@172.17.0.4:54981
I0129 06:45:31.617255 2447 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 437462ns
I0129 06:45:31.617293 2447 replica.cpp:712] Persisted action at 1
I0129 06:45:31.618039 2442 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0129 06:45:31.618446 2442 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 366793ns
I0129 06:45:31.618479 2442 replica.cpp:712] Persisted action at 1
I0129 06:45:31.618501 2442 replica.cpp:697] Replica learned APPEND action at position 1
I0129 06:45:31.619559 2455 registrar.cpp:484] Successfully updated the 'registry' in 4.61696ms
I0129 06:45:31.619709 2455 registrar.cpp:370] Successfully recovered registrar
I0129 06:45:31.619912 2447 log.cpp:702] Attempting to truncate the log to 1
I0129 06:45:31.620107 2448 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0129 06:45:31.620451 2446 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0129 06:45:31.620492 2451 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0129 06:45:31.621309 2443 replica.cpp:537] Replica received write request for position 2 from (14196)@172.17.0.4:54981
I0129 06:45:31.621703 2443 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 349429ns
I0129 06:45:31.621734 2443 replica.cpp:712] Persisted action at 2
I0129 06:45:31.622431 2443 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0129 06:45:31.622827 2443 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 353423ns
I0129 06:45:31.622896 2443 leveldb.cpp:399] Deleting ~1 keys from leveldb took 38444ns
I0129 06:45:31.622925 2443 replica.cpp:712] Persisted action at 2
I0129 06:45:31.622972 2443 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0129 06:45:31.630972 2421 scheduler.cpp:154] Version: 0.28.0
I0129 06:45:31.631646 2455 scheduler.cpp:236] New master detected at master@172.17.0.4:54981
I0129 06:45:31.632966 2441 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:54981
I0129 06:45:31.634698 2450 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 06:45:31.635257 2455 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:50811
I0129 06:45:31.635682 2455 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0129 06:45:31.635752 2455 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0129 06:45:31.636090 2455 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0129 06:45:31.636559 2451 hierarchical.cpp:265] Added framework 65d0861b-b1ff-4e08-a5f7-1253e2017263-0000
I0129 06:45:31.636752 2451 hierarchical.cpp:1403] No resources available to allocate!
I0129 06:45:31.636818 2451 hierarchical.cpp:1498] No inverse offers to send out!
I0129 06:45:31.636857 2451 hierarchical.cpp:1096] Performed allocation for 0 slaves in 156444ns
I0129 06:45:31.636658 2446 master.hpp:1658] Sending heartbeat to 65d0861b-b1ff-4e08-a5f7-1253e2017263-0000
I0129 06:45:31.637636 2448 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:54981
I0129 06:45:31.638172 2448 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:54981
I0129 06:45:31.638918 2454 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0129 06:45:31.639063 2448 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:54981
I0129 06:45:31.640761 2449 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0129 06:45:31.641209 2444 http.cpp:503] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:50812
I0129 06:45:31.641464 2444 master.cpp:2717] Processing REQUEST call for framework 65d0861b-b1ff-4e08-a5f7-1253e2017263-0000 (default)
I0129 06:45:31.641659 2446 hierarchical.cpp:589] Received resource request from framework 65d0861b-b1ff-4e08-a5f7-1253e2017263-0000
I0129 06:45:31.642051 2421 master.cpp:1025] Master terminating
I0129 06:45:31.642437 2441 hierarchical.cpp:326] Removed framework 65d0861b-b1ff-4e08-a5f7-1253e2017263-0000
E0129 06:45:31.643201 2446 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (59 ms)
[----------] 22 tests from ContentType/SchedulerTest (4304 ms total)
[----------] Global test environment tear-down
[==========] 968 tests from 127 test cases ran. (343586 ms total)
[ PASSED ] 967 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ShasumTest.SHA512SimpleFile
1 FAILED TEST
YOU HAVE 9 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1454048421-15188
Untagged: mesos-1454048421-15188:latest
Deleted: 9bf54b1a8390ad943c90d7cf0c8a125947ebf99ea3bdf1f3388862ff8a209568
Deleted: 3e8d4ad3a13a4db31b0dcfe7ba7ee1ae30d823b4b0d9d60c6b528f3557deae25
Deleted: 67fca024a822fa8d204ef8707bc68ece127deac6432497801bab9fcc90a9ba5a
Deleted: 0bb6e514f40848b775b30ab1a61860ae7948cc3652259158042ba88c9afb61e1
Deleted: e5d9971d56e233a5dc5ee309a0791dc6ee4c55439bff723520e155898b498869
Deleted: d34db359cf9ebfbdfaa9f4f544a8cc29da0b3dcbbcba834c21dde3046e016111
Deleted: 9e039304f458e32dc9b507f543ca9bf65f94ecc22fa5f7e16b81cc2b0b6664d1
Deleted: 3b1eef1709f89b06eabdc9b7d1bf0992ca3333662c7374a14ec7d89a03c67ab1
Deleted: a610f95909be3a1c1fdfe94168673cd44ea4e3406f5656caab0756b025b5aa1c
Deleted: 33c82f4965aecf334c7daaa651fe26f6b0a9b1043abb99ace19cb9104d217824
Deleted: b55322ed56042537e8d0d1b967d0239f842ae7824acf83550a0446bd2cb205ec
Deleted: 8211212d3ad1dac8906d0ac7c5e008fed08be15d7837079262947943646775f9
Deleted: 35c480a845ebc20efb6d7ea5417992759d273a642c587b6053a02fc1df3893c0
Build step 'Execute shell' marked build as failure