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 2015/11/10 01:38:04 UTC
Build failed in Jenkins: Mesos » gcc,--verbose,centos:7,docker||Hadoop #1206
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1206/changes>
Changes:
[tnachen] Fixed docker manifest validation error messages.
[tnachen] Removed unused parameter in Docker provisioner store moveLayers.
------------------------------------------
[...truncated 139271 lines...]
I1110 00:38:13.209348 30664 slave.cpp:2009] Asked to shut down framework 92daea69-401f-4bdd-aa2a-04366b1331f0-0000 by @0.0.0.0:0
I1110 00:38:13.209384 30664 slave.cpp:2034] Shutting down framework 92daea69-401f-4bdd-aa2a-04366b1331f0-0000
I1110 00:38:13.209458 30664 slave.cpp:3657] Cleaning up executor 'default' of framework 92daea69-401f-4bdd-aa2a-04366b1331f0-0000 at executor(132)@172.17.6.64:58535
I1110 00:38:13.209767 30687 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_clbYDZ/slaves/92daea69-401f-4bdd-aa2a-04366b1331f0-S0/frameworks/92daea69-401f-4bdd-aa2a-04366b1331f0-0000/executors/default/runs/6b4e500b-8202-48ca-aca6-50b48d169d64' for gc 6.9999975737363days in the future
I1110 00:38:13.210108 30693 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_clbYDZ/slaves/92daea69-401f-4bdd-aa2a-04366b1331f0-S0/frameworks/92daea69-401f-4bdd-aa2a-04366b1331f0-0000/executors/default' for gc 6.99999757013926days in the future
I1110 00:38:13.210232 30664 slave.cpp:3745] Cleaning up framework 92daea69-401f-4bdd-aa2a-04366b1331f0-0000
I1110 00:38:13.210386 30698 status_update_manager.cpp:284] Closing status update streams for framework 92daea69-401f-4bdd-aa2a-04366b1331f0-0000
I1110 00:38:13.210436 30698 status_update_manager.cpp:530] Cleaning up status update stream for task aa1ce56a-e3cb-4961-8f59-2c7dab88d175 of framework 92daea69-401f-4bdd-aa2a-04366b1331f0-0000
I1110 00:38:13.210805 30686 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_clbYDZ/slaves/92daea69-401f-4bdd-aa2a-04366b1331f0-S0/frameworks/92daea69-401f-4bdd-aa2a-04366b1331f0-0000' for gc 6.99999756130963days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (175 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I1110 00:38:13.235919 30664 leveldb.cpp:176] Opened db in 2.514511ms
I1110 00:38:13.236809 30664 leveldb.cpp:183] Compacted db in 711369ns
I1110 00:38:13.236939 30664 leveldb.cpp:198] Created db iterator in 25816ns
I1110 00:38:13.237046 30664 leveldb.cpp:204] Seeked to beginning of db in 2744ns
I1110 00:38:13.237145 30664 leveldb.cpp:273] Iterated through 0 keys in the db in 504ns
I1110 00:38:13.237290 30664 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1110 00:38:13.238059 30686 recover.cpp:449] Starting replica recovery
I1110 00:38:13.238399 30686 recover.cpp:475] Replica is in EMPTY status
I1110 00:38:13.239976 30693 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10530)@172.17.6.64:58535
I1110 00:38:13.240656 30689 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1110 00:38:13.241329 30689 recover.cpp:566] Updating replica status to STARTING
I1110 00:38:13.242172 30689 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 556528ns
I1110 00:38:13.242276 30689 replica.cpp:323] Persisted replica status to STARTING
I1110 00:38:13.242593 30689 recover.cpp:475] Replica is in STARTING status
I1110 00:38:13.243970 30688 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10531)@172.17.6.64:58535
I1110 00:38:13.246247 30687 recover.cpp:195] Received a recover response from a replica in STARTING status
I1110 00:38:13.247109 30687 recover.cpp:566] Updating replica status to VOTING
I1110 00:38:13.248090 30687 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 773541ns
I1110 00:38:13.248213 30687 replica.cpp:323] Persisted replica status to VOTING
I1110 00:38:13.248462 30693 recover.cpp:580] Successfully joined the Paxos group
I1110 00:38:13.248651 30693 recover.cpp:464] Recover process terminated
I1110 00:38:13.249578 30696 master.cpp:367] Master f760240a-9910-46f8-bb81-943a174d0ff3 (4d869def5079) started on 172.17.6.64:58535
I1110 00:38:13.249671 30696 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/RQC2St/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --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.26.0/_inst/share/mesos/webui" --work_dir="/tmp/RQC2St/master" --zk_session_timeout="10secs"
I1110 00:38:13.250228 30696 master.cpp:416] Master allowing unauthenticated frameworks to register
I1110 00:38:13.250360 30696 master.cpp:419] Master only allowing authenticated slaves to register
I1110 00:38:13.250450 30696 credentials.hpp:37] Loading credentials for authentication from '/tmp/RQC2St/credentials'
I1110 00:38:13.250952 30696 master.cpp:458] Using default 'crammd5' authenticator
I1110 00:38:13.251273 30696 master.cpp:495] Authorization enabled
I1110 00:38:13.252018 30692 whitelist_watcher.cpp:79] No whitelist given
I1110 00:38:13.252111 30683 hierarchical.cpp:140] Initialized hierarchical allocator process
I1110 00:38:13.254288 30696 master.cpp:1606] The newly elected leader is master@172.17.6.64:58535 with id f760240a-9910-46f8-bb81-943a174d0ff3
I1110 00:38:13.254387 30696 master.cpp:1619] Elected as the leading master!
I1110 00:38:13.254497 30696 master.cpp:1379] Recovering from registrar
I1110 00:38:13.254842 30690 registrar.cpp:309] Recovering registrar
I1110 00:38:13.255756 30692 log.cpp:661] Attempting to start the writer
I1110 00:38:13.257807 30697 replica.cpp:496] Replica received implicit promise request from (10532)@172.17.6.64:58535 with proposal 1
I1110 00:38:13.258339 30697 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 489732ns
I1110 00:38:13.258368 30697 replica.cpp:345] Persisted promised to 1
I1110 00:38:13.259392 30694 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1110 00:38:13.260946 30696 replica.cpp:391] Replica received explicit promise request from (10533)@172.17.6.64:58535 for position 0 with proposal 2
I1110 00:38:13.261368 30696 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 319371ns
I1110 00:38:13.261456 30696 replica.cpp:715] Persisted action at 0
I1110 00:38:13.262804 30684 replica.cpp:540] Replica received write request for position 0 from (10534)@172.17.6.64:58535
I1110 00:38:13.262867 30684 leveldb.cpp:438] Reading position from leveldb took 32223ns
I1110 00:38:13.263203 30684 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 287802ns
I1110 00:38:13.263231 30684 replica.cpp:715] Persisted action at 0
I1110 00:38:13.263900 30684 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1110 00:38:13.264631 30684 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 410232ns
I1110 00:38:13.264921 30684 replica.cpp:715] Persisted action at 0
I1110 00:38:13.265197 30684 replica.cpp:700] Replica learned NOP action at position 0
I1110 00:38:13.266350 30686 log.cpp:677] Writer started with ending position 0
I1110 00:38:13.267913 30686 leveldb.cpp:438] Reading position from leveldb took 37137ns
I1110 00:38:13.270198 30692 registrar.cpp:342] Successfully fetched the registry (0B) in 15.21792ms
I1110 00:38:13.270509 30692 registrar.cpp:441] Applied 1 operations in 81931ns; attempting to update the 'registry'
I1110 00:38:13.272449 30686 log.cpp:685] Attempting to append 174 bytes to the log
I1110 00:38:13.273003 30691 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1110 00:38:13.275697 30691 replica.cpp:540] Replica received write request for position 1 from (10535)@172.17.6.64:58535
I1110 00:38:13.276660 30691 leveldb.cpp:343] Persisting action (193 bytes) to leveldb took 585867ns
I1110 00:38:13.276988 30691 replica.cpp:715] Persisted action at 1
I1110 00:38:13.278408 30688 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1110 00:38:13.278977 30688 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 526464ns
I1110 00:38:13.279008 30688 replica.cpp:715] Persisted action at 1
I1110 00:38:13.279034 30688 replica.cpp:700] Replica learned APPEND action at position 1
I1110 00:38:13.281009 30688 log.cpp:704] Attempting to truncate the log to 1
I1110 00:38:13.281056 30684 registrar.cpp:486] Successfully updated the 'registry' in 10.272256ms
I1110 00:38:13.281268 30689 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1110 00:38:13.282012 30684 registrar.cpp:372] Successfully recovered registrar
I1110 00:38:13.282344 30698 replica.cpp:540] Replica received write request for position 2 from (10536)@172.17.6.64:58535
I1110 00:38:13.282413 30689 master.cpp:1416] Recovered 0 slaves from the Registry (135B) ; allowing 10mins for slaves to re-register
I1110 00:38:13.283031 30698 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 639044ns
I1110 00:38:13.283058 30698 replica.cpp:715] Persisted action at 2
I1110 00:38:13.284083 30698 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1110 00:38:13.284394 30698 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 278163ns
I1110 00:38:13.284448 30698 leveldb.cpp:401] Deleting ~1 keys from leveldb took 29506ns
I1110 00:38:13.284471 30698 replica.cpp:715] Persisted action at 2
I1110 00:38:13.284492 30698 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1110 00:38:13.294736 30664 scheduler.cpp:156] Version: 0.26.0
I1110 00:38:13.295891 30686 scheduler.cpp:238] New master detected at master@172.17.6.64:58535
I1110 00:38:13.297472 30692 scheduler.cpp:300] Sending SUBSCRIBE call to master@172.17.6.64:58535
I1110 00:38:13.299608 30689 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 00:38:13.299798 30689 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.6.64:57287
I1110 00:38:13.300048 30689 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1110 00:38:13.300133 30689 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1110 00:38:13.300920 30689 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1110 00:38:13.301517 30689 hierarchical.cpp:185] Added framework f760240a-9910-46f8-bb81-943a174d0ff3-0000
I1110 00:38:13.301583 30689 hierarchical.cpp:971] No resources available to allocate!
I1110 00:38:13.301622 30689 hierarchical.cpp:1064] No inverse offers to send out!
I1110 00:38:13.301648 30689 hierarchical.cpp:870] Performed allocation for 0 slaves in 104717ns
I1110 00:38:13.301769 30689 master.hpp:1439] Sending heartbeat to f760240a-9910-46f8-bb81-943a174d0ff3-0000
I1110 00:38:13.303906 30693 scheduler.cpp:459] Enqueuing event SUBSCRIBED received from master@172.17.6.64:58535
I1110 00:38:13.304303 30693 scheduler.cpp:459] Enqueuing event HEARTBEAT received from master@172.17.6.64:58535
I1110 00:38:13.304846 30693 master_maintenance_tests.cpp:174] Ignoring HEARTBEAT event
I1110 00:38:13.305420 30692 scheduler.cpp:300] Sending REQUEST call to master@172.17.6.64:58535
I1110 00:38:13.307050 30692 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 00:38:13.307229 30692 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.6.64:57288
I1110 00:38:13.307344 30692 master.cpp:2615] Processing REQUEST call for framework f760240a-9910-46f8-bb81-943a174d0ff3-0000 (default)
I1110 00:38:13.307871 30692 hierarchical.cpp:449] Received resource request from framework f760240a-9910-46f8-bb81-943a174d0ff3-0000
I1110 00:38:13.309990 30684 master.cpp:922] Master terminating
I1110 00:38:13.310196 30691 hierarchical.cpp:220] Removed framework f760240a-9910-46f8-bb81-943a174d0ff3-0000
E1110 00:38:13.311064 30684 scheduler.cpp:433] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (86 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1110 00:38:13.323256 30664 leveldb.cpp:176] Opened db in 4.137093ms
I1110 00:38:13.327972 30664 leveldb.cpp:183] Compacted db in 4.629293ms
I1110 00:38:13.328084 30664 leveldb.cpp:198] Created db iterator in 32045ns
I1110 00:38:13.328105 30664 leveldb.cpp:204] Seeked to beginning of db in 4170ns
I1110 00:38:13.328117 30664 leveldb.cpp:273] Iterated through 0 keys in the db in 246ns
I1110 00:38:13.328183 30664 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1110 00:38:13.328826 30687 recover.cpp:449] Starting replica recovery
I1110 00:38:13.329324 30687 recover.cpp:475] Replica is in EMPTY status
I1110 00:38:13.332015 30683 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10541)@172.17.6.64:58535
I1110 00:38:13.332164 30683 master.cpp:367] Master 64b23fa3-b2fa-4209-98ad-51da0666cd06 (4d869def5079) started on 172.17.6.64:58535
I1110 00:38:13.332185 30683 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/KeVMGj/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --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.26.0/_inst/share/mesos/webui" --work_dir="/tmp/KeVMGj/master" --zk_session_timeout="10secs"
I1110 00:38:13.332520 30683 master.cpp:416] Master allowing unauthenticated frameworks to register
I1110 00:38:13.332536 30683 master.cpp:419] Master only allowing authenticated slaves to register
I1110 00:38:13.332546 30683 credentials.hpp:37] Loading credentials for authentication from '/tmp/KeVMGj/credentials'
I1110 00:38:13.332873 30683 master.cpp:458] Using default 'crammd5' authenticator
I1110 00:38:13.333040 30683 master.cpp:495] Authorization enabled
I1110 00:38:13.336438 30683 hierarchical.cpp:140] Initialized hierarchical allocator process
I1110 00:38:13.336558 30683 whitelist_watcher.cpp:79] No whitelist given
I1110 00:38:13.337491 30693 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1110 00:38:13.338110 30690 recover.cpp:566] Updating replica status to STARTING
I1110 00:38:13.338394 30683 master.cpp:1606] The newly elected leader is master@172.17.6.64:58535 with id 64b23fa3-b2fa-4209-98ad-51da0666cd06
I1110 00:38:13.338426 30683 master.cpp:1619] Elected as the leading master!
I1110 00:38:13.338449 30683 master.cpp:1379] Recovering from registrar
I1110 00:38:13.339082 30686 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 804687ns
I1110 00:38:13.339114 30686 replica.cpp:323] Persisted replica status to STARTING
I1110 00:38:13.339228 30691 registrar.cpp:309] Recovering registrar
I1110 00:38:13.339628 30693 recover.cpp:475] Replica is in STARTING status
I1110 00:38:13.342106 30683 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10542)@172.17.6.64:58535
I1110 00:38:13.342531 30683 recover.cpp:195] Received a recover response from a replica in STARTING status
I1110 00:38:13.343188 30685 recover.cpp:566] Updating replica status to VOTING
I1110 00:38:13.343863 30685 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 479378ns
I1110 00:38:13.343888 30685 replica.cpp:323] Persisted replica status to VOTING
I1110 00:38:13.344053 30695 recover.cpp:580] Successfully joined the Paxos group
I1110 00:38:13.344243 30695 recover.cpp:464] Recover process terminated
I1110 00:38:13.344880 30685 log.cpp:661] Attempting to start the writer
I1110 00:38:13.346294 30685 replica.cpp:496] Replica received implicit promise request from (10543)@172.17.6.64:58535 with proposal 1
I1110 00:38:13.346734 30685 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 390397ns
I1110 00:38:13.346791 30685 replica.cpp:345] Persisted promised to 1
I1110 00:38:13.347779 30688 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1110 00:38:13.349045 30685 replica.cpp:391] Replica received explicit promise request from (10544)@172.17.6.64:58535 for position 0 with proposal 2
I1110 00:38:13.350183 30685 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 1.062927ms
I1110 00:38:13.350232 30685 replica.cpp:715] Persisted action at 0
I1110 00:38:13.351728 30688 replica.cpp:540] Replica received write request for position 0 from (10545)@172.17.6.64:58535
I1110 00:38:13.351794 30688 leveldb.cpp:438] Reading position from leveldb took 30675ns
I1110 00:38:13.352264 30688 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 424493ns
I1110 00:38:13.352290 30688 replica.cpp:715] Persisted action at 0
I1110 00:38:13.352877 30688 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1110 00:38:13.353294 30688 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 386402ns
I1110 00:38:13.353322 30688 replica.cpp:715] Persisted action at 0
I1110 00:38:13.353341 30688 replica.cpp:700] Replica learned NOP action at position 0
I1110 00:38:13.353917 30695 log.cpp:677] Writer started with ending position 0
I1110 00:38:13.355116 30692 leveldb.cpp:438] Reading position from leveldb took 30244ns
I1110 00:38:13.356025 30689 registrar.cpp:342] Successfully fetched the registry (0B) in 16.7488ms
I1110 00:38:13.356180 30689 registrar.cpp:441] Applied 1 operations in 57400ns; attempting to update the 'registry'
I1110 00:38:13.356907 30696 log.cpp:685] Attempting to append 174 bytes to the log
I1110 00:38:13.357149 30696 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1110 00:38:13.357812 30697 replica.cpp:540] Replica received write request for position 1 from (10546)@172.17.6.64:58535
I1110 00:38:13.358347 30697 leveldb.cpp:343] Persisting action (193 bytes) to leveldb took 493892ns
I1110 00:38:13.358376 30697 replica.cpp:715] Persisted action at 1
I1110 00:38:13.358991 30687 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1110 00:38:13.359318 30687 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 294747ns
I1110 00:38:13.359344 30687 replica.cpp:715] Persisted action at 1
I1110 00:38:13.359366 30687 replica.cpp:700] Replica learned APPEND action at position 1
I1110 00:38:13.360424 30688 registrar.cpp:486] Successfully updated the 'registry' in 4.166144ms
I1110 00:38:13.360569 30688 registrar.cpp:372] Successfully recovered registrar
I1110 00:38:13.360693 30686 log.cpp:704] Attempting to truncate the log to 1
I1110 00:38:13.360880 30686 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1110 00:38:13.360983 30688 master.cpp:1416] Recovered 0 slaves from the Registry (135B) ; allowing 10mins for slaves to re-register
I1110 00:38:13.362099 30692 replica.cpp:540] Replica received write request for position 2 from (10547)@172.17.6.64:58535
I1110 00:38:13.362599 30692 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 454170ns
I1110 00:38:13.362628 30692 replica.cpp:715] Persisted action at 2
I1110 00:38:13.363432 30692 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1110 00:38:13.363798 30692 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 331075ns
I1110 00:38:13.363855 30692 leveldb.cpp:401] Deleting ~1 keys from leveldb took 30384ns
I1110 00:38:13.363878 30692 replica.cpp:715] Persisted action at 2
I1110 00:38:13.363901 30692 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1110 00:38:13.372912 30664 scheduler.cpp:156] Version: 0.26.0
I1110 00:38:13.374215 30697 scheduler.cpp:238] New master detected at master@172.17.6.64:58535
I1110 00:38:13.376580 30695 scheduler.cpp:300] Sending SUBSCRIBE call to master@172.17.6.64:58535
I1110 00:38:13.379096 30684 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 00:38:13.379338 30684 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.6.64:57289
I1110 00:38:13.379766 30684 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1110 00:38:13.379842 30684 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1110 00:38:13.380668 30684 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1110 00:38:13.381593 30684 hierarchical.cpp:185] Added framework 64b23fa3-b2fa-4209-98ad-51da0666cd06-0000
I1110 00:38:13.381682 30684 hierarchical.cpp:971] No resources available to allocate!
I1110 00:38:13.381731 30684 hierarchical.cpp:1064] No inverse offers to send out!
I1110 00:38:13.381758 30684 hierarchical.cpp:870] Performed allocation for 0 slaves in 121817ns
I1110 00:38:13.381789 30684 master.hpp:1439] Sending heartbeat to 64b23fa3-b2fa-4209-98ad-51da0666cd06-0000
I1110 00:38:13.383316 30684 scheduler.cpp:459] Enqueuing event SUBSCRIBED received from master@172.17.6.64:58535
I1110 00:38:13.384042 30684 scheduler.cpp:459] Enqueuing event HEARTBEAT received from master@172.17.6.64:58535
I1110 00:38:13.384817 30690 master_maintenance_tests.cpp:174] Ignoring HEARTBEAT event
I1110 00:38:13.386085 30690 scheduler.cpp:300] Sending REQUEST call to master@172.17.6.64:58535
I1110 00:38:13.388732 30684 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 00:38:13.389148 30684 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.6.64:57290
I1110 00:38:13.389531 30684 master.cpp:2615] Processing REQUEST call for framework 64b23fa3-b2fa-4209-98ad-51da0666cd06-0000 (default)
I1110 00:38:13.390025 30695 hierarchical.cpp:449] Received resource request from framework 64b23fa3-b2fa-4209-98ad-51da0666cd06-0000
I1110 00:38:13.390373 30685 master.cpp:922] Master terminating
I1110 00:38:13.390836 30696 hierarchical.cpp:220] Removed framework 64b23fa3-b2fa-4209-98ad-51da0666cd06-0000
E1110 00:38:13.399538 30685 scheduler.cpp:433] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (96 ms)
[----------] 22 tests from ContentType/SchedulerTest (5066 ms total)
[----------] Global test environment tear-down
[==========] 828 tests from 112 test cases ran. (366091 ms total)
[ PASSED ] 827 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] SlaveTest.HTTPSchedulerSlaveRestart
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1447113989-31948
Untagged: mesos-1447113989-31948:latest
Deleted: 01663bf3cf905927c68e1de54d4e3b93755f54c75d81225c5060fefed29f5f38
Deleted: e1fea251508ab238d42a44412394d548586a35965a9adf1020ce62ff8ee30c57
Deleted: f204a973754e3c17f20a4148ba45f4d313a83c0973fbefb9402ecccc2d2c405b
Deleted: cc4588d5a4b50588b6894063e6feddea9ff047a50343fbd468bf590023e0ac04
Deleted: 4817ad3d27d691263b5a30f784f11695b0c632ec625801689293ac18771361cb
Deleted: 50b9f676ee6cdbe26dad30aed7512fb866368179a77d195241338cc807fa540f
Deleted: e9bb7bbdedde39ceb5751342034174a9a81e8b9baf5d26c8edb33a6139624d12
Deleted: a1cea4ba765e9a3ae53ef81d7e88187dddad2cb26b87458bcb6648009dff1849
Deleted: 434b34369e9be3223a6ecdd9bc708c259a01d70186c0d2eb073f40f7deebdfe4
Deleted: dede61b39fbc282515e5d60719e6cea69b69fa90f36e59aaf3b221c6fd339a90
Deleted: fc4a5d9fcdf61abf335a2c4d54b1f0b7c668b77aab14f4b7cccae5d1a2af126a
Deleted: 79d3ed22d63c205dd3e7782bcbba5cbb30f58eaba1c50752e466b11c7fc3c305
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose,centos:7,docker||Hadoop #1208
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1208/changes>
Build failed in Jenkins: Mesos » gcc,--verbose,centos:7,docker||Hadoop #1207
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1207/changes>
Changes:
[joris.van.remoortere] Fixed quoted strings in executor log messages on agent.
------------------------------------------
[...truncated 139095 lines...]
I1110 07:10:51.698421 30679 slave.cpp:2034] Shutting down framework 3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-0000
I1110 07:10:51.698593 30679 slave.cpp:3657] Cleaning up executor 'default' of framework 3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-0000 at executor(132)@172.17.11.107:38286
I1110 07:10:51.698958 30690 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_nGgqQl/slaves/3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-S0/frameworks/3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-0000/executors/default/runs/58decae9-0fa0-49c8-8c47-7371333ee90f' for gc 6.99999191121778days in the future
I1110 07:10:51.699333 30690 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_nGgqQl/slaves/3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-S0/frameworks/3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-0000/executors/default' for gc 6.99999190925037days in the future
I1110 07:10:51.699105 30679 slave.cpp:3745] Cleaning up framework 3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-0000
I1110 07:10:51.699542 30685 status_update_manager.cpp:284] Closing status update streams for framework 3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-0000
I1110 07:10:51.699759 30685 status_update_manager.cpp:530] Cleaning up status update stream for task 1ef9e41c-2cd7-4fc8-b5f0-89b64482a505 of framework 3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-0000
I1110 07:10:51.699651 30691 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_nGgqQl/slaves/3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-S0/frameworks/3a9086d2-ce36-4f97-a3f9-86c5dc6286fc-0000' for gc 6.99999190313778days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (151 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I1110 07:10:51.709172 30659 leveldb.cpp:176] Opened db in 2.33347ms
I1110 07:10:51.710000 30659 leveldb.cpp:183] Compacted db in 670155ns
I1110 07:10:51.710057 30659 leveldb.cpp:198] Created db iterator in 22723ns
I1110 07:10:51.710084 30659 leveldb.cpp:204] Seeked to beginning of db in 2141ns
I1110 07:10:51.710103 30659 leveldb.cpp:273] Iterated through 0 keys in the db in 465ns
I1110 07:10:51.710161 30659 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1110 07:10:51.710892 30683 recover.cpp:449] Starting replica recovery
I1110 07:10:51.711266 30683 recover.cpp:475] Replica is in EMPTY status
I1110 07:10:51.713609 30683 master.cpp:367] Master a6505bd5-657f-476e-b363-0053aa218b84 (54de9d10cbc2) started on 172.17.11.107:38286
I1110 07:10:51.713661 30683 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/swGNEV/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --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.26.0/_inst/share/mesos/webui" --work_dir="/tmp/swGNEV/master" --zk_session_timeout="10secs"
I1110 07:10:51.714103 30683 master.cpp:416] Master allowing unauthenticated frameworks to register
I1110 07:10:51.714124 30683 master.cpp:419] Master only allowing authenticated slaves to register
I1110 07:10:51.714136 30683 credentials.hpp:37] Loading credentials for authentication from '/tmp/swGNEV/credentials'
I1110 07:10:51.714557 30683 master.cpp:458] Using default 'crammd5' authenticator
I1110 07:10:51.714747 30683 master.cpp:495] Authorization enabled
I1110 07:10:51.715035 30680 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10533)@172.17.11.107:38286
I1110 07:10:51.715231 30685 whitelist_watcher.cpp:79] No whitelist given
I1110 07:10:51.715291 30690 hierarchical.cpp:140] Initialized hierarchical allocator process
I1110 07:10:51.716317 30679 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1110 07:10:51.717486 30683 recover.cpp:566] Updating replica status to STARTING
I1110 07:10:51.717810 30683 master.cpp:1606] The newly elected leader is master@172.17.11.107:38286 with id a6505bd5-657f-476e-b363-0053aa218b84
I1110 07:10:51.717914 30683 master.cpp:1619] Elected as the leading master!
I1110 07:10:51.718026 30683 master.cpp:1379] Recovering from registrar
I1110 07:10:51.718513 30689 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 754074ns
I1110 07:10:51.718590 30689 replica.cpp:323] Persisted replica status to STARTING
I1110 07:10:51.718900 30689 recover.cpp:475] Replica is in STARTING status
I1110 07:10:51.718984 30681 registrar.cpp:309] Recovering registrar
I1110 07:10:51.719948 30678 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10534)@172.17.11.107:38286
I1110 07:10:51.720250 30690 recover.cpp:195] Received a recover response from a replica in STARTING status
I1110 07:10:51.720824 30682 recover.cpp:566] Updating replica status to VOTING
I1110 07:10:51.721330 30693 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 263201ns
I1110 07:10:51.721356 30693 replica.cpp:323] Persisted replica status to VOTING
I1110 07:10:51.721503 30687 recover.cpp:580] Successfully joined the Paxos group
I1110 07:10:51.721814 30687 recover.cpp:464] Recover process terminated
I1110 07:10:51.722270 30693 log.cpp:661] Attempting to start the writer
I1110 07:10:51.723484 30687 replica.cpp:496] Replica received implicit promise request from (10535)@172.17.11.107:38286 with proposal 1
I1110 07:10:51.723837 30687 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 315762ns
I1110 07:10:51.723866 30687 replica.cpp:345] Persisted promised to 1
I1110 07:10:51.724759 30687 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1110 07:10:51.725972 30687 replica.cpp:391] Replica received explicit promise request from (10536)@172.17.11.107:38286 for position 0 with proposal 2
I1110 07:10:51.726318 30687 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 304521ns
I1110 07:10:51.726346 30687 replica.cpp:715] Persisted action at 0
I1110 07:10:51.727397 30682 replica.cpp:540] Replica received write request for position 0 from (10537)@172.17.11.107:38286
I1110 07:10:51.727555 30682 leveldb.cpp:438] Reading position from leveldb took 48794ns
I1110 07:10:51.727960 30682 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 287590ns
I1110 07:10:51.727998 30682 replica.cpp:715] Persisted action at 0
I1110 07:10:51.728739 30683 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1110 07:10:51.729038 30683 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 269939ns
I1110 07:10:51.729063 30683 replica.cpp:715] Persisted action at 0
I1110 07:10:51.729087 30683 replica.cpp:700] Replica learned NOP action at position 0
I1110 07:10:51.736641 30693 log.cpp:677] Writer started with ending position 0
I1110 07:10:51.738086 30687 leveldb.cpp:438] Reading position from leveldb took 74052ns
I1110 07:10:51.739344 30683 registrar.cpp:342] Successfully fetched the registry (0B) in 20.305152ms
I1110 07:10:51.739487 30683 registrar.cpp:441] Applied 1 operations in 38672ns; attempting to update the 'registry'
I1110 07:10:51.740514 30680 log.cpp:685] Attempting to append 178 bytes to the log
I1110 07:10:51.740684 30681 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1110 07:10:51.741494 30687 replica.cpp:540] Replica received write request for position 1 from (10538)@172.17.11.107:38286
I1110 07:10:51.742045 30687 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 497238ns
I1110 07:10:51.742075 30687 replica.cpp:715] Persisted action at 1
I1110 07:10:51.742705 30679 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1110 07:10:51.743079 30679 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 337502ns
I1110 07:10:51.743106 30679 replica.cpp:715] Persisted action at 1
I1110 07:10:51.743129 30679 replica.cpp:700] Replica learned APPEND action at position 1
I1110 07:10:51.744158 30691 registrar.cpp:486] Successfully updated the 'registry' in 4.608256ms
I1110 07:10:51.744285 30691 registrar.cpp:372] Successfully recovered registrar
I1110 07:10:51.744369 30679 log.cpp:704] Attempting to truncate the log to 1
I1110 07:10:51.744532 30682 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1110 07:10:51.745061 30688 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1110 07:10:51.745434 30693 replica.cpp:540] Replica received write request for position 2 from (10539)@172.17.11.107:38286
I1110 07:10:51.745733 30693 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 264368ns
I1110 07:10:51.745756 30693 replica.cpp:715] Persisted action at 2
I1110 07:10:51.746373 30693 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1110 07:10:51.746667 30693 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 266370ns
I1110 07:10:51.746714 30693 leveldb.cpp:401] Deleting ~1 keys from leveldb took 24456ns
I1110 07:10:51.746732 30693 replica.cpp:715] Persisted action at 2
I1110 07:10:51.746749 30693 replica.cpp:700] Replica learned TRUNCATE action at position 2
2015-11-10 07:10:51,747:30659(0x7f8187fff700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:38458] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1110 07:10:51.756113 30659 scheduler.cpp:156] Version: 0.26.0
I1110 07:10:51.756943 30678 scheduler.cpp:238] New master detected at master@172.17.11.107:38286
I1110 07:10:51.758134 30682 scheduler.cpp:300] Sending SUBSCRIBE call to master@172.17.11.107:38286
I1110 07:10:51.760171 30690 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 07:10:51.760413 30690 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.11.107:60647
I1110 07:10:51.760651 30690 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1110 07:10:51.760722 30690 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1110 07:10:51.761143 30690 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1110 07:10:51.761668 30681 hierarchical.cpp:185] Added framework a6505bd5-657f-476e-b363-0053aa218b84-0000
I1110 07:10:51.761740 30685 master.hpp:1439] Sending heartbeat to a6505bd5-657f-476e-b363-0053aa218b84-0000
I1110 07:10:51.761909 30681 hierarchical.cpp:971] No resources available to allocate!
I1110 07:10:51.762053 30681 hierarchical.cpp:1064] No inverse offers to send out!
I1110 07:10:51.762131 30681 hierarchical.cpp:870] Performed allocation for 0 slaves in 345465ns
I1110 07:10:51.762610 30689 scheduler.cpp:459] Enqueuing event SUBSCRIBED received from master@172.17.11.107:38286
I1110 07:10:51.763092 30689 scheduler.cpp:459] Enqueuing event HEARTBEAT received from master@172.17.11.107:38286
I1110 07:10:51.763778 30691 master_maintenance_tests.cpp:174] Ignoring HEARTBEAT event
I1110 07:10:51.764024 30689 scheduler.cpp:300] Sending REQUEST call to master@172.17.11.107:38286
I1110 07:10:51.765429 30684 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 07:10:51.765602 30684 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.11.107:60648
I1110 07:10:51.765717 30684 master.cpp:2615] Processing REQUEST call for framework a6505bd5-657f-476e-b363-0053aa218b84-0000 (default)
I1110 07:10:51.765866 30687 hierarchical.cpp:449] Received resource request from framework a6505bd5-657f-476e-b363-0053aa218b84-0000
I1110 07:10:51.766158 30692 master.cpp:922] Master terminating
I1110 07:10:51.766429 30687 hierarchical.cpp:220] Removed framework a6505bd5-657f-476e-b363-0053aa218b84-0000
E1110 07:10:51.767509 30688 scheduler.cpp:433] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (66 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1110 07:10:51.775208 30659 leveldb.cpp:176] Opened db in 2.34647ms
I1110 07:10:51.776486 30659 leveldb.cpp:183] Compacted db in 1.216866ms
I1110 07:10:51.776558 30659 leveldb.cpp:198] Created db iterator in 25998ns
I1110 07:10:51.776583 30659 leveldb.cpp:204] Seeked to beginning of db in 2138ns
I1110 07:10:51.776619 30659 leveldb.cpp:273] Iterated through 0 keys in the db in 561ns
I1110 07:10:51.776697 30659 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1110 07:10:51.777456 30681 recover.cpp:449] Starting replica recovery
I1110 07:10:51.778789 30681 recover.cpp:475] Replica is in EMPTY status
I1110 07:10:51.780764 30680 master.cpp:367] Master 068340c4-1d66-4e8b-9ab0-8a2ee26fb807 (54de9d10cbc2) started on 172.17.11.107:38286
I1110 07:10:51.780876 30680 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/dCPezs/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --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.26.0/_inst/share/mesos/webui" --work_dir="/tmp/dCPezs/master" --zk_session_timeout="10secs"
I1110 07:10:51.781205 30680 master.cpp:416] Master allowing unauthenticated frameworks to register
I1110 07:10:51.781221 30680 master.cpp:419] Master only allowing authenticated slaves to register
I1110 07:10:51.781234 30680 credentials.hpp:37] Loading credentials for authentication from '/tmp/dCPezs/credentials'
I1110 07:10:51.781584 30680 master.cpp:458] Using default 'crammd5' authenticator
I1110 07:10:51.781746 30680 master.cpp:495] Authorization enabled
I1110 07:10:51.782340 30691 hierarchical.cpp:140] Initialized hierarchical allocator process
I1110 07:10:51.782841 30681 whitelist_watcher.cpp:79] No whitelist given
I1110 07:10:51.783861 30681 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10544)@172.17.11.107:38286
I1110 07:10:51.784159 30685 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1110 07:10:51.785128 30691 recover.cpp:566] Updating replica status to STARTING
I1110 07:10:51.786185 30679 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 627705ns
I1110 07:10:51.786239 30679 replica.cpp:323] Persisted replica status to STARTING
I1110 07:10:51.786690 30683 recover.cpp:475] Replica is in STARTING status
I1110 07:10:51.786744 30685 master.cpp:1606] The newly elected leader is master@172.17.11.107:38286 with id 068340c4-1d66-4e8b-9ab0-8a2ee26fb807
I1110 07:10:51.787060 30685 master.cpp:1619] Elected as the leading master!
I1110 07:10:51.787252 30685 master.cpp:1379] Recovering from registrar
I1110 07:10:51.787839 30685 registrar.cpp:309] Recovering registrar
I1110 07:10:51.789036 30683 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10545)@172.17.11.107:38286
I1110 07:10:51.789438 30683 recover.cpp:195] Received a recover response from a replica in STARTING status
I1110 07:10:51.790148 30688 recover.cpp:566] Updating replica status to VOTING
I1110 07:10:51.790660 30683 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 376422ns
I1110 07:10:51.790699 30683 replica.cpp:323] Persisted replica status to VOTING
I1110 07:10:51.790832 30688 recover.cpp:580] Successfully joined the Paxos group
I1110 07:10:51.791035 30688 recover.cpp:464] Recover process terminated
I1110 07:10:51.791635 30679 log.cpp:661] Attempting to start the writer
I1110 07:10:51.793035 30693 replica.cpp:496] Replica received implicit promise request from (10546)@172.17.11.107:38286 with proposal 1
I1110 07:10:51.793462 30693 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 390037ns
I1110 07:10:51.793485 30693 replica.cpp:345] Persisted promised to 1
I1110 07:10:51.794284 30681 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1110 07:10:51.795857 30687 replica.cpp:391] Replica received explicit promise request from (10547)@172.17.11.107:38286 for position 0 with proposal 2
I1110 07:10:51.796345 30687 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 437742ns
I1110 07:10:51.796376 30687 replica.cpp:715] Persisted action at 0
I1110 07:10:51.797673 30693 replica.cpp:540] Replica received write request for position 0 from (10548)@172.17.11.107:38286
I1110 07:10:51.797813 30693 leveldb.cpp:438] Reading position from leveldb took 78858ns
I1110 07:10:51.798475 30693 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 421849ns
I1110 07:10:51.798629 30693 replica.cpp:715] Persisted action at 0
I1110 07:10:51.799298 30689 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1110 07:10:51.799670 30689 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 334746ns
I1110 07:10:51.799700 30689 replica.cpp:715] Persisted action at 0
I1110 07:10:51.799724 30689 replica.cpp:700] Replica learned NOP action at position 0
I1110 07:10:51.800309 30692 log.cpp:677] Writer started with ending position 0
I1110 07:10:51.801731 30682 leveldb.cpp:438] Reading position from leveldb took 39740ns
I1110 07:10:51.803078 30681 registrar.cpp:342] Successfully fetched the registry (0B) in 15.041792ms
I1110 07:10:51.803251 30681 registrar.cpp:441] Applied 1 operations in 37486ns; attempting to update the 'registry'
I1110 07:10:51.804083 30688 log.cpp:685] Attempting to append 178 bytes to the log
I1110 07:10:51.804354 30692 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1110 07:10:51.805428 30689 replica.cpp:540] Replica received write request for position 1 from (10549)@172.17.11.107:38286
I1110 07:10:51.805928 30689 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 455403ns
I1110 07:10:51.805956 30689 replica.cpp:715] Persisted action at 1
I1110 07:10:51.806854 30692 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1110 07:10:51.807215 30692 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 330574ns
I1110 07:10:51.807242 30692 replica.cpp:715] Persisted action at 1
I1110 07:10:51.807270 30692 replica.cpp:700] Replica learned APPEND action at position 1
I1110 07:10:51.809180 30682 registrar.cpp:486] Successfully updated the 'registry' in 5.854976ms
I1110 07:10:51.809475 30682 registrar.cpp:372] Successfully recovered registrar
I1110 07:10:51.809527 30689 log.cpp:704] Attempting to truncate the log to 1
I1110 07:10:51.809869 30678 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1110 07:10:51.810125 30689 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1110 07:10:51.811606 30684 replica.cpp:540] Replica received write request for position 2 from (10550)@172.17.11.107:38286
I1110 07:10:51.812129 30684 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 473329ns
I1110 07:10:51.812158 30684 replica.cpp:715] Persisted action at 2
I1110 07:10:51.812984 30679 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1110 07:10:51.813375 30679 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 350454ns
I1110 07:10:51.813432 30679 leveldb.cpp:401] Deleting ~1 keys from leveldb took 30041ns
I1110 07:10:51.813539 30679 replica.cpp:715] Persisted action at 2
I1110 07:10:51.813647 30679 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1110 07:10:51.821153 30659 scheduler.cpp:156] Version: 0.26.0
I1110 07:10:51.822260 30684 scheduler.cpp:238] New master detected at master@172.17.11.107:38286
I1110 07:10:51.823884 30678 scheduler.cpp:300] Sending SUBSCRIBE call to master@172.17.11.107:38286
I1110 07:10:51.826694 30682 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 07:10:51.826876 30682 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.11.107:60649
I1110 07:10:51.827273 30682 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1110 07:10:51.827350 30682 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1110 07:10:51.827710 30690 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1110 07:10:51.828302 30682 hierarchical.cpp:185] Added framework 068340c4-1d66-4e8b-9ab0-8a2ee26fb807-0000
I1110 07:10:51.828358 30682 hierarchical.cpp:971] No resources available to allocate!
I1110 07:10:51.828393 30682 hierarchical.cpp:1064] No inverse offers to send out!
I1110 07:10:51.828418 30682 hierarchical.cpp:870] Performed allocation for 0 slaves in 90619ns
I1110 07:10:51.828445 30682 master.hpp:1439] Sending heartbeat to 068340c4-1d66-4e8b-9ab0-8a2ee26fb807-0000
I1110 07:10:51.830420 30682 scheduler.cpp:459] Enqueuing event SUBSCRIBED received from master@172.17.11.107:38286
I1110 07:10:51.832141 30691 scheduler.cpp:300] Sending REQUEST call to master@172.17.11.107:38286
I1110 07:10:51.834202 30683 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 07:10:51.834259 30685 scheduler.cpp:459] Enqueuing event HEARTBEAT received from master@172.17.11.107:38286
I1110 07:10:51.834352 30683 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.11.107:60650
I1110 07:10:51.834576 30683 master.cpp:2615] Processing REQUEST call for framework 068340c4-1d66-4e8b-9ab0-8a2ee26fb807-0000 (default)
I1110 07:10:51.834887 30685 master_maintenance_tests.cpp:174] Ignoring HEARTBEAT event
I1110 07:10:51.835400 30683 hierarchical.cpp:449] Received resource request from framework 068340c4-1d66-4e8b-9ab0-8a2ee26fb807-0000
I1110 07:10:51.835870 30683 master.cpp:922] Master terminating
I1110 07:10:51.836254 30685 hierarchical.cpp:220] Removed framework 068340c4-1d66-4e8b-9ab0-8a2ee26fb807-0000
E1110 07:10:51.837810 30692 scheduler.cpp:433] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (72 ms)
[----------] 22 tests from ContentType/SchedulerTest (4426 ms total)
[----------] Global test environment tear-down
[==========] 828 tests from 112 test cases ran. (353088 ms total)
[ PASSED ] 827 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] SlaveTest.HTTPSchedulerSlaveRestart
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1447137696-26929
Untagged: mesos-1447137696-26929:latest
Deleted: ebc29b80d644dfed3bfabf631cbefeb9d48f380af72cd244a465f671a4170326
Deleted: 28f98a824784af1056b3ce2093b004a25742e09c1e35ddf126489e1de8fd35e9
Deleted: f57a767de4eab691e34a5b16c3f1c531a60dfe9f2f57f8fbb58b8f5ddad5992b
Deleted: c8037c0e45812d2fb67897e23bcfba5324d89ac3e093124a135cab7e68804734
Deleted: 07efdbea4792a34efe144d53cd76eefd46af1869f720c5517b2fa07c103948c7
Deleted: 51b9a8d870c220c9d71382a04bff2d5f744fd502a9147d4fab787d15fdc8486d
Deleted: 39dfe3080d685c636ce333fad964c1eb5823c29b5cd43bd984d3fd71d413bc88
Deleted: fc9dea7336ed7db7f19c4d242879531349ad48ce05c448f7c8430ffd245029f5
Deleted: 131076199a724262268680e0fec8f99cfd704d5a750cc0f58837b08e7fa8dd7f
Deleted: 7a191ecd01200ccaca2e734577ddf7e4003b562e12e0b87642663ee2323ec54f
Deleted: 7d21ebc727f6a0a3d65e72fb751944fbaf9a1272b0829db7b452e4579ccacbfa
Deleted: 8adf98b1e934b98cdc96a8dd5369f4fef787d5668e4e0428cea9710acb7dfb1f
Build step 'Execute shell' marked build as failure