You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/01/03 03:32:02 UTC
Build failed in Jenkins: mesos-reviewbot #10527
See <https://builds.apache.org/job/mesos-reviewbot/10527/>
------------------------------------------
[...truncated 165434 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (682 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0103 02:31:50.927086 31020 leveldb.cpp:174] Opened db in 123.679641ms
I0103 02:31:50.975011 31020 leveldb.cpp:181] Compacted db in 47.873716ms
I0103 02:31:50.975077 31020 leveldb.cpp:196] Created db iterator in 24089ns
I0103 02:31:50.975096 31020 leveldb.cpp:202] Seeked to beginning of db in 2105ns
I0103 02:31:50.975107 31020 leveldb.cpp:271] Iterated through 0 keys in the db in 428ns
I0103 02:31:50.975155 31020 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 02:31:50.975790 31042 recover.cpp:447] Starting replica recovery
I0103 02:31:50.976102 31053 recover.cpp:473] Replica is in EMPTY status
I0103 02:31:50.977138 31041 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12833)@172.17.0.5:37086
I0103 02:31:50.977511 31045 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 02:31:50.977938 31049 recover.cpp:564] Updating replica status to STARTING
I0103 02:31:50.978909 31046 master.cpp:365] Master e359101e-01ea-4f73-9184-4086d5e18dd6 (340fc150d555) started on 172.17.0.5:37086
I0103 02:31:50.978935 31046 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/UCJCSn/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/UCJCSn/master" --zk_session_timeout="10secs"
I0103 02:31:50.979249 31046 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 02:31:50.979259 31046 master.cpp:417] Master only allowing authenticated slaves to register
I0103 02:31:50.979265 31046 credentials.hpp:35] Loading credentials for authentication from '/tmp/UCJCSn/credentials'
I0103 02:31:50.979506 31046 master.cpp:456] Using default 'crammd5' authenticator
I0103 02:31:50.979641 31046 master.cpp:493] Authorization enabled
I0103 02:31:50.979800 31054 whitelist_watcher.cpp:77] No whitelist given
I0103 02:31:50.979816 31050 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 02:31:50.981411 31043 master.cpp:1629] The newly elected leader is master@172.17.0.5:37086 with id e359101e-01ea-4f73-9184-4086d5e18dd6
I0103 02:31:50.981447 31043 master.cpp:1642] Elected as the leading master!
I0103 02:31:50.981473 31043 master.cpp:1387] Recovering from registrar
I0103 02:31:50.981683 31047 registrar.cpp:307] Recovering registrar
I0103 02:31:51.044273 31039 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 66.189935ms
I0103 02:31:51.044318 31039 replica.cpp:320] Persisted replica status to STARTING
I0103 02:31:51.044562 31039 recover.cpp:473] Replica is in STARTING status
I0103 02:31:51.045542 31039 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12834)@172.17.0.5:37086
I0103 02:31:51.045927 31046 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 02:31:51.046278 31051 recover.cpp:564] Updating replica status to VOTING
I0103 02:31:51.086220 31050 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.792656ms
I0103 02:31:51.086258 31050 replica.cpp:320] Persisted replica status to VOTING
I0103 02:31:51.086457 31048 recover.cpp:578] Successfully joined the Paxos group
I0103 02:31:51.086771 31048 recover.cpp:462] Recover process terminated
I0103 02:31:51.087208 31048 log.cpp:659] Attempting to start the writer
I0103 02:31:51.088281 31050 replica.cpp:493] Replica received implicit promise request from (12835)@172.17.0.5:37086 with proposal 1
I0103 02:31:51.128706 31050 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 40.391585ms
I0103 02:31:51.128754 31050 replica.cpp:342] Persisted promised to 1
I0103 02:31:51.129597 31044 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 02:31:51.131176 31053 replica.cpp:388] Replica received explicit promise request from (12836)@172.17.0.5:37086 for position 0 with proposal 2
I0103 02:31:51.162144 31053 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 30.911275ms
I0103 02:31:51.162189 31053 replica.cpp:712] Persisted action at 0
I0103 02:31:51.163403 31054 replica.cpp:537] Replica received write request for position 0 from (12837)@172.17.0.5:37086
I0103 02:31:51.163483 31054 leveldb.cpp:436] Reading position from leveldb took 39484ns
I0103 02:31:51.187202 31054 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.663842ms
I0103 02:31:51.187235 31054 replica.cpp:712] Persisted action at 0
I0103 02:31:51.187965 31041 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 02:31:51.212570 31041 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.557212ms
I0103 02:31:51.212659 31041 replica.cpp:712] Persisted action at 0
I0103 02:31:51.212688 31041 replica.cpp:697] Replica learned NOP action at position 0
I0103 02:31:51.213521 31039 log.cpp:675] Writer started with ending position 0
I0103 02:31:51.214712 31044 leveldb.cpp:436] Reading position from leveldb took 55927ns
I0103 02:31:51.215713 31047 registrar.cpp:340] Successfully fetched the registry (0B) in 233.981952ms
I0103 02:31:51.215852 31047 registrar.cpp:439] Applied 1 operations in 39617ns; attempting to update the 'registry'
I0103 02:31:51.216591 31043 log.cpp:683] Attempting to append 170 bytes to the log
I0103 02:31:51.216770 31054 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 02:31:51.217494 31041 replica.cpp:537] Replica received write request for position 1 from (12838)@172.17.0.5:37086
I0103 02:31:51.237684 31041 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.145337ms
I0103 02:31:51.237736 31041 replica.cpp:712] Persisted action at 1
I0103 02:31:51.238492 31048 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 02:31:51.262868 31048 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.333476ms
I0103 02:31:51.262933 31048 replica.cpp:712] Persisted action at 1
I0103 02:31:51.262961 31048 replica.cpp:697] Replica learned APPEND action at position 1
I0103 02:31:51.264237 31048 registrar.cpp:484] Successfully updated the 'registry' in 48.315136ms
I0103 02:31:51.264365 31048 registrar.cpp:370] Successfully recovered registrar
I0103 02:31:51.264497 31051 log.cpp:702] Attempting to truncate the log to 1
I0103 02:31:51.264724 31046 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 02:31:51.264891 31042 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 02:31:51.264889 31052 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 02:31:51.265758 31041 replica.cpp:537] Replica received write request for position 2 from (12839)@172.17.0.5:37086
I0103 02:31:51.287969 31041 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.155802ms
I0103 02:31:51.288028 31041 replica.cpp:712] Persisted action at 2
I0103 02:31:51.288796 31046 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 02:31:51.313187 31046 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.336494ms
I0103 02:31:51.313319 31046 leveldb.cpp:399] Deleting ~1 keys from leveldb took 58897ns
I0103 02:31:51.313341 31046 replica.cpp:712] Persisted action at 2
I0103 02:31:51.313372 31046 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 02:31:51.316226 31020 scheduler.cpp:154] Version: 0.27.0
I0103 02:31:51.316925 31040 scheduler.cpp:236] New master detected at master@172.17.0.5:37086
I0103 02:31:51.318012 31039 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:37086
I0103 02:31:51.319809 31048 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 02:31:51.320291 31053 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:56454
I0103 02:31:51.320467 31053 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 02:31:51.320549 31053 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 02:31:51.320843 31053 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 02:31:51.321235 31047 hierarchical.cpp:260] Added framework e359101e-01ea-4f73-9184-4086d5e18dd6-0000
I0103 02:31:51.321280 31053 master.hpp:1659] Sending heartbeat to e359101e-01ea-4f73-9184-4086d5e18dd6-0000
I0103 02:31:51.321311 31047 hierarchical.cpp:1329] No resources available to allocate!
I0103 02:31:51.321354 31047 hierarchical.cpp:1423] No inverse offers to send out!
I0103 02:31:51.321388 31047 hierarchical.cpp:1079] Performed allocation for 0 slaves in 127536ns
I0103 02:31:51.322101 31042 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:37086
I0103 02:31:51.322489 31042 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:37086
I0103 02:31:51.323233 31039 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 02:31:51.323305 31042 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:37086
I0103 02:31:51.324658 31041 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 02:31:51.324996 31052 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:56455
I0103 02:31:51.325093 31052 master.cpp:2636] Processing REQUEST call for framework e359101e-01ea-4f73-9184-4086d5e18dd6-0000 (default)
I0103 02:31:51.325235 31043 hierarchical.cpp:579] Received resource request from framework e359101e-01ea-4f73-9184-4086d5e18dd6-0000
I0103 02:31:51.325464 31045 master.cpp:930] Master terminating
I0103 02:31:51.325716 31039 hierarchical.cpp:321] Removed framework e359101e-01ea-4f73-9184-4086d5e18dd6-0000
E0103 02:31:51.326699 31042 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (529 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0103 02:31:51.462520 31020 leveldb.cpp:174] Opened db in 130.539857ms
I0103 02:31:51.504665 31020 leveldb.cpp:181] Compacted db in 42.076413ms
I0103 02:31:51.504741 31020 leveldb.cpp:196] Created db iterator in 27146ns
I0103 02:31:51.504763 31020 leveldb.cpp:202] Seeked to beginning of db in 2320ns
I0103 02:31:51.504775 31020 leveldb.cpp:271] Iterated through 0 keys in the db in 438ns
I0103 02:31:51.504828 31020 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 02:31:51.505558 31051 recover.cpp:447] Starting replica recovery
I0103 02:31:51.505970 31051 recover.cpp:473] Replica is in EMPTY status
I0103 02:31:51.507124 31051 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12847)@172.17.0.5:37086
I0103 02:31:51.507556 31044 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 02:31:51.508034 31053 recover.cpp:564] Updating replica status to STARTING
I0103 02:31:51.508338 31045 master.cpp:365] Master 1d58bf47-9b3f-4931-a4ed-2812fd14af4c (340fc150d555) started on 172.17.0.5:37086
I0103 02:31:51.508368 31045 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/WcE3QJ/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/WcE3QJ/master" --zk_session_timeout="10secs"
I0103 02:31:51.508690 31045 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 02:31:51.508702 31045 master.cpp:417] Master only allowing authenticated slaves to register
I0103 02:31:51.508708 31045 credentials.hpp:35] Loading credentials for authentication from '/tmp/WcE3QJ/credentials'
I0103 02:31:51.508970 31045 master.cpp:456] Using default 'crammd5' authenticator
I0103 02:31:51.509096 31045 master.cpp:493] Authorization enabled
I0103 02:31:51.509263 31041 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 02:31:51.509316 31044 whitelist_watcher.cpp:77] No whitelist given
I0103 02:31:51.510996 31047 master.cpp:1629] The newly elected leader is master@172.17.0.5:37086 with id 1d58bf47-9b3f-4931-a4ed-2812fd14af4c
I0103 02:31:51.511028 31047 master.cpp:1642] Elected as the leading master!
I0103 02:31:51.511044 31047 master.cpp:1387] Recovering from registrar
I0103 02:31:51.511184 31050 registrar.cpp:307] Recovering registrar
I0103 02:31:51.546082 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.920149ms
I0103 02:31:51.546126 31043 replica.cpp:320] Persisted replica status to STARTING
I0103 02:31:51.546377 31043 recover.cpp:473] Replica is in STARTING status
I0103 02:31:51.547343 31054 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12848)@172.17.0.5:37086
I0103 02:31:51.547766 31039 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 02:31:51.548276 31054 recover.cpp:564] Updating replica status to VOTING
I0103 02:31:51.587995 31051 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.531751ms
I0103 02:31:51.588038 31051 replica.cpp:320] Persisted replica status to VOTING
I0103 02:31:51.588194 31045 recover.cpp:578] Successfully joined the Paxos group
I0103 02:31:51.588444 31045 recover.cpp:462] Recover process terminated
I0103 02:31:51.588992 31041 log.cpp:659] Attempting to start the writer
I0103 02:31:51.590162 31054 replica.cpp:493] Replica received implicit promise request from (12849)@172.17.0.5:37086 with proposal 1
I0103 02:31:51.629714 31054 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.516985ms
I0103 02:31:51.629755 31054 replica.cpp:342] Persisted promised to 1
I0103 02:31:51.630363 31042 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 02:31:51.631769 31048 replica.cpp:388] Replica received explicit promise request from (12850)@172.17.0.5:37086 for position 0 with proposal 2
I0103 02:31:51.671625 31048 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.778565ms
I0103 02:31:51.671671 31048 replica.cpp:712] Persisted action at 0
I0103 02:31:51.672966 31048 replica.cpp:537] Replica received write request for position 0 from (12851)@172.17.0.5:37086
I0103 02:31:51.673043 31048 leveldb.cpp:436] Reading position from leveldb took 39174ns
I0103 02:31:51.716156 31048 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 43.058176ms
I0103 02:31:51.716199 31048 replica.cpp:712] Persisted action at 0
I0103 02:31:51.717008 31053 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 02:31:51.741436 31053 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.384918ms
I0103 02:31:51.741487 31053 replica.cpp:712] Persisted action at 0
I0103 02:31:51.741524 31053 replica.cpp:697] Replica learned NOP action at position 0
I0103 02:31:51.742357 31044 log.cpp:675] Writer started with ending position 0
I0103 02:31:51.743705 31053 leveldb.cpp:436] Reading position from leveldb took 37406ns
I0103 02:31:51.744848 31041 registrar.cpp:340] Successfully fetched the registry (0B) in 233.613056ms
I0103 02:31:51.744994 31041 registrar.cpp:439] Applied 1 operations in 33544ns; attempting to update the 'registry'
I0103 02:31:51.745913 31046 log.cpp:683] Attempting to append 170 bytes to the log
I0103 02:31:51.746090 31049 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 02:31:51.747083 31053 replica.cpp:537] Replica received write request for position 1 from (12852)@172.17.0.5:37086
I0103 02:31:51.772626 31053 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 25.472127ms
I0103 02:31:51.772671 31053 replica.cpp:712] Persisted action at 1
I0103 02:31:51.773598 31046 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 02:31:51.799881 31046 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 26.142676ms
I0103 02:31:51.799921 31046 replica.cpp:712] Persisted action at 1
I0103 02:31:51.799944 31046 replica.cpp:697] Replica learned APPEND action at position 1
I0103 02:31:51.801172 31040 registrar.cpp:484] Successfully updated the 'registry' in 56.09984ms
I0103 02:31:51.801342 31040 registrar.cpp:370] Successfully recovered registrar
I0103 02:31:51.801384 31052 log.cpp:702] Attempting to truncate the log to 1
I0103 02:31:51.801486 31043 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 02:31:51.801851 31047 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 02:31:51.801874 31045 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 02:31:51.802391 31040 replica.cpp:537] Replica received write request for position 2 from (12853)@172.17.0.5:37086
I0103 02:31:51.824934 31040 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.50721ms
I0103 02:31:51.824975 31040 replica.cpp:712] Persisted action at 2
I0103 02:31:51.825588 31046 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 02:31:51.850167 31046 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.459518ms
I0103 02:31:51.850260 31046 leveldb.cpp:399] Deleting ~1 keys from leveldb took 46141ns
I0103 02:31:51.850285 31046 replica.cpp:712] Persisted action at 2
I0103 02:31:51.850307 31046 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 02:31:51.852870 31020 scheduler.cpp:154] Version: 0.27.0
I0103 02:31:51.853487 31050 scheduler.cpp:236] New master detected at master@172.17.0.5:37086
I0103 02:31:51.854732 31042 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:37086
I0103 02:31:51.857148 31047 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 02:31:51.857830 31046 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:56456
I0103 02:31:51.858239 31046 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 02:31:51.858314 31046 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 02:31:51.858676 31046 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 02:31:51.859199 31040 hierarchical.cpp:260] Added framework 1d58bf47-9b3f-4931-a4ed-2812fd14af4c-0000
I0103 02:31:51.859280 31043 master.hpp:1659] Sending heartbeat to 1d58bf47-9b3f-4931-a4ed-2812fd14af4c-0000
I0103 02:31:51.859421 31040 hierarchical.cpp:1329] No resources available to allocate!
I0103 02:31:51.859820 31040 hierarchical.cpp:1423] No inverse offers to send out!
I0103 02:31:51.859953 31040 hierarchical.cpp:1079] Performed allocation for 0 slaves in 619008ns
I0103 02:31:51.860450 31040 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:37086
I0103 02:31:51.861099 31046 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:37086
I0103 02:31:51.861929 31052 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 02:31:51.861971 31046 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:37086
I0103 02:31:51.863642 31043 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 02:31:51.864042 31048 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:56457
I0103 02:31:51.864306 31048 master.cpp:2636] Processing REQUEST call for framework 1d58bf47-9b3f-4931-a4ed-2812fd14af4c-0000 (default)
I0103 02:31:51.864493 31053 hierarchical.cpp:579] Received resource request from framework 1d58bf47-9b3f-4931-a4ed-2812fd14af4c-0000
I0103 02:31:51.864828 31041 master.cpp:930] Master terminating
I0103 02:31:51.865046 31039 hierarchical.cpp:321] Removed framework 1d58bf47-9b3f-4931-a4ed-2812fd14af4c-0000
E0103 02:31:51.866051 31041 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (540 ms)
[----------] 22 tests from ContentType/SchedulerTest (15915 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (697959 ms total)
[ PASSED ] 913 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization
2 FAILED TESTS
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1451785780-14912
Untagged: mesos-1451785780-14912:latest
Deleted: 5f0f39bcaded21241a4ffe6ca7ed500dcdf70b816b5f3628913ab4c37b6dc21f
Deleted: c8b5689ef576851d13a38ae6adc36032c48ec9889c392285ce8388767368f09f
Deleted: fcdeece2faa447f2959bf9842961734110959ae8fdd2be7260dad45d7b0a7782
Deleted: 3653eb07ac1837de123e5dfffe9fdb5408f21e77b0e5dee8c9a2a7d197b278c5
Deleted: b0dc5f614d97465f13a33aec802cdba784b160b4af70ebec903bd4024040795c
Deleted: c6a5eeeb34583c976bd8187b1aa679ada74704edfe7e94f6ff6c865ebc160ba4
Deleted: 807b518c042473f431bec53bde2bc8a5129267c96a7d83d65ac3b500420cd4be
Deleted: e53d00fa3d539c690ca6a82703fe54baedef02a836ca4e35e621f565d300c876
Deleted: a24c65bcd6117974464610e98ed320e1d7765fdd0161665e50b037f446d7debb
Deleted: 4c4090ffc1e87155675e99fe2f4add3bec8a66bdc98c2f51b8cbc51cc716d323
Deleted: c241eaed22a360ddb1d1b9d17555836ad4926ff923cf0381631698c04ba5d61b
Deleted: 75dfbfdab0050b988ca09705fe79dcb7bd1c3bb9acf006855972e84a33ed9211
Deleted: 60b21cd843228ef100a76b9e6062dee987cf3d49ed3139732522350f94dfe016
Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : mesos-reviewbot #10533
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10533/>
Build failed in Jenkins: mesos-reviewbot #10532
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10532/>
------------------------------------------
[...truncated 165444 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (785 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0103 10:06:23.399935 31012 leveldb.cpp:174] Opened db in 138.142122ms
I0103 10:06:23.458582 31012 leveldb.cpp:181] Compacted db in 58.604527ms
I0103 10:06:23.458675 31012 leveldb.cpp:196] Created db iterator in 18895ns
I0103 10:06:23.458694 31012 leveldb.cpp:202] Seeked to beginning of db in 1975ns
I0103 10:06:23.458706 31012 leveldb.cpp:271] Iterated through 0 keys in the db in 343ns
I0103 10:06:23.458745 31012 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 10:06:23.460086 31042 recover.cpp:447] Starting replica recovery
I0103 10:06:23.460353 31042 recover.cpp:473] Replica is in EMPTY status
I0103 10:06:23.461437 31041 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12846)@172.17.0.5:36256
I0103 10:06:23.461918 31039 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 10:06:23.462419 31046 master.cpp:365] Master 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8 (faa43f3fe7be) started on 172.17.0.5:36256
I0103 10:06:23.462528 31042 recover.cpp:564] Updating replica status to STARTING
I0103 10:06:23.462451 31046 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Zs4hFS/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/Zs4hFS/master" --zk_session_timeout="10secs"
I0103 10:06:23.462857 31046 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 10:06:23.462877 31046 master.cpp:417] Master only allowing authenticated slaves to register
I0103 10:06:23.462889 31046 credentials.hpp:35] Loading credentials for authentication from '/tmp/Zs4hFS/credentials'
I0103 10:06:23.463150 31046 master.cpp:456] Using default 'crammd5' authenticator
I0103 10:06:23.463268 31046 master.cpp:493] Authorization enabled
I0103 10:06:23.463420 31040 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 10:06:23.463435 31033 whitelist_watcher.cpp:77] No whitelist given
I0103 10:06:23.464854 31043 master.cpp:1629] The newly elected leader is master@172.17.0.5:36256 with id 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8
I0103 10:06:23.464895 31043 master.cpp:1642] Elected as the leading master!
I0103 10:06:23.464922 31043 master.cpp:1387] Recovering from registrar
I0103 10:06:23.465106 31038 registrar.cpp:307] Recovering registrar
I0103 10:06:23.484159 31037 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.375564ms
I0103 10:06:23.484203 31037 replica.cpp:320] Persisted replica status to STARTING
I0103 10:06:23.484447 31034 recover.cpp:473] Replica is in STARTING status
I0103 10:06:23.485379 31045 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12847)@172.17.0.5:36256
I0103 10:06:23.485647 31031 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 10:06:23.485996 31043 recover.cpp:564] Updating replica status to VOTING
I0103 10:06:23.509169 31041 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.03954ms
I0103 10:06:23.509197 31041 replica.cpp:320] Persisted replica status to VOTING
I0103 10:06:23.509296 31034 recover.cpp:578] Successfully joined the Paxos group
I0103 10:06:23.509503 31034 recover.cpp:462] Recover process terminated
I0103 10:06:23.509994 31044 log.cpp:659] Attempting to start the writer
I0103 10:06:23.511304 31035 replica.cpp:493] Replica received implicit promise request from (12848)@172.17.0.5:36256 with proposal 1
I0103 10:06:23.534361 31035 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.017577ms
I0103 10:06:23.534400 31035 replica.cpp:342] Persisted promised to 1
I0103 10:06:23.535095 31034 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 10:06:23.536370 31035 replica.cpp:388] Replica received explicit promise request from (12849)@172.17.0.5:36256 for position 0 with proposal 2
I0103 10:06:23.559478 31035 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 23.056301ms
I0103 10:06:23.559517 31035 replica.cpp:712] Persisted action at 0
I0103 10:06:23.560896 31042 replica.cpp:537] Replica received write request for position 0 from (12850)@172.17.0.5:36256
I0103 10:06:23.560974 31042 leveldb.cpp:436] Reading position from leveldb took 34662ns
I0103 10:06:23.584632 31042 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.576699ms
I0103 10:06:23.584674 31042 replica.cpp:712] Persisted action at 0
I0103 10:06:23.585398 31044 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 10:06:23.609644 31044 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.204414ms
I0103 10:06:23.609685 31044 replica.cpp:712] Persisted action at 0
I0103 10:06:23.609707 31044 replica.cpp:697] Replica learned NOP action at position 0
I0103 10:06:23.610385 31046 log.cpp:675] Writer started with ending position 0
I0103 10:06:23.611520 31031 leveldb.cpp:436] Reading position from leveldb took 33331ns
I0103 10:06:23.612584 31036 registrar.cpp:340] Successfully fetched the registry (0B) in 147.428864ms
I0103 10:06:23.612746 31036 registrar.cpp:439] Applied 1 operations in 26045ns; attempting to update the 'registry'
I0103 10:06:23.613477 31033 log.cpp:683] Attempting to append 170 bytes to the log
I0103 10:06:23.613697 31036 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 10:06:23.614470 31044 replica.cpp:537] Replica received write request for position 1 from (12851)@172.17.0.5:36256
I0103 10:06:23.634748 31044 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.234109ms
I0103 10:06:23.634788 31044 replica.cpp:712] Persisted action at 1
I0103 10:06:23.635648 31043 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 10:06:23.659863 31043 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.176989ms
I0103 10:06:23.659903 31043 replica.cpp:712] Persisted action at 1
I0103 10:06:23.659925 31043 replica.cpp:697] Replica learned APPEND action at position 1
I0103 10:06:23.661023 31037 registrar.cpp:484] Successfully updated the 'registry' in 48.2112ms
I0103 10:06:23.661173 31037 registrar.cpp:370] Successfully recovered registrar
I0103 10:06:23.661352 31046 log.cpp:702] Attempting to truncate the log to 1
I0103 10:06:23.661594 31032 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 10:06:23.661802 31036 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 10:06:23.661864 31038 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 10:06:23.662566 31042 replica.cpp:537] Replica received write request for position 2 from (12852)@172.17.0.5:36256
I0103 10:06:23.692401 31042 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 29.758908ms
I0103 10:06:23.692440 31042 replica.cpp:712] Persisted action at 2
I0103 10:06:23.693146 31046 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 10:06:23.734133 31046 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.895971ms
I0103 10:06:23.734215 31046 leveldb.cpp:399] Deleting ~1 keys from leveldb took 42497ns
I0103 10:06:23.734249 31046 replica.cpp:712] Persisted action at 2
I0103 10:06:23.734273 31046 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 10:06:23.742905 31012 scheduler.cpp:154] Version: 0.27.0
I0103 10:06:23.743630 31038 scheduler.cpp:236] New master detected at master@172.17.0.5:36256
I0103 10:06:23.744801 31037 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:36256
I0103 10:06:23.746687 31034 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 10:06:23.747359 31040 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35765
I0103 10:06:23.747582 31040 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 10:06:23.747675 31040 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 10:06:23.748029 31040 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 10:06:23.748438 31034 hierarchical.cpp:260] Added framework 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8-0000
I0103 10:06:23.748514 31034 hierarchical.cpp:1329] No resources available to allocate!
I0103 10:06:23.748500 31044 master.hpp:1659] Sending heartbeat to 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8-0000
I0103 10:06:23.748675 31034 hierarchical.cpp:1423] No inverse offers to send out!
I0103 10:06:23.748716 31034 hierarchical.cpp:1079] Performed allocation for 0 slaves in 241349ns
I0103 10:06:23.749495 31037 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:36256
I0103 10:06:23.750072 31037 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:36256
I0103 10:06:23.750870 31038 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 10:06:23.750933 31037 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:36256
I0103 10:06:23.752663 31034 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 10:06:23.753125 31044 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35766
I0103 10:06:23.753257 31044 master.cpp:2636] Processing REQUEST call for framework 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8-0000 (default)
I0103 10:06:23.753456 31039 hierarchical.cpp:579] Received resource request from framework 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8-0000
I0103 10:06:23.753783 31034 master.cpp:930] Master terminating
I0103 10:06:23.753998 31039 hierarchical.cpp:321] Removed framework 8fb0621a-61a9-46fc-98e8-a3b0ea626dd8-0000
E0103 10:06:23.755105 31042 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (500 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0103 10:06:23.844879 31012 leveldb.cpp:174] Opened db in 82.713294ms
I0103 10:06:23.874131 31012 leveldb.cpp:181] Compacted db in 29.209999ms
I0103 10:06:23.874196 31012 leveldb.cpp:196] Created db iterator in 17804ns
I0103 10:06:23.874215 31012 leveldb.cpp:202] Seeked to beginning of db in 1975ns
I0103 10:06:23.874228 31012 leveldb.cpp:271] Iterated through 0 keys in the db in 325ns
I0103 10:06:23.874264 31012 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 10:06:23.874954 31033 recover.cpp:447] Starting replica recovery
I0103 10:06:23.875293 31033 recover.cpp:473] Replica is in EMPTY status
I0103 10:06:23.876361 31040 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12860)@172.17.0.5:36256
I0103 10:06:23.876725 31038 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 10:06:23.877341 31031 recover.cpp:564] Updating replica status to STARTING
I0103 10:06:23.878155 31035 master.cpp:365] Master ec5677a7-3657-4516-a9a2-2fb1676df5fd (faa43f3fe7be) started on 172.17.0.5:36256
I0103 10:06:23.878190 31035 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/NFbCoC/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/NFbCoC/master" --zk_session_timeout="10secs"
I0103 10:06:23.878520 31035 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 10:06:23.878535 31035 master.cpp:417] Master only allowing authenticated slaves to register
I0103 10:06:23.878545 31035 credentials.hpp:35] Loading credentials for authentication from '/tmp/NFbCoC/credentials'
I0103 10:06:23.878825 31035 master.cpp:456] Using default 'crammd5' authenticator
I0103 10:06:23.878954 31035 master.cpp:493] Authorization enabled
I0103 10:06:23.879109 31033 whitelist_watcher.cpp:77] No whitelist given
I0103 10:06:23.879122 31045 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 10:06:23.880945 31044 master.cpp:1629] The newly elected leader is master@172.17.0.5:36256 with id ec5677a7-3657-4516-a9a2-2fb1676df5fd
I0103 10:06:23.880985 31044 master.cpp:1642] Elected as the leading master!
I0103 10:06:23.881009 31044 master.cpp:1387] Recovering from registrar
I0103 10:06:23.881199 31039 registrar.cpp:307] Recovering registrar
I0103 10:06:23.918556 31032 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 40.990527ms
I0103 10:06:23.918634 31032 replica.cpp:320] Persisted replica status to STARTING
I0103 10:06:23.918969 31036 recover.cpp:473] Replica is in STARTING status
I0103 10:06:23.920362 31035 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12861)@172.17.0.5:36256
I0103 10:06:23.920655 31044 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 10:06:23.921221 31032 recover.cpp:564] Updating replica status to VOTING
I0103 10:06:23.951941 31033 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.548253ms
I0103 10:06:23.951980 31033 replica.cpp:320] Persisted replica status to VOTING
I0103 10:06:23.952121 31037 recover.cpp:578] Successfully joined the Paxos group
I0103 10:06:23.952390 31037 recover.cpp:462] Recover process terminated
I0103 10:06:23.952905 31037 log.cpp:659] Attempting to start the writer
I0103 10:06:23.954212 31038 replica.cpp:493] Replica received implicit promise request from (12862)@172.17.0.5:36256 with proposal 1
I0103 10:06:23.977155 31038 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.904527ms
I0103 10:06:23.977200 31038 replica.cpp:342] Persisted promised to 1
I0103 10:06:23.977845 31032 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 10:06:23.979231 31041 replica.cpp:388] Replica received explicit promise request from (12863)@172.17.0.5:36256 for position 0 with proposal 2
I0103 10:06:24.002146 31041 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.864524ms
I0103 10:06:24.002185 31041 replica.cpp:712] Persisted action at 0
I0103 10:06:24.003482 31036 replica.cpp:537] Replica received write request for position 0 from (12864)@172.17.0.5:36256
I0103 10:06:24.003551 31036 leveldb.cpp:436] Reading position from leveldb took 29417ns
I0103 10:06:24.027261 31036 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.663876ms
I0103 10:06:24.027299 31036 replica.cpp:712] Persisted action at 0
I0103 10:06:24.028159 31041 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 10:06:24.052376 31041 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.169573ms
I0103 10:06:24.052414 31041 replica.cpp:712] Persisted action at 0
I0103 10:06:24.052438 31041 replica.cpp:697] Replica learned NOP action at position 0
I0103 10:06:24.053149 31045 log.cpp:675] Writer started with ending position 0
I0103 10:06:24.054363 31041 leveldb.cpp:436] Reading position from leveldb took 34609ns
I0103 10:06:24.055371 31033 registrar.cpp:340] Successfully fetched the registry (0B) in 174.024192ms
I0103 10:06:24.055493 31033 registrar.cpp:439] Applied 1 operations in 28019ns; attempting to update the 'registry'
I0103 10:06:24.056323 31036 log.cpp:683] Attempting to append 170 bytes to the log
I0103 10:06:24.056495 31040 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 10:06:24.057356 31046 replica.cpp:537] Replica received write request for position 1 from (12865)@172.17.0.5:36256
I0103 10:06:24.077491 31046 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.087164ms
I0103 10:06:24.077532 31046 replica.cpp:712] Persisted action at 1
I0103 10:06:24.078441 31031 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 10:06:24.102677 31031 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.193814ms
I0103 10:06:24.102717 31031 replica.cpp:712] Persisted action at 1
I0103 10:06:24.102740 31031 replica.cpp:697] Replica learned APPEND action at position 1
I0103 10:06:24.104463 31045 registrar.cpp:484] Successfully updated the 'registry' in 48.908032ms
I0103 10:06:24.104679 31045 registrar.cpp:370] Successfully recovered registrar
I0103 10:06:24.104756 31035 log.cpp:702] Attempting to truncate the log to 1
I0103 10:06:24.104948 31033 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 10:06:24.105463 31040 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 10:06:24.105525 31044 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 10:06:24.105960 31036 replica.cpp:537] Replica received write request for position 2 from (12866)@172.17.0.5:36256
I0103 10:06:24.127794 31036 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 21.78832ms
I0103 10:06:24.127833 31036 replica.cpp:712] Persisted action at 2
I0103 10:06:24.128536 31040 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 10:06:24.152978 31040 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.39931ms
I0103 10:06:24.153059 31040 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40203ns
I0103 10:06:24.153081 31040 replica.cpp:712] Persisted action at 2
I0103 10:06:24.153105 31040 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 10:06:24.156466 31012 scheduler.cpp:154] Version: 0.27.0
I0103 10:06:24.157127 31042 scheduler.cpp:236] New master detected at master@172.17.0.5:36256
I0103 10:06:24.158314 31035 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:36256
I0103 10:06:24.160380 31045 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 10:06:24.160948 31039 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35767
I0103 10:06:24.161346 31039 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 10:06:24.161433 31039 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 10:06:24.161797 31039 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 10:06:24.162436 31034 master.hpp:1659] Sending heartbeat to ec5677a7-3657-4516-a9a2-2fb1676df5fd-0000
I0103 10:06:24.162822 31041 hierarchical.cpp:260] Added framework ec5677a7-3657-4516-a9a2-2fb1676df5fd-0000
I0103 10:06:24.162901 31041 hierarchical.cpp:1329] No resources available to allocate!
I0103 10:06:24.162955 31041 hierarchical.cpp:1423] No inverse offers to send out!
I0103 10:06:24.162992 31041 hierarchical.cpp:1079] Performed allocation for 0 slaves in 133182ns
I0103 10:06:24.163482 31035 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:36256
I0103 10:06:24.164039 31035 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:36256
I0103 10:06:24.164831 31045 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 10:06:24.164870 31035 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:36256
I0103 10:06:24.166674 31032 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 10:06:24.167199 31035 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:35768
I0103 10:06:24.167481 31035 master.cpp:2636] Processing REQUEST call for framework ec5677a7-3657-4516-a9a2-2fb1676df5fd-0000 (default)
I0103 10:06:24.167696 31036 hierarchical.cpp:579] Received resource request from framework ec5677a7-3657-4516-a9a2-2fb1676df5fd-0000
I0103 10:06:24.168066 31031 master.cpp:930] Master terminating
I0103 10:06:24.168301 31033 hierarchical.cpp:321] Removed framework ec5677a7-3657-4516-a9a2-2fb1676df5fd-0000
E0103 10:06:24.169953 31037 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (414 ms)
[----------] 22 tests from ContentType/SchedulerTest (15300 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (717932 ms total)
[ PASSED ] 913 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization
2 FAILED TESTS
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1451812778-17164
Untagged: mesos-1451812778-17164:latest
Deleted: 26c98aa3128fa1c60137fa9ead1df0ad52604d3a7774f6988346c14acdb80400
Deleted: 7861f0847ba3d6bb1ea8ac1788cd78749ad05672f9888f1faebbe18d96647464
Deleted: 253adc5bb6447f45fc72cf1f5843717ad4d6de7a579cc5f85e1b474d9ea12896
Deleted: 24ffe788f54679aed91dc08582f0ea854630d7f704a6b7cb7638d0a5cf3a56d4
Deleted: 49c49c88c0cb56dbe8728f6e7061a08d2bebbb27c63e08d50114e5c000a098ab
Deleted: 8b6bfbcd5486cf76c2fdfacc1a47802a0fb7a6564e1820415c153ebcd2d3034c
Deleted: 418a7788cf60bc4d0ed964b7459a0f60a82aae71c1bf2c9c9a1aa783ade6633a
Deleted: 39577ddc71b6ddfe2d9b4d9e8d2c0dffc1c745fa56e132472b6f50b50873e4a1
Deleted: 2551271882bcde909fa16b3ac96b3f19df80a7e93b50f3d9fa134351f37d1973
Deleted: ef029f566c79103b440f876587877e74af80f53eaceb0c01acc0e2d802f02d56
Deleted: 864aea00e64bc2ee598dfe89f1fa6f2d896c7e99580238cd29dba594130dc4cc
Deleted: 5cd88ab478b9baca0ae5f3aa7e937a2217f9d48ac5c9049e5e36a6cd923e73c7
Deleted: 9532f2c87ca16da73ddfb739dd80b2a9727422ba71fc20702d13c70347850d91
Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10531
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10531/>
------------------------------------------
[...truncated 165035 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (663 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0103 08:56:51.594421 31016 leveldb.cpp:174] Opened db in 84.707564ms
I0103 08:56:51.619884 31016 leveldb.cpp:181] Compacted db in 25.419627ms
I0103 08:56:51.619949 31016 leveldb.cpp:196] Created db iterator in 20484ns
I0103 08:56:51.619969 31016 leveldb.cpp:202] Seeked to beginning of db in 2293ns
I0103 08:56:51.619982 31016 leveldb.cpp:271] Iterated through 0 keys in the db in 398ns
I0103 08:56:51.620020 31016 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 08:56:51.620539 31045 recover.cpp:447] Starting replica recovery
I0103 08:56:51.621093 31045 recover.cpp:473] Replica is in EMPTY status
I0103 08:56:51.622313 31046 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12832)@172.17.0.2:58080
I0103 08:56:51.622879 31049 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 08:56:51.623400 31042 recover.cpp:564] Updating replica status to STARTING
I0103 08:56:51.623739 31045 master.cpp:365] Master fb3f5bea-15c3-4782-9424-98aa13afe330 (4cd3539047c1) started on 172.17.0.2:58080
I0103 08:56:51.623764 31045 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Nee8Yv/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/Nee8Yv/master" --zk_session_timeout="10secs"
I0103 08:56:51.624089 31045 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 08:56:51.624104 31045 master.cpp:417] Master only allowing authenticated slaves to register
I0103 08:56:51.624112 31045 credentials.hpp:35] Loading credentials for authentication from '/tmp/Nee8Yv/credentials'
I0103 08:56:51.624395 31045 master.cpp:456] Using default 'crammd5' authenticator
I0103 08:56:51.624539 31045 master.cpp:493] Authorization enabled
I0103 08:56:51.624733 31040 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 08:56:51.624773 31035 whitelist_watcher.cpp:77] No whitelist given
I0103 08:56:51.626643 31050 master.cpp:1629] The newly elected leader is master@172.17.0.2:58080 with id fb3f5bea-15c3-4782-9424-98aa13afe330
I0103 08:56:51.626688 31050 master.cpp:1642] Elected as the leading master!
I0103 08:56:51.626713 31050 master.cpp:1387] Recovering from registrar
I0103 08:56:51.626870 31047 registrar.cpp:307] Recovering registrar
I0103 08:56:51.657742 31044 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 34.164301ms
I0103 08:56:51.657779 31044 replica.cpp:320] Persisted replica status to STARTING
I0103 08:56:51.658043 31036 recover.cpp:473] Replica is in STARTING status
I0103 08:56:51.659354 31038 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12833)@172.17.0.2:58080
I0103 08:56:51.659610 31037 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 08:56:51.660221 31043 recover.cpp:564] Updating replica status to VOTING
I0103 08:56:51.682793 31036 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.396397ms
I0103 08:56:51.682831 31036 replica.cpp:320] Persisted replica status to VOTING
I0103 08:56:51.682965 31050 recover.cpp:578] Successfully joined the Paxos group
I0103 08:56:51.683235 31050 recover.cpp:462] Recover process terminated
I0103 08:56:51.683701 31047 log.cpp:659] Attempting to start the writer
I0103 08:56:51.685237 31036 replica.cpp:493] Replica received implicit promise request from (12834)@172.17.0.2:58080 with proposal 1
I0103 08:56:51.707942 31036 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.667061ms
I0103 08:56:51.707978 31036 replica.cpp:342] Persisted promised to 1
I0103 08:56:51.708703 31041 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 08:56:51.710186 31048 replica.cpp:388] Replica received explicit promise request from (12835)@172.17.0.2:58080 for position 0 with proposal 2
I0103 08:56:51.733052 31048 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.81864ms
I0103 08:56:51.733089 31048 replica.cpp:712] Persisted action at 0
I0103 08:56:51.734705 31049 replica.cpp:537] Replica received write request for position 0 from (12836)@172.17.0.2:58080
I0103 08:56:51.734788 31049 leveldb.cpp:436] Reading position from leveldb took 36911ns
I0103 08:56:51.758174 31049 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.32948ms
I0103 08:56:51.758213 31049 replica.cpp:712] Persisted action at 0
I0103 08:56:51.759019 31042 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 08:56:51.783273 31042 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.212938ms
I0103 08:56:51.783313 31042 replica.cpp:712] Persisted action at 0
I0103 08:56:51.783335 31042 replica.cpp:697] Replica learned NOP action at position 0
I0103 08:56:51.784083 31037 log.cpp:675] Writer started with ending position 0
I0103 08:56:51.785308 31050 leveldb.cpp:436] Reading position from leveldb took 33244ns
I0103 08:56:51.786332 31050 registrar.cpp:340] Successfully fetched the registry (0B) in 159.407104ms
I0103 08:56:51.786453 31050 registrar.cpp:439] Applied 1 operations in 26219ns; attempting to update the 'registry'
I0103 08:56:51.787293 31039 log.cpp:683] Attempting to append 170 bytes to the log
I0103 08:56:51.787421 31036 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 08:56:51.788343 31036 replica.cpp:537] Replica received write request for position 1 from (12837)@172.17.0.2:58080
I0103 08:56:51.808403 31036 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.009373ms
I0103 08:56:51.808441 31036 replica.cpp:712] Persisted action at 1
I0103 08:56:51.809187 31040 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 08:56:51.833513 31040 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.28082ms
I0103 08:56:51.833559 31040 replica.cpp:712] Persisted action at 1
I0103 08:56:51.833583 31040 replica.cpp:697] Replica learned APPEND action at position 1
I0103 08:56:51.834722 31042 registrar.cpp:484] Successfully updated the 'registry' in 48.200704ms
I0103 08:56:51.834878 31042 registrar.cpp:370] Successfully recovered registrar
I0103 08:56:51.834960 31049 log.cpp:702] Attempting to truncate the log to 1
I0103 08:56:51.835186 31045 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 08:56:51.835399 31040 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 08:56:51.835444 31042 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 08:56:51.836158 31048 replica.cpp:537] Replica received write request for position 2 from (12838)@172.17.0.2:58080
I0103 08:56:51.858692 31048 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.483431ms
I0103 08:56:51.858738 31048 replica.cpp:712] Persisted action at 2
I0103 08:56:51.859416 31037 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 08:56:51.883746 31037 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.233222ms
I0103 08:56:51.883851 31037 leveldb.cpp:399] Deleting ~1 keys from leveldb took 56065ns
I0103 08:56:51.883885 31037 replica.cpp:712] Persisted action at 2
I0103 08:56:51.883922 31037 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 08:56:51.886452 31016 scheduler.cpp:154] Version: 0.27.0
I0103 08:56:51.887179 31041 scheduler.cpp:236] New master detected at master@172.17.0.2:58080
I0103 08:56:51.888293 31035 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:58080
I0103 08:56:51.890274 31045 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:56:51.890888 31050 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53213
I0103 08:56:51.891155 31050 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 08:56:51.891234 31050 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 08:56:51.891705 31050 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 08:56:51.892251 31046 master.hpp:1659] Sending heartbeat to fb3f5bea-15c3-4782-9424-98aa13afe330-0000
I0103 08:56:51.892277 31041 hierarchical.cpp:260] Added framework fb3f5bea-15c3-4782-9424-98aa13afe330-0000
I0103 08:56:51.892333 31041 hierarchical.cpp:1329] No resources available to allocate!
I0103 08:56:51.892360 31041 hierarchical.cpp:1423] No inverse offers to send out!
I0103 08:56:51.892381 31041 hierarchical.cpp:1079] Performed allocation for 0 slaves in 81038ns
I0103 08:56:51.893512 31048 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:58080
I0103 08:56:51.894034 31048 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:58080
I0103 08:56:51.894932 31044 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 08:56:51.895009 31048 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:58080
I0103 08:56:51.896836 31038 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:56:51.897402 31049 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53214
I0103 08:56:51.897547 31049 master.cpp:2636] Processing REQUEST call for framework fb3f5bea-15c3-4782-9424-98aa13afe330-0000 (default)
I0103 08:56:51.897753 31047 hierarchical.cpp:579] Received resource request from framework fb3f5bea-15c3-4782-9424-98aa13afe330-0000
I0103 08:56:51.898051 31049 master.cpp:930] Master terminating
I0103 08:56:51.898285 31040 hierarchical.cpp:321] Removed framework fb3f5bea-15c3-4782-9424-98aa13afe330-0000
E0103 08:56:51.899785 31045 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (397 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0103 08:56:52.003738 31016 leveldb.cpp:174] Opened db in 97.217872ms
I0103 08:56:52.029258 31016 leveldb.cpp:181] Compacted db in 25.484327ms
I0103 08:56:52.029321 31016 leveldb.cpp:196] Created db iterator in 17969ns
I0103 08:56:52.029341 31016 leveldb.cpp:202] Seeked to beginning of db in 2067ns
I0103 08:56:52.029353 31016 leveldb.cpp:271] Iterated through 0 keys in the db in 208ns
I0103 08:56:52.029388 31016 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 08:56:52.030047 31036 recover.cpp:447] Starting replica recovery
I0103 08:56:52.030360 31036 recover.cpp:473] Replica is in EMPTY status
I0103 08:56:52.031530 31040 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12846)@172.17.0.2:58080
I0103 08:56:52.032995 31035 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 08:56:52.033486 31037 recover.cpp:564] Updating replica status to STARTING
I0103 08:56:52.034054 31038 master.cpp:365] Master 015e28d2-d07b-4b76-8066-2d220284240a (4cd3539047c1) started on 172.17.0.2:58080
I0103 08:56:52.034205 31038 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/HessGh/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/HessGh/master" --zk_session_timeout="10secs"
I0103 08:56:52.034540 31038 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 08:56:52.034556 31038 master.cpp:417] Master only allowing authenticated slaves to register
I0103 08:56:52.034572 31038 credentials.hpp:35] Loading credentials for authentication from '/tmp/HessGh/credentials'
I0103 08:56:52.034857 31038 master.cpp:456] Using default 'crammd5' authenticator
I0103 08:56:52.035004 31038 master.cpp:493] Authorization enabled
I0103 08:56:52.035212 31047 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 08:56:52.035217 31035 whitelist_watcher.cpp:77] No whitelist given
I0103 08:56:52.037068 31040 master.cpp:1629] The newly elected leader is master@172.17.0.2:58080 with id 015e28d2-d07b-4b76-8066-2d220284240a
I0103 08:56:52.037106 31040 master.cpp:1642] Elected as the leading master!
I0103 08:56:52.037147 31040 master.cpp:1387] Recovering from registrar
I0103 08:56:52.037300 31044 registrar.cpp:307] Recovering registrar
I0103 08:56:52.056298 31042 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.488439ms
I0103 08:56:52.056340 31042 replica.cpp:320] Persisted replica status to STARTING
I0103 08:56:52.056610 31046 recover.cpp:473] Replica is in STARTING status
I0103 08:56:52.057646 31043 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12847)@172.17.0.2:58080
I0103 08:56:52.057903 31042 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 08:56:52.058368 31040 recover.cpp:564] Updating replica status to VOTING
I0103 08:56:52.081424 31038 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.847041ms
I0103 08:56:52.081464 31038 replica.cpp:320] Persisted replica status to VOTING
I0103 08:56:52.081596 31039 recover.cpp:578] Successfully joined the Paxos group
I0103 08:56:52.081871 31039 recover.cpp:462] Recover process terminated
I0103 08:56:52.082315 31043 log.cpp:659] Attempting to start the writer
I0103 08:56:52.083477 31048 replica.cpp:493] Replica received implicit promise request from (12848)@172.17.0.2:58080 with proposal 1
I0103 08:56:52.106698 31048 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.186254ms
I0103 08:56:52.106741 31048 replica.cpp:342] Persisted promised to 1
I0103 08:56:52.107496 31036 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 08:56:52.108775 31037 replica.cpp:388] Replica received explicit promise request from (12849)@172.17.0.2:58080 for position 0 with proposal 2
I0103 08:56:52.131650 31037 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.830751ms
I0103 08:56:52.131685 31037 replica.cpp:712] Persisted action at 0
I0103 08:56:52.132820 31040 replica.cpp:537] Replica received write request for position 0 from (12850)@172.17.0.2:58080
I0103 08:56:52.132887 31040 leveldb.cpp:436] Reading position from leveldb took 27640ns
I0103 08:56:52.156769 31040 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.830809ms
I0103 08:56:52.156803 31040 replica.cpp:712] Persisted action at 0
I0103 08:56:52.157449 31039 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 08:56:52.181874 31039 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.389655ms
I0103 08:56:52.181913 31039 replica.cpp:712] Persisted action at 0
I0103 08:56:52.181936 31039 replica.cpp:697] Replica learned NOP action at position 0
I0103 08:56:52.182641 31040 log.cpp:675] Writer started with ending position 0
I0103 08:56:52.183789 31049 leveldb.cpp:436] Reading position from leveldb took 30846ns
I0103 08:56:52.184751 31047 registrar.cpp:340] Successfully fetched the registry (0B) in 147.30496ms
I0103 08:56:52.184864 31047 registrar.cpp:439] Applied 1 operations in 25549ns; attempting to update the 'registry'
I0103 08:56:52.185685 31040 log.cpp:683] Attempting to append 170 bytes to the log
I0103 08:56:52.185853 31047 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 08:56:52.186813 31042 replica.cpp:537] Replica received write request for position 1 from (12851)@172.17.0.2:58080
I0103 08:56:52.217573 31042 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 30.70995ms
I0103 08:56:52.217612 31042 replica.cpp:712] Persisted action at 1
I0103 08:56:52.218349 31050 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 08:56:52.251154 31050 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.737702ms
I0103 08:56:52.251196 31050 replica.cpp:712] Persisted action at 1
I0103 08:56:52.251219 31050 replica.cpp:697] Replica learned APPEND action at position 1
I0103 08:56:52.252380 31046 registrar.cpp:484] Successfully updated the 'registry' in 67.45216ms
I0103 08:56:52.252562 31046 registrar.cpp:370] Successfully recovered registrar
I0103 08:56:52.252727 31042 log.cpp:702] Attempting to truncate the log to 1
I0103 08:56:52.252933 31046 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 08:56:52.253288 31049 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 08:56:52.253310 31035 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 08:56:52.253937 31037 replica.cpp:537] Replica received write request for position 2 from (12852)@172.17.0.2:58080
I0103 08:56:52.292758 31037 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.773429ms
I0103 08:56:52.292795 31037 replica.cpp:712] Persisted action at 2
I0103 08:56:52.293666 31040 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 08:56:52.334614 31040 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.906273ms
I0103 08:56:52.334693 31040 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40276ns
I0103 08:56:52.334719 31040 replica.cpp:712] Persisted action at 2
I0103 08:56:52.334743 31040 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 08:56:52.344507 31016 scheduler.cpp:154] Version: 0.27.0
I0103 08:56:52.345172 31042 scheduler.cpp:236] New master detected at master@172.17.0.2:58080
I0103 08:56:52.346247 31050 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:58080
I0103 08:56:52.348168 31049 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:56:52.348675 31035 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53215
I0103 08:56:52.349081 31035 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 08:56:52.349191 31035 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 08:56:52.349506 31035 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 08:56:52.349938 31038 hierarchical.cpp:260] Added framework 015e28d2-d07b-4b76-8066-2d220284240a-0000
I0103 08:56:52.350014 31038 hierarchical.cpp:1329] No resources available to allocate!
I0103 08:56:52.350062 31038 hierarchical.cpp:1423] No inverse offers to send out!
I0103 08:56:52.350096 31038 hierarchical.cpp:1079] Performed allocation for 0 slaves in 124958ns
I0103 08:56:52.350149 31036 master.hpp:1659] Sending heartbeat to 015e28d2-d07b-4b76-8066-2d220284240a-0000
I0103 08:56:52.351055 31037 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:58080
I0103 08:56:52.351605 31037 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:58080
I0103 08:56:52.352316 31041 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 08:56:52.352396 31039 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:58080
I0103 08:56:52.354225 31042 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:56:52.354678 31036 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:53216
I0103 08:56:52.354923 31036 master.cpp:2636] Processing REQUEST call for framework 015e28d2-d07b-4b76-8066-2d220284240a-0000 (default)
I0103 08:56:52.355084 31040 hierarchical.cpp:579] Received resource request from framework 015e28d2-d07b-4b76-8066-2d220284240a-0000
I0103 08:56:52.355525 31039 master.cpp:930] Master terminating
I0103 08:56:52.355725 31036 hierarchical.cpp:321] Removed framework 015e28d2-d07b-4b76-8066-2d220284240a-0000
E0103 08:56:52.358103 31039 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (456 ms)
[----------] 22 tests from ContentType/SchedulerTest (15055 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (697402 ms total)
[ PASSED ] 913 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization
2 FAILED TESTS
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1451809177-4795
Untagged: mesos-1451809177-4795:latest
Deleted: 327660c48a1dc620a8214955fe25538ee7267d7b9f9f8f4618b82425f8a40b89
Deleted: 28e98d794dbe25f7698d19502b779278eb0aeb28db113bf44b64b74dda16660d
Deleted: dad750a9ff77ac134f382f0d1e847194c01d259dc392fbe9c1ce61b8f43bd296
Deleted: e1eb5c6dabacb735bec684f786cd79b1e29142ffe35cc9fec56be9527ba469f4
Deleted: 7d92fe783c7e1542f513283acb2cece3b503727414fff76d12810481534b3b30
Deleted: bc57ea5411e76e6993c68e70a852da7be471513f3a2deadbe1f0a9830b910587
Deleted: 671cd75d58cf3582b1ef391a07143656b1139b4ec58b89b2e193adc42dc7729c
Deleted: 034f5320afa9292120e1d506ec376a8178d4ad08d0ef7950ca0746f0c343bee1
Deleted: c1dc21088aec58589a5ac1e27f7e278403119af9914c933a3c99b02d2d1f3471
Deleted: 43e4ff7262e2ea4368ba19743a0f457feaf968d5c72b030e033b94e633b70a6f
Deleted: dfccdc8a129b7062dd3e167dc4efbd879e87125175cf9d1943d6c502fe53ffed
Deleted: 525de3b0fc5ba90ac444a785464a9419d09234e01db57d9a60c5a0eea0073652
Deleted: a9779b0df9c47ba3fb167a0e016e84ed3f11a9fd955b86e793efb7c3b865292f
Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10530
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10530/>
------------------------------------------
[...truncated 165361 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (626 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0103 08:00:07.958400 31023 leveldb.cpp:174] Opened db in 191.416532ms
I0103 08:00:08.167613 31023 leveldb.cpp:181] Compacted db in 209.145984ms
I0103 08:00:08.167717 31023 leveldb.cpp:196] Created db iterator in 28212ns
I0103 08:00:08.167737 31023 leveldb.cpp:202] Seeked to beginning of db in 3363ns
I0103 08:00:08.167747 31023 leveldb.cpp:271] Iterated through 0 keys in the db in 297ns
I0103 08:00:08.167798 31023 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 08:00:08.168346 31044 recover.cpp:447] Starting replica recovery
I0103 08:00:08.168570 31044 recover.cpp:473] Replica is in EMPTY status
I0103 08:00:08.169728 31057 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12827)@172.17.0.5:45435
I0103 08:00:08.170269 31050 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 08:00:08.170737 31051 recover.cpp:564] Updating replica status to STARTING
I0103 08:00:08.171924 31055 master.cpp:365] Master f9d0d569-02cb-4420-8ba5-d57d4f3c61c4 (b78012871317) started on 172.17.0.5:45435
I0103 08:00:08.171967 31055 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/GS2GMh/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/GS2GMh/master" --zk_session_timeout="10secs"
I0103 08:00:08.172229 31055 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 08:00:08.172245 31055 master.cpp:417] Master only allowing authenticated slaves to register
I0103 08:00:08.172258 31055 credentials.hpp:35] Loading credentials for authentication from '/tmp/GS2GMh/credentials'
I0103 08:00:08.172518 31055 master.cpp:456] Using default 'crammd5' authenticator
I0103 08:00:08.172688 31055 master.cpp:493] Authorization enabled
I0103 08:00:08.172842 31048 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 08:00:08.172869 31056 whitelist_watcher.cpp:77] No whitelist given
I0103 08:00:08.174540 31050 master.cpp:1629] The newly elected leader is master@172.17.0.5:45435 with id f9d0d569-02cb-4420-8ba5-d57d4f3c61c4
I0103 08:00:08.174573 31050 master.cpp:1642] Elected as the leading master!
I0103 08:00:08.174595 31050 master.cpp:1387] Recovering from registrar
I0103 08:00:08.174783 31053 registrar.cpp:307] Recovering registrar
I0103 08:00:08.202488 31043 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.552205ms
I0103 08:00:08.202545 31043 replica.cpp:320] Persisted replica status to STARTING
I0103 08:00:08.202849 31056 recover.cpp:473] Replica is in STARTING status
I0103 08:00:08.203860 31056 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12828)@172.17.0.5:45435
I0103 08:00:08.204278 31052 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 08:00:08.204777 31044 recover.cpp:564] Updating replica status to VOTING
I0103 08:00:08.227705 31049 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.751706ms
I0103 08:00:08.227747 31049 replica.cpp:320] Persisted replica status to VOTING
I0103 08:00:08.227877 31057 recover.cpp:578] Successfully joined the Paxos group
I0103 08:00:08.228119 31057 recover.cpp:462] Recover process terminated
I0103 08:00:08.228662 31043 log.cpp:659] Attempting to start the writer
I0103 08:00:08.229955 31049 replica.cpp:493] Replica received implicit promise request from (12829)@172.17.0.5:45435 with proposal 1
I0103 08:00:08.252713 31049 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.721653ms
I0103 08:00:08.252758 31049 replica.cpp:342] Persisted promised to 1
I0103 08:00:08.253440 31045 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 08:00:08.255167 31051 replica.cpp:388] Replica received explicit promise request from (12830)@172.17.0.5:45435 for position 0 with proposal 2
I0103 08:00:08.277834 31051 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.586964ms
I0103 08:00:08.277883 31051 replica.cpp:712] Persisted action at 0
I0103 08:00:08.279183 31046 replica.cpp:537] Replica received write request for position 0 from (12831)@172.17.0.5:45435
I0103 08:00:08.279263 31046 leveldb.cpp:436] Reading position from leveldb took 37111ns
I0103 08:00:08.302904 31046 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.590959ms
I0103 08:00:08.302942 31046 replica.cpp:712] Persisted action at 0
I0103 08:00:08.303772 31048 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 08:00:08.328032 31048 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.161587ms
I0103 08:00:08.328073 31048 replica.cpp:712] Persisted action at 0
I0103 08:00:08.328094 31048 replica.cpp:697] Replica learned NOP action at position 0
I0103 08:00:08.328840 31053 log.cpp:675] Writer started with ending position 0
I0103 08:00:08.330284 31052 leveldb.cpp:436] Reading position from leveldb took 34151ns
I0103 08:00:08.331452 31048 registrar.cpp:340] Successfully fetched the registry (0B) in 156.617984ms
I0103 08:00:08.331620 31048 registrar.cpp:439] Applied 1 operations in 43934ns; attempting to update the 'registry'
I0103 08:00:08.332567 31047 log.cpp:683] Attempting to append 170 bytes to the log
I0103 08:00:08.332779 31045 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 08:00:08.333642 31053 replica.cpp:537] Replica received write request for position 1 from (12832)@172.17.0.5:45435
I0103 08:00:08.359645 31053 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 25.94942ms
I0103 08:00:08.359684 31053 replica.cpp:712] Persisted action at 1
I0103 08:00:08.360492 31051 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 08:00:08.391893 31051 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 31.362483ms
I0103 08:00:08.391945 31051 replica.cpp:712] Persisted action at 1
I0103 08:00:08.391983 31051 replica.cpp:697] Replica learned APPEND action at position 1
I0103 08:00:08.393196 31046 registrar.cpp:484] Successfully updated the 'registry' in 61.50272ms
I0103 08:00:08.393399 31046 registrar.cpp:370] Successfully recovered registrar
I0103 08:00:08.393493 31055 log.cpp:702] Attempting to truncate the log to 1
I0103 08:00:08.393771 31053 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 08:00:08.394129 31043 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 08:00:08.394170 31050 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 08:00:08.394958 31054 replica.cpp:537] Replica received write request for position 2 from (12833)@172.17.0.5:45435
I0103 08:00:08.433662 31054 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.659143ms
I0103 08:00:08.433706 31054 replica.cpp:712] Persisted action at 2
I0103 08:00:08.434432 31056 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 08:00:08.467104 31056 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 32.632467ms
I0103 08:00:08.467185 31056 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40718ns
I0103 08:00:08.467211 31056 replica.cpp:712] Persisted action at 2
I0103 08:00:08.467233 31056 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 08:00:08.476002 31023 scheduler.cpp:154] Version: 0.27.0
I0103 08:00:08.476685 31048 scheduler.cpp:236] New master detected at master@172.17.0.5:45435
I0103 08:00:08.477668 31047 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:45435
I0103 08:00:08.479421 31053 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:00:08.479874 31046 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:53395
I0103 08:00:08.480044 31046 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 08:00:08.480103 31046 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 08:00:08.480331 31046 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 08:00:08.480762 31054 hierarchical.cpp:260] Added framework f9d0d569-02cb-4420-8ba5-d57d4f3c61c4-0000
I0103 08:00:08.480828 31056 master.hpp:1659] Sending heartbeat to f9d0d569-02cb-4420-8ba5-d57d4f3c61c4-0000
I0103 08:00:08.480927 31054 hierarchical.cpp:1329] No resources available to allocate!
I0103 08:00:08.480965 31054 hierarchical.cpp:1423] No inverse offers to send out!
I0103 08:00:08.481001 31054 hierarchical.cpp:1079] Performed allocation for 0 slaves in 134993ns
I0103 08:00:08.481798 31052 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:45435
I0103 08:00:08.482305 31052 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:45435
I0103 08:00:08.483131 31053 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 08:00:08.483245 31052 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:45435
I0103 08:00:08.485139 31046 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:00:08.485666 31044 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:53396
I0103 08:00:08.485797 31044 master.cpp:2636] Processing REQUEST call for framework f9d0d569-02cb-4420-8ba5-d57d4f3c61c4-0000 (default)
I0103 08:00:08.486009 31047 hierarchical.cpp:579] Received resource request from framework f9d0d569-02cb-4420-8ba5-d57d4f3c61c4-0000
I0103 08:00:08.486296 31048 master.cpp:930] Master terminating
I0103 08:00:08.486542 31042 hierarchical.cpp:321] Removed framework f9d0d569-02cb-4420-8ba5-d57d4f3c61c4-0000
E0103 08:00:08.487849 31043 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (727 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0103 08:00:08.610317 31023 leveldb.cpp:174] Opened db in 115.891089ms
I0103 08:00:08.660559 31023 leveldb.cpp:181] Compacted db in 50.197707ms
I0103 08:00:08.660645 31023 leveldb.cpp:196] Created db iterator in 44839ns
I0103 08:00:08.660667 31023 leveldb.cpp:202] Seeked to beginning of db in 2015ns
I0103 08:00:08.660678 31023 leveldb.cpp:271] Iterated through 0 keys in the db in 412ns
I0103 08:00:08.660718 31023 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 08:00:08.661274 31046 recover.cpp:447] Starting replica recovery
I0103 08:00:08.661640 31046 recover.cpp:473] Replica is in EMPTY status
I0103 08:00:08.662685 31046 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12841)@172.17.0.5:45435
I0103 08:00:08.663106 31055 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 08:00:08.663472 31045 recover.cpp:564] Updating replica status to STARTING
I0103 08:00:08.664139 31052 master.cpp:365] Master ea0e792e-5701-4e89-98f4-a00a14fd73c8 (b78012871317) started on 172.17.0.5:45435
I0103 08:00:08.664161 31052 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/vmIYYV/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/vmIYYV/master" --zk_session_timeout="10secs"
I0103 08:00:08.664408 31052 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 08:00:08.664420 31052 master.cpp:417] Master only allowing authenticated slaves to register
I0103 08:00:08.664427 31052 credentials.hpp:35] Loading credentials for authentication from '/tmp/vmIYYV/credentials'
I0103 08:00:08.664651 31052 master.cpp:456] Using default 'crammd5' authenticator
I0103 08:00:08.664759 31052 master.cpp:493] Authorization enabled
I0103 08:00:08.664911 31044 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 08:00:08.664937 31053 whitelist_watcher.cpp:77] No whitelist given
I0103 08:00:08.666646 31046 master.cpp:1629] The newly elected leader is master@172.17.0.5:45435 with id ea0e792e-5701-4e89-98f4-a00a14fd73c8
I0103 08:00:08.666683 31046 master.cpp:1642] Elected as the leading master!
I0103 08:00:08.666702 31046 master.cpp:1387] Recovering from registrar
I0103 08:00:08.666851 31048 registrar.cpp:307] Recovering registrar
I0103 08:00:08.695274 31057 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.684859ms
I0103 08:00:08.695322 31057 replica.cpp:320] Persisted replica status to STARTING
I0103 08:00:08.695554 31057 recover.cpp:473] Replica is in STARTING status
I0103 08:00:08.696557 31046 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12842)@172.17.0.5:45435
I0103 08:00:08.696779 31047 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 08:00:08.697190 31057 recover.cpp:564] Updating replica status to VOTING
I0103 08:00:08.737790 31048 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 40.455171ms
I0103 08:00:08.737889 31048 replica.cpp:320] Persisted replica status to VOTING
I0103 08:00:08.738149 31051 recover.cpp:578] Successfully joined the Paxos group
I0103 08:00:08.738400 31051 recover.cpp:462] Recover process terminated
I0103 08:00:08.739013 31055 log.cpp:659] Attempting to start the writer
I0103 08:00:08.740310 31056 replica.cpp:493] Replica received implicit promise request from (12843)@172.17.0.5:45435 with proposal 1
I0103 08:00:08.778928 31056 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.561094ms
I0103 08:00:08.779011 31056 replica.cpp:342] Persisted promised to 1
I0103 08:00:08.779819 31043 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 08:00:08.781096 31043 replica.cpp:388] Replica received explicit promise request from (12844)@172.17.0.5:45435 for position 0 with proposal 2
I0103 08:00:08.820572 31043 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.419219ms
I0103 08:00:08.820711 31043 replica.cpp:712] Persisted action at 0
I0103 08:00:08.821876 31056 replica.cpp:537] Replica received write request for position 0 from (12845)@172.17.0.5:45435
I0103 08:00:08.821951 31056 leveldb.cpp:436] Reading position from leveldb took 38386ns
I0103 08:00:08.862565 31056 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.557047ms
I0103 08:00:08.862701 31056 replica.cpp:712] Persisted action at 0
I0103 08:00:08.863461 31049 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 08:00:08.904299 31049 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.796594ms
I0103 08:00:08.904364 31049 replica.cpp:712] Persisted action at 0
I0103 08:00:08.904391 31049 replica.cpp:697] Replica learned NOP action at position 0
I0103 08:00:08.905117 31044 log.cpp:675] Writer started with ending position 0
I0103 08:00:08.906714 31054 leveldb.cpp:436] Reading position from leveldb took 69056ns
I0103 08:00:08.907791 31057 registrar.cpp:340] Successfully fetched the registry (0B) in 240.88704ms
I0103 08:00:08.907919 31057 registrar.cpp:439] Applied 1 operations in 35855ns; attempting to update the 'registry'
I0103 08:00:08.908639 31049 log.cpp:683] Attempting to append 170 bytes to the log
I0103 08:00:08.908787 31043 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 08:00:08.909498 31055 replica.cpp:537] Replica received write request for position 1 from (12846)@172.17.0.5:45435
I0103 08:00:08.946055 31055 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.517125ms
I0103 08:00:08.946095 31055 replica.cpp:712] Persisted action at 1
I0103 08:00:08.946826 31050 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 08:00:08.987946 31050 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 41.085233ms
I0103 08:00:08.987993 31050 replica.cpp:712] Persisted action at 1
I0103 08:00:08.988018 31050 replica.cpp:697] Replica learned APPEND action at position 1
I0103 08:00:08.989183 31055 registrar.cpp:484] Successfully updated the 'registry' in 81.19424ms
I0103 08:00:08.989380 31055 registrar.cpp:370] Successfully recovered registrar
I0103 08:00:08.989667 31048 log.cpp:702] Attempting to truncate the log to 1
I0103 08:00:08.989809 31047 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 08:00:08.990200 31043 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 08:00:08.990288 31056 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 08:00:08.990803 31042 replica.cpp:537] Replica received write request for position 2 from (12847)@172.17.0.5:45435
I0103 08:00:09.029706 31042 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.857357ms
I0103 08:00:09.029750 31042 replica.cpp:712] Persisted action at 2
I0103 08:00:09.030525 31055 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 08:00:09.071470 31055 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.901572ms
I0103 08:00:09.071553 31055 leveldb.cpp:399] Deleting ~1 keys from leveldb took 43276ns
I0103 08:00:09.071589 31055 replica.cpp:712] Persisted action at 2
I0103 08:00:09.071638 31055 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 08:00:09.081853 31023 scheduler.cpp:154] Version: 0.27.0
I0103 08:00:09.082952 31051 scheduler.cpp:236] New master detected at master@172.17.0.5:45435
I0103 08:00:09.084180 31050 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:45435
I0103 08:00:09.086302 31056 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:00:09.086869 31045 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:53397
I0103 08:00:09.087235 31045 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 08:00:09.087319 31045 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 08:00:09.087678 31045 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 08:00:09.088089 31042 hierarchical.cpp:260] Added framework ea0e792e-5701-4e89-98f4-a00a14fd73c8-0000
I0103 08:00:09.088155 31042 hierarchical.cpp:1329] No resources available to allocate!
I0103 08:00:09.088186 31042 hierarchical.cpp:1423] No inverse offers to send out!
I0103 08:00:09.088207 31051 master.hpp:1659] Sending heartbeat to ea0e792e-5701-4e89-98f4-a00a14fd73c8-0000
I0103 08:00:09.088208 31042 hierarchical.cpp:1079] Performed allocation for 0 slaves in 93953ns
I0103 08:00:09.089041 31046 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:45435
I0103 08:00:09.089596 31046 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:45435
I0103 08:00:09.090219 31055 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 08:00:09.090291 31046 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:45435
I0103 08:00:09.091850 31051 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 08:00:09.092218 31042 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:53398
I0103 08:00:09.092455 31042 master.cpp:2636] Processing REQUEST call for framework ea0e792e-5701-4e89-98f4-a00a14fd73c8-0000 (default)
I0103 08:00:09.092686 31055 hierarchical.cpp:579] Received resource request from framework ea0e792e-5701-4e89-98f4-a00a14fd73c8-0000
I0103 08:00:09.093042 31043 master.cpp:930] Master terminating
I0103 08:00:09.093273 31045 hierarchical.cpp:321] Removed framework ea0e792e-5701-4e89-98f4-a00a14fd73c8-0000
E0103 08:00:09.094825 31047 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (607 ms)
[----------] 22 tests from ContentType/SchedulerTest (15644 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (733194 ms total)
[ PASSED ] 913 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization
2 FAILED TESTS
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1451805581-18682
Untagged: mesos-1451805581-18682:latest
Deleted: 70f1eb252c32f8d11b5b5247043c6ada607be4d5b46efab1c610dd7dc28d95a2
Deleted: 89eaeb7751883c6618368f18c6cb46047ecdf83f2abeafb901aba3279a2591c6
Deleted: 43dda9d6cc094349336bd2d2ca4391a3066c4ba9db408cd61e8e42aa5e243c11
Deleted: 1f4b772c453785bfab452bb9a67386fabf319310dce939ef6bba36991db98b23
Deleted: 9c9ac7065022d249381f1286be781f0d9dae33ce37e762448e7f22ea441d29df
Deleted: 19cadc96ab3b129828ba2f4f6ff96fd02f2f1843ab039935cab8b0cd89a2499f
Deleted: 754cfeda366d1f9a73c4cb96464bd0a7afae5fdcdc36658bc333ab16b26ef5cc
Deleted: 1e7e9e84509fb32c635d4eead5fc3fc7a075eb8a2c439b500158160253f3b74f
Deleted: 6ace36d52803e29b195e151b7de77e2aad5fadfe5ba9d70225a5e8eaf11f6efb
Deleted: 3789dd283246c87b16cc4e0421bcc24da8c69a8a674754df6af1533fe972febe
Deleted: 6909fa490b8a8a5e5643f2f53be8c96dae7c3bf8be17cfaeb9aa4b1a6771d563
Deleted: 535767f52afd7828730daf2d503e88ab908699148285d16f5b75faf1801e1d73
Deleted: a67ec3ec0ee77e8fa5226aebfc57ac3b3460fe3d06361e50fb1f9bcec0c9c00b
Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10529
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10529/>
------------------------------------------
[...truncated 165508 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (717 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0103 04:54:48.151000 31022 leveldb.cpp:174] Opened db in 125.680992ms
I0103 04:54:48.187516 31022 leveldb.cpp:181] Compacted db in 36.472174ms
I0103 04:54:48.187584 31022 leveldb.cpp:196] Created db iterator in 19552ns
I0103 04:54:48.187634 31022 leveldb.cpp:202] Seeked to beginning of db in 30812ns
I0103 04:54:48.187671 31022 leveldb.cpp:271] Iterated through 0 keys in the db in 362ns
I0103 04:54:48.187711 31022 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 04:54:48.188172 31054 recover.cpp:447] Starting replica recovery
I0103 04:54:48.188532 31042 recover.cpp:473] Replica is in EMPTY status
I0103 04:54:48.189749 31052 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12834)@172.17.0.5:54185
I0103 04:54:48.190209 31050 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 04:54:48.190721 31056 recover.cpp:564] Updating replica status to STARTING
I0103 04:54:48.191468 31055 master.cpp:365] Master 14b8f132-7e86-474e-8688-46129f4260b4 (68c319a7463c) started on 172.17.0.5:54185
I0103 04:54:48.191493 31055 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/oJfW3b/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/oJfW3b/master" --zk_session_timeout="10secs"
I0103 04:54:48.191891 31055 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 04:54:48.191905 31055 master.cpp:417] Master only allowing authenticated slaves to register
I0103 04:54:48.191913 31055 credentials.hpp:35] Loading credentials for authentication from '/tmp/oJfW3b/credentials'
I0103 04:54:48.192178 31055 master.cpp:456] Using default 'crammd5' authenticator
I0103 04:54:48.192315 31055 master.cpp:493] Authorization enabled
I0103 04:54:48.192494 31045 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 04:54:48.192539 31051 whitelist_watcher.cpp:77] No whitelist given
I0103 04:54:48.194247 31056 master.cpp:1629] The newly elected leader is master@172.17.0.5:54185 with id 14b8f132-7e86-474e-8688-46129f4260b4
I0103 04:54:48.194283 31056 master.cpp:1642] Elected as the leading master!
I0103 04:54:48.194300 31056 master.cpp:1387] Recovering from registrar
I0103 04:54:48.194422 31050 registrar.cpp:307] Recovering registrar
I0103 04:54:48.228796 31046 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.900024ms
I0103 04:54:48.228828 31046 replica.cpp:320] Persisted replica status to STARTING
I0103 04:54:48.229053 31055 recover.cpp:473] Replica is in STARTING status
I0103 04:54:48.229854 31051 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12835)@172.17.0.5:54185
I0103 04:54:48.230185 31055 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 04:54:48.230628 31041 recover.cpp:564] Updating replica status to VOTING
I0103 04:54:48.270797 31049 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.97065ms
I0103 04:54:48.270843 31049 replica.cpp:320] Persisted replica status to VOTING
I0103 04:54:48.270979 31049 recover.cpp:578] Successfully joined the Paxos group
I0103 04:54:48.271193 31049 recover.cpp:462] Recover process terminated
I0103 04:54:48.271540 31048 log.cpp:659] Attempting to start the writer
I0103 04:54:48.272876 31054 replica.cpp:493] Replica received implicit promise request from (12836)@172.17.0.5:54185 with proposal 1
I0103 04:54:48.312429 31054 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.515156ms
I0103 04:54:48.312468 31054 replica.cpp:342] Persisted promised to 1
I0103 04:54:48.313297 31045 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 04:54:48.314590 31056 replica.cpp:388] Replica received explicit promise request from (12837)@172.17.0.5:54185 for position 0 with proposal 2
I0103 04:54:48.354203 31056 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.534785ms
I0103 04:54:48.354249 31056 replica.cpp:712] Persisted action at 0
I0103 04:54:48.355717 31054 replica.cpp:537] Replica received write request for position 0 from (12838)@172.17.0.5:54185
I0103 04:54:48.355784 31054 leveldb.cpp:436] Reading position from leveldb took 29us
I0103 04:54:48.396193 31054 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.35855ms
I0103 04:54:48.396239 31054 replica.cpp:712] Persisted action at 0
I0103 04:54:48.397045 31052 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 04:54:48.437829 31052 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.741298ms
I0103 04:54:48.437870 31052 replica.cpp:712] Persisted action at 0
I0103 04:54:48.437891 31052 replica.cpp:697] Replica learned NOP action at position 0
I0103 04:54:48.438717 31050 log.cpp:675] Writer started with ending position 0
I0103 04:54:48.439898 31043 leveldb.cpp:436] Reading position from leveldb took 34212ns
I0103 04:54:48.440997 31056 registrar.cpp:340] Successfully fetched the registry (0B) in 246528us
I0103 04:54:48.441134 31056 registrar.cpp:439] Applied 1 operations in 28954ns; attempting to update the 'registry'
I0103 04:54:48.442013 31044 log.cpp:683] Attempting to append 170 bytes to the log
I0103 04:54:48.442147 31047 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 04:54:48.443045 31053 replica.cpp:537] Replica received write request for position 1 from (12839)@172.17.0.5:54185
I0103 04:54:48.487854 31053 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 44.762101ms
I0103 04:54:48.487893 31053 replica.cpp:712] Persisted action at 1
I0103 04:54:48.488654 31042 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 04:54:48.529721 31042 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 41.028046ms
I0103 04:54:48.529759 31042 replica.cpp:712] Persisted action at 1
I0103 04:54:48.529781 31042 replica.cpp:697] Replica learned APPEND action at position 1
I0103 04:54:48.530800 31054 registrar.cpp:484] Successfully updated the 'registry' in 89.595136ms
I0103 04:54:48.530989 31054 registrar.cpp:370] Successfully recovered registrar
I0103 04:54:48.531153 31050 log.cpp:702] Attempting to truncate the log to 1
I0103 04:54:48.531368 31047 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 04:54:48.531774 31041 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 04:54:48.531800 31045 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 04:54:48.532383 31051 replica.cpp:537] Replica received write request for position 2 from (12840)@172.17.0.5:54185
I0103 04:54:48.568186 31051 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 35.758049ms
I0103 04:54:48.568225 31051 replica.cpp:712] Persisted action at 2
I0103 04:54:48.569103 31056 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 04:54:48.610113 31056 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.970787ms
I0103 04:54:48.610203 31056 leveldb.cpp:399] Deleting ~1 keys from leveldb took 44556ns
I0103 04:54:48.610227 31056 replica.cpp:712] Persisted action at 2
I0103 04:54:48.610249 31056 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 04:54:48.613072 31022 scheduler.cpp:154] Version: 0.27.0
I0103 04:54:48.613662 31048 scheduler.cpp:236] New master detected at master@172.17.0.5:54185
I0103 04:54:48.614997 31052 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:54185
I0103 04:54:48.616925 31048 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 04:54:48.617473 31050 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:58533
I0103 04:54:48.617733 31050 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 04:54:48.617799 31050 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 04:54:48.618109 31050 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 04:54:48.618623 31042 master.hpp:1659] Sending heartbeat to 14b8f132-7e86-474e-8688-46129f4260b4-0000
I0103 04:54:48.618595 31047 hierarchical.cpp:260] Added framework 14b8f132-7e86-474e-8688-46129f4260b4-0000
I0103 04:54:48.618947 31047 hierarchical.cpp:1329] No resources available to allocate!
I0103 04:54:48.618999 31047 hierarchical.cpp:1423] No inverse offers to send out!
I0103 04:54:48.619035 31047 hierarchical.cpp:1079] Performed allocation for 0 slaves in 130709ns
I0103 04:54:48.619544 31048 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:54185
I0103 04:54:48.620106 31048 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:54185
I0103 04:54:48.620817 31050 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 04:54:48.620915 31056 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:54185
I0103 04:54:48.622745 31043 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 04:54:48.623164 31053 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:58534
I0103 04:54:48.623302 31053 master.cpp:2636] Processing REQUEST call for framework 14b8f132-7e86-474e-8688-46129f4260b4-0000 (default)
I0103 04:54:48.623586 31045 hierarchical.cpp:579] Received resource request from framework 14b8f132-7e86-474e-8688-46129f4260b4-0000
I0103 04:54:48.623963 31042 master.cpp:930] Master terminating
I0103 04:54:48.624307 31055 hierarchical.cpp:321] Removed framework 14b8f132-7e86-474e-8688-46129f4260b4-0000
E0103 04:54:48.625849 31049 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (607 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0103 04:54:48.743753 31022 leveldb.cpp:174] Opened db in 111.811218ms
I0103 04:54:48.785892 31022 leveldb.cpp:181] Compacted db in 42.096886ms
I0103 04:54:48.785955 31022 leveldb.cpp:196] Created db iterator in 17540ns
I0103 04:54:48.785976 31022 leveldb.cpp:202] Seeked to beginning of db in 2140ns
I0103 04:54:48.785989 31022 leveldb.cpp:271] Iterated through 0 keys in the db in 350ns
I0103 04:54:48.786025 31022 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 04:54:48.786469 31052 recover.cpp:447] Starting replica recovery
I0103 04:54:48.786823 31052 recover.cpp:473] Replica is in EMPTY status
I0103 04:54:48.788072 31047 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12848)@172.17.0.5:54185
I0103 04:54:48.788589 31053 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 04:54:48.789120 31044 recover.cpp:564] Updating replica status to STARTING
I0103 04:54:48.790074 31044 master.cpp:365] Master 63c76e0e-8787-45d5-89e7-d30f38386a4f (68c319a7463c) started on 172.17.0.5:54185
I0103 04:54:48.790101 31044 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/qvidFY/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/qvidFY/master" --zk_session_timeout="10secs"
I0103 04:54:48.790436 31044 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 04:54:48.790449 31044 master.cpp:417] Master only allowing authenticated slaves to register
I0103 04:54:48.790457 31044 credentials.hpp:35] Loading credentials for authentication from '/tmp/qvidFY/credentials'
I0103 04:54:48.790760 31044 master.cpp:456] Using default 'crammd5' authenticator
I0103 04:54:48.790896 31044 master.cpp:493] Authorization enabled
I0103 04:54:48.791090 31049 whitelist_watcher.cpp:77] No whitelist given
I0103 04:54:48.791128 31054 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 04:54:48.792984 31046 master.cpp:1629] The newly elected leader is master@172.17.0.5:54185 with id 63c76e0e-8787-45d5-89e7-d30f38386a4f
I0103 04:54:48.793022 31046 master.cpp:1642] Elected as the leading master!
I0103 04:54:48.793047 31046 master.cpp:1387] Recovering from registrar
I0103 04:54:48.793211 31055 registrar.cpp:307] Recovering registrar
I0103 04:54:48.810662 31056 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.320107ms
I0103 04:54:48.810699 31056 replica.cpp:320] Persisted replica status to STARTING
I0103 04:54:48.810931 31042 recover.cpp:473] Replica is in STARTING status
I0103 04:54:48.811825 31047 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12849)@172.17.0.5:54185
I0103 04:54:48.812216 31046 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 04:54:48.812649 31049 recover.cpp:564] Updating replica status to VOTING
I0103 04:54:48.835733 31042 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.805801ms
I0103 04:54:48.835772 31042 replica.cpp:320] Persisted replica status to VOTING
I0103 04:54:48.835896 31047 recover.cpp:578] Successfully joined the Paxos group
I0103 04:54:48.836127 31047 recover.cpp:462] Recover process terminated
I0103 04:54:48.836534 31053 log.cpp:659] Attempting to start the writer
I0103 04:54:48.837744 31042 replica.cpp:493] Replica received implicit promise request from (12850)@172.17.0.5:54185 with proposal 1
I0103 04:54:48.860923 31042 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.143379ms
I0103 04:54:48.860960 31042 replica.cpp:342] Persisted promised to 1
I0103 04:54:48.861769 31049 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 04:54:48.863104 31053 replica.cpp:388] Replica received explicit promise request from (12851)@172.17.0.5:54185 for position 0 with proposal 2
I0103 04:54:48.897011 31053 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 33.859147ms
I0103 04:54:48.897049 31053 replica.cpp:712] Persisted action at 0
I0103 04:54:48.898356 31050 replica.cpp:537] Replica received write request for position 0 from (12852)@172.17.0.5:54185
I0103 04:54:48.898429 31050 leveldb.cpp:436] Reading position from leveldb took 30084ns
I0103 04:54:48.939045 31050 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.560483ms
I0103 04:54:48.939091 31050 replica.cpp:712] Persisted action at 0
I0103 04:54:48.939951 31054 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 04:54:48.980700 31054 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.616733ms
I0103 04:54:48.980746 31054 replica.cpp:712] Persisted action at 0
I0103 04:54:48.980770 31054 replica.cpp:697] Replica learned NOP action at position 0
I0103 04:54:48.981587 31042 log.cpp:675] Writer started with ending position 0
I0103 04:54:48.982847 31051 leveldb.cpp:436] Reading position from leveldb took 29646ns
I0103 04:54:48.983844 31048 registrar.cpp:340] Successfully fetched the registry (0B) in 190.578944ms
I0103 04:54:48.983981 31048 registrar.cpp:439] Applied 1 operations in 30544ns; attempting to update the 'registry'
I0103 04:54:48.984849 31046 log.cpp:683] Attempting to append 170 bytes to the log
I0103 04:54:48.985008 31049 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 04:54:48.985894 31053 replica.cpp:537] Replica received write request for position 1 from (12853)@172.17.0.5:54185
I0103 04:54:49.027461 31053 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 41.521276ms
I0103 04:54:49.027499 31053 replica.cpp:712] Persisted action at 1
I0103 04:54:49.028332 31055 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 04:54:49.072582 31055 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 44.208831ms
I0103 04:54:49.072659 31055 replica.cpp:712] Persisted action at 1
I0103 04:54:49.072697 31055 replica.cpp:697] Replica learned APPEND action at position 1
I0103 04:54:49.073884 31050 registrar.cpp:484] Successfully updated the 'registry' in 89.823232ms
I0103 04:54:49.074059 31050 registrar.cpp:370] Successfully recovered registrar
I0103 04:54:49.074156 31051 log.cpp:702] Attempting to truncate the log to 1
I0103 04:54:49.074342 31045 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 04:54:49.074700 31042 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 04:54:49.074857 31046 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 04:54:49.075417 31044 replica.cpp:537] Replica received write request for position 2 from (12854)@172.17.0.5:54185
I0103 04:54:49.114470 31044 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 39.008334ms
I0103 04:54:49.114514 31044 replica.cpp:712] Persisted action at 2
I0103 04:54:49.115530 31043 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 04:54:49.156183 31043 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.61016ms
I0103 04:54:49.156271 31043 leveldb.cpp:399] Deleting ~1 keys from leveldb took 43859ns
I0103 04:54:49.156296 31043 replica.cpp:712] Persisted action at 2
I0103 04:54:49.156318 31043 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 04:54:49.166015 31022 scheduler.cpp:154] Version: 0.27.0
I0103 04:54:49.166800 31051 scheduler.cpp:236] New master detected at master@172.17.0.5:54185
I0103 04:54:49.168038 31041 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:54185
I0103 04:54:49.170081 31052 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 04:54:49.170570 31049 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:58535
I0103 04:54:49.170989 31049 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 04:54:49.171056 31049 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 04:54:49.171389 31049 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 04:54:49.171870 31050 hierarchical.cpp:260] Added framework 63c76e0e-8787-45d5-89e7-d30f38386a4f-0000
I0103 04:54:49.171958 31050 hierarchical.cpp:1329] No resources available to allocate!
I0103 04:54:49.172011 31050 hierarchical.cpp:1423] No inverse offers to send out!
I0103 04:54:49.172077 31050 hierarchical.cpp:1079] Performed allocation for 0 slaves in 172846ns
I0103 04:54:49.172039 31042 master.hpp:1659] Sending heartbeat to 63c76e0e-8787-45d5-89e7-d30f38386a4f-0000
I0103 04:54:49.173158 31041 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:54185
I0103 04:54:49.173861 31041 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:54185
I0103 04:54:49.174579 31041 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:54185
I0103 04:54:49.174643 31043 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 04:54:49.176318 31056 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 04:54:49.176868 31046 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:58536
I0103 04:54:49.177136 31046 master.cpp:2636] Processing REQUEST call for framework 63c76e0e-8787-45d5-89e7-d30f38386a4f-0000 (default)
I0103 04:54:49.177316 31049 hierarchical.cpp:579] Received resource request from framework 63c76e0e-8787-45d5-89e7-d30f38386a4f-0000
I0103 04:54:49.177633 31049 master.cpp:930] Master terminating
I0103 04:54:49.177855 31052 hierarchical.cpp:321] Removed framework 63c76e0e-8787-45d5-89e7-d30f38386a4f-0000
E0103 04:54:49.179108 31042 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (554 ms)
[----------] 22 tests from ContentType/SchedulerTest (16423 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (715288 ms total)
[ PASSED ] 913 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization
2 FAILED TESTS
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1451794175-14078
Untagged: mesos-1451794175-14078:latest
Deleted: 3f2c40ea8c02ae68016135524eb3c465dc7ea448e013e99ae5efb0d5591db8d3
Deleted: 2ce91a3b4f4c0363e320402e08ab25d10436dff57fe81de34950b5267d1a430c
Deleted: 9a2ef9f90904e4a3752f67d0463ec5e02051c4b07090ddacca16ce0746906dd3
Deleted: fe65dba2b5272d373d3db4cdce34ef79e0246535b96d70eb652f4de37ac42b3f
Deleted: 76ab13865b62540bc70d411ddc3b32828fc75ecabfd508a5815623520521f0a7
Deleted: 6d2bda5e33f41e2f32bc9b4c532ebdccd9f3873e2255de2476c9509e355fd386
Deleted: f19178cc6660c7af02fe78007479de9ff5466127a02089330a27ec68d7e5f6c4
Deleted: 7f425888e3f4c2cf0574619135e5ab7b2fecb03ce0c281c9d6b814595728020a
Deleted: edb8d8fd115f8fec29335387f6a84604d0bf1ddaab95a8958872180241cf03c0
Deleted: 702345a61adfecaea6e75702f92087f81e05cfedebc6021b3e3092fd60627d14
Deleted: a39dea209330ec3dafc0a25a798dce25cbbd11ffc024ee6c08a225ab1edf9dd3
Deleted: 6d583766af4280eb926996add90884cc0d7bc9fa72924e793fa3a7a726f1e002
Deleted: e0f61c4a0b1481729e6a08f123d4bf712b7522c54f86649148c005a95d6c9db8
Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10528
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10528/>
------------------------------------------
[...truncated 165320 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (689 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0103 03:50:09.630249 31030 leveldb.cpp:174] Opened db in 100.823589ms
I0103 03:50:09.667826 31030 leveldb.cpp:181] Compacted db in 37.533269ms
I0103 03:50:09.667891 31030 leveldb.cpp:196] Created db iterator in 19619ns
I0103 03:50:09.667911 31030 leveldb.cpp:202] Seeked to beginning of db in 1948ns
I0103 03:50:09.667922 31030 leveldb.cpp:271] Iterated through 0 keys in the db in 357ns
I0103 03:50:09.667964 31030 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 03:50:09.668560 31058 recover.cpp:447] Starting replica recovery
I0103 03:50:09.668819 31058 recover.cpp:473] Replica is in EMPTY status
I0103 03:50:09.670148 31049 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12825)@172.17.0.2:45080
I0103 03:50:09.670559 31053 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 03:50:09.671200 31054 recover.cpp:564] Updating replica status to STARTING
I0103 03:50:09.672320 31064 master.cpp:365] Master ae0d364f-3eed-4b2f-abc5-e7b68f2ec7ea (c14b220ac019) started on 172.17.0.2:45080
I0103 03:50:09.672348 31064 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/mv14gI/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/mv14gI/master" --zk_session_timeout="10secs"
I0103 03:50:09.672608 31064 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 03:50:09.672619 31064 master.cpp:417] Master only allowing authenticated slaves to register
I0103 03:50:09.672626 31064 credentials.hpp:35] Loading credentials for authentication from '/tmp/mv14gI/credentials'
I0103 03:50:09.672827 31064 master.cpp:456] Using default 'crammd5' authenticator
I0103 03:50:09.672943 31064 master.cpp:493] Authorization enabled
I0103 03:50:09.673094 31057 whitelist_watcher.cpp:77] No whitelist given
I0103 03:50:09.673161 31051 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 03:50:09.674760 31063 master.cpp:1629] The newly elected leader is master@172.17.0.2:45080 with id ae0d364f-3eed-4b2f-abc5-e7b68f2ec7ea
I0103 03:50:09.674798 31063 master.cpp:1642] Elected as the leading master!
I0103 03:50:09.674815 31063 master.cpp:1387] Recovering from registrar
I0103 03:50:09.675003 31051 registrar.cpp:307] Recovering registrar
I0103 03:50:09.709450 31058 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.906244ms
I0103 03:50:09.709492 31058 replica.cpp:320] Persisted replica status to STARTING
I0103 03:50:09.709734 31058 recover.cpp:473] Replica is in STARTING status
I0103 03:50:09.710939 31052 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12826)@172.17.0.2:45080
I0103 03:50:09.711546 31055 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 03:50:09.712193 31050 recover.cpp:564] Updating replica status to VOTING
I0103 03:50:09.742851 31057 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.454109ms
I0103 03:50:09.742892 31057 replica.cpp:320] Persisted replica status to VOTING
I0103 03:50:09.743024 31057 recover.cpp:578] Successfully joined the Paxos group
I0103 03:50:09.743398 31057 recover.cpp:462] Recover process terminated
I0103 03:50:09.744112 31049 log.cpp:659] Attempting to start the writer
I0103 03:50:09.745601 31049 replica.cpp:493] Replica received implicit promise request from (12827)@172.17.0.2:45080 with proposal 1
I0103 03:50:09.776218 31049 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.573827ms
I0103 03:50:09.776257 31049 replica.cpp:342] Persisted promised to 1
I0103 03:50:09.777022 31063 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 03:50:09.778811 31055 replica.cpp:388] Replica received explicit promise request from (12828)@172.17.0.2:45080 for position 0 with proposal 2
I0103 03:50:09.809659 31055 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 30.799524ms
I0103 03:50:09.809695 31055 replica.cpp:712] Persisted action at 0
I0103 03:50:09.810907 31063 replica.cpp:537] Replica received write request for position 0 from (12829)@172.17.0.2:45080
I0103 03:50:09.810978 31063 leveldb.cpp:436] Reading position from leveldb took 31944ns
I0103 03:50:09.843155 31063 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 32.102448ms
I0103 03:50:09.843194 31063 replica.cpp:712] Persisted action at 0
I0103 03:50:09.843897 31063 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 03:50:09.876575 31063 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.558269ms
I0103 03:50:09.876613 31063 replica.cpp:712] Persisted action at 0
I0103 03:50:09.876636 31063 replica.cpp:697] Replica learned NOP action at position 0
I0103 03:50:09.877322 31051 log.cpp:675] Writer started with ending position 0
I0103 03:50:09.878536 31056 leveldb.cpp:436] Reading position from leveldb took 32254ns
I0103 03:50:09.879601 31058 registrar.cpp:340] Successfully fetched the registry (0B) in 204.539904ms
I0103 03:50:09.879714 31058 registrar.cpp:439] Applied 1 operations in 25757ns; attempting to update the 'registry'
I0103 03:50:09.880579 31064 log.cpp:683] Attempting to append 170 bytes to the log
I0103 03:50:09.880736 31055 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 03:50:09.881664 31053 replica.cpp:537] Replica received write request for position 1 from (12830)@172.17.0.2:45080
I0103 03:50:09.918355 31053 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.646972ms
I0103 03:50:09.918400 31053 replica.cpp:712] Persisted action at 1
I0103 03:50:09.919209 31058 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 03:50:09.951810 31058 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.559099ms
I0103 03:50:09.951849 31058 replica.cpp:712] Persisted action at 1
I0103 03:50:09.951871 31058 replica.cpp:697] Replica learned APPEND action at position 1
I0103 03:50:09.953004 31051 registrar.cpp:484] Successfully updated the 'registry' in 73.21728ms
I0103 03:50:09.953203 31051 registrar.cpp:370] Successfully recovered registrar
I0103 03:50:09.953294 31053 log.cpp:702] Attempting to truncate the log to 1
I0103 03:50:09.953456 31058 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 03:50:09.953862 31062 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 03:50:09.953902 31064 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 03:50:09.954560 31057 replica.cpp:537] Replica received write request for position 2 from (12831)@172.17.0.2:45080
I0103 03:50:09.993646 31057 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 39.041001ms
I0103 03:50:09.993690 31057 replica.cpp:712] Persisted action at 2
I0103 03:50:09.994613 31055 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 03:50:10.027034 31055 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 32.381337ms
I0103 03:50:10.027160 31055 leveldb.cpp:399] Deleting ~1 keys from leveldb took 53429ns
I0103 03:50:10.027197 31055 replica.cpp:712] Persisted action at 2
I0103 03:50:10.027233 31055 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 03:50:10.034865 31030 scheduler.cpp:154] Version: 0.27.0
I0103 03:50:10.035485 31051 scheduler.cpp:236] New master detected at master@172.17.0.2:45080
I0103 03:50:10.036672 31049 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:45080
I0103 03:50:10.038653 31064 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 03:50:10.039233 31055 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:58343
I0103 03:50:10.039434 31055 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 03:50:10.039499 31055 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 03:50:10.039813 31055 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 03:50:10.040264 31058 hierarchical.cpp:260] Added framework ae0d364f-3eed-4b2f-abc5-e7b68f2ec7ea-0000
I0103 03:50:10.040293 31056 master.hpp:1659] Sending heartbeat to ae0d364f-3eed-4b2f-abc5-e7b68f2ec7ea-0000
I0103 03:50:10.040405 31058 hierarchical.cpp:1329] No resources available to allocate!
I0103 03:50:10.040446 31058 hierarchical.cpp:1423] No inverse offers to send out!
I0103 03:50:10.040477 31058 hierarchical.cpp:1079] Performed allocation for 0 slaves in 111348ns
I0103 03:50:10.041165 31055 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:45080
I0103 03:50:10.041656 31055 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:45080
I0103 03:50:10.042217 31062 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 03:50:10.042433 31053 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:45080
I0103 03:50:10.043994 31059 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 03:50:10.044512 31056 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:58344
I0103 03:50:10.044632 31056 master.cpp:2636] Processing REQUEST call for framework ae0d364f-3eed-4b2f-abc5-e7b68f2ec7ea-0000 (default)
I0103 03:50:10.044817 31058 hierarchical.cpp:579] Received resource request from framework ae0d364f-3eed-4b2f-abc5-e7b68f2ec7ea-0000
I0103 03:50:10.045219 31059 master.cpp:930] Master terminating
I0103 03:50:10.045420 31053 hierarchical.cpp:321] Removed framework ae0d364f-3eed-4b2f-abc5-e7b68f2ec7ea-0000
E0103 03:50:10.046468 31063 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (523 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0103 03:50:10.156314 31030 leveldb.cpp:174] Opened db in 103.408333ms
I0103 03:50:10.198246 31030 leveldb.cpp:181] Compacted db in 41.887032ms
I0103 03:50:10.198309 31030 leveldb.cpp:196] Created db iterator in 15675ns
I0103 03:50:10.198328 31030 leveldb.cpp:202] Seeked to beginning of db in 1777ns
I0103 03:50:10.198340 31030 leveldb.cpp:271] Iterated through 0 keys in the db in 213ns
I0103 03:50:10.198374 31030 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0103 03:50:10.198832 31052 recover.cpp:447] Starting replica recovery
I0103 03:50:10.199097 31052 recover.cpp:473] Replica is in EMPTY status
I0103 03:50:10.200211 31058 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12839)@172.17.0.2:45080
I0103 03:50:10.200614 31063 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0103 03:50:10.201228 31060 recover.cpp:564] Updating replica status to STARTING
I0103 03:50:10.202297 31051 master.cpp:365] Master cd168ef4-a9ab-4910-930c-87644291bea0 (c14b220ac019) started on 172.17.0.2:45080
I0103 03:50:10.202323 31051 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/sxJ18U/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/sxJ18U/master" --zk_session_timeout="10secs"
I0103 03:50:10.202700 31051 master.cpp:414] Master allowing unauthenticated frameworks to register
I0103 03:50:10.202714 31051 master.cpp:417] Master only allowing authenticated slaves to register
I0103 03:50:10.202723 31051 credentials.hpp:35] Loading credentials for authentication from '/tmp/sxJ18U/credentials'
I0103 03:50:10.202991 31051 master.cpp:456] Using default 'crammd5' authenticator
I0103 03:50:10.203120 31051 master.cpp:493] Authorization enabled
I0103 03:50:10.203389 31058 hierarchical.cpp:147] Initialized hierarchical allocator process
I0103 03:50:10.203405 31056 whitelist_watcher.cpp:77] No whitelist given
I0103 03:50:10.205116 31060 master.cpp:1629] The newly elected leader is master@172.17.0.2:45080 with id cd168ef4-a9ab-4910-930c-87644291bea0
I0103 03:50:10.205243 31060 master.cpp:1642] Elected as the leading master!
I0103 03:50:10.205262 31060 master.cpp:1387] Recovering from registrar
I0103 03:50:10.205395 31062 registrar.cpp:307] Recovering registrar
I0103 03:50:10.232219 31059 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.803201ms
I0103 03:50:10.232262 31059 replica.cpp:320] Persisted replica status to STARTING
I0103 03:50:10.232527 31060 recover.cpp:473] Replica is in STARTING status
I0103 03:50:10.233782 31058 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12840)@172.17.0.2:45080
I0103 03:50:10.234062 31049 recover.cpp:193] Received a recover response from a replica in STARTING status
I0103 03:50:10.234657 31056 recover.cpp:564] Updating replica status to VOTING
I0103 03:50:10.265625 31051 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.731479ms
I0103 03:50:10.265667 31051 replica.cpp:320] Persisted replica status to VOTING
I0103 03:50:10.265810 31059 recover.cpp:578] Successfully joined the Paxos group
I0103 03:50:10.266202 31059 recover.cpp:462] Recover process terminated
I0103 03:50:10.267573 31054 log.cpp:659] Attempting to start the writer
I0103 03:50:10.269512 31059 replica.cpp:493] Replica received implicit promise request from (12841)@172.17.0.2:45080 with proposal 1
I0103 03:50:10.299046 31059 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 29.492606ms
I0103 03:50:10.299083 31059 replica.cpp:342] Persisted promised to 1
I0103 03:50:10.299938 31057 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0103 03:50:10.301847 31052 replica.cpp:388] Replica received explicit promise request from (12842)@172.17.0.2:45080 for position 0 with proposal 2
I0103 03:50:10.332443 31052 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 30.545135ms
I0103 03:50:10.332484 31052 replica.cpp:712] Persisted action at 0
I0103 03:50:10.333734 31050 replica.cpp:537] Replica received write request for position 0 from (12843)@172.17.0.2:45080
I0103 03:50:10.333801 31050 leveldb.cpp:436] Reading position from leveldb took 28944ns
I0103 03:50:10.369297 31050 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 35.44378ms
I0103 03:50:10.369343 31050 replica.cpp:712] Persisted action at 0
I0103 03:50:10.370077 31049 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0103 03:50:10.394173 31049 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 23.941089ms
I0103 03:50:10.394212 31049 replica.cpp:712] Persisted action at 0
I0103 03:50:10.394235 31049 replica.cpp:697] Replica learned NOP action at position 0
I0103 03:50:10.394955 31059 log.cpp:675] Writer started with ending position 0
I0103 03:50:10.396093 31063 leveldb.cpp:436] Reading position from leveldb took 37314ns
I0103 03:50:10.397114 31056 registrar.cpp:340] Successfully fetched the registry (0B) in 191.6672ms
I0103 03:50:10.397263 31056 registrar.cpp:439] Applied 1 operations in 29809ns; attempting to update the 'registry'
I0103 03:50:10.398038 31058 log.cpp:683] Attempting to append 170 bytes to the log
I0103 03:50:10.398186 31060 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0103 03:50:10.398983 31054 replica.cpp:537] Replica received write request for position 1 from (12844)@172.17.0.2:45080
I0103 03:50:10.419401 31054 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.375117ms
I0103 03:50:10.419440 31054 replica.cpp:712] Persisted action at 1
I0103 03:50:10.420202 31056 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0103 03:50:10.444461 31056 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.218286ms
I0103 03:50:10.444500 31056 replica.cpp:712] Persisted action at 1
I0103 03:50:10.444522 31056 replica.cpp:697] Replica learned APPEND action at position 1
I0103 03:50:10.445637 31062 registrar.cpp:484] Successfully updated the 'registry' in 48.309248ms
I0103 03:50:10.445783 31062 registrar.cpp:370] Successfully recovered registrar
I0103 03:50:10.446163 31051 log.cpp:702] Attempting to truncate the log to 1
I0103 03:50:10.446359 31049 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0103 03:50:10.446521 31053 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0103 03:50:10.446557 31054 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0103 03:50:10.447471 31058 replica.cpp:537] Replica received write request for position 2 from (12845)@172.17.0.2:45080
I0103 03:50:10.469620 31058 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.101488ms
I0103 03:50:10.469666 31058 replica.cpp:712] Persisted action at 2
I0103 03:50:10.470496 31061 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0103 03:50:10.494791 31061 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.251315ms
I0103 03:50:10.494887 31061 leveldb.cpp:399] Deleting ~1 keys from leveldb took 53711ns
I0103 03:50:10.494922 31061 replica.cpp:712] Persisted action at 2
I0103 03:50:10.494957 31061 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0103 03:50:10.497866 31030 scheduler.cpp:154] Version: 0.27.0
I0103 03:50:10.498682 31057 scheduler.cpp:236] New master detected at master@172.17.0.2:45080
I0103 03:50:10.499946 31062 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:45080
I0103 03:50:10.501822 31055 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 03:50:10.502327 31062 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:58345
I0103 03:50:10.502708 31062 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0103 03:50:10.502774 31062 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0103 03:50:10.503083 31062 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0103 03:50:10.503487 31052 hierarchical.cpp:260] Added framework cd168ef4-a9ab-4910-930c-87644291bea0-0000
I0103 03:50:10.503551 31052 hierarchical.cpp:1329] No resources available to allocate!
I0103 03:50:10.503605 31052 hierarchical.cpp:1423] No inverse offers to send out!
I0103 03:50:10.503638 31052 hierarchical.cpp:1079] Performed allocation for 0 slaves in 120217ns
I0103 03:50:10.503649 31054 master.hpp:1659] Sending heartbeat to cd168ef4-a9ab-4910-930c-87644291bea0-0000
I0103 03:50:10.504868 31062 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:45080
I0103 03:50:10.505427 31062 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:45080
I0103 03:50:10.506422 31053 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0103 03:50:10.506609 31058 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:45080
I0103 03:50:10.508564 31049 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0103 03:50:10.509083 31063 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:58346
I0103 03:50:10.509368 31063 master.cpp:2636] Processing REQUEST call for framework cd168ef4-a9ab-4910-930c-87644291bea0-0000 (default)
I0103 03:50:10.509553 31059 hierarchical.cpp:579] Received resource request from framework cd168ef4-a9ab-4910-930c-87644291bea0-0000
I0103 03:50:10.509943 31030 master.cpp:930] Master terminating
I0103 03:50:10.510311 31053 hierarchical.cpp:321] Removed framework cd168ef4-a9ab-4910-930c-87644291bea0-0000
E0103 03:50:10.511396 31050 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (465 ms)
[----------] 22 tests from ContentType/SchedulerTest (15023 ms total)
[----------] Global test environment tear-down
[==========] 915 tests from 120 test cases ran. (692697 ms total)
[ PASSED ] 913 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] ProvisionerDockerLocalStoreTest.LocalStoreTestWithTar
[ FAILED ] ProvisionerDockerLocalStoreTest.MetadataManagerInitialization
2 FAILED TESTS
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1451790245-9035
Untagged: mesos-1451790245-9035:latest
Deleted: 4bb0a56a85d52f3a1b987c6dc7145627b7d37c077c50fd79c3022963465c0a4d
Deleted: c9513b59360e6dd940d3d035dcb7edc14e25e3e49aafd9e699081c238e2a4a04
Deleted: 527ee53a47f7c0ecab2fa7e02f26527b1b6d35c2821f53f3b543028701160a0b
Deleted: fa9a8587ab97a862acdef95dc0c736afa9b2a37dff64755e8a6cf4abf3119933
Deleted: c26d9dd8bb2fe6fab6fe5769e341b783380e44c977fe2c378729f106cc66172f
Deleted: c3c9e9b1ecfecff03443088f1f7ee0c172d31f59818081cac5a0a67c5a3744e5
Deleted: a6f3d3d97cb2a6a808367fee856aaa7b181f1b4d20bac2f4e2930cfba2434812
Deleted: 307522d0e5e908b430fee39c44750298163f863c59e851b5d85992f311362f90
Deleted: 23882674ad8c0020d19e938cd81adfa8e12e64698efc0788c738881e7bd3c912
Deleted: a012ce382cb8406b1cc6f873adfd1106c983362cf3cf4e018075a0acfa9ed739
Deleted: fe5e43768513ffabba30b6b60192c98ac82e83dec4da3dcf645a2921e6102ab1
Deleted: 9b36b1679e84f8f2f0baf4c09a4df391bd54c586f791a19afe83d5df7f290295
Deleted: 58981f933611d465219d3e35ba67ee3800a662e76703b785d587900960a8345c
Error handling URL https://reviews.apache.org/api/review-requests/41731/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard f05eb74b905ebb1eec2db0b694e2ff0c34413d26
Build step 'Execute shell' marked build as failure