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/06 21:56:55 UTC
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,centos:7,docker||Hadoop #1186
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1186/changes>
Changes:
[adam] Added documentation about roles.
------------------------------------------
[...truncated 137295 lines...]
I1106 20:57:00.173877 32109 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1106 20:57:00.174633 32118 replica.cpp:540] Replica received write request for position 1 from (10505)@172.17.8.35:53065
I1106 20:57:00.175012 32118 leveldb.cpp:343] Persisting action (193 bytes) to leveldb took 342920ns
I1106 20:57:00.175077 32118 replica.cpp:715] Persisted action at 1
I1106 20:57:00.175891 32119 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1106 20:57:00.176376 32119 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 457137ns
I1106 20:57:00.176403 32119 replica.cpp:715] Persisted action at 1
I1106 20:57:00.176429 32119 replica.cpp:700] Replica learned APPEND action at position 1
I1106 20:57:00.177446 32110 registrar.cpp:486] Successfully updated the 'registry' in 4.333056ms
I1106 20:57:00.177592 32110 registrar.cpp:372] Successfully recovered registrar
I1106 20:57:00.177654 32123 log.cpp:704] Attempting to truncate the log to 1
I1106 20:57:00.177989 32118 master.cpp:1416] Recovered 0 slaves from the Registry (135B) ; allowing 10mins for slaves to re-register
I1106 20:57:00.178040 32114 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1106 20:57:00.179000 32119 replica.cpp:540] Replica received write request for position 2 from (10506)@172.17.8.35:53065
I1106 20:57:00.179379 32119 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 334396ns
I1106 20:57:00.179411 32119 replica.cpp:715] Persisted action at 2
I1106 20:57:00.180058 32113 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1106 20:57:00.180454 32113 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 352048ns
I1106 20:57:00.180510 32113 leveldb.cpp:401] Deleting ~1 keys from leveldb took 28575ns
I1106 20:57:00.180531 32113 replica.cpp:715] Persisted action at 2
I1106 20:57:00.180552 32113 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1106 20:57:00.190716 32110 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1106 20:57:00.190909 32110 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.8.35:59314
I1106 20:57:00.191318 32110 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1106 20:57:00.191390 32110 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1106 20:57:00.191668 32115 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1106 20:57:00.192131 32117 hierarchical.cpp:185] Added framework 6ba607fe-d62f-4ed2-bb1b-b1fba1ad1db8-0000
I1106 20:57:00.192191 32117 hierarchical.cpp:952] No resources available to allocate!
I1106 20:57:00.192237 32117 hierarchical.cpp:1045] No inverse offers to send out!
I1106 20:57:00.192266 32117 hierarchical.cpp:851] Performed allocation for 0 slaves in 107423ns
I1106 20:57:00.192378 32116 master.hpp:1439] Sending heartbeat to 6ba607fe-d62f-4ed2-bb1b-b1fba1ad1db8-0000
I1106 20:57:00.193161 32114 master.cpp:922] Master terminating
I1106 20:57:00.193326 32121 hierarchical.cpp:220] Removed framework 6ba607fe-d62f-4ed2-bb1b-b1fba1ad1db8-0000
[ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (55 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
I1106 20:57:00.200804 32090 leveldb.cpp:176] Opened db in 2.449459ms
I1106 20:57:00.201807 32090 leveldb.cpp:183] Compacted db in 971307ns
I1106 20:57:00.201860 32090 leveldb.cpp:198] Created db iterator in 23030ns
I1106 20:57:00.201887 32090 leveldb.cpp:204] Seeked to beginning of db in 2288ns
I1106 20:57:00.201905 32090 leveldb.cpp:273] Iterated through 0 keys in the db in 663ns
I1106 20:57:00.201958 32090 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1106 20:57:00.202378 32116 recover.cpp:449] Starting replica recovery
I1106 20:57:00.202661 32116 recover.cpp:475] Replica is in EMPTY status
I1106 20:57:00.203521 32120 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10510)@172.17.8.35:53065
I1106 20:57:00.203899 32115 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1106 20:57:00.204315 32120 recover.cpp:566] Updating replica status to STARTING
I1106 20:57:00.204875 32116 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 451550ns
I1106 20:57:00.204897 32116 replica.cpp:323] Persisted replica status to STARTING
I1106 20:57:00.205081 32115 recover.cpp:475] Replica is in STARTING status
I1106 20:57:00.205271 32118 master.cpp:367] Master acc5b2a0-aeb9-4153-a37c-17df3fe6188b (a6e2642c57a3) started on 172.17.8.35:53065
I1106 20:57:00.205296 32118 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/UjqK7v/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/UjqK7v/master" --zk_session_timeout="10secs"
I1106 20:57:00.205579 32118 master.cpp:416] Master allowing unauthenticated frameworks to register
I1106 20:57:00.205595 32118 master.cpp:419] Master only allowing authenticated slaves to register
I1106 20:57:00.205605 32118 credentials.hpp:37] Loading credentials for authentication from '/tmp/UjqK7v/credentials'
I1106 20:57:00.205819 32118 master.cpp:458] Using default 'crammd5' authenticator
I1106 20:57:00.205844 32117 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10511)@172.17.8.35:53065
I1106 20:57:00.205937 32118 master.cpp:495] Authorization enabled
I1106 20:57:00.206362 32119 whitelist_watcher.cpp:79] No whitelist given
I1106 20:57:00.206373 32114 recover.cpp:195] Received a recover response from a replica in STARTING status
I1106 20:57:00.206388 32123 hierarchical.cpp:140] Initialized hierarchical allocator process
I1106 20:57:00.206800 32114 recover.cpp:566] Updating replica status to VOTING
I1106 20:57:00.207365 32117 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 291144ns
I1106 20:57:00.207391 32117 replica.cpp:323] Persisted replica status to VOTING
I1106 20:57:00.207517 32117 recover.cpp:580] Successfully joined the Paxos group
I1106 20:57:00.207891 32121 master.cpp:1606] The newly elected leader is master@172.17.8.35:53065 with id acc5b2a0-aeb9-4153-a37c-17df3fe6188b
I1106 20:57:00.207923 32121 master.cpp:1619] Elected as the leading master!
I1106 20:57:00.207948 32121 master.cpp:1379] Recovering from registrar
I1106 20:57:00.208039 32117 recover.cpp:464] Recover process terminated
I1106 20:57:00.208140 32111 registrar.cpp:309] Recovering registrar
I1106 20:57:00.208942 32116 log.cpp:661] Attempting to start the writer
I1106 20:57:00.210060 32119 replica.cpp:496] Replica received implicit promise request from (10512)@172.17.8.35:53065 with proposal 1
I1106 20:57:00.210439 32119 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 346035ns
I1106 20:57:00.210460 32119 replica.cpp:345] Persisted promised to 1
I1106 20:57:00.211122 32115 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1106 20:57:00.212139 32122 replica.cpp:391] Replica received explicit promise request from (10513)@172.17.8.35:53065 for position 0 with proposal 2
I1106 20:57:00.212453 32122 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 273960ns
I1106 20:57:00.212476 32122 replica.cpp:715] Persisted action at 0
I1106 20:57:00.213392 32111 replica.cpp:540] Replica received write request for position 0 from (10514)@172.17.8.35:53065
I1106 20:57:00.213454 32111 leveldb.cpp:438] Reading position from leveldb took 30458ns
I1106 20:57:00.213812 32111 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 319186ns
I1106 20:57:00.213835 32111 replica.cpp:715] Persisted action at 0
I1106 20:57:00.214350 32120 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1106 20:57:00.214695 32120 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 313681ns
I1106 20:57:00.214717 32120 replica.cpp:715] Persisted action at 0
I1106 20:57:00.214733 32120 replica.cpp:700] Replica learned NOP action at position 0
I1106 20:57:00.215240 32116 log.cpp:677] Writer started with ending position 0
I1106 20:57:00.216233 32115 leveldb.cpp:438] Reading position from leveldb took 24636ns
I1106 20:57:00.217003 32112 registrar.cpp:342] Successfully fetched the registry (0B) in 8.81792ms
I1106 20:57:00.217141 32112 registrar.cpp:441] Applied 1 operations in 33886ns; attempting to update the 'registry'
I1106 20:57:00.217800 32120 log.cpp:685] Attempting to append 174 bytes to the log
I1106 20:57:00.217957 32118 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1106 20:57:00.218600 32113 replica.cpp:540] Replica received write request for position 1 from (10515)@172.17.8.35:53065
I1106 20:57:00.218983 32113 leveldb.cpp:343] Persisting action (193 bytes) to leveldb took 348395ns
I1106 20:57:00.219007 32113 replica.cpp:715] Persisted action at 1
I1106 20:57:00.219573 32113 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1106 20:57:00.219877 32113 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 272804ns
I1106 20:57:00.219899 32113 replica.cpp:715] Persisted action at 1
I1106 20:57:00.219915 32113 replica.cpp:700] Replica learned APPEND action at position 1
I1106 20:57:00.220782 32119 registrar.cpp:486] Successfully updated the 'registry' in 3.582976ms
I1106 20:57:00.220921 32119 registrar.cpp:372] Successfully recovered registrar
I1106 20:57:00.220981 32124 log.cpp:704] Attempting to truncate the log to 1
I1106 20:57:00.221149 32111 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1106 20:57:00.221354 32110 master.cpp:1416] Recovered 0 slaves from the Registry (135B) ; allowing 10mins for slaves to re-register
I1106 20:57:00.221845 32113 replica.cpp:540] Replica received write request for position 2 from (10516)@172.17.8.35:53065
I1106 20:57:00.222175 32113 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 296205ns
I1106 20:57:00.222201 32113 replica.cpp:715] Persisted action at 2
I1106 20:57:00.222695 32118 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1106 20:57:00.223064 32118 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 338197ns
I1106 20:57:00.223115 32118 leveldb.cpp:401] Deleting ~1 keys from leveldb took 28462ns
I1106 20:57:00.223134 32118 replica.cpp:715] Persisted action at 2
I1106 20:57:00.223150 32118 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1106 20:57:00.233584 32111 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1106 20:57:00.233800 32111 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.8.35:59315
I1106 20:57:00.234007 32111 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1106 20:57:00.234102 32111 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1106 20:57:00.234361 32113 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1106 20:57:00.234725 32114 hierarchical.cpp:185] Added framework acc5b2a0-aeb9-4153-a37c-17df3fe6188b-0000
I1106 20:57:00.234786 32114 hierarchical.cpp:952] No resources available to allocate!
I1106 20:57:00.234828 32114 hierarchical.cpp:1045] No inverse offers to send out!
I1106 20:57:00.234856 32114 hierarchical.cpp:851] Performed allocation for 0 slaves in 105782ns
I1106 20:57:00.234863 32113 master.hpp:1439] Sending heartbeat to acc5b2a0-aeb9-4153-a37c-17df3fe6188b-0000
I1106 20:57:00.235612 32114 master.cpp:922] Master terminating
I1106 20:57:00.235793 32110 hierarchical.cpp:220] Removed framework acc5b2a0-aeb9-4153-a37c-17df3fe6188b-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (42 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
I1106 20:57:00.243410 32090 leveldb.cpp:176] Opened db in 2.528779ms
I1106 20:57:00.244223 32090 leveldb.cpp:183] Compacted db in 781748ns
I1106 20:57:00.244271 32090 leveldb.cpp:198] Created db iterator in 20065ns
I1106 20:57:00.244288 32090 leveldb.cpp:204] Seeked to beginning of db in 1986ns
I1106 20:57:00.244297 32090 leveldb.cpp:273] Iterated through 0 keys in the db in 482ns
I1106 20:57:00.244338 32090 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1106 20:57:00.244779 32112 recover.cpp:449] Starting replica recovery
I1106 20:57:00.245321 32112 recover.cpp:475] Replica is in EMPTY status
I1106 20:57:00.246323 32109 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10520)@172.17.8.35:53065
I1106 20:57:00.246774 32117 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1106 20:57:00.246985 32122 master.cpp:367] Master a2b25f93-bd54-452f-983c-485bc20edbe5 (a6e2642c57a3) started on 172.17.8.35:53065
I1106 20:57:00.247011 32122 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/6YoRbL/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/6YoRbL/master" --zk_session_timeout="10secs"
I1106 20:57:00.247385 32122 master.cpp:416] Master allowing unauthenticated frameworks to register
I1106 20:57:00.247407 32122 master.cpp:419] Master only allowing authenticated slaves to register
I1106 20:57:00.247419 32122 credentials.hpp:37] Loading credentials for authentication from '/tmp/6YoRbL/credentials'
I1106 20:57:00.247596 32114 recover.cpp:566] Updating replica status to STARTING
I1106 20:57:00.247675 32122 master.cpp:458] Using default 'crammd5' authenticator
I1106 20:57:00.247872 32122 master.cpp:495] Authorization enabled
I1106 20:57:00.248129 32116 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 395691ns
I1106 20:57:00.248159 32116 replica.cpp:323] Persisted replica status to STARTING
I1106 20:57:00.248180 32110 whitelist_watcher.cpp:79] No whitelist given
I1106 20:57:00.248215 32109 hierarchical.cpp:140] Initialized hierarchical allocator process
I1106 20:57:00.248363 32110 recover.cpp:475] Replica is in STARTING status
I1106 20:57:00.249172 32110 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10521)@172.17.8.35:53065
I1106 20:57:00.249482 32113 recover.cpp:195] Received a recover response from a replica in STARTING status
I1106 20:57:00.249924 32110 recover.cpp:566] Updating replica status to VOTING
I1106 20:57:00.250020 32122 master.cpp:1606] The newly elected leader is master@172.17.8.35:53065 with id a2b25f93-bd54-452f-983c-485bc20edbe5
I1106 20:57:00.250071 32122 master.cpp:1619] Elected as the leading master!
I1106 20:57:00.250095 32122 master.cpp:1379] Recovering from registrar
I1106 20:57:00.250285 32114 registrar.cpp:309] Recovering registrar
I1106 20:57:00.250428 32117 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 316995ns
I1106 20:57:00.250461 32117 replica.cpp:323] Persisted replica status to VOTING
I1106 20:57:00.250578 32117 recover.cpp:580] Successfully joined the Paxos group
I1106 20:57:00.250903 32117 recover.cpp:464] Recover process terminated
I1106 20:57:00.251584 32118 log.cpp:661] Attempting to start the writer
I1106 20:57:00.252907 32117 replica.cpp:496] Replica received implicit promise request from (10522)@172.17.8.35:53065 with proposal 1
I1106 20:57:00.253288 32117 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 345114ns
I1106 20:57:00.253317 32117 replica.cpp:345] Persisted promised to 1
I1106 20:57:00.253952 32120 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1106 20:57:00.255147 32116 replica.cpp:391] Replica received explicit promise request from (10523)@172.17.8.35:53065 for position 0 with proposal 2
I1106 20:57:00.255475 32116 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 288603ns
I1106 20:57:00.255498 32116 replica.cpp:715] Persisted action at 0
I1106 20:57:00.256507 32109 replica.cpp:540] Replica received write request for position 0 from (10524)@172.17.8.35:53065
I1106 20:57:00.256569 32109 leveldb.cpp:438] Reading position from leveldb took 30709ns
I1106 20:57:00.256968 32109 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 353167ns
I1106 20:57:00.256989 32109 replica.cpp:715] Persisted action at 0
I1106 20:57:00.257602 32118 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1106 20:57:00.257951 32118 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 308308ns
I1106 20:57:00.257985 32118 replica.cpp:715] Persisted action at 0
I1106 20:57:00.258033 32118 replica.cpp:700] Replica learned NOP action at position 0
I1106 20:57:00.258658 32121 log.cpp:677] Writer started with ending position 0
I1106 20:57:00.262193 32110 leveldb.cpp:438] Reading position from leveldb took 73799ns
I1106 20:57:00.263969 32110 registrar.cpp:342] Successfully fetched the registry (0B) in 13.55008ms
I1106 20:57:00.264273 32110 registrar.cpp:441] Applied 1 operations in 47367ns; attempting to update the 'registry'
I1106 20:57:00.265254 32120 log.cpp:685] Attempting to append 174 bytes to the log
I1106 20:57:00.265537 32124 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1106 20:57:00.266872 32109 replica.cpp:540] Replica received write request for position 1 from (10525)@172.17.8.35:53065
I1106 20:57:00.267475 32109 leveldb.cpp:343] Persisting action (193 bytes) to leveldb took 551911ns
I1106 20:57:00.267518 32109 replica.cpp:715] Persisted action at 1
I1106 20:57:00.269489 32113 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1106 20:57:00.269968 32113 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 446804ns
I1106 20:57:00.270016 32113 replica.cpp:715] Persisted action at 1
I1106 20:57:00.270068 32113 replica.cpp:700] Replica learned APPEND action at position 1
I1106 20:57:00.271639 32114 registrar.cpp:486] Successfully updated the 'registry' in 7.271168ms
I1106 20:57:00.271803 32114 registrar.cpp:372] Successfully recovered registrar
I1106 20:57:00.271893 32111 log.cpp:704] Attempting to truncate the log to 1
I1106 20:57:00.272135 32110 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1106 20:57:00.272595 32119 master.cpp:1416] Recovered 0 slaves from the Registry (135B) ; allowing 10mins for slaves to re-register
I1106 20:57:00.273875 32109 replica.cpp:540] Replica received write request for position 2 from (10526)@172.17.8.35:53065
I1106 20:57:00.275068 32109 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 1.150176ms
I1106 20:57:00.275100 32109 replica.cpp:715] Persisted action at 2
I1106 20:57:00.276101 32116 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1106 20:57:00.277048 32116 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 917932ns
I1106 20:57:00.277114 32116 leveldb.cpp:401] Deleting ~1 keys from leveldb took 37441ns
I1106 20:57:00.277137 32116 replica.cpp:715] Persisted action at 2
I1106 20:57:00.277155 32116 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1106 20:57:00.286231 32124 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1106 20:57:00.286422 32124 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.8.35:59316
I1106 20:57:00.286775 32124 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1106 20:57:00.286845 32124 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1106 20:57:00.287211 32121 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1106 20:57:00.287953 32109 hierarchical.cpp:185] Added framework a2b25f93-bd54-452f-983c-485bc20edbe5-0000
I1106 20:57:00.288138 32112 master.hpp:1439] Sending heartbeat to a2b25f93-bd54-452f-983c-485bc20edbe5-0000
I1106 20:57:00.288017 32109 hierarchical.cpp:952] No resources available to allocate!
I1106 20:57:00.288301 32109 hierarchical.cpp:1045] No inverse offers to send out!
I1106 20:57:00.288333 32109 hierarchical.cpp:851] Performed allocation for 0 slaves in 355368ns
I1106 20:57:00.288941 32117 master.cpp:922] Master terminating
I1106 20:57:00.289197 32109 hierarchical.cpp:220] Removed framework a2b25f93-bd54-452f-983c-485bc20edbe5-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (62 ms)
[----------] 20 tests from ContentType/SchedulerHttpApiTest (1152 ms total)
[----------] Global test environment tear-down
[==========] 829 tests from 113 test cases ran. (329154 ms total)
[ PASSED ] 828 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RegistryClientTest.BadRequest
1 FAILED TEST
YOU HAVE 8 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-1446841665-21863
Untagged: mesos-1446841665-21863:latest
Deleted: addbdcd27478b5a6127cdb525aca10e46e797b334a0428eda6865905ccbe98c8
Deleted: 0ab4a9a51dd05381f94c9f36ff1628f478c6d15c554c482ec18fe04747fd9850
Deleted: f5d0655b484f61dde20a06a24d1f65400ac633a7227220c4c6af8a0cbfd3eec0
Deleted: 811009e28c099a03b333a36b9b8c5df74f94874662d24ae6c567f3961b1c4120
Deleted: 08bef528b4fcf401967151ee45d6fa77404b7d3063a981bf395239010c58a8fa
Deleted: 17d35c990da0c2cc32d7b4d40d737d8d75b0e4470a3ef99f3e449cad2b2fd2a5
Deleted: 1c024b01ce017559d8984a3b7d7de75b6de02241a3f36c3184b639dc0d9089d4
Deleted: b3b59677b6d1df38e0afd05705ac73240769703ea97baf647523361472e41dec
Deleted: cf13bdd6659b16922ab8f5f9e54f8727c108446cf7120d404b9458a6211a14e2
Deleted: f1fadf6014b9cfd49261ff8ad17ff7d5d0bafe1bfc9ccadd2f6bb9ec5703dfec
Deleted: 315545fb0c1c0db8bea78f4a095d417fc5c4fbe729190912459931a9aab41f52
Deleted: ce69de6cefee6d2f0337d596f1f40638fd86448897bfe935dabb501f02f17476
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent --enable-ssl,centos:7,docker||Hadoop #1190
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1190/changes>
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,centos:7,docker||Hadoop #1189
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1189/changes>
Changes:
[yujie.jay] TemporaryDirectoryTest Merge: Elevate `TemporaryDirectoryTest::sandbox`
[yujie.jay] TemporaryDirectoryTest Merge: Point tests to the Stout version of the
[yujie.jay] TemporaryDirectoryTest Merge: Remove non-Stout version of
------------------------------------------
[...truncated 137405 lines...]
I1107 02:07:01.582159 32117 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 02:07:01.582792 32117 replica.cpp:540] Replica received write request for position 1 from (10556)@172.17.11.150:48396
I1107 02:07:01.583132 32117 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 299804ns
I1107 02:07:01.583158 32117 replica.cpp:715] Persisted action at 1
I1107 02:07:01.583700 32114 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 02:07:01.584044 32114 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 316336ns
I1107 02:07:01.584067 32114 replica.cpp:715] Persisted action at 1
I1107 02:07:01.584082 32114 replica.cpp:700] Replica learned APPEND action at position 1
I1107 02:07:01.584844 32122 registrar.cpp:486] Successfully updated the 'registry' in 3.366912ms
I1107 02:07:01.584975 32122 registrar.cpp:372] Successfully recovered registrar
I1107 02:07:01.585083 32116 log.cpp:704] Attempting to truncate the log to 1
I1107 02:07:01.585325 32119 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1107 02:07:01.585413 32125 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 02:07:01.586171 32115 replica.cpp:540] Replica received write request for position 2 from (10557)@172.17.11.150:48396
I1107 02:07:01.586549 32115 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 345549ns
I1107 02:07:01.586573 32115 replica.cpp:715] Persisted action at 2
I1107 02:07:01.587200 32115 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 02:07:01.587546 32115 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 316231ns
I1107 02:07:01.587595 32115 leveldb.cpp:401] Deleting ~1 keys from leveldb took 24672ns
I1107 02:07:01.587618 32115 replica.cpp:715] Persisted action at 2
I1107 02:07:01.587635 32115 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 02:07:01.597060 32123 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 02:07:01.597244 32123 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.11.150:49399
I1107 02:07:01.597546 32123 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 02:07:01.597615 32123 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 02:07:01.597854 32123 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 02:07:01.598145 32112 hierarchical.cpp:185] Added framework 22a97a2c-e360-4c94-a2fa-cb747636466f-0000
I1107 02:07:01.598189 32112 hierarchical.cpp:952] No resources available to allocate!
I1107 02:07:01.598224 32112 hierarchical.cpp:1045] No inverse offers to send out!
I1107 02:07:01.598289 32123 master.hpp:1439] Sending heartbeat to 22a97a2c-e360-4c94-a2fa-cb747636466f-0000
I1107 02:07:01.598247 32112 hierarchical.cpp:851] Performed allocation for 0 slaves in 79222ns
I1107 02:07:01.599274 32092 master.cpp:922] Master terminating
I1107 02:07:01.599527 32112 hierarchical.cpp:220] Removed framework 22a97a2c-e360-4c94-a2fa-cb747636466f-0000
[ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (45 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
I1107 02:07:01.606117 32092 leveldb.cpp:176] Opened db in 2.24937ms
I1107 02:07:01.606941 32092 leveldb.cpp:183] Compacted db in 794301ns
I1107 02:07:01.606983 32092 leveldb.cpp:198] Created db iterator in 13658ns
I1107 02:07:01.607002 32092 leveldb.cpp:204] Seeked to beginning of db in 1774ns
I1107 02:07:01.607015 32092 leveldb.cpp:273] Iterated through 0 keys in the db in 284ns
I1107 02:07:01.607055 32092 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1107 02:07:01.607738 32115 recover.cpp:449] Starting replica recovery
I1107 02:07:01.608111 32115 recover.cpp:475] Replica is in EMPTY status
I1107 02:07:01.609539 32111 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10561)@172.17.11.150:48396
I1107 02:07:01.610039 32118 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1107 02:07:01.610551 32111 recover.cpp:566] Updating replica status to STARTING
I1107 02:07:01.611392 32118 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 550678ns
I1107 02:07:01.611424 32118 replica.cpp:323] Persisted replica status to STARTING
I1107 02:07:01.611724 32117 recover.cpp:475] Replica is in STARTING status
I1107 02:07:01.612066 32118 master.cpp:367] Master ee70946b-6e28-4646-b7c7-0df3f5a2f1c7 (5392456e4e79) started on 172.17.11.150:48396
I1107 02:07:01.612202 32118 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/gVmIBR/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/gVmIBR/master" --zk_session_timeout="10secs"
I1107 02:07:01.612576 32118 master.cpp:416] Master allowing unauthenticated frameworks to register
I1107 02:07:01.612593 32118 master.cpp:419] Master only allowing authenticated slaves to register
I1107 02:07:01.612607 32118 credentials.hpp:37] Loading credentials for authentication from '/tmp/gVmIBR/credentials'
I1107 02:07:01.612762 32111 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10562)@172.17.11.150:48396
I1107 02:07:01.612932 32118 master.cpp:458] Using default 'crammd5' authenticator
I1107 02:07:01.613093 32118 master.cpp:495] Authorization enabled
I1107 02:07:01.613206 32121 recover.cpp:195] Received a recover response from a replica in STARTING status
I1107 02:07:01.613359 32119 whitelist_watcher.cpp:79] No whitelist given
I1107 02:07:01.613385 32117 hierarchical.cpp:140] Initialized hierarchical allocator process
I1107 02:07:01.613677 32123 recover.cpp:566] Updating replica status to VOTING
I1107 02:07:01.614204 32126 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 275016ns
I1107 02:07:01.614231 32126 replica.cpp:323] Persisted replica status to VOTING
I1107 02:07:01.614382 32123 recover.cpp:580] Successfully joined the Paxos group
I1107 02:07:01.614586 32123 recover.cpp:464] Recover process terminated
I1107 02:07:01.615123 32118 master.cpp:1606] The newly elected leader is master@172.17.11.150:48396 with id ee70946b-6e28-4646-b7c7-0df3f5a2f1c7
I1107 02:07:01.615156 32118 master.cpp:1619] Elected as the leading master!
I1107 02:07:01.615180 32118 master.cpp:1379] Recovering from registrar
I1107 02:07:01.615356 32112 registrar.cpp:309] Recovering registrar
I1107 02:07:01.615774 32118 log.cpp:661] Attempting to start the writer
I1107 02:07:01.616796 32117 replica.cpp:496] Replica received implicit promise request from (10563)@172.17.11.150:48396 with proposal 1
I1107 02:07:01.617138 32117 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 313036ns
I1107 02:07:01.617161 32117 replica.cpp:345] Persisted promised to 1
I1107 02:07:01.617710 32120 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1107 02:07:01.618717 32119 replica.cpp:391] Replica received explicit promise request from (10564)@172.17.11.150:48396 for position 0 with proposal 2
I1107 02:07:01.619032 32119 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 280294ns
I1107 02:07:01.619055 32119 replica.cpp:715] Persisted action at 0
I1107 02:07:01.619943 32117 replica.cpp:540] Replica received write request for position 0 from (10565)@172.17.11.150:48396
I1107 02:07:01.620007 32117 leveldb.cpp:438] Reading position from leveldb took 27697ns
I1107 02:07:01.620331 32117 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 279875ns
I1107 02:07:01.620353 32117 replica.cpp:715] Persisted action at 0
I1107 02:07:01.620882 32120 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1107 02:07:01.621201 32120 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 289123ns
I1107 02:07:01.621227 32120 replica.cpp:715] Persisted action at 0
I1107 02:07:01.621250 32120 replica.cpp:700] Replica learned NOP action at position 0
I1107 02:07:01.621748 32123 log.cpp:677] Writer started with ending position 0
I1107 02:07:01.622661 32112 leveldb.cpp:438] Reading position from leveldb took 21721ns
I1107 02:07:01.623414 32112 registrar.cpp:342] Successfully fetched the registry (0B) in 8.012032ms
I1107 02:07:01.623512 32112 registrar.cpp:441] Applied 1 operations in 20329ns; attempting to update the 'registry'
I1107 02:07:01.624096 32123 log.cpp:685] Attempting to append 178 bytes to the log
I1107 02:07:01.624236 32115 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 02:07:01.624930 32125 replica.cpp:540] Replica received write request for position 1 from (10566)@172.17.11.150:48396
I1107 02:07:01.625247 32125 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 278119ns
I1107 02:07:01.625283 32125 replica.cpp:715] Persisted action at 1
I1107 02:07:01.625885 32123 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 02:07:01.626284 32123 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 368209ns
I1107 02:07:01.626307 32123 replica.cpp:715] Persisted action at 1
I1107 02:07:01.626322 32123 replica.cpp:700] Replica learned APPEND action at position 1
I1107 02:07:01.627094 32123 registrar.cpp:486] Successfully updated the 'registry' in 3.526912ms
I1107 02:07:01.627225 32123 registrar.cpp:372] Successfully recovered registrar
I1107 02:07:01.627302 32113 log.cpp:704] Attempting to truncate the log to 1
I1107 02:07:01.627415 32111 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 02:07:01.627648 32118 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1107 02:07:01.628204 32118 replica.cpp:540] Replica received write request for position 2 from (10567)@172.17.11.150:48396
I1107 02:07:01.628566 32118 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 326163ns
I1107 02:07:01.628590 32118 replica.cpp:715] Persisted action at 2
I1107 02:07:01.629107 32118 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 02:07:01.629245 32118 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 109951ns
I1107 02:07:01.629309 32118 leveldb.cpp:401] Deleting ~1 keys from leveldb took 29734ns
I1107 02:07:01.629335 32118 replica.cpp:715] Persisted action at 2
I1107 02:07:01.629361 32118 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 02:07:01.640015 32111 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 02:07:01.640211 32111 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.11.150:49400
I1107 02:07:01.640442 32111 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 02:07:01.640517 32111 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 02:07:01.640844 32111 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 02:07:01.641237 32114 hierarchical.cpp:185] Added framework ee70946b-6e28-4646-b7c7-0df3f5a2f1c7-0000
I1107 02:07:01.641324 32114 hierarchical.cpp:952] No resources available to allocate!
I1107 02:07:01.641461 32112 master.hpp:1439] Sending heartbeat to ee70946b-6e28-4646-b7c7-0df3f5a2f1c7-0000
I1107 02:07:01.641533 32114 hierarchical.cpp:1045] No inverse offers to send out!
I1107 02:07:01.641563 32114 hierarchical.cpp:851] Performed allocation for 0 slaves in 275298ns
I1107 02:07:01.643187 32123 master.cpp:922] Master terminating
I1107 02:07:01.643460 32113 hierarchical.cpp:220] Removed framework ee70946b-6e28-4646-b7c7-0df3f5a2f1c7-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (44 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
I1107 02:07:01.649695 32092 leveldb.cpp:176] Opened db in 1.842846ms
I1107 02:07:01.650320 32092 leveldb.cpp:183] Compacted db in 593539ns
I1107 02:07:01.650358 32092 leveldb.cpp:198] Created db iterator in 12498ns
I1107 02:07:01.650378 32092 leveldb.cpp:204] Seeked to beginning of db in 1664ns
I1107 02:07:01.650389 32092 leveldb.cpp:273] Iterated through 0 keys in the db in 199ns
I1107 02:07:01.650426 32092 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1107 02:07:01.650758 32122 recover.cpp:449] Starting replica recovery
I1107 02:07:01.651121 32111 recover.cpp:475] Replica is in EMPTY status
I1107 02:07:01.652320 32116 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10571)@172.17.11.150:48396
I1107 02:07:01.652583 32116 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1107 02:07:01.652966 32112 master.cpp:367] Master c0e821b3-2504-4653-baae-767323044085 (5392456e4e79) started on 172.17.11.150:48396
I1107 02:07:01.653040 32118 recover.cpp:566] Updating replica status to STARTING
I1107 02:07:01.653105 32112 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/AasxgD/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/AasxgD/master" --zk_session_timeout="10secs"
I1107 02:07:01.653484 32112 master.cpp:416] Master allowing unauthenticated frameworks to register
I1107 02:07:01.653501 32112 master.cpp:419] Master only allowing authenticated slaves to register
I1107 02:07:01.653511 32112 credentials.hpp:37] Loading credentials for authentication from '/tmp/AasxgD/credentials'
I1107 02:07:01.653569 32119 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 406084ns
I1107 02:07:01.653594 32119 replica.cpp:323] Persisted replica status to STARTING
I1107 02:07:01.653777 32115 recover.cpp:475] Replica is in STARTING status
I1107 02:07:01.653800 32112 master.cpp:458] Using default 'crammd5' authenticator
I1107 02:07:01.653951 32112 master.cpp:495] Authorization enabled
I1107 02:07:01.654157 32116 whitelist_watcher.cpp:79] No whitelist given
I1107 02:07:01.654228 32121 hierarchical.cpp:140] Initialized hierarchical allocator process
I1107 02:07:01.654961 32124 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10572)@172.17.11.150:48396
I1107 02:07:01.655967 32111 recover.cpp:195] Received a recover response from a replica in STARTING status
I1107 02:07:01.656518 32124 master.cpp:1606] The newly elected leader is master@172.17.11.150:48396 with id c0e821b3-2504-4653-baae-767323044085
I1107 02:07:01.656561 32124 master.cpp:1619] Elected as the leading master!
I1107 02:07:01.656595 32124 master.cpp:1379] Recovering from registrar
I1107 02:07:01.656664 32114 recover.cpp:566] Updating replica status to VOTING
I1107 02:07:01.656798 32112 registrar.cpp:309] Recovering registrar
I1107 02:07:01.657498 32125 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 545504ns
I1107 02:07:01.657531 32125 replica.cpp:323] Persisted replica status to VOTING
I1107 02:07:01.657646 32118 recover.cpp:580] Successfully joined the Paxos group
I1107 02:07:01.657892 32118 recover.cpp:464] Recover process terminated
I1107 02:07:01.658448 32117 log.cpp:661] Attempting to start the writer
I1107 02:07:01.659893 32126 replica.cpp:496] Replica received implicit promise request from (10573)@172.17.11.150:48396 with proposal 1
I1107 02:07:01.660500 32126 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 565948ns
I1107 02:07:01.660531 32126 replica.cpp:345] Persisted promised to 1
I1107 02:07:01.661321 32114 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1107 02:07:01.662683 32119 replica.cpp:391] Replica received explicit promise request from (10574)@172.17.11.150:48396 for position 0 with proposal 2
I1107 02:07:01.663045 32119 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 274667ns
I1107 02:07:01.663067 32119 replica.cpp:715] Persisted action at 0
I1107 02:07:01.664083 32125 replica.cpp:540] Replica received write request for position 0 from (10575)@172.17.11.150:48396
I1107 02:07:01.664144 32125 leveldb.cpp:438] Reading position from leveldb took 25829ns
I1107 02:07:01.664582 32125 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 393545ns
I1107 02:07:01.664609 32125 replica.cpp:715] Persisted action at 0
I1107 02:07:01.665124 32113 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1107 02:07:01.665443 32113 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 289698ns
I1107 02:07:01.665467 32113 replica.cpp:715] Persisted action at 0
I1107 02:07:01.665482 32113 replica.cpp:700] Replica learned NOP action at position 0
I1107 02:07:01.665973 32122 log.cpp:677] Writer started with ending position 0
I1107 02:07:01.666833 32113 leveldb.cpp:438] Reading position from leveldb took 21846ns
I1107 02:07:01.667626 32119 registrar.cpp:342] Successfully fetched the registry (0B) in 10.777088ms
I1107 02:07:01.667726 32119 registrar.cpp:441] Applied 1 operations in 22174ns; attempting to update the 'registry'
I1107 02:07:01.668341 32113 log.cpp:685] Attempting to append 178 bytes to the log
I1107 02:07:01.668453 32124 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 02:07:01.669224 32116 replica.cpp:540] Replica received write request for position 1 from (10576)@172.17.11.150:48396
I1107 02:07:01.669780 32116 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 485056ns
I1107 02:07:01.669818 32116 replica.cpp:715] Persisted action at 1
I1107 02:07:01.670647 32126 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 02:07:01.671074 32126 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 385427ns
I1107 02:07:01.671106 32126 replica.cpp:715] Persisted action at 1
I1107 02:07:01.671129 32126 replica.cpp:700] Replica learned APPEND action at position 1
I1107 02:07:01.672353 32125 registrar.cpp:486] Successfully updated the 'registry' in 4.48896ms
I1107 02:07:01.672575 32125 registrar.cpp:372] Successfully recovered registrar
I1107 02:07:01.672674 32111 log.cpp:704] Attempting to truncate the log to 1
I1107 02:07:01.673060 32123 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1107 02:07:01.672909 32119 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 02:07:01.674094 32117 replica.cpp:540] Replica received write request for position 2 from (10577)@172.17.11.150:48396
I1107 02:07:01.674520 32117 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 372632ns
I1107 02:07:01.674554 32117 replica.cpp:715] Persisted action at 2
I1107 02:07:01.675365 32124 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 02:07:01.675876 32124 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 467224ns
I1107 02:07:01.675976 32124 leveldb.cpp:401] Deleting ~1 keys from leveldb took 48168ns
I1107 02:07:01.676022 32124 replica.cpp:715] Persisted action at 2
I1107 02:07:01.676076 32124 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 02:07:01.685045 32115 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 02:07:01.685395 32115 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.11.150:49401
I1107 02:07:01.685868 32115 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 02:07:01.685950 32115 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 02:07:01.686702 32115 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 02:07:01.687374 32122 hierarchical.cpp:185] Added framework c0e821b3-2504-4653-baae-767323044085-0000
I1107 02:07:01.687423 32122 hierarchical.cpp:952] No resources available to allocate!
I1107 02:07:01.687458 32122 hierarchical.cpp:1045] No inverse offers to send out!
I1107 02:07:01.687484 32122 hierarchical.cpp:851] Performed allocation for 0 slaves in 84322ns
I1107 02:07:01.687615 32114 master.hpp:1439] Sending heartbeat to c0e821b3-2504-4653-baae-767323044085-0000
I1107 02:07:01.687885 32092 master.cpp:922] Master terminating
I1107 02:07:01.688063 32114 hierarchical.cpp:220] Removed framework c0e821b3-2504-4653-baae-767323044085-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (45 ms)
[----------] 20 tests from ContentType/SchedulerHttpApiTest (1008 ms total)
[----------] Global test environment tear-down
[==========] 831 tests from 113 test cases ran. (331972 ms total)
[ PASSED ] 830 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RegistryClientTest.BadRequest
1 FAILED TEST
YOU HAVE 8 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-1446860227-21020
Untagged: mesos-1446860227-21020:latest
Deleted: 3c43dea30b266089bd997cbca1a0ed7ff104034945bb3cad0758f3f36543e371
Deleted: 4ac4ac1c0eb7995ff2895beca86871d34ce5bdca019f32b5c39ff04da30439c9
Deleted: 3a755b1bcf333e7bd1e71687748e549738da7aa5bf960b2c02ce84a55205aa74
Deleted: 6b4f0c2880f6c3fba3fad756bf1d20b518e7c0ecb08d0a3ae6b882f567e46503
Deleted: 43a63fe7bc1560c56d8fe29898cd55358c6c7bf9210e8eec27bbe7ef8924178c
Deleted: bd0ecc3540695844379f6fadd1183f0fffc9d2476cee44e27bd9c99cf8e8a818
Deleted: caca14b086d84b34a34d13c28775277e03b135fc9e9942cbf4381ae2bfed7d9e
Deleted: 728e4a0e33c5975f6ae6f33dc0221610016a9761028c396ae8eaf6b7249be08a
Deleted: d3472fd34d7b5394fa886ea7ae18c0d2a33294a42c3e081f3e16578693f76d4a
Deleted: 169dbde98d8f9a5680ff5561bae3451fa812ac0b8db90be94f0bc173408a1b99
Deleted: e161548502939771656b9ecdde21738233de238e011afbb2b090100f1e2b31be
Deleted: c3cefbb2e765e3b0265b830b7d24fea2a91e7e9220afe16aa00291c6cd2aa9b9
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,centos:7,docker||Hadoop #1188
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1188/changes>
Changes:
[kapil] Include ContainerInfo in command ExecutorInfo
[tnachen] Fixed some style issues in docker containerizer and tests.
[tnachen] Added Docker Image type to Container Image for v1 API.
[tnachen] Fixed Rootfs in tests to handle symlink directories.
[yujie.jay] Fixed a few style issues in slave tests.
------------------------------------------
[...truncated 137499 lines...]
I1107 01:21:47.398954 32126 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 01:21:47.399894 32118 replica.cpp:540] Replica received write request for position 1 from (10539)@172.17.15.185:38584
I1107 01:21:47.400435 32118 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 498086ns
I1107 01:21:47.400465 32118 replica.cpp:715] Persisted action at 1
I1107 01:21:47.401234 32126 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 01:21:47.401650 32126 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 378129ns
I1107 01:21:47.401679 32126 replica.cpp:715] Persisted action at 1
I1107 01:21:47.401701 32126 replica.cpp:700] Replica learned APPEND action at position 1
I1107 01:21:47.402725 32123 registrar.cpp:486] Successfully updated the 'registry' in 4.62592ms
I1107 01:21:47.402889 32123 registrar.cpp:372] Successfully recovered registrar
I1107 01:21:47.402966 32118 log.cpp:704] Attempting to truncate the log to 1
I1107 01:21:47.403102 32120 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 01:21:47.403282 32127 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1107 01:21:47.404186 32114 replica.cpp:540] Replica received write request for position 2 from (10540)@172.17.15.185:38584
I1107 01:21:47.404640 32114 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 411436ns
I1107 01:21:47.404671 32114 replica.cpp:715] Persisted action at 2
I1107 01:21:47.405432 32123 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 01:21:47.406003 32123 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 450822ns
I1107 01:21:47.406075 32123 leveldb.cpp:401] Deleting ~1 keys from leveldb took 40024ns
I1107 01:21:47.406100 32123 replica.cpp:715] Persisted action at 2
I1107 01:21:47.406123 32123 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 01:21:47.415525 32117 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 01:21:47.415778 32117 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.15.185:57277
I1107 01:21:47.416223 32117 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 01:21:47.416295 32117 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 01:21:47.416548 32117 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 01:21:47.417006 32122 master.hpp:1439] Sending heartbeat to e5ece224-5f8f-4fd7-aa7d-b7ae0d6c66a4-0000
I1107 01:21:47.417007 32128 hierarchical.cpp:185] Added framework e5ece224-5f8f-4fd7-aa7d-b7ae0d6c66a4-0000
I1107 01:21:47.417104 32128 hierarchical.cpp:952] No resources available to allocate!
I1107 01:21:47.417139 32128 hierarchical.cpp:1045] No inverse offers to send out!
I1107 01:21:47.417160 32128 hierarchical.cpp:851] Performed allocation for 0 slaves in 90070ns
I1107 01:21:47.418766 32123 master.cpp:922] Master terminating
I1107 01:21:47.418978 32117 hierarchical.cpp:220] Removed framework e5ece224-5f8f-4fd7-aa7d-b7ae0d6c66a4-0000
[ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (51 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
I1107 01:21:47.428360 32094 leveldb.cpp:176] Opened db in 3.024954ms
I1107 01:21:47.429369 32094 leveldb.cpp:183] Compacted db in 965376ns
I1107 01:21:47.429422 32094 leveldb.cpp:198] Created db iterator in 16934ns
I1107 01:21:47.429443 32094 leveldb.cpp:204] Seeked to beginning of db in 1748ns
I1107 01:21:47.429455 32094 leveldb.cpp:273] Iterated through 0 keys in the db in 280ns
I1107 01:21:47.429492 32094 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1107 01:21:47.429986 32122 recover.cpp:449] Starting replica recovery
I1107 01:21:47.430328 32122 recover.cpp:475] Replica is in EMPTY status
I1107 01:21:47.431293 32121 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10544)@172.17.15.185:38584
I1107 01:21:47.431897 32118 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1107 01:21:47.432526 32121 recover.cpp:566] Updating replica status to STARTING
I1107 01:21:47.433303 32114 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 549225ns
I1107 01:21:47.433337 32114 replica.cpp:323] Persisted replica status to STARTING
I1107 01:21:47.433428 32127 master.cpp:367] Master 4d9926cf-b28a-4845-8e22-e1be5f727175 (4b19ea60c66f) started on 172.17.15.185:38584
I1107 01:21:47.433650 32115 recover.cpp:475] Replica is in STARTING status
I1107 01:21:47.433457 32127 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ZrjSuS/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/ZrjSuS/master" --zk_session_timeout="10secs"
I1107 01:21:47.433902 32127 master.cpp:416] Master allowing unauthenticated frameworks to register
I1107 01:21:47.433925 32127 master.cpp:419] Master only allowing authenticated slaves to register
I1107 01:21:47.433934 32127 credentials.hpp:37] Loading credentials for authentication from '/tmp/ZrjSuS/credentials'
I1107 01:21:47.434288 32127 master.cpp:458] Using default 'crammd5' authenticator
I1107 01:21:47.434417 32127 master.cpp:495] Authorization enabled
I1107 01:21:47.434612 32118 whitelist_watcher.cpp:79] No whitelist given
I1107 01:21:47.434799 32117 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10545)@172.17.15.185:38584
I1107 01:21:47.434934 32116 hierarchical.cpp:140] Initialized hierarchical allocator process
I1107 01:21:47.435319 32128 recover.cpp:195] Received a recover response from a replica in STARTING status
I1107 01:21:47.435971 32119 recover.cpp:566] Updating replica status to VOTING
I1107 01:21:47.436574 32126 master.cpp:1606] The newly elected leader is master@172.17.15.185:38584 with id 4d9926cf-b28a-4845-8e22-e1be5f727175
I1107 01:21:47.436609 32126 master.cpp:1619] Elected as the leading master!
I1107 01:21:47.436626 32126 master.cpp:1379] Recovering from registrar
I1107 01:21:47.436617 32115 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 362182ns
I1107 01:21:47.436653 32115 replica.cpp:323] Persisted replica status to VOTING
I1107 01:21:47.436779 32113 registrar.cpp:309] Recovering registrar
I1107 01:21:47.437144 32124 recover.cpp:580] Successfully joined the Paxos group
I1107 01:21:47.437919 32124 recover.cpp:464] Recover process terminated
I1107 01:21:47.438103 32121 log.cpp:661] Attempting to start the writer
I1107 01:21:47.439389 32116 replica.cpp:496] Replica received implicit promise request from (10546)@172.17.15.185:38584 with proposal 1
I1107 01:21:47.439893 32116 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 458997ns
I1107 01:21:47.439924 32116 replica.cpp:345] Persisted promised to 1
I1107 01:21:47.440640 32116 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1107 01:21:47.442059 32115 replica.cpp:391] Replica received explicit promise request from (10547)@172.17.15.185:38584 for position 0 with proposal 2
I1107 01:21:47.442517 32115 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 405133ns
I1107 01:21:47.442551 32115 replica.cpp:715] Persisted action at 0
I1107 01:21:47.443884 32119 replica.cpp:540] Replica received write request for position 0 from (10548)@172.17.15.185:38584
I1107 01:21:47.443967 32119 leveldb.cpp:438] Reading position from leveldb took 37241ns
I1107 01:21:47.444430 32119 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 402088ns
I1107 01:21:47.444460 32119 replica.cpp:715] Persisted action at 0
I1107 01:21:47.445225 32118 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1107 01:21:47.445744 32118 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 474244ns
I1107 01:21:47.445777 32118 replica.cpp:715] Persisted action at 0
I1107 01:21:47.445811 32118 replica.cpp:700] Replica learned NOP action at position 0
I1107 01:21:47.446617 32114 log.cpp:677] Writer started with ending position 0
I1107 01:21:47.447839 32120 leveldb.cpp:438] Reading position from leveldb took 34117ns
I1107 01:21:47.448998 32116 registrar.cpp:342] Successfully fetched the registry (0B) in 12.126976ms
I1107 01:21:47.449132 32116 registrar.cpp:441] Applied 1 operations in 28719ns; attempting to update the 'registry'
I1107 01:21:47.450006 32128 log.cpp:685] Attempting to append 178 bytes to the log
I1107 01:21:47.450142 32122 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 01:21:47.451299 32123 replica.cpp:540] Replica received write request for position 1 from (10549)@172.17.15.185:38584
I1107 01:21:47.451848 32123 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 499319ns
I1107 01:21:47.451879 32123 replica.cpp:715] Persisted action at 1
I1107 01:21:47.452639 32122 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 01:21:47.453164 32122 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 480644ns
I1107 01:21:47.453197 32122 replica.cpp:715] Persisted action at 1
I1107 01:21:47.453219 32122 replica.cpp:700] Replica learned APPEND action at position 1
I1107 01:21:47.454447 32119 registrar.cpp:486] Successfully updated the 'registry' in 5.228032ms
I1107 01:21:47.454644 32119 registrar.cpp:372] Successfully recovered registrar
I1107 01:21:47.454895 32126 log.cpp:704] Attempting to truncate the log to 1
I1107 01:21:47.455060 32116 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 01:21:47.455294 32127 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1107 01:21:47.456189 32115 replica.cpp:540] Replica received write request for position 2 from (10550)@172.17.15.185:38584
I1107 01:21:47.456751 32115 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 519225ns
I1107 01:21:47.456782 32115 replica.cpp:715] Persisted action at 2
I1107 01:21:47.457540 32115 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 01:21:47.458112 32115 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 527170ns
I1107 01:21:47.458200 32115 leveldb.cpp:401] Deleting ~1 keys from leveldb took 54811ns
I1107 01:21:47.458233 32115 replica.cpp:715] Persisted action at 2
I1107 01:21:47.458271 32115 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 01:21:47.467628 32123 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 01:21:47.467872 32123 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.15.185:57278
I1107 01:21:47.468070 32123 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 01:21:47.468143 32123 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 01:21:47.468523 32123 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 01:21:47.468958 32121 hierarchical.cpp:185] Added framework 4d9926cf-b28a-4845-8e22-e1be5f727175-0000
I1107 01:21:47.469020 32121 hierarchical.cpp:952] No resources available to allocate!
I1107 01:21:47.469069 32121 hierarchical.cpp:1045] No inverse offers to send out!
I1107 01:21:47.469099 32121 hierarchical.cpp:851] Performed allocation for 0 slaves in 108237ns
I1107 01:21:47.469213 32120 master.hpp:1439] Sending heartbeat to 4d9926cf-b28a-4845-8e22-e1be5f727175-0000
I1107 01:21:47.470270 32114 master.cpp:922] Master terminating
I1107 01:21:47.470422 32128 hierarchical.cpp:220] Removed framework 4d9926cf-b28a-4845-8e22-e1be5f727175-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (52 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
I1107 01:21:47.480271 32094 leveldb.cpp:176] Opened db in 3.108865ms
I1107 01:21:47.481515 32094 leveldb.cpp:183] Compacted db in 1.199912ms
I1107 01:21:47.481575 32094 leveldb.cpp:198] Created db iterator in 14857ns
I1107 01:21:47.481597 32094 leveldb.cpp:204] Seeked to beginning of db in 1760ns
I1107 01:21:47.481609 32094 leveldb.cpp:273] Iterated through 0 keys in the db in 162ns
I1107 01:21:47.481644 32094 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1107 01:21:47.482071 32127 recover.cpp:449] Starting replica recovery
I1107 01:21:47.482357 32126 recover.cpp:475] Replica is in EMPTY status
I1107 01:21:47.483551 32118 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10554)@172.17.15.185:38584
I1107 01:21:47.484030 32114 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1107 01:21:47.484555 32117 recover.cpp:566] Updating replica status to STARTING
I1107 01:21:47.485242 32122 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 498501ns
I1107 01:21:47.485273 32122 replica.cpp:323] Persisted replica status to STARTING
I1107 01:21:47.485510 32122 recover.cpp:475] Replica is in STARTING status
I1107 01:21:47.486019 32123 master.cpp:367] Master 770e247b-ba1b-4b8c-9e70-cb7d75a0988f (4b19ea60c66f) started on 172.17.15.185:38584
I1107 01:21:47.486053 32123 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/RYg4yT/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/RYg4yT/master" --zk_session_timeout="10secs"
I1107 01:21:47.486376 32123 master.cpp:416] Master allowing unauthenticated frameworks to register
I1107 01:21:47.486392 32123 master.cpp:419] Master only allowing authenticated slaves to register
I1107 01:21:47.486408 32123 credentials.hpp:37] Loading credentials for authentication from '/tmp/RYg4yT/credentials'
I1107 01:21:47.486701 32123 master.cpp:458] Using default 'crammd5' authenticator
I1107 01:21:47.486786 32124 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10555)@172.17.15.185:38584
I1107 01:21:47.486901 32123 master.cpp:495] Authorization enabled
I1107 01:21:47.487130 32119 whitelist_watcher.cpp:79] No whitelist given
I1107 01:21:47.487169 32120 hierarchical.cpp:140] Initialized hierarchical allocator process
I1107 01:21:47.487308 32124 recover.cpp:195] Received a recover response from a replica in STARTING status
I1107 01:21:47.487978 32120 recover.cpp:566] Updating replica status to VOTING
I1107 01:21:47.488569 32127 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 371334ns
I1107 01:21:47.488606 32127 replica.cpp:323] Persisted replica status to VOTING
I1107 01:21:47.488759 32118 recover.cpp:580] Successfully joined the Paxos group
I1107 01:21:47.489264 32118 recover.cpp:464] Recover process terminated
I1107 01:21:47.489401 32123 master.cpp:1606] The newly elected leader is master@172.17.15.185:38584 with id 770e247b-ba1b-4b8c-9e70-cb7d75a0988f
I1107 01:21:47.489542 32123 master.cpp:1619] Elected as the leading master!
I1107 01:21:47.489579 32123 master.cpp:1379] Recovering from registrar
I1107 01:21:47.489871 32116 registrar.cpp:309] Recovering registrar
I1107 01:21:47.490561 32122 log.cpp:661] Attempting to start the writer
I1107 01:21:47.491992 32119 replica.cpp:496] Replica received implicit promise request from (10556)@172.17.15.185:38584 with proposal 1
I1107 01:21:47.492472 32119 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 435010ns
I1107 01:21:47.492502 32119 replica.cpp:345] Persisted promised to 1
I1107 01:21:47.493165 32116 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1107 01:21:47.494501 32125 replica.cpp:391] Replica received explicit promise request from (10557)@172.17.15.185:38584 for position 0 with proposal 2
I1107 01:21:47.494938 32125 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 382868ns
I1107 01:21:47.494978 32125 replica.cpp:715] Persisted action at 0
I1107 01:21:47.496152 32116 replica.cpp:540] Replica received write request for position 0 from (10558)@172.17.15.185:38584
I1107 01:21:47.496224 32116 leveldb.cpp:438] Reading position from leveldb took 28844ns
I1107 01:21:47.496597 32116 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 322134ns
I1107 01:21:47.496626 32116 replica.cpp:715] Persisted action at 0
I1107 01:21:47.497392 32128 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1107 01:21:47.497803 32128 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 357662ns
I1107 01:21:47.497851 32128 replica.cpp:715] Persisted action at 0
I1107 01:21:47.497872 32128 replica.cpp:700] Replica learned NOP action at position 0
I1107 01:21:47.498492 32124 log.cpp:677] Writer started with ending position 0
I1107 01:21:47.499578 32121 leveldb.cpp:438] Reading position from leveldb took 33991ns
I1107 01:21:47.500550 32124 registrar.cpp:342] Successfully fetched the registry (0B) in 10.621952ms
I1107 01:21:47.500679 32124 registrar.cpp:441] Applied 1 operations in 27414ns; attempting to update the 'registry'
I1107 01:21:47.501494 32119 log.cpp:685] Attempting to append 178 bytes to the log
I1107 01:21:47.501627 32114 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1107 01:21:47.502408 32120 replica.cpp:540] Replica received write request for position 1 from (10559)@172.17.15.185:38584
I1107 01:21:47.502907 32120 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 451205ns
I1107 01:21:47.502940 32120 replica.cpp:715] Persisted action at 1
I1107 01:21:47.503715 32119 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1107 01:21:47.504173 32119 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 421970ns
I1107 01:21:47.504205 32119 replica.cpp:715] Persisted action at 1
I1107 01:21:47.504233 32119 replica.cpp:700] Replica learned APPEND action at position 1
I1107 01:21:47.505280 32122 registrar.cpp:486] Successfully updated the 'registry' in 4.530176ms
I1107 01:21:47.505470 32122 registrar.cpp:372] Successfully recovered registrar
I1107 01:21:47.505533 32123 log.cpp:704] Attempting to truncate the log to 1
I1107 01:21:47.505973 32124 master.cpp:1416] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1107 01:21:47.506000 32127 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1107 01:21:47.506943 32113 replica.cpp:540] Replica received write request for position 2 from (10560)@172.17.15.185:38584
I1107 01:21:47.507439 32113 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 450090ns
I1107 01:21:47.507472 32113 replica.cpp:715] Persisted action at 2
I1107 01:21:47.508363 32116 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1107 01:21:47.508797 32116 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 392571ns
I1107 01:21:47.508884 32116 leveldb.cpp:401] Deleting ~1 keys from leveldb took 41384ns
I1107 01:21:47.508913 32116 replica.cpp:715] Persisted action at 2
I1107 01:21:47.508935 32116 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1107 01:21:47.518136 32119 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1107 01:21:47.518385 32119 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.15.185:57279
I1107 01:21:47.518807 32119 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1107 01:21:47.518939 32119 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1107 01:21:47.519253 32119 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1107 01:21:47.519618 32124 hierarchical.cpp:185] Added framework 770e247b-ba1b-4b8c-9e70-cb7d75a0988f-0000
I1107 01:21:47.519673 32124 hierarchical.cpp:952] No resources available to allocate!
I1107 01:21:47.519748 32124 hierarchical.cpp:1045] No inverse offers to send out!
I1107 01:21:47.519780 32119 master.hpp:1439] Sending heartbeat to 770e247b-ba1b-4b8c-9e70-cb7d75a0988f-0000
I1107 01:21:47.520037 32124 hierarchical.cpp:851] Performed allocation for 0 slaves in 387043ns
I1107 01:21:47.521160 32118 master.cpp:922] Master terminating
I1107 01:21:47.521330 32113 hierarchical.cpp:220] Removed framework 770e247b-ba1b-4b8c-9e70-cb7d75a0988f-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (50 ms)
[----------] 20 tests from ContentType/SchedulerHttpApiTest (1099 ms total)
[----------] Global test environment tear-down
[==========] 831 tests from 113 test cases ran. (343748 ms total)
[ PASSED ] 830 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RegistryClientTest.BadRequest
1 FAILED TEST
YOU HAVE 8 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-1446857631-12247
Untagged: mesos-1446857631-12247:latest
Deleted: 9377ef9402c422d116e6fb998cccccaa7b64b92734b65fa4e203a910834a1f03
Deleted: 43a09b560fcb8265900b2802cd0c8a8532adf51e6fd085ddf6f75271749ef26e
Deleted: b626f5bd08870cacc5d6054ef20a637a5f06f722776b440c0b840fec90c36190
Deleted: 15878da2ba2e8bb8caa93a0adec85164f6d64314158631859a77df8a4640b857
Deleted: fefb555ece97d17fd05afb93ba4a7479f183c33f2262932ecee979820986cf69
Deleted: 4889c9d3e78b3156adf4050abaf90c294c73ed64076ae32264e9e02144a07f80
Deleted: bd8953db4d88db3fcb9f218c60d59c2ccd466ba55475ad069486da5d2651f194
Deleted: b58b29927b04b7d4094cd99d866353586f46ec6ad831c9fe77bb6e3b5f76bfb7
Deleted: 66d3be652b2b19000ec117e0bb6d86156ca659038a926ea2dd5cafa535f2a064
Deleted: 2a8dbcb2d1d1a513c7ae8a3bea58c67820e5788e48d16e79dadeeaf6b2962ca7
Deleted: 170e4b7b4fc1f9455aa93c20562a0f9480b28281de56dd96c59d3e4eb28cd93b
Deleted: d7c054ae0f14bfdfb1de4bc43d788db49efafa4be7289c4145f638028d18ecd6
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,centos:7,docker||Hadoop #1187
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1187/changes>
Changes:
[tnachen] Fixed typo in comments from slave.
------------------------------------------
[...truncated 137396 lines...]
I1106 23:53:04.436830 32124 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1106 23:53:04.437628 32119 replica.cpp:540] Replica received write request for position 1 from (10509)@172.17.11.97:48441
I1106 23:53:04.438195 32119 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 507122ns
I1106 23:53:04.438231 32119 replica.cpp:715] Persisted action at 1
I1106 23:53:04.438984 32124 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1106 23:53:04.439450 32124 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 423773ns
I1106 23:53:04.439482 32124 replica.cpp:715] Persisted action at 1
I1106 23:53:04.439504 32124 replica.cpp:700] Replica learned APPEND action at position 1
I1106 23:53:04.440624 32122 registrar.cpp:486] Successfully updated the 'registry' in 5.030912ms
I1106 23:53:04.440781 32122 registrar.cpp:372] Successfully recovered registrar
I1106 23:53:04.440944 32126 log.cpp:704] Attempting to truncate the log to 1
I1106 23:53:04.441146 32127 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1106 23:53:04.441335 32125 master.cpp:1416] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1106 23:53:04.442291 32133 replica.cpp:540] Replica received write request for position 2 from (10510)@172.17.11.97:48441
I1106 23:53:04.442669 32133 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 345486ns
I1106 23:53:04.442697 32133 replica.cpp:715] Persisted action at 2
I1106 23:53:04.443331 32125 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1106 23:53:04.443750 32125 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 393156ns
I1106 23:53:04.443794 32125 leveldb.cpp:401] Deleting ~1 keys from leveldb took 23399ns
I1106 23:53:04.443809 32125 replica.cpp:715] Persisted action at 2
I1106 23:53:04.443825 32125 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1106 23:53:04.453501 32120 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1106 23:53:04.453704 32120 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.11.97:60424
I1106 23:53:04.453995 32120 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1106 23:53:04.454049 32120 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1106 23:53:04.454380 32127 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1106 23:53:04.454844 32125 hierarchical.cpp:185] Added framework 2bb6e3bc-327a-4541-91bf-a5f63bb5a608-0000
I1106 23:53:04.454906 32125 hierarchical.cpp:952] No resources available to allocate!
I1106 23:53:04.454957 32129 master.hpp:1439] Sending heartbeat to 2bb6e3bc-327a-4541-91bf-a5f63bb5a608-0000
I1106 23:53:04.455003 32125 hierarchical.cpp:1045] No inverse offers to send out!
I1106 23:53:04.455039 32125 hierarchical.cpp:851] Performed allocation for 0 slaves in 163162ns
I1106 23:53:04.455986 32123 master.cpp:922] Master terminating
I1106 23:53:04.456164 32133 hierarchical.cpp:220] Removed framework 2bb6e3bc-327a-4541-91bf-a5f63bb5a608-0000
[ OK ] ContentType/SchedulerHttpApiTest.NoAcceptHeader/1 (48 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/0
I1106 23:53:04.463845 32100 leveldb.cpp:176] Opened db in 2.551216ms
I1106 23:53:04.465000 32100 leveldb.cpp:183] Compacted db in 1.121694ms
I1106 23:53:04.465061 32100 leveldb.cpp:198] Created db iterator in 16939ns
I1106 23:53:04.465082 32100 leveldb.cpp:204] Seeked to beginning of db in 2030ns
I1106 23:53:04.465095 32100 leveldb.cpp:273] Iterated through 0 keys in the db in 302ns
I1106 23:53:04.465131 32100 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1106 23:53:04.465615 32134 recover.cpp:449] Starting replica recovery
I1106 23:53:04.465998 32134 recover.cpp:475] Replica is in EMPTY status
I1106 23:53:04.467342 32125 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10514)@172.17.11.97:48441
I1106 23:53:04.467942 32123 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1106 23:53:04.468564 32125 recover.cpp:566] Updating replica status to STARTING
I1106 23:53:04.469629 32123 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 913709ns
I1106 23:53:04.469663 32123 replica.cpp:323] Persisted replica status to STARTING
I1106 23:53:04.469683 32125 master.cpp:367] Master 06818d7e-98e2-4290-932b-116ce440171a (9ebe7196437f) started on 172.17.11.97:48441
I1106 23:53:04.469995 32120 recover.cpp:475] Replica is in STARTING status
I1106 23:53:04.469709 32125 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/GMCaGM/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/GMCaGM/master" --zk_session_timeout="10secs"
I1106 23:53:04.470054 32125 master.cpp:416] Master allowing unauthenticated frameworks to register
I1106 23:53:04.470069 32125 master.cpp:419] Master only allowing authenticated slaves to register
I1106 23:53:04.470080 32125 credentials.hpp:37] Loading credentials for authentication from '/tmp/GMCaGM/credentials'
I1106 23:53:04.470407 32125 master.cpp:458] Using default 'crammd5' authenticator
I1106 23:53:04.470530 32125 master.cpp:495] Authorization enabled
I1106 23:53:04.470762 32124 whitelist_watcher.cpp:79] No whitelist given
I1106 23:53:04.470878 32132 hierarchical.cpp:140] Initialized hierarchical allocator process
I1106 23:53:04.471160 32119 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10515)@172.17.11.97:48441
I1106 23:53:04.471561 32120 recover.cpp:195] Received a recover response from a replica in STARTING status
I1106 23:53:04.472030 32132 recover.cpp:566] Updating replica status to VOTING
I1106 23:53:04.472851 32121 master.cpp:1606] The newly elected leader is master@172.17.11.97:48441 with id 06818d7e-98e2-4290-932b-116ce440171a
I1106 23:53:04.472858 32123 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 603578ns
I1106 23:53:04.472884 32121 master.cpp:1619] Elected as the leading master!
I1106 23:53:04.472884 32123 replica.cpp:323] Persisted replica status to VOTING
I1106 23:53:04.472909 32121 master.cpp:1379] Recovering from registrar
I1106 23:53:04.473033 32130 recover.cpp:580] Successfully joined the Paxos group
I1106 23:53:04.473340 32123 registrar.cpp:309] Recovering registrar
I1106 23:53:04.473429 32130 recover.cpp:464] Recover process terminated
I1106 23:53:04.473942 32119 log.cpp:661] Attempting to start the writer
I1106 23:53:04.475023 32120 replica.cpp:496] Replica received implicit promise request from (10516)@172.17.11.97:48441 with proposal 1
I1106 23:53:04.475467 32120 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 412024ns
I1106 23:53:04.475489 32120 replica.cpp:345] Persisted promised to 1
I1106 23:53:04.476043 32123 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1106 23:53:04.477183 32125 replica.cpp:391] Replica received explicit promise request from (10517)@172.17.11.97:48441 for position 0 with proposal 2
I1106 23:53:04.477622 32125 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 402600ns
I1106 23:53:04.477644 32125 replica.cpp:715] Persisted action at 0
I1106 23:53:04.478601 32125 replica.cpp:540] Replica received write request for position 0 from (10518)@172.17.11.97:48441
I1106 23:53:04.478657 32125 leveldb.cpp:438] Reading position from leveldb took 26880ns
I1106 23:53:04.479045 32125 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 330028ns
I1106 23:53:04.479068 32125 replica.cpp:715] Persisted action at 0
I1106 23:53:04.479579 32134 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1106 23:53:04.480041 32134 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 433181ns
I1106 23:53:04.480064 32134 replica.cpp:715] Persisted action at 0
I1106 23:53:04.480079 32134 replica.cpp:700] Replica learned NOP action at position 0
I1106 23:53:04.480675 32120 log.cpp:677] Writer started with ending position 0
I1106 23:53:04.481847 32126 leveldb.cpp:438] Reading position from leveldb took 50200ns
I1106 23:53:04.483017 32129 registrar.cpp:342] Successfully fetched the registry (0B) in 9.626112ms
I1106 23:53:04.483152 32129 registrar.cpp:441] Applied 1 operations in 33501ns; attempting to update the 'registry'
I1106 23:53:04.484169 32133 log.cpp:685] Attempting to append 176 bytes to the log
I1106 23:53:04.484371 32119 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1106 23:53:04.485270 32121 replica.cpp:540] Replica received write request for position 1 from (10519)@172.17.11.97:48441
I1106 23:53:04.485731 32121 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 401438ns
I1106 23:53:04.485774 32121 replica.cpp:715] Persisted action at 1
I1106 23:53:04.486697 32126 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1106 23:53:04.487223 32126 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 488686ns
I1106 23:53:04.487280 32126 replica.cpp:715] Persisted action at 1
I1106 23:53:04.487371 32126 replica.cpp:700] Replica learned APPEND action at position 1
I1106 23:53:04.488548 32131 registrar.cpp:486] Successfully updated the 'registry' in 5312us
I1106 23:53:04.488751 32131 registrar.cpp:372] Successfully recovered registrar
I1106 23:53:04.488837 32126 log.cpp:704] Attempting to truncate the log to 1
I1106 23:53:04.489053 32134 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1106 23:53:04.489245 32129 master.cpp:1416] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1106 23:53:04.490016 32123 replica.cpp:540] Replica received write request for position 2 from (10520)@172.17.11.97:48441
I1106 23:53:04.490422 32123 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 372678ns
I1106 23:53:04.490444 32123 replica.cpp:715] Persisted action at 2
I1106 23:53:04.490984 32127 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1106 23:53:04.491371 32127 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 354924ns
I1106 23:53:04.491423 32127 leveldb.cpp:401] Deleting ~1 keys from leveldb took 28435ns
I1106 23:53:04.491442 32127 replica.cpp:715] Persisted action at 2
I1106 23:53:04.491459 32127 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1106 23:53:04.501749 32133 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1106 23:53:04.501911 32133 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.11.97:60425
I1106 23:53:04.502113 32133 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1106 23:53:04.502174 32133 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1106 23:53:04.502496 32129 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1106 23:53:04.502918 32132 hierarchical.cpp:185] Added framework 06818d7e-98e2-4290-932b-116ce440171a-0000
I1106 23:53:04.502975 32132 hierarchical.cpp:952] No resources available to allocate!
I1106 23:53:04.503010 32132 hierarchical.cpp:1045] No inverse offers to send out!
I1106 23:53:04.503031 32132 hierarchical.cpp:851] Performed allocation for 0 slaves in 85827ns
I1106 23:53:04.503089 32129 master.hpp:1439] Sending heartbeat to 06818d7e-98e2-4290-932b-116ce440171a-0000
I1106 23:53:04.504021 32134 master.cpp:922] Master terminating
I1106 23:53:04.504215 32124 hierarchical.cpp:220] Removed framework 06818d7e-98e2-4290-932b-116ce440171a-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/0 (48 ms)
[ RUN ] ContentType/SchedulerHttpApiTest.DefaultAccept/1
I1106 23:53:04.513952 32100 leveldb.cpp:176] Opened db in 3.119785ms
I1106 23:53:04.514987 32100 leveldb.cpp:183] Compacted db in 996370ns
I1106 23:53:04.515040 32100 leveldb.cpp:198] Created db iterator in 20332ns
I1106 23:53:04.515063 32100 leveldb.cpp:204] Seeked to beginning of db in 2128ns
I1106 23:53:04.515074 32100 leveldb.cpp:273] Iterated through 0 keys in the db in 385ns
I1106 23:53:04.515115 32100 replica.cpp:780] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1106 23:53:04.515604 32120 recover.cpp:449] Starting replica recovery
I1106 23:53:04.515961 32120 recover.cpp:475] Replica is in EMPTY status
I1106 23:53:04.517086 32133 replica.cpp:676] Replica in EMPTY status received a broadcasted recover request from (10524)@172.17.11.97:48441
I1106 23:53:04.517580 32128 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1106 23:53:04.518126 32123 recover.cpp:566] Updating replica status to STARTING
I1106 23:53:04.518918 32127 master.cpp:367] Master a9986c59-0ec8-433a-b6f8-fe55bd567d9e (9ebe7196437f) started on 172.17.11.97:48441
I1106 23:53:04.518966 32133 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 583402ns
I1106 23:53:04.518995 32133 replica.cpp:323] Persisted replica status to STARTING
I1106 23:53:04.518944 32127 master.cpp:369] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/EbA0EW/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/EbA0EW/master" --zk_session_timeout="10secs"
I1106 23:53:04.519402 32127 master.cpp:416] Master allowing unauthenticated frameworks to register
I1106 23:53:04.519418 32127 master.cpp:419] Master only allowing authenticated slaves to register
I1106 23:53:04.519426 32127 credentials.hpp:37] Loading credentials for authentication from '/tmp/EbA0EW/credentials'
I1106 23:53:04.519428 32119 recover.cpp:475] Replica is in STARTING status
I1106 23:53:04.519714 32127 master.cpp:458] Using default 'crammd5' authenticator
I1106 23:53:04.519985 32127 master.cpp:495] Authorization enabled
I1106 23:53:04.520244 32120 whitelist_watcher.cpp:79] No whitelist given
I1106 23:53:04.520544 32131 hierarchical.cpp:140] Initialized hierarchical allocator process
I1106 23:53:04.520884 32126 replica.cpp:676] Replica in STARTING status received a broadcasted recover request from (10525)@172.17.11.97:48441
I1106 23:53:04.521230 32130 recover.cpp:195] Received a recover response from a replica in STARTING status
I1106 23:53:04.521980 32128 recover.cpp:566] Updating replica status to VOTING
I1106 23:53:04.522707 32120 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 482298ns
I1106 23:53:04.522740 32120 replica.cpp:323] Persisted replica status to VOTING
I1106 23:53:04.522846 32119 master.cpp:1606] The newly elected leader is master@172.17.11.97:48441 with id a9986c59-0ec8-433a-b6f8-fe55bd567d9e
I1106 23:53:04.522861 32132 recover.cpp:580] Successfully joined the Paxos group
I1106 23:53:04.522884 32119 master.cpp:1619] Elected as the leading master!
I1106 23:53:04.522909 32119 master.cpp:1379] Recovering from registrar
I1106 23:53:04.523051 32120 registrar.cpp:309] Recovering registrar
I1106 23:53:04.523326 32132 recover.cpp:464] Recover process terminated
I1106 23:53:04.523999 32127 log.cpp:661] Attempting to start the writer
I1106 23:53:04.525285 32120 replica.cpp:496] Replica received implicit promise request from (10526)@172.17.11.97:48441 with proposal 1
I1106 23:53:04.525805 32120 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 485956ns
I1106 23:53:04.525835 32120 replica.cpp:345] Persisted promised to 1
I1106 23:53:04.526625 32122 coordinator.cpp:240] Coordinator attempting to fill missing positions
I1106 23:53:04.527940 32122 replica.cpp:391] Replica received explicit promise request from (10527)@172.17.11.97:48441 for position 0 with proposal 2
I1106 23:53:04.528373 32122 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 390409ns
I1106 23:53:04.528399 32122 replica.cpp:715] Persisted action at 0
I1106 23:53:04.529675 32131 replica.cpp:540] Replica received write request for position 0 from (10528)@172.17.11.97:48441
I1106 23:53:04.529737 32131 leveldb.cpp:438] Reading position from leveldb took 28413ns
I1106 23:53:04.530309 32131 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 528885ns
I1106 23:53:04.530341 32131 replica.cpp:715] Persisted action at 0
I1106 23:53:04.531030 32131 replica.cpp:694] Replica received learned notice for position 0 from @0.0.0.0:0
I1106 23:53:04.531572 32131 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 503876ns
I1106 23:53:04.531601 32131 replica.cpp:715] Persisted action at 0
I1106 23:53:04.531622 32131 replica.cpp:700] Replica learned NOP action at position 0
I1106 23:53:04.532286 32123 log.cpp:677] Writer started with ending position 0
I1106 23:53:04.533577 32125 leveldb.cpp:438] Reading position from leveldb took 34571ns
I1106 23:53:04.534616 32130 registrar.cpp:342] Successfully fetched the registry (0B) in 11.512832ms
I1106 23:53:04.534821 32130 registrar.cpp:441] Applied 1 operations in 72080ns; attempting to update the 'registry'
I1106 23:53:04.535694 32125 log.cpp:685] Attempting to append 176 bytes to the log
I1106 23:53:04.535826 32123 coordinator.cpp:350] Coordinator attempting to write APPEND action at position 1
I1106 23:53:04.536610 32126 replica.cpp:540] Replica received write request for position 1 from (10529)@172.17.11.97:48441
I1106 23:53:04.537026 32126 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 374103ns
I1106 23:53:04.537050 32126 replica.cpp:715] Persisted action at 1
I1106 23:53:04.537639 32131 replica.cpp:694] Replica received learned notice for position 1 from @0.0.0.0:0
I1106 23:53:04.537992 32131 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 321798ns
I1106 23:53:04.538014 32131 replica.cpp:715] Persisted action at 1
I1106 23:53:04.538030 32131 replica.cpp:700] Replica learned APPEND action at position 1
I1106 23:53:04.538889 32129 registrar.cpp:486] Successfully updated the 'registry' in 3.98592ms
I1106 23:53:04.539026 32129 registrar.cpp:372] Successfully recovered registrar
I1106 23:53:04.539093 32131 log.cpp:704] Attempting to truncate the log to 1
I1106 23:53:04.539369 32122 coordinator.cpp:350] Coordinator attempting to write TRUNCATE action at position 2
I1106 23:53:04.539422 32133 master.cpp:1416] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1106 23:53:04.540206 32122 replica.cpp:540] Replica received write request for position 2 from (10530)@172.17.11.97:48441
I1106 23:53:04.540719 32122 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 476729ns
I1106 23:53:04.540741 32122 replica.cpp:715] Persisted action at 2
I1106 23:53:04.541373 32131 replica.cpp:694] Replica received learned notice for position 2 from @0.0.0.0:0
I1106 23:53:04.541805 32131 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 400833ns
I1106 23:53:04.541851 32131 leveldb.cpp:401] Deleting ~1 keys from leveldb took 24307ns
I1106 23:53:04.541872 32131 replica.cpp:715] Persisted action at 2
I1106 23:53:04.541896 32131 replica.cpp:700] Replica learned TRUNCATE action at position 2
I1106 23:53:04.551964 32120 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1106 23:53:04.552183 32120 http.cpp:340] HTTP POST for /master/api/v1/scheduler from 172.17.11.97:60426
I1106 23:53:04.552539 32120 master.cpp:1868] Received subscription request for HTTP framework 'default'
I1106 23:53:04.552589 32120 master.cpp:1645] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1106 23:53:04.552868 32120 master.cpp:1960] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1106 23:53:04.553223 32133 hierarchical.cpp:185] Added framework a9986c59-0ec8-433a-b6f8-fe55bd567d9e-0000
I1106 23:53:04.553297 32133 hierarchical.cpp:952] No resources available to allocate!
I1106 23:53:04.553400 32134 master.hpp:1439] Sending heartbeat to a9986c59-0ec8-433a-b6f8-fe55bd567d9e-0000
I1106 23:53:04.553496 32133 hierarchical.cpp:1045] No inverse offers to send out!
I1106 23:53:04.553526 32133 hierarchical.cpp:851] Performed allocation for 0 slaves in 278151ns
I1106 23:53:04.554574 32100 master.cpp:922] Master terminating
I1106 23:53:04.554814 32129 hierarchical.cpp:220] Removed framework a9986c59-0ec8-433a-b6f8-fe55bd567d9e-0000
[ OK ] ContentType/SchedulerHttpApiTest.DefaultAccept/1 (50 ms)
[----------] 20 tests from ContentType/SchedulerHttpApiTest (1045 ms total)
[----------] Global test environment tear-down
[==========] 829 tests from 113 test cases ran. (338832 ms total)
[ PASSED ] 828 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RegistryClientTest.BadRequest
1 FAILED TEST
YOU HAVE 8 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-1446851966-25162
Untagged: mesos-1446851966-25162:latest
Deleted: 9ef25134a401664067fb82463d36421e7ac267c95051f21481c7fd9817240d8c
Deleted: e41f207dff64247cb97ab0ff2272037812c9507f864d05fa7b43b06f6cfa7fbf
Deleted: d8ae6d6c76cc6fc4efe02577228e2aff157784fd47525b2b20e1dae2f5bf5ed8
Deleted: 82a639f39fb62b9c4480da5cfa52b09ecbd18a5b2c47e112be6d4a187d1248d2
Deleted: 77a9601a3ac796091b54e7b2eabc7b674fb7929ad7b985db1d3260ba22020efc
Deleted: a9fa4fe01fe3bcdb40d54383c2f50a751dbe65ba133947c58f2edbc459768fb3
Deleted: f234a6aecf6b6ab7e975d88e267f20973af812b3b99f8f6551d55c6b7971f381
Deleted: 797541601d8cd6107be33ec4ec152daf8698500e27ff64a865dccf77e3b5feb1
Deleted: e40e3de0f7af5ca0c0251135f872d333a6e6bb451f2d401d93fc3a51ea428b47
Deleted: 87e2394c4a8b4a13de784664131c7ebe853523f339c206c21cfd94cf043b2ac5
Deleted: 63b0b35454b7b1c716a73ca7903ec15d44e08881a86a8284a067979daf8ecb07
Deleted: 30b19916b6a815ee9cc87de6d8424e75181490df2bcbfa9186f42fbc3834df4d
Build step 'Execute shell' marked build as failure