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/12 18:51:24 UTC
Build failed in Jenkins: Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #1226
See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1226/changes>
Changes:
[bernd] Updated upgrade documentation with changes in NetworkInfo protobuf.
------------------------------------------
[...truncated 140953 lines...]
I1112 17:51:17.378175 28097 slave.cpp:2009] Asked to shut down framework 105e15fa-6648-4af0-98cb-5f5e12e58698-0000 by @0.0.0.0:0
I1112 17:51:17.378216 28097 slave.cpp:2034] Shutting down framework 105e15fa-6648-4af0-98cb-5f5e12e58698-0000
I1112 17:51:17.378294 28097 slave.cpp:3657] Cleaning up executor 'default' of framework 105e15fa-6648-4af0-98cb-5f5e12e58698-0000 at executor(132)@172.17.6.239:32961
I1112 17:51:17.378770 28097 slave.cpp:3745] Cleaning up framework 105e15fa-6648-4af0-98cb-5f5e12e58698-0000
I1112 17:51:17.378890 28122 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_Hx9cZc/slaves/105e15fa-6648-4af0-98cb-5f5e12e58698-S0/frameworks/105e15fa-6648-4af0-98cb-5f5e12e58698-0000/executors/default/runs/e28c1439-6343-4b52-a535-34114c91f20c' for gc 6.99999561904889days in the future
I1112 17:51:17.379133 28122 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_Hx9cZc/slaves/105e15fa-6648-4af0-98cb-5f5e12e58698-S0/frameworks/105e15fa-6648-4af0-98cb-5f5e12e58698-0000/executors/default' for gc 6.99999561678222days in the future
I1112 17:51:17.379256 28122 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_Hx9cZc/slaves/105e15fa-6648-4af0-98cb-5f5e12e58698-S0/frameworks/105e15fa-6648-4af0-98cb-5f5e12e58698-0000' for gc 6.99999561478222days in the future
I1112 17:51:17.379370 28122 status_update_manager.cpp:284] Closing status update streams for framework 105e15fa-6648-4af0-98cb-5f5e12e58698-0000
I1112 17:51:17.379443 28122 status_update_manager.cpp:530] Cleaning up status update stream for task e22dd11d-7cde-4e5a-9d0e-75eb616407dd of framework 105e15fa-6648-4af0-98cb-5f5e12e58698-0000
[ OK ] ContentType/SchedulerTest.Message/1 (182 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I1112 17:51:17.390677 28097 leveldb.cpp:176] Opened db in 3.016832ms
I1112 17:51:17.393116 28097 leveldb.cpp:183] Compacted db in 2.403474ms
I1112 17:51:17.393174 28097 leveldb.cpp:198] Created db iterator in 31334ns
I1112 17:51:17.393190 28097 leveldb.cpp:204] Seeked to beginning of db in 7957ns
I1112 17:51:17.393199 28097 leveldb.cpp:273] Iterated through 0 keys in the db in 5648ns
I1112 17:51:17.393244 28097 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1112 17:51:17.394876 28122 recover.cpp:449] Starting replica recovery
I1112 17:51:17.399888 28122 master.cpp:367] Master 7c6ca341-c190-4819-bafb-2bb5050fe11b (f4f9d084d7ba) started on 172.17.6.239:32961
I1112 17:51:17.401128 28122 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/fAdRLT/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/fAdRLT/master" --zk_session_timeout="10secs"
I1112 17:51:17.402081 28122 master.cpp:416] Master allowing unauthenticated frameworks to register
I1112 17:51:17.402163 28122 master.cpp:419] Master only allowing authenticated slaves to register
I1112 17:51:17.402251 28122 credentials.hpp:37] Loading credentials for authentication from '/tmp/fAdRLT/credentials'
I1112 17:51:17.402688 28122 master.cpp:458] Using default 'crammd5' authenticator
I1112 17:51:17.404228 28122 master.cpp:495] Authorization enabled
I1112 17:51:17.410389 28122 recover.cpp:475] Replica is in EMPTY status
I1112 17:51:17.412962 28122 hierarchical.cpp:151] Initialized hierarchical allocator process
I1112 17:51:17.413187 28122 whitelist_watcher.cpp:79] No whitelist given
I1112 17:51:17.413969 28130 master.cpp:1606] The newly elected leader is master@172.17.6.239:32961 with id 7c6ca341-c190-4819-bafb-2bb5050fe11b
I1112 17:51:17.414011 28130 master.cpp:1619] Elected as the leading master!
I1112 17:51:17.414023 28130 master.cpp:1379] Recovering from registrar
I1112 17:51:17.414412 28122 registrar.cpp:309] Recovering registrar
I1112 17:51:17.414970 28122 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10497)@172.17.6.239:32961
I1112 17:51:17.415340 28130 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1112 17:51:17.415935 28123 recover.cpp:566] Updating replica status to STARTING
I1112 17:51:17.416916 28123 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 776219ns
I1112 17:51:17.416960 28123 replica.cpp:323] Persisted replica status to STARTING
I1112 17:51:17.417172 28123 recover.cpp:475] Replica is in STARTING status
I1112 17:51:17.418455 28123 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10498)@172.17.6.239:32961
I1112 17:51:17.418933 28120 recover.cpp:195] Received a recover response from a replica in STARTING status
I1112 17:51:17.419651 28120 recover.cpp:566] Updating replica status to VOTING
I1112 17:51:17.420497 28120 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 611692ns
I1112 17:51:17.420526 28120 replica.cpp:323] Persisted replica status to VOTING
I1112 17:51:17.420639 28120 recover.cpp:580] Successfully joined the Paxos group
I1112 17:51:17.420815 28120 recover.cpp:464] Recover process terminated
I1112 17:51:17.421353 28120 log.cpp:661] Attempting to start the writer
I1112 17:51:17.422827 28127 replica.cpp:496] Replica received implicit promise request from (10499)@172.17.6.239:32961 with proposal 1
I1112 17:51:17.423548 28127 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 516367ns
I1112 17:51:17.423771 28127 replica.cpp:345] Persisted promised to 1
I1112 17:51:17.424571 28118 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1112 17:51:17.426131 28127 replica.cpp:391] Replica received explicit promise request from (10500)@172.17.6.239:32961 for position 0 with proposal 2
I1112 17:51:17.426802 28127 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 466545ns
I1112 17:51:17.427033 28127 replica.cpp:715] Persisted action at 0
I1112 17:51:17.428941 28123 replica.cpp:540] Replica received write request for position 0 from (10501)@172.17.6.239:32961
I1112 17:51:17.429049 28123 leveldb.cpp:438] Reading position from leveldb took 59545ns
I1112 17:51:17.429576 28123 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 489045ns
I1112 17:51:17.429601 28123 replica.cpp:715] Persisted action at 0
I1112 17:51:17.430174 28125 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1112 17:51:17.430552 28125 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 352271ns
I1112 17:51:17.430579 28125 replica.cpp:715] Persisted action at 0
I1112 17:51:17.430601 28125 replica.cpp:700] Replica learned NOP action at position 0
I1112 17:51:17.431615 28129 log.cpp:677] Writer started with ending position 0
I1112 17:51:17.433174 28130 leveldb.cpp:438] Reading position from leveldb took 64387ns
I1112 17:51:17.434456 28120 registrar.cpp:342] Successfully fetched the registry (0B) in 19.97696ms
I1112 17:51:17.434645 28120 registrar.cpp:441] Applied 1 operations in 50676ns; attempting to update the 'registry'
I1112 17:51:17.435513 28124 log.cpp:685] Attempting to append 176 bytes to the log
I1112 17:51:17.435648 28116 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1112 17:51:17.436478 28120 replica.cpp:540] Replica received write request for position 1 from (10502)@172.17.6.239:32961
I1112 17:51:17.437090 28120 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 585558ns
I1112 17:51:17.437119 28120 replica.cpp:715] Persisted action at 1
I1112 17:51:17.437932 28126 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1112 17:51:17.438452 28126 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 492719ns
I1112 17:51:17.438482 28126 replica.cpp:715] Persisted action at 1
I1112 17:51:17.438508 28126 replica.cpp:700] Replica learned APPEND action at position 1
I1112 17:51:17.439658 28129 registrar.cpp:486] Successfully updated the 'registry' in 4.932352ms
I1112 17:51:17.439841 28129 registrar.cpp:372] Successfully recovered registrar
I1112 17:51:17.439895 28124 log.cpp:704] Attempting to truncate the log to 1
I1112 17:51:17.440017 28127 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1112 17:51:17.440244 28121 master.cpp:1416] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1112 17:51:17.441288 28117 replica.cpp:540] Replica received write request for position 2 from (10503)@172.17.6.239:32961
I1112 17:51:17.441968 28117 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 652079ns
I1112 17:51:17.441997 28117 replica.cpp:715] Persisted action at 2
I1112 17:51:17.442574 28117 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1112 17:51:17.442980 28117 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 389107ns
I1112 17:51:17.443038 28117 leveldb.cpp:401] Deleting ~1 keys from leveldb took 41755ns
I1112 17:51:17.443056 28117 replica.cpp:715] Persisted action at 2
I1112 17:51:17.443078 28117 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1112 17:51:17.451871 28097 scheduler.cpp:156] Version: 0.26.0
I1112 17:51:17.453519 28130 scheduler.cpp:238] New master detected at master@172.17.6.239:32961
I1112 17:51:17.455070 28123 scheduler.cpp:300] Sending SUBSCRIBE call to master@172.17.6.239:32961
I1112 17:51:17.457713 28116 process.cpp:3080] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1112 17:51:17.457803 28116 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.6.239:36995
I1112 17:51:17.458163 28116 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1112 17:51:17.458217 28116 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1112 17:51:17.458658 28116 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1112 17:51:17.459120 28125 hierarchical.cpp:195] Added framework 7c6ca341-c190-4819-bafb-2bb5050fe11b-0000
I1112 17:51:17.459187 28125 hierarchical.cpp:977] No resources available to allocate!
I1112 17:51:17.459235 28125 hierarchical.cpp:1070] No inverse offers to send out!
I1112 17:51:17.459270 28125 hierarchical.cpp:876] Performed allocation for 0 slaves in 134215ns
I1112 17:51:17.459660 28116 master.hpp:1439] Sending heartbeat to 7c6ca341-c190-4819-bafb-2bb5050fe11b-0000
I1112 17:51:17.463112 28128 scheduler.cpp:459] Enqueuing event SUBSCRIBED received from master@172.17.6.239:32961
I1112 17:51:17.464046 28125 scheduler.cpp:459] Enqueuing event HEARTBEAT received from master@172.17.6.239:32961
I1112 17:51:17.464819 28125 master_maintenance_tests.cpp:174] Ignoring HEARTBEAT event
I1112 17:51:17.465275 28128 scheduler.cpp:300] Sending REQUEST call to master@172.17.6.239:32961
I1112 17:51:17.469228 28127 process.cpp:3080] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1112 17:51:17.469326 28127 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.6.239:36996
I1112 17:51:17.469521 28127 master.cpp:2615] Processing REQUEST call for framework 7c6ca341-c190-4819-bafb-2bb5050fe11b-0000 (default)
I1112 17:51:17.469825 28127 hierarchical.cpp:458] Received resource request from framework 7c6ca341-c190-4819-bafb-2bb5050fe11b-0000
I1112 17:51:17.470684 28123 master.cpp:922] Master terminating
I1112 17:51:17.471109 28119 hierarchical.cpp:230] Removed framework 7c6ca341-c190-4819-bafb-2bb5050fe11b-0000
[ OK ] ContentType/SchedulerTest.Request/0 (92 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1112 17:51:17.482259 28097 leveldb.cpp:176] Opened db in 2.981123ms
I1112 17:51:17.483597 28097 leveldb.cpp:183] Compacted db in 1.052602ms
I1112 17:51:17.483659 28097 leveldb.cpp:198] Created db iterator in 33663ns
I1112 17:51:17.483675 28097 leveldb.cpp:204] Seeked to beginning of db in 7568ns
I1112 17:51:17.483685 28097 leveldb.cpp:273] Iterated through 0 keys in the db in 6190ns
I1112 17:51:17.483739 28097 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1112 17:51:17.484688 28118 recover.cpp:449] Starting replica recovery
I1112 17:51:17.485072 28116 recover.cpp:475] Replica is in EMPTY status
I1112 17:51:17.488243 28126 master.cpp:367] Master 8e714773-4a32-4338-9e80-927fce2f5ba9 (f4f9d084d7ba) started on 172.17.6.239:32961
I1112 17:51:17.488282 28126 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/fd1x6s/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/fd1x6s/master" --zk_session_timeout="10secs"
I1112 17:51:17.488617 28126 master.cpp:416] Master allowing unauthenticated frameworks to register
I1112 17:51:17.488628 28126 master.cpp:419] Master only allowing authenticated slaves to register
I1112 17:51:17.488636 28126 credentials.hpp:37] Loading credentials for authentication from '/tmp/fd1x6s/credentials'
I1112 17:51:17.488948 28126 master.cpp:458] Using default 'crammd5' authenticator
I1112 17:51:17.489071 28126 master.cpp:495] Authorization enabled
I1112 17:51:17.489476 28128 hierarchical.cpp:151] Initialized hierarchical allocator process
I1112 17:51:17.489559 28128 whitelist_watcher.cpp:79] No whitelist given
I1112 17:51:17.489619 28128 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10508)@172.17.6.239:32961
I1112 17:51:17.490007 28117 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1112 17:51:17.491255 28126 master.cpp:1606] The newly elected leader is master@172.17.6.239:32961 with id 8e714773-4a32-4338-9e80-927fce2f5ba9
I1112 17:51:17.491292 28126 master.cpp:1619] Elected as the leading master!
I1112 17:51:17.491302 28126 master.cpp:1379] Recovering from registrar
I1112 17:51:17.491524 28126 registrar.cpp:309] Recovering registrar
I1112 17:51:17.492246 28120 recover.cpp:566] Updating replica status to STARTING
I1112 17:51:17.493969 28117 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 1.638661ms
I1112 17:51:17.494015 28117 replica.cpp:323] Persisted replica status to STARTING
I1112 17:51:17.494308 28129 recover.cpp:475] Replica is in STARTING status
I1112 17:51:17.495888 28129 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10509)@172.17.6.239:32961
I1112 17:51:17.496397 28129 recover.cpp:195] Received a recover response from a replica in STARTING status
I1112 17:51:17.496985 28125 recover.cpp:566] Updating replica status to VOTING
I1112 17:51:17.497972 28125 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 508156ns
I1112 17:51:17.498015 28125 replica.cpp:323] Persisted replica status to VOTING
I1112 17:51:17.498148 28125 recover.cpp:580] Successfully joined the Paxos group
I1112 17:51:17.498442 28125 recover.cpp:464] Recover process terminated
I1112 17:51:17.499109 28125 log.cpp:661] Attempting to start the writer
I1112 17:51:17.500741 28125 replica.cpp:496] Replica received implicit promise request from (10510)@172.17.6.239:32961 with proposal 1
I1112 17:51:17.501967 28125 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 1.201643ms
I1112 17:51:17.502009 28125 replica.cpp:345] Persisted promised to 1
I1112 17:51:17.502987 28120 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1112 17:51:17.505363 28120 replica.cpp:391] Replica received explicit promise request from (10511)@172.17.6.239:32961 for position 0 with proposal 2
I1112 17:51:17.505966 28120 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 562049ns
I1112 17:51:17.505996 28120 replica.cpp:715] Persisted action at 0
I1112 17:51:17.507282 28115 replica.cpp:540] Replica received write request for position 0 from (10512)@172.17.6.239:32961
I1112 17:51:17.507407 28115 leveldb.cpp:438] Reading position from leveldb took 74298ns
I1112 17:51:17.507913 28115 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 447618ns
I1112 17:51:17.507949 28115 replica.cpp:715] Persisted action at 0
I1112 17:51:17.508595 28117 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1112 17:51:17.509212 28117 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 601149ns
I1112 17:51:17.509302 28117 replica.cpp:715] Persisted action at 0
I1112 17:51:17.509333 28117 replica.cpp:700] Replica learned NOP action at position 0
I1112 17:51:17.510366 28125 log.cpp:677] Writer started with ending position 0
I1112 17:51:17.511673 28124 leveldb.cpp:438] Reading position from leveldb took 106986ns
I1112 17:51:17.512836 28118 registrar.cpp:342] Successfully fetched the registry (0B) in 21.273088ms
I1112 17:51:17.513152 28118 registrar.cpp:441] Applied 1 operations in 130387ns; attempting to update the 'registry'
I1112 17:51:17.513969 28118 log.cpp:685] Attempting to append 176 bytes to the log
I1112 17:51:17.514180 28124 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1112 17:51:17.515092 28124 replica.cpp:540] Replica received write request for position 1 from (10513)@172.17.6.239:32961
I1112 17:51:17.515636 28124 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 503890ns
I1112 17:51:17.515664 28124 replica.cpp:715] Persisted action at 1
I1112 17:51:17.516337 28120 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1112 17:51:17.516710 28120 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 355999ns
I1112 17:51:17.516798 28120 replica.cpp:715] Persisted action at 1
I1112 17:51:17.516831 28120 replica.cpp:700] Replica learned APPEND action at position 1
I1112 17:51:17.518299 28115 registrar.cpp:486] Successfully updated the 'registry' in 5.069824ms
I1112 17:51:17.518501 28127 log.cpp:704] Attempting to truncate the log to 1
I1112 17:51:17.518546 28115 registrar.cpp:372] Successfully recovered registrar
I1112 17:51:17.519026 28117 master.cpp:1416] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1112 17:51:17.518694 28120 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1112 17:51:17.520436 28121 replica.cpp:540] Replica received write request for position 2 from (10514)@172.17.6.239:32961
I1112 17:51:17.521239 28121 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 689172ns
I1112 17:51:17.521284 28121 replica.cpp:715] Persisted action at 2
I1112 17:51:17.522193 28117 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1112 17:51:17.522716 28117 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 427752ns
I1112 17:51:17.522780 28117 leveldb.cpp:401] Deleting ~1 keys from leveldb took 49718ns
I1112 17:51:17.522809 28117 replica.cpp:715] Persisted action at 2
I1112 17:51:17.522846 28117 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1112 17:51:17.531816 28097 scheduler.cpp:156] Version: 0.26.0
I1112 17:51:17.532570 28121 scheduler.cpp:238] New master detected at master@172.17.6.239:32961
I1112 17:51:17.534353 28127 scheduler.cpp:300] Sending SUBSCRIBE call to master@172.17.6.239:32961
I1112 17:51:17.536648 28125 process.cpp:3080] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1112 17:51:17.536726 28125 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.6.239:36997
I1112 17:51:17.537184 28125 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1112 17:51:17.537216 28125 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1112 17:51:17.537514 28125 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1112 17:51:17.538022 28117 hierarchical.cpp:195] Added framework 8e714773-4a32-4338-9e80-927fce2f5ba9-0000
I1112 17:51:17.538300 28125 master.hpp:1439] Sending heartbeat to 8e714773-4a32-4338-9e80-927fce2f5ba9-0000
I1112 17:51:17.538398 28117 hierarchical.cpp:977] No resources available to allocate!
I1112 17:51:17.538547 28117 hierarchical.cpp:1070] No inverse offers to send out!
I1112 17:51:17.538673 28117 hierarchical.cpp:876] Performed allocation for 0 slaves in 395201ns
I1112 17:51:17.540367 28122 scheduler.cpp:459] Enqueuing event SUBSCRIBED received from master@172.17.6.239:32961
I1112 17:51:17.541172 28128 scheduler.cpp:459] Enqueuing event HEARTBEAT received from master@172.17.6.239:32961
I1112 17:51:17.541635 28129 master_maintenance_tests.cpp:174] Ignoring HEARTBEAT event
I1112 17:51:17.541676 28128 scheduler.cpp:300] Sending REQUEST call to master@172.17.6.239:32961
I1112 17:51:17.544073 28126 process.cpp:3080] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1112 17:51:17.544138 28126 http.cpp:334] HTTP POST for /master/api/v1/scheduler from 172.17.6.239:36998
I1112 17:51:17.544384 28126 master.cpp:2615] Processing REQUEST call for framework 8e714773-4a32-4338-9e80-927fce2f5ba9-0000 (default)
I1112 17:51:17.544526 28129 hierarchical.cpp:458] Received resource request from framework 8e714773-4a32-4338-9e80-927fce2f5ba9-0000
I1112 17:51:17.544996 28129 master.cpp:922] Master terminating
I1112 17:51:17.545424 28120 hierarchical.cpp:230] Removed framework 8e714773-4a32-4338-9e80-927fce2f5ba9-0000
E1112 17:51:17.546879 28129 scheduler.cpp:433] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (76 ms)
[----------] 22 tests from ContentType/SchedulerTest (5059 ms total)
[----------] Global test environment tear-down
[==========] 827 tests from 112 test cases ran. (352548 ms total)
[ PASSED ] 826 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] PersistentVolumeTest.SlaveRecovery
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[4]: *** [check-local] Error 1
make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1447348599-3289
Untagged: mesos-1447348599-3289:latest
Deleted: b6c8ad51de516011fff9f7e3ac78f772c51151d27115259363ba53191270fbfa
Deleted: e105c951a6e8838df90b3c21d7c38d23603d01f844473a697b9a5fa1031db0db
Deleted: 0d33e128ca6490e58a9cfa1b6f71984202ed89e91ab5e429e4709ec7526189ab
Deleted: 48a81e582ccf15326b90d984d100ef7fd48505f3d5d7794271a77093b97b2c6f
Deleted: dafdab726c6baa159611980f2a6d5b6e50001780ed500ac5c3a22316be63b60e
Deleted: 5c7c1242c36395b73550ec3399decc9c06a46d958407c7ffbb63ff623efd853f
Deleted: 0a0752ba5d732c05b0449b3f0f0c201481e3f3b1d764e529b4cd66e801d7b692
Deleted: 57d622e83750728675401239d6696eefbb9bc67406a87c82e8eceb0bca42e21e
Deleted: 20b93a3e16cb7906b89ca993c603e8b16795d93c0d20569d440c1ff9aac3b260
Deleted: c1695709089c2865fda8b17802abebd81d355a17e1a6c9922a74c294c61fb02f
Deleted: 182b1d581e7bfeb345e613412660c6720de1380b984f0afee90ac470714e4cca
Deleted: 7b6e81f18cd5cccca482b12f9ba54de55da4ab7e271343ab02e591b9f828395f
Deleted: 9a31cad33b1b04b458fd3b35eff76e3d6572b35eda37436278d2414203954ac6
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #1228
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1228/changes>
Build failed in Jenkins: Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #1227
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1227/changes>
Changes:
[vinodkone] Added principal field to /master/framework and /master/state endpoint.
------------------------------------------
[...truncated 141037 lines...]
I1112 18:33:03.200141 28127 slave.cpp:3657] Cleaning up executor 'default' of framework 5bf9a04e-e5b5-421c-a145-003b758aea71-0000 at executor(132)@172.17.7.0:45469
I1112 18:33:03.200455 28117 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_BnafD0/slaves/5bf9a04e-e5b5-421c-a145-003b758aea71-S0/frameworks/5bf9a04e-e5b5-421c-a145-003b758aea71-0000/executors/default/runs/8f456059-79c4-4ef9-9a53-0154a4f950bc' for gc 6.99999768206222days in the future
I1112 18:33:03.200490 28127 slave.cpp:3745] Cleaning up framework 5bf9a04e-e5b5-421c-a145-003b758aea71-0000
I1112 18:33:03.200709 28121 status_update_manager.cpp:284] Closing status update streams for framework 5bf9a04e-e5b5-421c-a145-003b758aea71-0000
I1112 18:33:03.200762 28121 status_update_manager.cpp:530] Cleaning up status update stream for task 50631ae0-df16-4a44-bcb1-5c0cd9cc4ccb of framework 5bf9a04e-e5b5-421c-a145-003b758aea71-0000
I1112 18:33:03.201216 28117 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_BnafD0/slaves/5bf9a04e-e5b5-421c-a145-003b758aea71-S0/frameworks/5bf9a04e-e5b5-421c-a145-003b758aea71-0000/executors/default' for gc 6.99999768008296days in the future
I1112 18:33:03.201455 28117 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_BnafD0/slaves/5bf9a04e-e5b5-421c-a145-003b758aea71-S0/frameworks/5bf9a04e-e5b5-421c-a145-003b758aea71-0000' for gc 6.99999767690963days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (134 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I1112 18:33:03.209079 28094 leveldb.cpp:176] Opened db in 2.890719ms
I1112 18:33:03.210257 28094 leveldb.cpp:183] Compacted db in 1.040622ms
I1112 18:33:03.210369 28094 leveldb.cpp:198] Created db iterator in 33312ns
I1112 18:33:03.210479 28094 leveldb.cpp:204] Seeked to beginning of db in 13501ns
I1112 18:33:03.210563 28094 leveldb.cpp:273] Iterated through 0 keys in the db in 11488ns
I1112 18:33:03.210680 28094 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1112 18:33:03.211431 28119 recover.cpp:449] Starting replica recovery
I1112 18:33:03.211721 28117 recover.cpp:475] Replica is in EMPTY status
I1112 18:33:03.212860 28116 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10500)@172.17.7.0:45469
I1112 18:33:03.213341 28120 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1112 18:33:03.213863 28120 recover.cpp:566] Updating replica status to STARTING
I1112 18:33:03.214722 28120 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 584831ns
I1112 18:33:03.214751 28120 replica.cpp:323] Persisted replica status to STARTING
I1112 18:33:03.214902 28120 recover.cpp:475] Replica is in STARTING status
I1112 18:33:03.216122 28120 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10501)@172.17.7.0:45469
I1112 18:33:03.217748 28120 master.cpp:367] Master 3e587b7d-7615-46b8-b203-88f5405c5d49 (1828098d99d3) started on 172.17.7.0:45469
I1112 18:33:03.217998 28118 recover.cpp:195] Received a recover response from a replica in STARTING status
I1112 18:33:03.217779 28120 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/PXbvIl/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/PXbvIl/master" --zk_session_timeout="10secs"
I1112 18:33:03.218502 28115 recover.cpp:566] Updating replica status to VOTING
I1112 18:33:03.218533 28120 master.cpp:416] Master allowing unauthenticated frameworks to register
I1112 18:33:03.218744 28120 master.cpp:419] Master only allowing authenticated slaves to register
I1112 18:33:03.218756 28120 credentials.hpp:37] Loading credentials for authentication from '/tmp/PXbvIl/credentials'
I1112 18:33:03.219241 28120 master.cpp:458] Using default 'crammd5' authenticator
I1112 18:33:03.219410 28120 master.cpp:495] Authorization enabled
I1112 18:33:03.219405 28127 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 679529ns
I1112 18:33:03.219442 28127 replica.cpp:323] Persisted replica status to VOTING
I1112 18:33:03.219593 28127 recover.cpp:580] Successfully joined the Paxos group
I1112 18:33:03.219796 28127 recover.cpp:464] Recover process terminated
I1112 18:33:03.219959 28115 whitelist_watcher.cpp:79] No whitelist given
I1112 18:33:03.220023 28127 hierarchical.cpp:151] Initialized hierarchical allocator process
I1112 18:33:03.221637 28120 master.cpp:1606] The newly elected leader is master@172.17.7.0:45469 with id 3e587b7d-7615-46b8-b203-88f5405c5d49
I1112 18:33:03.221673 28120 master.cpp:1619] Elected as the leading master!
I1112 18:33:03.221683 28120 master.cpp:1379] Recovering from registrar
I1112 18:33:03.221958 28120 registrar.cpp:309] Recovering registrar
I1112 18:33:03.222805 28120 log.cpp:661] Attempting to start the writer
I1112 18:33:03.224383 28121 replica.cpp:496] Replica received implicit promise request from (10502)@172.17.7.0:45469 with proposal 1
I1112 18:33:03.224970 28121 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 537167ns
I1112 18:33:03.225005 28121 replica.cpp:345] Persisted promised to 1
I1112 18:33:03.226387 28116 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1112 18:33:03.227670 28120 replica.cpp:391] Replica received explicit promise request from (10503)@172.17.7.0:45469 for position 0 with proposal 2
I1112 18:33:03.228160 28120 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 457290ns
I1112 18:33:03.228190 28120 replica.cpp:715] Persisted action at 0
I1112 18:33:03.229393 28120 replica.cpp:540] Replica received write request for position 0 from (10504)@172.17.7.0:45469
I1112 18:33:03.229447 28120 leveldb.cpp:438] Reading position from leveldb took 38522ns
I1112 18:33:03.229840 28120 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 365769ns
I1112 18:33:03.229871 28120 replica.cpp:715] Persisted action at 0
I1112 18:33:03.231142 28119 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1112 18:33:03.231706 28119 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 533938ns
I1112 18:33:03.231736 28119 replica.cpp:715] Persisted action at 0
I1112 18:33:03.231763 28119 replica.cpp:700] Replica learned NOP action at position 0
I1112 18:33:03.232998 28124 log.cpp:677] Writer started with ending position 0
I1112 18:33:03.234138 28121 leveldb.cpp:438] Reading position from leveldb took 66786ns
I1112 18:33:03.235199 28112 registrar.cpp:342] Successfully fetched the registry (0B) in 13.154816ms
I1112 18:33:03.235357 28112 registrar.cpp:441] Applied 1 operations in 48289ns; attempting to update the 'registry'
I1112 18:33:03.236512 28112 log.cpp:685] Attempting to append 168 bytes to the log
I1112 18:33:03.236706 28112 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1112 18:33:03.237692 28123 replica.cpp:540] Replica received write request for position 1 from (10505)@172.17.7.0:45469
I1112 18:33:03.238895 28123 leveldb.cpp:343] Persisting action (187 bytes) to leveldb took 1.175793ms
I1112 18:33:03.238942 28123 replica.cpp:715] Persisted action at 1
I1112 18:33:03.239827 28123 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1112 18:33:03.240139 28123 leveldb.cpp:343] Persisting action (189 bytes) to leveldb took 296365ns
I1112 18:33:03.240169 28123 replica.cpp:715] Persisted action at 1
I1112 18:33:03.240188 28123 replica.cpp:700] Replica learned APPEND action at position 1
I1112 18:33:03.241653 28123 registrar.cpp:486] Successfully updated the 'registry' in 6.23104ms
I1112 18:33:03.241781 28123 registrar.cpp:372] Successfully recovered registrar
I1112 18:33:03.241988 28112 log.cpp:704] Attempting to truncate the log to 1
I1112 18:33:03.242137 28115 master.cpp:1416] Recovered 0 slaves from the Registry (129B) ; allowing 10mins for slaves to re-register
I1112 18:33:03.242348 28112 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1112 18:33:03.243262 28112 replica.cpp:540] Replica received write request for position 2 from (10506)@172.17.7.0:45469
I1112 18:33:03.243684 28112 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 398241ns
I1112 18:33:03.243708 28112 replica.cpp:715] Persisted action at 2
I1112 18:33:03.244441 28125 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1112 18:33:03.244809 28125 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 351288ns
I1112 18:33:03.244863 28125 leveldb.cpp:401] Deleting ~1 keys from leveldb took 38595ns
I1112 18:33:03.244884 28125 replica.cpp:715] Persisted action at 2
I1112 18:33:03.244905 28125 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1112 18:33:03.253335 28094 scheduler.cpp:156] Version: 0.26.0
I1112 18:33:03.254138 28113 scheduler.cpp:238] New master detected at master@172.17.7.0:45469
I1112 18:33:03.255146 28113 scheduler.cpp:300] Sending SUBSCRIBE call to master@172.17.7.0:45469
I1112 18:33:03.257200 28121 process.cpp:3080] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1112 18:33:03.257257 28121 http.cpp:338] HTTP POST for /master/api/v1/scheduler from 172.17.7.0:59373
I1112 18:33:03.257449 28121 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1112 18:33:03.257477 28121 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1112 18:33:03.257767 28125 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1112 18:33:03.259099 28125 hierarchical.cpp:195] Added framework 3e587b7d-7615-46b8-b203-88f5405c5d49-0000
I1112 18:33:03.259152 28125 hierarchical.cpp:977] No resources available to allocate!
I1112 18:33:03.259182 28125 hierarchical.cpp:1070] No inverse offers to send out!
I1112 18:33:03.259203 28125 hierarchical.cpp:876] Performed allocation for 0 slaves in 92834ns
I1112 18:33:03.259517 28121 master.hpp:1439] Sending heartbeat to 3e587b7d-7615-46b8-b203-88f5405c5d49-0000
I1112 18:33:03.260184 28126 scheduler.cpp:459] Enqueuing event SUBSCRIBED received from master@172.17.7.0:45469
I1112 18:33:03.261313 28116 scheduler.cpp:300] Sending REQUEST call to master@172.17.7.0:45469
I1112 18:33:03.262356 28125 scheduler.cpp:459] Enqueuing event HEARTBEAT received from master@172.17.7.0:45469
I1112 18:33:03.262850 28125 master_maintenance_tests.cpp:174] Ignoring HEARTBEAT event
I1112 18:33:03.263031 28125 process.cpp:3080] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1112 18:33:03.263083 28125 http.cpp:338] HTTP POST for /master/api/v1/scheduler from 172.17.7.0:59374
I1112 18:33:03.263181 28125 master.cpp:2615] Processing REQUEST call for framework 3e587b7d-7615-46b8-b203-88f5405c5d49-0000 (default)
I1112 18:33:03.263392 28125 hierarchical.cpp:458] Received resource request from framework 3e587b7d-7615-46b8-b203-88f5405c5d49-0000
I1112 18:33:03.263576 28094 master.cpp:922] Master terminating
I1112 18:33:03.263743 28117 hierarchical.cpp:230] Removed framework 3e587b7d-7615-46b8-b203-88f5405c5d49-0000
E1112 18:33:03.265411 28126 scheduler.cpp:433] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (64 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1112 18:33:03.272290 28094 leveldb.cpp:176] Opened db in 2.239074ms
I1112 18:33:03.273263 28094 leveldb.cpp:183] Compacted db in 952947ns
I1112 18:33:03.273308 28094 leveldb.cpp:198] Created db iterator in 26471ns
I1112 18:33:03.273322 28094 leveldb.cpp:204] Seeked to beginning of db in 7542ns
I1112 18:33:03.273334 28094 leveldb.cpp:273] Iterated through 0 keys in the db in 6141ns
I1112 18:33:03.273371 28094 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1112 18:33:03.273730 28123 recover.cpp:449] Starting replica recovery
I1112 18:33:03.274086 28123 recover.cpp:475] Replica is in EMPTY status
I1112 18:33:03.275277 28126 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10511)@172.17.7.0:45469
I1112 18:33:03.275579 28114 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1112 18:33:03.276237 28114 recover.cpp:566] Updating replica status to STARTING
I1112 18:33:03.276876 28114 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 471485ns
I1112 18:33:03.276904 28114 replica.cpp:323] Persisted replica status to STARTING
I1112 18:33:03.277070 28122 recover.cpp:475] Replica is in STARTING status
I1112 18:33:03.277168 28118 master.cpp:367] Master 3cb3a61e-70ba-4f59-aa29-e4175fa156f9 (1828098d99d3) started on 172.17.7.0:45469
I1112 18:33:03.277199 28118 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/b3uyHN/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/b3uyHN/master" --zk_session_timeout="10secs"
I1112 18:33:03.277490 28118 master.cpp:416] Master allowing unauthenticated frameworks to register
I1112 18:33:03.277501 28118 master.cpp:419] Master only allowing authenticated slaves to register
I1112 18:33:03.277510 28118 credentials.hpp:37] Loading credentials for authentication from '/tmp/b3uyHN/credentials'
I1112 18:33:03.277740 28118 master.cpp:458] Using default 'crammd5' authenticator
I1112 18:33:03.277851 28118 master.cpp:495] Authorization enabled
I1112 18:33:03.278046 28122 whitelist_watcher.cpp:79] No whitelist given
I1112 18:33:03.278077 28127 hierarchical.cpp:151] Initialized hierarchical allocator process
I1112 18:33:03.278520 28121 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10512)@172.17.7.0:45469
I1112 18:33:03.279202 28114 recover.cpp:195] Received a recover response from a replica in STARTING status
I1112 18:33:03.279716 28119 master.cpp:1606] The newly elected leader is master@172.17.7.0:45469 with id 3cb3a61e-70ba-4f59-aa29-e4175fa156f9
I1112 18:33:03.279907 28119 master.cpp:1619] Elected as the leading master!
I1112 18:33:03.279932 28119 master.cpp:1379] Recovering from registrar
I1112 18:33:03.281060 28120 registrar.cpp:309] Recovering registrar
I1112 18:33:03.281077 28119 recover.cpp:566] Updating replica status to VOTING
I1112 18:33:03.281884 28120 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 455298ns
I1112 18:33:03.281911 28120 replica.cpp:323] Persisted replica status to VOTING
I1112 18:33:03.282018 28120 recover.cpp:580] Successfully joined the Paxos group
I1112 18:33:03.282162 28120 recover.cpp:464] Recover process terminated
I1112 18:33:03.282445 28120 log.cpp:661] Attempting to start the writer
I1112 18:33:03.283589 28118 replica.cpp:496] Replica received implicit promise request from (10513)@172.17.7.0:45469 with proposal 1
I1112 18:33:03.283941 28118 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 333212ns
I1112 18:33:03.283967 28118 replica.cpp:345] Persisted promised to 1
I1112 18:33:03.284449 28119 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1112 18:33:03.285547 28125 replica.cpp:391] Replica received explicit promise request from (10514)@172.17.7.0:45469 for position 0 with proposal 2
I1112 18:33:03.285954 28125 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 383534ns
I1112 18:33:03.285980 28125 replica.cpp:715] Persisted action at 0
I1112 18:33:03.287050 28125 replica.cpp:540] Replica received write request for position 0 from (10515)@172.17.7.0:45469
I1112 18:33:03.287102 28125 leveldb.cpp:438] Reading position from leveldb took 34793ns
I1112 18:33:03.287575 28125 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 449175ns
I1112 18:33:03.287600 28125 replica.cpp:715] Persisted action at 0
I1112 18:33:03.288177 28125 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1112 18:33:03.288791 28125 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 603947ns
I1112 18:33:03.288815 28125 replica.cpp:715] Persisted action at 0
I1112 18:33:03.288833 28125 replica.cpp:700] Replica learned NOP action at position 0
I1112 18:33:03.289459 28125 log.cpp:677] Writer started with ending position 0
I1112 18:33:03.290577 28125 leveldb.cpp:438] Reading position from leveldb took 36643ns
I1112 18:33:03.291543 28125 registrar.cpp:342] Successfully fetched the registry (0B) in 10.444032ms
I1112 18:33:03.291671 28125 registrar.cpp:441] Applied 1 operations in 37092ns; attempting to update the 'registry'
I1112 18:33:03.292531 28122 log.cpp:685] Attempting to append 168 bytes to the log
I1112 18:33:03.292676 28122 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1112 18:33:03.293381 28119 replica.cpp:540] Replica received write request for position 1 from (10516)@172.17.7.0:45469
I1112 18:33:03.293711 28119 leveldb.cpp:343] Persisting action (187 bytes) to leveldb took 308116ns
I1112 18:33:03.293736 28119 replica.cpp:715] Persisted action at 1
I1112 18:33:03.294488 28119 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1112 18:33:03.294867 28119 leveldb.cpp:343] Persisting action (189 bytes) to leveldb took 364680ns
I1112 18:33:03.294894 28119 replica.cpp:715] Persisted action at 1
I1112 18:33:03.294911 28119 replica.cpp:700] Replica learned APPEND action at position 1
I1112 18:33:03.296106 28119 registrar.cpp:486] Successfully updated the 'registry' in 4.382208ms
I1112 18:33:03.296222 28119 registrar.cpp:372] Successfully recovered registrar
I1112 18:33:03.296425 28119 log.cpp:704] Attempting to truncate the log to 1
I1112 18:33:03.296711 28119 master.cpp:1416] Recovered 0 slaves from the Registry (129B) ; allowing 10mins for slaves to re-register
I1112 18:33:03.296797 28119 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1112 18:33:03.297708 28117 replica.cpp:540] Replica received write request for position 2 from (10517)@172.17.7.0:45469
I1112 18:33:03.298138 28117 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 408504ns
I1112 18:33:03.298164 28117 replica.cpp:715] Persisted action at 2
I1112 18:33:03.298895 28117 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1112 18:33:03.299340 28117 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 429906ns
I1112 18:33:03.299394 28117 leveldb.cpp:401] Deleting ~1 keys from leveldb took 38066ns
I1112 18:33:03.299417 28117 replica.cpp:715] Persisted action at 2
I1112 18:33:03.299435 28117 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1112 18:33:03.307946 28094 scheduler.cpp:156] Version: 0.26.0
I1112 18:33:03.308465 28124 scheduler.cpp:238] New master detected at master@172.17.7.0:45469
I1112 18:33:03.309355 28121 scheduler.cpp:300] Sending SUBSCRIBE call to master@172.17.7.0:45469
I1112 18:33:03.311491 28121 process.cpp:3080] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1112 18:33:03.311547 28121 http.cpp:338] HTTP POST for /master/api/v1/scheduler from 172.17.7.0:59375
I1112 18:33:03.311871 28121 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1112 18:33:03.311900 28121 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1112 18:33:03.312209 28115 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1112 18:33:03.312569 28124 hierarchical.cpp:195] Added framework 3cb3a61e-70ba-4f59-aa29-e4175fa156f9-0000
I1112 18:33:03.312623 28124 hierarchical.cpp:977] No resources available to allocate!
I1112 18:33:03.312656 28124 hierarchical.cpp:1070] No inverse offers to send out!
I1112 18:33:03.312670 28115 master.hpp:1439] Sending heartbeat to 3cb3a61e-70ba-4f59-aa29-e4175fa156f9-0000
I1112 18:33:03.312681 28124 hierarchical.cpp:876] Performed allocation for 0 slaves in 98878ns
I1112 18:33:03.314278 28123 scheduler.cpp:459] Enqueuing event SUBSCRIBED received from master@172.17.7.0:45469
I1112 18:33:03.314707 28123 scheduler.cpp:459] Enqueuing event HEARTBEAT received from master@172.17.7.0:45469
I1112 18:33:03.315376 28119 master_maintenance_tests.cpp:174] Ignoring HEARTBEAT event
I1112 18:33:03.315966 28113 scheduler.cpp:300] Sending REQUEST call to master@172.17.7.0:45469
I1112 18:33:03.317569 28118 process.cpp:3080] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1112 18:33:03.317699 28118 http.cpp:338] HTTP POST for /master/api/v1/scheduler from 172.17.7.0:59376
I1112 18:33:03.317978 28118 master.cpp:2615] Processing REQUEST call for framework 3cb3a61e-70ba-4f59-aa29-e4175fa156f9-0000 (default)
I1112 18:33:03.318256 28112 hierarchical.cpp:458] Received resource request from framework 3cb3a61e-70ba-4f59-aa29-e4175fa156f9-0000
I1112 18:33:03.318644 28094 master.cpp:922] Master terminating
I1112 18:33:03.318977 28121 hierarchical.cpp:230] Removed framework 3cb3a61e-70ba-4f59-aa29-e4175fa156f9-0000
E1112 18:33:03.320178 28121 scheduler.cpp:433] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (60 ms)
[----------] 22 tests from ContentType/SchedulerTest (5061 ms total)
[----------] Global test environment tear-down
2015-11-12 18:33:03,436:28094(0x2ab733e11700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:38404] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
[==========] 827 tests from 112 test cases ran. (355815 ms total)
[ PASSED ] 826 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] FetcherCacheTest.RemoveLRUCacheEntries
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[4]: *** [check-local] Error 1
make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1447351046-7596
Untagged: mesos-1447351046-7596:latest
Deleted: f3ac066b57db2e45a928b2d9a9cdf0535ae60de7202ab7146993da2029f41f59
Deleted: fd5b2d7d54e20bf3eee6848d7d742beef4c44e0e3b45f29d365e95b610d00ee4
Deleted: 06d3344d9077150f54636761615e4fee044f7ac986a500b2b270d283136cd0ed
Deleted: 3d0068f79211001ff2613d90abfd56b37d0bfd2618903df1c1e250694000b9bb
Deleted: 8623d548e607b9fbb8f49f9d76992ceefe1f3a9ccf09ba8311eae00740507f40
Deleted: ca8297ff8d01d71013b63f6d379df2c01f8c934bd60deedc243ff17622a0ed54
Deleted: 4e4403aca88c4df17b14986fe936819f31903f45a0f113efc2f09d09c5a8614a
Deleted: 1067f0526ff5366b0d5163d409242cabb1fa038a5b072a35ecaa657d00e5cc39
Deleted: 1db3d98ad2bdc67c66948ef5c7e8e4d4b948a88762993d435fcc8c7d82ff9afe
Deleted: 42bb3c61a756f1cf9c98ff35c28879755674b97d6d50ebe9c70176d2c8f94dbf
Deleted: d43bebb6cfb8ab1278eb50dd6465392387be7ef4632de4ad4102c68e988e44ee
Deleted: 05a5fd01fe993b960ebcdc33e43f350dbef388e593fdec3dc7e52fa4c9336634
Deleted: b5afc250ecf4065d6d9c21d73bec2b0d357a41055247dac610ab8fe06ff59ddb
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #1226
Posted by Vinod Kone <vi...@apache.org>.
filed https://issues.apache.org/jira/browse/MESOS-3907
On Thu, Nov 12, 2015 at 9:51 AM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1226/changes
> >
>
> Changes:
>
> [bernd] Updated upgrade documentation with changes in NetworkInfo protobuf.
>
> ------------------------------------------
> [...truncated 140953 lines...]
> I1112 17:51:17.378175 28097 slave.cpp:2009] Asked to shut down framework
> 105e15fa-6648-4af0-98cb-5f5e12e58698-0000 by @0.0.0.0:0
> I1112 17:51:17.378216 28097 slave.cpp:2034] Shutting down framework
> 105e15fa-6648-4af0-98cb-5f5e12e58698-0000
> I1112 17:51:17.378294 28097 slave.cpp:3657] Cleaning up executor 'default'
> of framework 105e15fa-6648-4af0-98cb-5f5e12e58698-0000 at executor(132)@
> 172.17.6.239:32961
> I1112 17:51:17.378770 28097 slave.cpp:3745] Cleaning up framework
> 105e15fa-6648-4af0-98cb-5f5e12e58698-0000
> I1112 17:51:17.378890 28122 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_Hx9cZc/slaves/105e15fa-6648-4af0-98cb-5f5e12e58698-S0/frameworks/105e15fa-6648-4af0-98cb-5f5e12e58698-0000/executors/default/runs/e28c1439-6343-4b52-a535-34114c91f20c'
> for gc 6.99999561904889days in the future
> I1112 17:51:17.379133 28122 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_Hx9cZc/slaves/105e15fa-6648-4af0-98cb-5f5e12e58698-S0/frameworks/105e15fa-6648-4af0-98cb-5f5e12e58698-0000/executors/default'
> for gc 6.99999561678222days in the future
> I1112 17:51:17.379256 28122 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_Hx9cZc/slaves/105e15fa-6648-4af0-98cb-5f5e12e58698-S0/frameworks/105e15fa-6648-4af0-98cb-5f5e12e58698-0000'
> for gc 6.99999561478222days in the future
> I1112 17:51:17.379370 28122 status_update_manager.cpp:284] Closing status
> update streams for framework 105e15fa-6648-4af0-98cb-5f5e12e58698-0000
> I1112 17:51:17.379443 28122 status_update_manager.cpp:530] Cleaning up
> status update stream for task e22dd11d-7cde-4e5a-9d0e-75eb616407dd of
> framework 105e15fa-6648-4af0-98cb-5f5e12e58698-0000
> [ OK ] ContentType/SchedulerTest.Message/1 (182 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> I1112 17:51:17.390677 28097 leveldb.cpp:176] Opened db in 3.016832ms
> I1112 17:51:17.393116 28097 leveldb.cpp:183] Compacted db in 2.403474ms
> I1112 17:51:17.393174 28097 leveldb.cpp:198] Created db iterator in 31334ns
> I1112 17:51:17.393190 28097 leveldb.cpp:204] Seeked to beginning of db in
> 7957ns
> I1112 17:51:17.393199 28097 leveldb.cpp:273] Iterated through 0 keys in
> the db in 5648ns
> I1112 17:51:17.393244 28097 replica.cpp:780] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I1112 17:51:17.394876 28122 recover.cpp:449] Starting replica recovery
> I1112 17:51:17.399888 28122 master.cpp:367] Master
> 7c6ca341-c190-4819-bafb-2bb5050fe11b (f4f9d084d7ba) started on
> 172.17.6.239:32961
> I1112 17:51:17.401128 28122 master.cpp:369] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/fAdRLT/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/fAdRLT/master" --zk_session_timeout="10secs"
> I1112 17:51:17.402081 28122 master.cpp:416] Master allowing
> unauthenticated frameworks to register
> I1112 17:51:17.402163 28122 master.cpp:419] Master only allowing
> authenticated slaves to register
> I1112 17:51:17.402251 28122 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/fAdRLT/credentials'
> I1112 17:51:17.402688 28122 master.cpp:458] Using default 'crammd5'
> authenticator
> I1112 17:51:17.404228 28122 master.cpp:495] Authorization enabled
> I1112 17:51:17.410389 28122 recover.cpp:475] Replica is in EMPTY status
> I1112 17:51:17.412962 28122 hierarchical.cpp:151] Initialized hierarchical
> allocator process
> I1112 17:51:17.413187 28122 whitelist_watcher.cpp:79] No whitelist given
> I1112 17:51:17.413969 28130 master.cpp:1606] The newly elected leader is
> master@172.17.6.239:32961 with id 7c6ca341-c190-4819-bafb-2bb5050fe11b
> I1112 17:51:17.414011 28130 master.cpp:1619] Elected as the leading master!
> I1112 17:51:17.414023 28130 master.cpp:1379] Recovering from registrar
> I1112 17:51:17.414412 28122 registrar.cpp:309] Recovering registrar
> I1112 17:51:17.414970 28122 replica.cpp:676] Replica in EMPTY status
> received a broadcasted recover request from (10497)@172.17.6.239:32961
> I1112 17:51:17.415340 28130 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I1112 17:51:17.415935 28123 recover.cpp:566] Updating replica status to
> STARTING
> I1112 17:51:17.416916 28123 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 776219ns
> I1112 17:51:17.416960 28123 replica.cpp:323] Persisted replica status to
> STARTING
> I1112 17:51:17.417172 28123 recover.cpp:475] Replica is in STARTING status
> I1112 17:51:17.418455 28123 replica.cpp:676] Replica in STARTING status
> received a broadcasted recover request from (10498)@172.17.6.239:32961
> I1112 17:51:17.418933 28120 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I1112 17:51:17.419651 28120 recover.cpp:566] Updating replica status to
> VOTING
> I1112 17:51:17.420497 28120 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 611692ns
> I1112 17:51:17.420526 28120 replica.cpp:323] Persisted replica status to
> VOTING
> I1112 17:51:17.420639 28120 recover.cpp:580] Successfully joined the Paxos
> group
> I1112 17:51:17.420815 28120 recover.cpp:464] Recover process terminated
> I1112 17:51:17.421353 28120 log.cpp:661] Attempting to start the writer
> I1112 17:51:17.422827 28127 replica.cpp:496] Replica received implicit
> promise request from (10499)@172.17.6.239:32961 with proposal 1
> I1112 17:51:17.423548 28127 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 516367ns
> I1112 17:51:17.423771 28127 replica.cpp:345] Persisted promised to 1
> I1112 17:51:17.424571 28118 coordinator.cpp:240] Coordinator attempting to
> fill missing positions
> I1112 17:51:17.426131 28127 replica.cpp:391] Replica received explicit
> promise request from (10500)@172.17.6.239:32961 for position 0 with
> proposal 2
> I1112 17:51:17.426802 28127 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 466545ns
> I1112 17:51:17.427033 28127 replica.cpp:715] Persisted action at 0
> I1112 17:51:17.428941 28123 replica.cpp:540] Replica received write
> request for position 0 from (10501)@172.17.6.239:32961
> I1112 17:51:17.429049 28123 leveldb.cpp:438] Reading position from leveldb
> took 59545ns
> I1112 17:51:17.429576 28123 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 489045ns
> I1112 17:51:17.429601 28123 replica.cpp:715] Persisted action at 0
> I1112 17:51:17.430174 28125 replica.cpp:694] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I1112 17:51:17.430552 28125 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 352271ns
> I1112 17:51:17.430579 28125 replica.cpp:715] Persisted action at 0
> I1112 17:51:17.430601 28125 replica.cpp:700] Replica learned NOP action at
> position 0
> I1112 17:51:17.431615 28129 log.cpp:677] Writer started with ending
> position 0
> I1112 17:51:17.433174 28130 leveldb.cpp:438] Reading position from leveldb
> took 64387ns
> I1112 17:51:17.434456 28120 registrar.cpp:342] Successfully fetched the
> registry (0B) in 19.97696ms
> I1112 17:51:17.434645 28120 registrar.cpp:441] Applied 1 operations in
> 50676ns; attempting to update the 'registry'
> I1112 17:51:17.435513 28124 log.cpp:685] Attempting to append 176 bytes to
> the log
> I1112 17:51:17.435648 28116 coordinator.cpp:350] Coordinator attempting to
> write APPEND action at position 1
> I1112 17:51:17.436478 28120 replica.cpp:540] Replica received write
> request for position 1 from (10502)@172.17.6.239:32961
> I1112 17:51:17.437090 28120 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 585558ns
> I1112 17:51:17.437119 28120 replica.cpp:715] Persisted action at 1
> I1112 17:51:17.437932 28126 replica.cpp:694] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I1112 17:51:17.438452 28126 leveldb.cpp:343] Persisting action (197 bytes)
> to leveldb took 492719ns
> I1112 17:51:17.438482 28126 replica.cpp:715] Persisted action at 1
> I1112 17:51:17.438508 28126 replica.cpp:700] Replica learned APPEND action
> at position 1
> I1112 17:51:17.439658 28129 registrar.cpp:486] Successfully updated the
> 'registry' in 4.932352ms
> I1112 17:51:17.439841 28129 registrar.cpp:372] Successfully recovered
> registrar
> I1112 17:51:17.439895 28124 log.cpp:704] Attempting to truncate the log to
> 1
> I1112 17:51:17.440017 28127 coordinator.cpp:350] Coordinator attempting to
> write TRUNCATE action at position 2
> I1112 17:51:17.440244 28121 master.cpp:1416] Recovered 0 slaves from the
> Registry (137B) ; allowing 10mins for slaves to re-register
> I1112 17:51:17.441288 28117 replica.cpp:540] Replica received write
> request for position 2 from (10503)@172.17.6.239:32961
> I1112 17:51:17.441968 28117 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 652079ns
> I1112 17:51:17.441997 28117 replica.cpp:715] Persisted action at 2
> I1112 17:51:17.442574 28117 replica.cpp:694] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I1112 17:51:17.442980 28117 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 389107ns
> I1112 17:51:17.443038 28117 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 41755ns
> I1112 17:51:17.443056 28117 replica.cpp:715] Persisted action at 2
> I1112 17:51:17.443078 28117 replica.cpp:700] Replica learned TRUNCATE
> action at position 2
> I1112 17:51:17.451871 28097 scheduler.cpp:156] Version: 0.26.0
> I1112 17:51:17.453519 28130 scheduler.cpp:238] New master detected at
> master@172.17.6.239:32961
> I1112 17:51:17.455070 28123 scheduler.cpp:300] Sending SUBSCRIBE call to
> master@172.17.6.239:32961
> I1112 17:51:17.457713 28116 process.cpp:3080] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1112 17:51:17.457803 28116 http.cpp:334] HTTP POST for
> /master/api/v1/scheduler from 172.17.6.239:36995
> I1112 17:51:17.458163 28116 master.cpp:1868] Received subscription request
> for HTTP framework 'default'
> I1112 17:51:17.458217 28116 master.cpp:1645] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I1112 17:51:17.458658 28116 master.cpp:1960] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I1112 17:51:17.459120 28125 hierarchical.cpp:195] Added framework
> 7c6ca341-c190-4819-bafb-2bb5050fe11b-0000
> I1112 17:51:17.459187 28125 hierarchical.cpp:977] No resources available
> to allocate!
> I1112 17:51:17.459235 28125 hierarchical.cpp:1070] No inverse offers to
> send out!
> I1112 17:51:17.459270 28125 hierarchical.cpp:876] Performed allocation for
> 0 slaves in 134215ns
> I1112 17:51:17.459660 28116 master.hpp:1439] Sending heartbeat to
> 7c6ca341-c190-4819-bafb-2bb5050fe11b-0000
> I1112 17:51:17.463112 28128 scheduler.cpp:459] Enqueuing event SUBSCRIBED
> received from master@172.17.6.239:32961
> I1112 17:51:17.464046 28125 scheduler.cpp:459] Enqueuing event HEARTBEAT
> received from master@172.17.6.239:32961
> I1112 17:51:17.464819 28125 master_maintenance_tests.cpp:174] Ignoring
> HEARTBEAT event
> I1112 17:51:17.465275 28128 scheduler.cpp:300] Sending REQUEST call to
> master@172.17.6.239:32961
> I1112 17:51:17.469228 28127 process.cpp:3080] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1112 17:51:17.469326 28127 http.cpp:334] HTTP POST for
> /master/api/v1/scheduler from 172.17.6.239:36996
> I1112 17:51:17.469521 28127 master.cpp:2615] Processing REQUEST call for
> framework 7c6ca341-c190-4819-bafb-2bb5050fe11b-0000 (default)
> I1112 17:51:17.469825 28127 hierarchical.cpp:458] Received resource
> request from framework 7c6ca341-c190-4819-bafb-2bb5050fe11b-0000
> I1112 17:51:17.470684 28123 master.cpp:922] Master terminating
> I1112 17:51:17.471109 28119 hierarchical.cpp:230] Removed framework
> 7c6ca341-c190-4819-bafb-2bb5050fe11b-0000
> [ OK ] ContentType/SchedulerTest.Request/0 (92 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I1112 17:51:17.482259 28097 leveldb.cpp:176] Opened db in 2.981123ms
> I1112 17:51:17.483597 28097 leveldb.cpp:183] Compacted db in 1.052602ms
> I1112 17:51:17.483659 28097 leveldb.cpp:198] Created db iterator in 33663ns
> I1112 17:51:17.483675 28097 leveldb.cpp:204] Seeked to beginning of db in
> 7568ns
> I1112 17:51:17.483685 28097 leveldb.cpp:273] Iterated through 0 keys in
> the db in 6190ns
> I1112 17:51:17.483739 28097 replica.cpp:780] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I1112 17:51:17.484688 28118 recover.cpp:449] Starting replica recovery
> I1112 17:51:17.485072 28116 recover.cpp:475] Replica is in EMPTY status
> I1112 17:51:17.488243 28126 master.cpp:367] Master
> 8e714773-4a32-4338-9e80-927fce2f5ba9 (f4f9d084d7ba) started on
> 172.17.6.239:32961
> I1112 17:51:17.488282 28126 master.cpp:369] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/fd1x6s/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/fd1x6s/master" --zk_session_timeout="10secs"
> I1112 17:51:17.488617 28126 master.cpp:416] Master allowing
> unauthenticated frameworks to register
> I1112 17:51:17.488628 28126 master.cpp:419] Master only allowing
> authenticated slaves to register
> I1112 17:51:17.488636 28126 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/fd1x6s/credentials'
> I1112 17:51:17.488948 28126 master.cpp:458] Using default 'crammd5'
> authenticator
> I1112 17:51:17.489071 28126 master.cpp:495] Authorization enabled
> I1112 17:51:17.489476 28128 hierarchical.cpp:151] Initialized hierarchical
> allocator process
> I1112 17:51:17.489559 28128 whitelist_watcher.cpp:79] No whitelist given
> I1112 17:51:17.489619 28128 replica.cpp:676] Replica in EMPTY status
> received a broadcasted recover request from (10508)@172.17.6.239:32961
> I1112 17:51:17.490007 28117 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I1112 17:51:17.491255 28126 master.cpp:1606] The newly elected leader is
> master@172.17.6.239:32961 with id 8e714773-4a32-4338-9e80-927fce2f5ba9
> I1112 17:51:17.491292 28126 master.cpp:1619] Elected as the leading master!
> I1112 17:51:17.491302 28126 master.cpp:1379] Recovering from registrar
> I1112 17:51:17.491524 28126 registrar.cpp:309] Recovering registrar
> I1112 17:51:17.492246 28120 recover.cpp:566] Updating replica status to
> STARTING
> I1112 17:51:17.493969 28117 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 1.638661ms
> I1112 17:51:17.494015 28117 replica.cpp:323] Persisted replica status to
> STARTING
> I1112 17:51:17.494308 28129 recover.cpp:475] Replica is in STARTING status
> I1112 17:51:17.495888 28129 replica.cpp:676] Replica in STARTING status
> received a broadcasted recover request from (10509)@172.17.6.239:32961
> I1112 17:51:17.496397 28129 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I1112 17:51:17.496985 28125 recover.cpp:566] Updating replica status to
> VOTING
> I1112 17:51:17.497972 28125 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 508156ns
> I1112 17:51:17.498015 28125 replica.cpp:323] Persisted replica status to
> VOTING
> I1112 17:51:17.498148 28125 recover.cpp:580] Successfully joined the Paxos
> group
> I1112 17:51:17.498442 28125 recover.cpp:464] Recover process terminated
> I1112 17:51:17.499109 28125 log.cpp:661] Attempting to start the writer
> I1112 17:51:17.500741 28125 replica.cpp:496] Replica received implicit
> promise request from (10510)@172.17.6.239:32961 with proposal 1
> I1112 17:51:17.501967 28125 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 1.201643ms
> I1112 17:51:17.502009 28125 replica.cpp:345] Persisted promised to 1
> I1112 17:51:17.502987 28120 coordinator.cpp:240] Coordinator attempting to
> fill missing positions
> I1112 17:51:17.505363 28120 replica.cpp:391] Replica received explicit
> promise request from (10511)@172.17.6.239:32961 for position 0 with
> proposal 2
> I1112 17:51:17.505966 28120 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 562049ns
> I1112 17:51:17.505996 28120 replica.cpp:715] Persisted action at 0
> I1112 17:51:17.507282 28115 replica.cpp:540] Replica received write
> request for position 0 from (10512)@172.17.6.239:32961
> I1112 17:51:17.507407 28115 leveldb.cpp:438] Reading position from leveldb
> took 74298ns
> I1112 17:51:17.507913 28115 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 447618ns
> I1112 17:51:17.507949 28115 replica.cpp:715] Persisted action at 0
> I1112 17:51:17.508595 28117 replica.cpp:694] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I1112 17:51:17.509212 28117 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 601149ns
> I1112 17:51:17.509302 28117 replica.cpp:715] Persisted action at 0
> I1112 17:51:17.509333 28117 replica.cpp:700] Replica learned NOP action at
> position 0
> I1112 17:51:17.510366 28125 log.cpp:677] Writer started with ending
> position 0
> I1112 17:51:17.511673 28124 leveldb.cpp:438] Reading position from leveldb
> took 106986ns
> I1112 17:51:17.512836 28118 registrar.cpp:342] Successfully fetched the
> registry (0B) in 21.273088ms
> I1112 17:51:17.513152 28118 registrar.cpp:441] Applied 1 operations in
> 130387ns; attempting to update the 'registry'
> I1112 17:51:17.513969 28118 log.cpp:685] Attempting to append 176 bytes to
> the log
> I1112 17:51:17.514180 28124 coordinator.cpp:350] Coordinator attempting to
> write APPEND action at position 1
> I1112 17:51:17.515092 28124 replica.cpp:540] Replica received write
> request for position 1 from (10513)@172.17.6.239:32961
> I1112 17:51:17.515636 28124 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 503890ns
> I1112 17:51:17.515664 28124 replica.cpp:715] Persisted action at 1
> I1112 17:51:17.516337 28120 replica.cpp:694] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I1112 17:51:17.516710 28120 leveldb.cpp:343] Persisting action (197 bytes)
> to leveldb took 355999ns
> I1112 17:51:17.516798 28120 replica.cpp:715] Persisted action at 1
> I1112 17:51:17.516831 28120 replica.cpp:700] Replica learned APPEND action
> at position 1
> I1112 17:51:17.518299 28115 registrar.cpp:486] Successfully updated the
> 'registry' in 5.069824ms
> I1112 17:51:17.518501 28127 log.cpp:704] Attempting to truncate the log to
> 1
> I1112 17:51:17.518546 28115 registrar.cpp:372] Successfully recovered
> registrar
> I1112 17:51:17.519026 28117 master.cpp:1416] Recovered 0 slaves from the
> Registry (137B) ; allowing 10mins for slaves to re-register
> I1112 17:51:17.518694 28120 coordinator.cpp:350] Coordinator attempting to
> write TRUNCATE action at position 2
> I1112 17:51:17.520436 28121 replica.cpp:540] Replica received write
> request for position 2 from (10514)@172.17.6.239:32961
> I1112 17:51:17.521239 28121 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 689172ns
> I1112 17:51:17.521284 28121 replica.cpp:715] Persisted action at 2
> I1112 17:51:17.522193 28117 replica.cpp:694] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I1112 17:51:17.522716 28117 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 427752ns
> I1112 17:51:17.522780 28117 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 49718ns
> I1112 17:51:17.522809 28117 replica.cpp:715] Persisted action at 2
> I1112 17:51:17.522846 28117 replica.cpp:700] Replica learned TRUNCATE
> action at position 2
> I1112 17:51:17.531816 28097 scheduler.cpp:156] Version: 0.26.0
> I1112 17:51:17.532570 28121 scheduler.cpp:238] New master detected at
> master@172.17.6.239:32961
> I1112 17:51:17.534353 28127 scheduler.cpp:300] Sending SUBSCRIBE call to
> master@172.17.6.239:32961
> I1112 17:51:17.536648 28125 process.cpp:3080] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1112 17:51:17.536726 28125 http.cpp:334] HTTP POST for
> /master/api/v1/scheduler from 172.17.6.239:36997
> I1112 17:51:17.537184 28125 master.cpp:1868] Received subscription request
> for HTTP framework 'default'
> I1112 17:51:17.537216 28125 master.cpp:1645] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I1112 17:51:17.537514 28125 master.cpp:1960] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I1112 17:51:17.538022 28117 hierarchical.cpp:195] Added framework
> 8e714773-4a32-4338-9e80-927fce2f5ba9-0000
> I1112 17:51:17.538300 28125 master.hpp:1439] Sending heartbeat to
> 8e714773-4a32-4338-9e80-927fce2f5ba9-0000
> I1112 17:51:17.538398 28117 hierarchical.cpp:977] No resources available
> to allocate!
> I1112 17:51:17.538547 28117 hierarchical.cpp:1070] No inverse offers to
> send out!
> I1112 17:51:17.538673 28117 hierarchical.cpp:876] Performed allocation for
> 0 slaves in 395201ns
> I1112 17:51:17.540367 28122 scheduler.cpp:459] Enqueuing event SUBSCRIBED
> received from master@172.17.6.239:32961
> I1112 17:51:17.541172 28128 scheduler.cpp:459] Enqueuing event HEARTBEAT
> received from master@172.17.6.239:32961
> I1112 17:51:17.541635 28129 master_maintenance_tests.cpp:174] Ignoring
> HEARTBEAT event
> I1112 17:51:17.541676 28128 scheduler.cpp:300] Sending REQUEST call to
> master@172.17.6.239:32961
> I1112 17:51:17.544073 28126 process.cpp:3080] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1112 17:51:17.544138 28126 http.cpp:334] HTTP POST for
> /master/api/v1/scheduler from 172.17.6.239:36998
> I1112 17:51:17.544384 28126 master.cpp:2615] Processing REQUEST call for
> framework 8e714773-4a32-4338-9e80-927fce2f5ba9-0000 (default)
> I1112 17:51:17.544526 28129 hierarchical.cpp:458] Received resource
> request from framework 8e714773-4a32-4338-9e80-927fce2f5ba9-0000
> I1112 17:51:17.544996 28129 master.cpp:922] Master terminating
> I1112 17:51:17.545424 28120 hierarchical.cpp:230] Removed framework
> 8e714773-4a32-4338-9e80-927fce2f5ba9-0000
> E1112 17:51:17.546879 28129 scheduler.cpp:433] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (76 ms)
> [----------] 22 tests from ContentType/SchedulerTest (5059 ms total)
>
> [----------] Global test environment tear-down
> [==========] 827 tests from 112 test cases ran. (352548 ms total)
> [ PASSED ] 826 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] PersistentVolumeTest.SlaveRecovery
>
> 1 FAILED TEST
> YOU HAVE 7 DISABLED TESTS
>
> make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
> make[4]: *** [check-local] Error 1
> make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
> make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
> make[1]: *** [check-recursive] Error 1
> make: *** [distcheck] Error 1
> + docker rmi mesos-1447348599-3289
> Untagged: mesos-1447348599-3289:latest
> Deleted: b6c8ad51de516011fff9f7e3ac78f772c51151d27115259363ba53191270fbfa
> Deleted: e105c951a6e8838df90b3c21d7c38d23603d01f844473a697b9a5fa1031db0db
> Deleted: 0d33e128ca6490e58a9cfa1b6f71984202ed89e91ab5e429e4709ec7526189ab
> Deleted: 48a81e582ccf15326b90d984d100ef7fd48505f3d5d7794271a77093b97b2c6f
> Deleted: dafdab726c6baa159611980f2a6d5b6e50001780ed500ac5c3a22316be63b60e
> Deleted: 5c7c1242c36395b73550ec3399decc9c06a46d958407c7ffbb63ff623efd853f
> Deleted: 0a0752ba5d732c05b0449b3f0f0c201481e3f3b1d764e529b4cd66e801d7b692
> Deleted: 57d622e83750728675401239d6696eefbb9bc67406a87c82e8eceb0bca42e21e
> Deleted: 20b93a3e16cb7906b89ca993c603e8b16795d93c0d20569d440c1ff9aac3b260
> Deleted: c1695709089c2865fda8b17802abebd81d355a17e1a6c9922a74c294c61fb02f
> Deleted: 182b1d581e7bfeb345e613412660c6720de1380b984f0afee90ac470714e4cca
> Deleted: 7b6e81f18cd5cccca482b12f9ba54de55da4ab7e271343ab02e591b9f828395f
> Deleted: 9a31cad33b1b04b458fd3b35eff76e3d6572b35eda37436278d2414203954ac6
> Build step 'Execute shell' marked build as failure
>