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/07 01:48:08 UTC
Build failed in Jenkins: mesos-reviewbot #10626
See <https://builds.apache.org/job/mesos-reviewbot/10626/>
------------------------------------------
[...truncated 162997 lines...]
I0107 00:48:00.608572 31123 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_MkLTTm/slaves/a80ba770-e994-479d-933f-d80fdaf0bf5e-S0/frameworks/a80ba770-e994-479d-933f-d80fdaf0bf5e-0000' for gc 6.99999295712889days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (119 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0107 00:48:00.615950 31097 leveldb.cpp:174] Opened db in 2.910346ms
I0107 00:48:00.617127 31097 leveldb.cpp:181] Compacted db in 1.135798ms
I0107 00:48:00.617187 31097 leveldb.cpp:196] Created db iterator in 19419ns
I0107 00:48:00.617205 31097 leveldb.cpp:202] Seeked to beginning of db in 2173ns
I0107 00:48:00.617216 31097 leveldb.cpp:271] Iterated through 0 keys in the db in 348ns
I0107 00:48:00.617257 31097 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 00:48:00.617754 31127 recover.cpp:447] Starting replica recovery
I0107 00:48:00.618232 31131 recover.cpp:473] Replica is in EMPTY status
I0107 00:48:00.619607 31126 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12951)@172.17.0.2:45033
I0107 00:48:00.620138 31122 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 00:48:00.620545 31116 recover.cpp:564] Updating replica status to STARTING
I0107 00:48:00.621146 31120 master.cpp:365] Master 73483e23-edcd-47b0-968e-aaa322202404 (e82632d0720c) started on 172.17.0.2:45033
I0107 00:48:00.621354 31125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 584797ns
I0107 00:48:00.621379 31125 replica.cpp:320] Persisted replica status to STARTING
I0107 00:48:00.621168 31120 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/RgyHSD/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/RgyHSD/master" --zk_session_timeout="10secs"
I0107 00:48:00.621419 31120 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 00:48:00.621430 31120 master.cpp:417] Master only allowing authenticated slaves to register
I0107 00:48:00.621441 31120 credentials.hpp:35] Loading credentials for authentication from '/tmp/RgyHSD/credentials'
I0107 00:48:00.621585 31129 recover.cpp:473] Replica is in STARTING status
I0107 00:48:00.621698 31120 master.cpp:456] Using default 'crammd5' authenticator
I0107 00:48:00.621948 31120 master.cpp:493] Authorization enabled
I0107 00:48:00.622131 31118 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 00:48:00.622277 31127 whitelist_watcher.cpp:77] No whitelist given
I0107 00:48:00.622659 31121 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12952)@172.17.0.2:45033
I0107 00:48:00.623154 31131 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 00:48:00.623787 31125 recover.cpp:564] Updating replica status to VOTING
I0107 00:48:00.624518 31131 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 393793ns
I0107 00:48:00.624553 31131 replica.cpp:320] Persisted replica status to VOTING
I0107 00:48:00.624714 31118 recover.cpp:578] Successfully joined the Paxos group
I0107 00:48:00.624877 31125 master.cpp:1629] The newly elected leader is master@172.17.0.2:45033 with id 73483e23-edcd-47b0-968e-aaa322202404
I0107 00:48:00.624922 31125 master.cpp:1642] Elected as the leading master!
I0107 00:48:00.624956 31125 master.cpp:1387] Recovering from registrar
I0107 00:48:00.625030 31118 recover.cpp:462] Recover process terminated
I0107 00:48:00.625125 31121 registrar.cpp:307] Recovering registrar
I0107 00:48:00.625944 31120 log.cpp:659] Attempting to start the writer
I0107 00:48:00.627320 31116 replica.cpp:493] Replica received implicit promise request from (12953)@172.17.0.2:45033 with proposal 1
I0107 00:48:00.627946 31116 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 582104ns
I0107 00:48:00.627977 31116 replica.cpp:342] Persisted promised to 1
I0107 00:48:00.628720 31117 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 00:48:00.630182 31130 replica.cpp:388] Replica received explicit promise request from (12954)@172.17.0.2:45033 for position 0 with proposal 2
I0107 00:48:00.630746 31130 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 514957ns
I0107 00:48:00.630779 31130 replica.cpp:712] Persisted action at 0
I0107 00:48:00.632081 31122 replica.cpp:537] Replica received write request for position 0 from (12955)@172.17.0.2:45033
I0107 00:48:00.632163 31122 leveldb.cpp:436] Reading position from leveldb took 38382ns
I0107 00:48:00.632660 31122 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 445777ns
I0107 00:48:00.632693 31122 replica.cpp:712] Persisted action at 0
I0107 00:48:00.633501 31129 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 00:48:00.633929 31129 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 397711ns
I0107 00:48:00.633952 31129 replica.cpp:712] Persisted action at 0
I0107 00:48:00.633970 31129 replica.cpp:697] Replica learned NOP action at position 0
I0107 00:48:00.634639 31116 log.cpp:675] Writer started with ending position 0
I0107 00:48:00.635779 31124 leveldb.cpp:436] Reading position from leveldb took 38447ns
I0107 00:48:00.637037 31121 registrar.cpp:340] Successfully fetched the registry (0B) in 11.80416ms
I0107 00:48:00.637162 31121 registrar.cpp:439] Applied 1 operations in 28092ns; attempting to update the 'registry'
I0107 00:48:00.637969 31126 log.cpp:683] Attempting to append 170 bytes to the log
I0107 00:48:00.638113 31122 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 00:48:00.639068 31117 replica.cpp:537] Replica received write request for position 1 from (12956)@172.17.0.2:45033
I0107 00:48:00.639569 31117 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 451137ns
I0107 00:48:00.639602 31117 replica.cpp:712] Persisted action at 1
I0107 00:48:00.640323 31125 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 00:48:00.640797 31125 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 437048ns
I0107 00:48:00.640848 31125 replica.cpp:712] Persisted action at 1
I0107 00:48:00.640872 31125 replica.cpp:697] Replica learned APPEND action at position 1
I0107 00:48:00.641990 31118 registrar.cpp:484] Successfully updated the 'registry' in 4.761856ms
I0107 00:48:00.642148 31118 registrar.cpp:370] Successfully recovered registrar
I0107 00:48:00.642308 31128 log.cpp:702] Attempting to truncate the log to 1
I0107 00:48:00.642598 31118 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 00:48:00.642875 31120 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 00:48:00.642899 31121 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 00:48:00.643702 31124 replica.cpp:537] Replica received write request for position 2 from (12957)@172.17.0.2:45033
I0107 00:48:00.644245 31124 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 491558ns
I0107 00:48:00.644278 31124 replica.cpp:712] Persisted action at 2
I0107 00:48:00.645028 31128 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 00:48:00.645443 31128 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 378188ns
I0107 00:48:00.645515 31128 leveldb.cpp:399] Deleting ~1 keys from leveldb took 38319ns
I0107 00:48:00.645555 31128 replica.cpp:712] Persisted action at 2
I0107 00:48:00.645586 31128 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 00:48:00.653481 31097 scheduler.cpp:154] Version: 0.27.0
I0107 00:48:00.654302 31116 scheduler.cpp:236] New master detected at master@172.17.0.2:45033
I0107 00:48:00.655686 31121 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:45033
I0107 00:48:00.657788 31119 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 00:48:00.658371 31121 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51614
I0107 00:48:00.658583 31121 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 00:48:00.658653 31121 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 00:48:00.659034 31121 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 00:48:00.659505 31116 hierarchical.cpp:260] Added framework 73483e23-edcd-47b0-968e-aaa322202404-0000
I0107 00:48:00.659560 31119 master.hpp:1662] Sending heartbeat to 73483e23-edcd-47b0-968e-aaa322202404-0000
I0107 00:48:00.659592 31116 hierarchical.cpp:1329] No resources available to allocate!
I0107 00:48:00.659659 31116 hierarchical.cpp:1423] No inverse offers to send out!
I0107 00:48:00.659723 31116 hierarchical.cpp:1079] Performed allocation for 0 slaves in 180148ns
I0107 00:48:00.660514 31118 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:45033
I0107 00:48:00.661139 31118 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:45033
I0107 00:48:00.661963 31131 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 00:48:00.662092 31118 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:45033
I0107 00:48:00.663899 31129 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 00:48:00.664422 31116 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51615
I0107 00:48:00.664572 31116 master.cpp:2636] Processing REQUEST call for framework 73483e23-edcd-47b0-968e-aaa322202404-0000 (default)
I0107 00:48:00.664748 31117 hierarchical.cpp:579] Received resource request from framework 73483e23-edcd-47b0-968e-aaa322202404-0000
I0107 00:48:00.665210 31121 master.cpp:930] Master terminating
I0107 00:48:00.665464 31123 hierarchical.cpp:321] Removed framework 73483e23-edcd-47b0-968e-aaa322202404-0000
E0107 00:48:00.667075 31131 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (60 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0107 00:48:00.676117 31097 leveldb.cpp:174] Opened db in 3.097532ms
I0107 00:48:00.677235 31097 leveldb.cpp:181] Compacted db in 1.078189ms
I0107 00:48:00.677292 31097 leveldb.cpp:196] Created db iterator in 16327ns
I0107 00:48:00.677310 31097 leveldb.cpp:202] Seeked to beginning of db in 1948ns
I0107 00:48:00.677321 31097 leveldb.cpp:271] Iterated through 0 keys in the db in 407ns
I0107 00:48:00.677357 31097 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 00:48:00.677873 31119 recover.cpp:447] Starting replica recovery
I0107 00:48:00.678274 31125 recover.cpp:473] Replica is in EMPTY status
I0107 00:48:00.679188 31123 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12965)@172.17.0.2:45033
I0107 00:48:00.679721 31118 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 00:48:00.680276 31120 recover.cpp:564] Updating replica status to STARTING
I0107 00:48:00.681164 31130 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 674917ns
I0107 00:48:00.681195 31130 replica.cpp:320] Persisted replica status to STARTING
I0107 00:48:00.681391 31116 recover.cpp:473] Replica is in STARTING status
I0107 00:48:00.681699 31128 master.cpp:365] Master ceba39fc-d87e-4090-a375-38c4f6655061 (e82632d0720c) started on 172.17.0.2:45033
I0107 00:48:00.681813 31128 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Y8RC8o/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/Y8RC8o/master" --zk_session_timeout="10secs"
I0107 00:48:00.682199 31128 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 00:48:00.682226 31128 master.cpp:417] Master only allowing authenticated slaves to register
I0107 00:48:00.682241 31128 credentials.hpp:35] Loading credentials for authentication from '/tmp/Y8RC8o/credentials'
I0107 00:48:00.682622 31128 master.cpp:456] Using default 'crammd5' authenticator
I0107 00:48:00.682754 31128 master.cpp:493] Authorization enabled
I0107 00:48:00.682893 31122 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12966)@172.17.0.2:45033
I0107 00:48:00.682950 31116 whitelist_watcher.cpp:77] No whitelist given
I0107 00:48:00.682953 31130 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 00:48:00.683213 31117 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 00:48:00.683709 31127 recover.cpp:564] Updating replica status to VOTING
I0107 00:48:00.684356 31123 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 433915ns
I0107 00:48:00.684396 31123 replica.cpp:320] Persisted replica status to VOTING
I0107 00:48:00.684543 31116 recover.cpp:578] Successfully joined the Paxos group
I0107 00:48:00.685282 31116 recover.cpp:462] Recover process terminated
I0107 00:48:00.685380 31124 master.cpp:1629] The newly elected leader is master@172.17.0.2:45033 with id ceba39fc-d87e-4090-a375-38c4f6655061
I0107 00:48:00.685513 31124 master.cpp:1642] Elected as the leading master!
I0107 00:48:00.685554 31124 master.cpp:1387] Recovering from registrar
I0107 00:48:00.685750 31123 registrar.cpp:307] Recovering registrar
I0107 00:48:00.686537 31125 log.cpp:659] Attempting to start the writer
I0107 00:48:00.688010 31128 replica.cpp:493] Replica received implicit promise request from (12967)@172.17.0.2:45033 with proposal 1
I0107 00:48:00.688557 31128 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 501003ns
I0107 00:48:00.688593 31128 replica.cpp:342] Persisted promised to 1
I0107 00:48:00.689257 31125 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 00:48:00.690486 31131 replica.cpp:388] Replica received explicit promise request from (12968)@172.17.0.2:45033 for position 0 with proposal 2
I0107 00:48:00.690956 31131 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 430189ns
I0107 00:48:00.690982 31131 replica.cpp:712] Persisted action at 0
I0107 00:48:00.692004 31126 replica.cpp:537] Replica received write request for position 0 from (12969)@172.17.0.2:45033
I0107 00:48:00.692059 31126 leveldb.cpp:436] Reading position from leveldb took 23783ns
I0107 00:48:00.692404 31126 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 299716ns
I0107 00:48:00.692430 31126 replica.cpp:712] Persisted action at 0
I0107 00:48:00.692972 31128 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 00:48:00.693394 31128 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 327644ns
I0107 00:48:00.693420 31128 replica.cpp:712] Persisted action at 0
I0107 00:48:00.693438 31128 replica.cpp:697] Replica learned NOP action at position 0
I0107 00:48:00.694047 31128 log.cpp:675] Writer started with ending position 0
I0107 00:48:00.695040 31131 leveldb.cpp:436] Reading position from leveldb took 25228ns
I0107 00:48:00.695868 31117 registrar.cpp:340] Successfully fetched the registry (0B) in 10.063872ms
I0107 00:48:00.696030 31117 registrar.cpp:439] Applied 1 operations in 22236ns; attempting to update the 'registry'
I0107 00:48:00.696712 31127 log.cpp:683] Attempting to append 170 bytes to the log
I0107 00:48:00.696866 31122 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 00:48:00.697612 31128 replica.cpp:537] Replica received write request for position 1 from (12970)@172.17.0.2:45033
I0107 00:48:00.698094 31128 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 445588ns
I0107 00:48:00.698122 31128 replica.cpp:712] Persisted action at 1
I0107 00:48:00.698973 31129 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 00:48:00.699501 31129 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 364764ns
I0107 00:48:00.699533 31129 replica.cpp:712] Persisted action at 1
I0107 00:48:00.699558 31129 replica.cpp:697] Replica learned APPEND action at position 1
I0107 00:48:00.700798 31119 registrar.cpp:484] Successfully updated the 'registry' in 4.701696ms
I0107 00:48:00.700968 31119 registrar.cpp:370] Successfully recovered registrar
I0107 00:48:00.701043 31123 log.cpp:702] Attempting to truncate the log to 1
I0107 00:48:00.701225 31116 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 00:48:00.701650 31118 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 00:48:00.701704 31124 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 00:48:00.702924 31126 replica.cpp:537] Replica received write request for position 2 from (12971)@172.17.0.2:45033
I0107 00:48:00.703527 31126 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 548782ns
I0107 00:48:00.703558 31126 replica.cpp:712] Persisted action at 2
I0107 00:48:00.704385 31117 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 00:48:00.704812 31117 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 380856ns
I0107 00:48:00.704910 31117 leveldb.cpp:399] Deleting ~1 keys from leveldb took 45012ns
I0107 00:48:00.704946 31117 replica.cpp:712] Persisted action at 2
I0107 00:48:00.704972 31117 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 00:48:00.712390 31097 scheduler.cpp:154] Version: 0.27.0
I0107 00:48:00.713052 31124 scheduler.cpp:236] New master detected at master@172.17.0.2:45033
I0107 00:48:00.714520 31122 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:45033
I0107 00:48:00.716537 31123 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 00:48:00.717357 31121 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51616
I0107 00:48:00.717741 31121 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 00:48:00.717810 31121 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 00:48:00.718181 31128 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 00:48:00.718593 31118 hierarchical.cpp:260] Added framework ceba39fc-d87e-4090-a375-38c4f6655061-0000
I0107 00:48:00.718662 31118 hierarchical.cpp:1329] No resources available to allocate!
I0107 00:48:00.718691 31118 hierarchical.cpp:1423] No inverse offers to send out!
I0107 00:48:00.718741 31118 hierarchical.cpp:1079] Performed allocation for 0 slaves in 112655ns
I0107 00:48:00.718757 31130 master.hpp:1662] Sending heartbeat to ceba39fc-d87e-4090-a375-38c4f6655061-0000
I0107 00:48:00.719764 31129 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:45033
I0107 00:48:00.720621 31129 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:45033
I0107 00:48:00.721568 31116 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 00:48:00.721658 31129 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:45033
I0107 00:48:00.723580 31122 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 00:48:00.724141 31129 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:51617
I0107 00:48:00.724470 31129 master.cpp:2636] Processing REQUEST call for framework ceba39fc-d87e-4090-a375-38c4f6655061-0000 (default)
I0107 00:48:00.724647 31118 hierarchical.cpp:579] Received resource request from framework ceba39fc-d87e-4090-a375-38c4f6655061-0000
I0107 00:48:00.725080 31122 master.cpp:930] Master terminating
I0107 00:48:00.725281 31119 hierarchical.cpp:321] Removed framework ceba39fc-d87e-4090-a375-38c4f6655061-0000
E0107 00:48:00.727175 31121 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (60 ms)
[----------] 22 tests from ContentType/SchedulerTest (4237 ms total)
[----------] Global test environment tear-down
[==========] 923 tests from 120 test cases ran. (339831 ms total)
[ PASSED ] 922 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DiskUsageCollectorTest.File
1 FAILED TEST
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-1452126017-7192
Untagged: mesos-1452126017-7192:latest
Deleted: efb84466fdf4d5734d93a22ee41859602696e57dd98cc98821e3896a72de73fb
Deleted: 9dfcc4a7b1f0fce06d455eb30d3e4a2cc50c6287188a8ae656bb39b5f7e29248
Deleted: 30305d6393055f230b203ad2cb26c20fbb6957fdf845dc3cdc2172c7dc48b558
Deleted: 85a1b3ba7e7cf5a1f20d2714a4266f5531496bbd7fb2073fb7db62ad9a8f5584
Deleted: a820f98861293b80733182d9fec8a5374e0add89b493a6d467f39f04678207fc
Deleted: be287397cc7a4d27dc6bb0913bea625315067425203f96a320b19a07f31b492f
Deleted: 4b8a86cfb0227015b8405e3582f113d77eb7115e7b4775a282faa7f201bfd682
Deleted: f3eb7752b8bd9caeb77f447dc54d2290cdfa63098350527cd89847ba0bf00141
Deleted: 55d3c486eafb8649994745bf02c460ceb6c90d50289f13b2d67e17a4973577d4
Deleted: b29da307d3a6ca36915c7dddd931c862853839720f92fc03fba705d0f8953bf9
Deleted: 741711d301cfb5fc872a590aeeecbb5739b9c8049583fe0c9deb417f3aa8c00f
Deleted: 23520aeaf243ef4e6185ef9604acc7500acda10639d4059b33e98718e188b533
Deleted: b63523c3381dc46d2a69e2984f964c90e54fb7371db6a0ad07ad34317ef7f779
Error handling URL https://reviews.apache.org/api/review-requests/41963/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 80a10db85b79de7d0bc4dd57b70aa2731acefd23
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : mesos-reviewbot #10631
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10631/>
Build failed in Jenkins: mesos-reviewbot #10630
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10630/changes>
Changes:
[tnachen] Fixed posix filesystem isolator to not allow executors with image.
------------------------------------------
[...truncated 166167 lines...]
I0107 04:29:58.443732 31132 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_mLlGPB/slaves/54e96a60-892a-43cc-9c7b-30b31add180d-S0/frameworks/54e96a60-892a-43cc-9c7b-30b31add180d-0000' for gc 6.99999486522074days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (603 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0107 04:29:58.535977 31098 leveldb.cpp:174] Opened db in 87.117085ms
I0107 04:29:58.583971 31098 leveldb.cpp:181] Compacted db in 47.951683ms
I0107 04:29:58.584036 31098 leveldb.cpp:196] Created db iterator in 20157ns
I0107 04:29:58.584058 31098 leveldb.cpp:202] Seeked to beginning of db in 2137ns
I0107 04:29:58.584069 31098 leveldb.cpp:271] Iterated through 0 keys in the db in 447ns
I0107 04:29:58.584106 31098 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 04:29:58.584619 31119 recover.cpp:447] Starting replica recovery
I0107 04:29:58.584908 31119 recover.cpp:473] Replica is in EMPTY status
I0107 04:29:58.586004 31132 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12988)@172.17.0.2:48027
I0107 04:29:58.586602 31122 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 04:29:58.587213 31124 recover.cpp:564] Updating replica status to STARTING
I0107 04:29:58.588171 31120 master.cpp:365] Master 5b7ce243-8754-4c6c-b450-c94b95fbb8d2 (a41b009d642a) started on 172.17.0.2:48027
I0107 04:29:58.588310 31120 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/mDg5Dr/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/mDg5Dr/master" --zk_session_timeout="10secs"
I0107 04:29:58.588616 31120 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 04:29:58.588635 31120 master.cpp:417] Master only allowing authenticated slaves to register
I0107 04:29:58.588650 31120 credentials.hpp:35] Loading credentials for authentication from '/tmp/mDg5Dr/credentials'
I0107 04:29:58.588995 31120 master.cpp:456] Using default 'crammd5' authenticator
I0107 04:29:58.589190 31120 master.cpp:493] Authorization enabled
I0107 04:29:58.589366 31122 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 04:29:58.589372 31129 whitelist_watcher.cpp:77] No whitelist given
I0107 04:29:58.591145 31123 master.cpp:1629] The newly elected leader is master@172.17.0.2:48027 with id 5b7ce243-8754-4c6c-b450-c94b95fbb8d2
I0107 04:29:58.591187 31123 master.cpp:1642] Elected as the leading master!
I0107 04:29:58.591204 31123 master.cpp:1387] Recovering from registrar
I0107 04:29:58.591367 31124 registrar.cpp:307] Recovering registrar
I0107 04:29:58.621279 31125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 33.849038ms
I0107 04:29:58.621323 31125 replica.cpp:320] Persisted replica status to STARTING
I0107 04:29:58.621609 31131 recover.cpp:473] Replica is in STARTING status
I0107 04:29:58.622552 31130 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12989)@172.17.0.2:48027
I0107 04:29:58.622895 31131 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 04:29:58.623327 31130 recover.cpp:564] Updating replica status to VOTING
I0107 04:29:58.646291 31119 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.783827ms
I0107 04:29:58.646329 31119 replica.cpp:320] Persisted replica status to VOTING
I0107 04:29:58.646453 31119 recover.cpp:578] Successfully joined the Paxos group
I0107 04:29:58.646705 31119 recover.cpp:462] Recover process terminated
I0107 04:29:58.647249 31124 log.cpp:659] Attempting to start the writer
I0107 04:29:58.648628 31128 replica.cpp:493] Replica received implicit promise request from (12990)@172.17.0.2:48027 with proposal 1
I0107 04:29:58.671408 31128 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.735069ms
I0107 04:29:58.671447 31128 replica.cpp:342] Persisted promised to 1
I0107 04:29:58.672099 31130 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 04:29:58.673764 31125 replica.cpp:388] Replica received explicit promise request from (12991)@172.17.0.2:48027 for position 0 with proposal 2
I0107 04:29:58.696521 31125 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.699545ms
I0107 04:29:58.696558 31125 replica.cpp:712] Persisted action at 0
I0107 04:29:58.697688 31120 replica.cpp:537] Replica received write request for position 0 from (12992)@172.17.0.2:48027
I0107 04:29:58.697741 31120 leveldb.cpp:436] Reading position from leveldb took 25250ns
I0107 04:29:58.721742 31120 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.964999ms
I0107 04:29:58.721788 31120 replica.cpp:712] Persisted action at 0
I0107 04:29:58.722720 31121 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 04:29:58.746738 31121 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 23.980943ms
I0107 04:29:58.746778 31121 replica.cpp:712] Persisted action at 0
I0107 04:29:58.746800 31121 replica.cpp:697] Replica learned NOP action at position 0
I0107 04:29:58.747542 31128 log.cpp:675] Writer started with ending position 0
I0107 04:29:58.748806 31132 leveldb.cpp:436] Reading position from leveldb took 32487ns
I0107 04:29:58.749807 31117 registrar.cpp:340] Successfully fetched the registry (0B) in 158.379776ms
I0107 04:29:58.749946 31117 registrar.cpp:439] Applied 1 operations in 28814ns; attempting to update the 'registry'
I0107 04:29:58.750807 31118 log.cpp:683] Attempting to append 170 bytes to the log
I0107 04:29:58.750960 31119 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 04:29:58.751857 31130 replica.cpp:537] Replica received write request for position 1 from (12993)@172.17.0.2:48027
I0107 04:29:58.776720 31130 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 24.810479ms
I0107 04:29:58.776759 31130 replica.cpp:712] Persisted action at 1
I0107 04:29:58.777593 31128 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 04:29:58.801962 31128 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.330548ms
I0107 04:29:58.802001 31128 replica.cpp:712] Persisted action at 1
I0107 04:29:58.802023 31128 replica.cpp:697] Replica learned APPEND action at position 1
I0107 04:29:58.803158 31121 registrar.cpp:484] Successfully updated the 'registry' in 53.11488ms
I0107 04:29:58.803344 31121 registrar.cpp:370] Successfully recovered registrar
I0107 04:29:58.803427 31128 log.cpp:702] Attempting to truncate the log to 1
I0107 04:29:58.803587 31123 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 04:29:58.803922 31131 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 04:29:58.803959 31121 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 04:29:58.804749 31122 replica.cpp:537] Replica received write request for position 2 from (12994)@172.17.0.2:48027
I0107 04:29:58.827008 31122 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.217275ms
I0107 04:29:58.827047 31122 replica.cpp:712] Persisted action at 2
I0107 04:29:58.828227 31127 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 04:29:58.852103 31127 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 23.835765ms
I0107 04:29:58.852203 31127 leveldb.cpp:399] Deleting ~1 keys from leveldb took 42784ns
I0107 04:29:58.852231 31127 replica.cpp:712] Persisted action at 2
I0107 04:29:58.852253 31127 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 04:29:58.854861 31098 scheduler.cpp:154] Version: 0.27.0
I0107 04:29:58.855496 31131 scheduler.cpp:236] New master detected at master@172.17.0.2:48027
I0107 04:29:58.856655 31128 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:48027
I0107 04:29:58.858613 31122 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 04:29:58.859088 31127 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:57391
I0107 04:29:58.859328 31127 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 04:29:58.859391 31127 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 04:29:58.859690 31127 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 04:29:58.860164 31128 hierarchical.cpp:260] Added framework 5b7ce243-8754-4c6c-b450-c94b95fbb8d2-0000
I0107 04:29:58.860265 31127 master.hpp:1662] Sending heartbeat to 5b7ce243-8754-4c6c-b450-c94b95fbb8d2-0000
I0107 04:29:58.860282 31128 hierarchical.cpp:1329] No resources available to allocate!
I0107 04:29:58.860327 31128 hierarchical.cpp:1423] No inverse offers to send out!
I0107 04:29:58.860362 31128 hierarchical.cpp:1079] Performed allocation for 0 slaves in 122270ns
I0107 04:29:58.861057 31118 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:48027
I0107 04:29:58.861603 31118 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:48027
I0107 04:29:58.862491 31124 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 04:29:58.862565 31118 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:48027
I0107 04:29:58.864397 31129 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 04:29:58.864802 31132 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:57392
I0107 04:29:58.864922 31132 master.cpp:2636] Processing REQUEST call for framework 5b7ce243-8754-4c6c-b450-c94b95fbb8d2-0000 (default)
I0107 04:29:58.865092 31120 hierarchical.cpp:579] Received resource request from framework 5b7ce243-8754-4c6c-b450-c94b95fbb8d2-0000
I0107 04:29:58.865465 31126 master.cpp:930] Master terminating
I0107 04:29:58.865669 31127 hierarchical.cpp:321] Removed framework 5b7ce243-8754-4c6c-b450-c94b95fbb8d2-0000
E0107 04:29:58.866770 31126 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (424 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0107 04:29:58.978643 31098 leveldb.cpp:174] Opened db in 105.704324ms
I0107 04:29:59.029067 31098 leveldb.cpp:181] Compacted db in 50.382382ms
I0107 04:29:59.029157 31098 leveldb.cpp:196] Created db iterator in 44306ns
I0107 04:29:59.029181 31098 leveldb.cpp:202] Seeked to beginning of db in 2077ns
I0107 04:29:59.029191 31098 leveldb.cpp:271] Iterated through 0 keys in the db in 330ns
I0107 04:29:59.029228 31098 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 04:29:59.029598 31129 recover.cpp:447] Starting replica recovery
I0107 04:29:59.029856 31128 recover.cpp:473] Replica is in EMPTY status
I0107 04:29:59.030674 31129 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13002)@172.17.0.2:48027
I0107 04:29:59.031010 31124 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 04:29:59.031795 31126 master.cpp:365] Master 65ba95ba-f17c-49b6-a21e-40c532d29cc8 (a41b009d642a) started on 172.17.0.2:48027
I0107 04:29:59.031813 31126 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/C0lDdK/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/C0lDdK/master" --zk_session_timeout="10secs"
I0107 04:29:59.032078 31126 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 04:29:59.032094 31126 master.cpp:417] Master only allowing authenticated slaves to register
I0107 04:29:59.032105 31126 credentials.hpp:35] Loading credentials for authentication from '/tmp/C0lDdK/credentials'
I0107 04:29:59.032073 31127 recover.cpp:564] Updating replica status to STARTING
I0107 04:29:59.032423 31126 master.cpp:456] Using default 'crammd5' authenticator
I0107 04:29:59.032526 31126 master.cpp:493] Authorization enabled
I0107 04:29:59.032662 31123 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 04:29:59.032670 31122 whitelist_watcher.cpp:77] No whitelist given
I0107 04:29:59.034036 31128 master.cpp:1629] The newly elected leader is master@172.17.0.2:48027 with id 65ba95ba-f17c-49b6-a21e-40c532d29cc8
I0107 04:29:59.034062 31128 master.cpp:1642] Elected as the leading master!
I0107 04:29:59.034075 31128 master.cpp:1387] Recovering from registrar
I0107 04:29:59.034198 31122 registrar.cpp:307] Recovering registrar
I0107 04:29:59.059773 31117 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 27.454023ms
I0107 04:29:59.059801 31117 replica.cpp:320] Persisted replica status to STARTING
I0107 04:29:59.060003 31132 recover.cpp:473] Replica is in STARTING status
I0107 04:29:59.061422 31125 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13003)@172.17.0.2:48027
I0107 04:29:59.061703 31120 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 04:29:59.062099 31121 recover.cpp:564] Updating replica status to VOTING
I0107 04:29:59.084894 31131 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.639225ms
I0107 04:29:59.084933 31131 replica.cpp:320] Persisted replica status to VOTING
I0107 04:29:59.085067 31128 recover.cpp:578] Successfully joined the Paxos group
I0107 04:29:59.085340 31128 recover.cpp:462] Recover process terminated
I0107 04:29:59.085819 31132 log.cpp:659] Attempting to start the writer
I0107 04:29:59.087194 31130 replica.cpp:493] Replica received implicit promise request from (13004)@172.17.0.2:48027 with proposal 1
I0107 04:29:59.110074 31130 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.832589ms
I0107 04:29:59.110118 31130 replica.cpp:342] Persisted promised to 1
I0107 04:29:59.110780 31128 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 04:29:59.112239 31129 replica.cpp:388] Replica received explicit promise request from (13005)@172.17.0.2:48027 for position 0 with proposal 2
I0107 04:29:59.135120 31129 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.827822ms
I0107 04:29:59.135177 31129 replica.cpp:712] Persisted action at 0
I0107 04:29:59.136430 31127 replica.cpp:537] Replica received write request for position 0 from (13006)@172.17.0.2:48027
I0107 04:29:59.136500 31127 leveldb.cpp:436] Reading position from leveldb took 30374ns
I0107 04:29:59.160296 31127 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.748144ms
I0107 04:29:59.160334 31127 replica.cpp:712] Persisted action at 0
I0107 04:29:59.161036 31124 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 04:29:59.189476 31124 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 28.396448ms
I0107 04:29:59.189515 31124 replica.cpp:712] Persisted action at 0
I0107 04:29:59.189538 31124 replica.cpp:697] Replica learned NOP action at position 0
I0107 04:29:59.190294 31117 log.cpp:675] Writer started with ending position 0
I0107 04:29:59.191445 31131 leveldb.cpp:436] Reading position from leveldb took 32054ns
I0107 04:29:59.192335 31121 registrar.cpp:340] Successfully fetched the registry (0B) in 158.091008ms
I0107 04:29:59.192464 31121 registrar.cpp:439] Applied 1 operations in 31597ns; attempting to update the 'registry'
I0107 04:29:59.193284 31126 log.cpp:683] Attempting to append 170 bytes to the log
I0107 04:29:59.193409 31129 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 04:29:59.194196 31128 replica.cpp:537] Replica received write request for position 1 from (13007)@172.17.0.2:48027
I0107 04:29:59.222856 31128 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 28.608916ms
I0107 04:29:59.222892 31128 replica.cpp:712] Persisted action at 1
I0107 04:29:59.223728 31132 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 04:29:59.256309 31132 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.543403ms
I0107 04:29:59.256350 31132 replica.cpp:712] Persisted action at 1
I0107 04:29:59.256372 31132 replica.cpp:697] Replica learned APPEND action at position 1
I0107 04:29:59.257474 31131 registrar.cpp:484] Successfully updated the 'registry' in 64.93824ms
I0107 04:29:59.257661 31131 registrar.cpp:370] Successfully recovered registrar
I0107 04:29:59.257819 31129 log.cpp:702] Attempting to truncate the log to 1
I0107 04:29:59.257977 31127 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 04:29:59.258313 31122 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 04:29:59.258396 31120 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 04:29:59.259207 31124 replica.cpp:537] Replica received write request for position 2 from (13008)@172.17.0.2:48027
I0107 04:29:59.289814 31124 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 30.563366ms
I0107 04:29:59.289854 31124 replica.cpp:712] Persisted action at 2
I0107 04:29:59.290575 31127 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 04:29:59.323197 31127 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 32.583587ms
I0107 04:29:59.323274 31127 leveldb.cpp:399] Deleting ~1 keys from leveldb took 39586ns
I0107 04:29:59.323302 31127 replica.cpp:712] Persisted action at 2
I0107 04:29:59.323324 31127 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 04:29:59.329491 31098 scheduler.cpp:154] Version: 0.27.0
I0107 04:29:59.330242 31120 scheduler.cpp:236] New master detected at master@172.17.0.2:48027
I0107 04:29:59.331492 31118 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:48027
I0107 04:29:59.333608 31128 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 04:29:59.334192 31127 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:57393
I0107 04:29:59.334560 31127 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 04:29:59.334625 31127 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 04:29:59.334930 31127 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 04:29:59.335330 31129 hierarchical.cpp:260] Added framework 65ba95ba-f17c-49b6-a21e-40c532d29cc8-0000
I0107 04:29:59.335402 31129 hierarchical.cpp:1329] No resources available to allocate!
I0107 04:29:59.335464 31128 master.hpp:1662] Sending heartbeat to 65ba95ba-f17c-49b6-a21e-40c532d29cc8-0000
I0107 04:29:59.335599 31129 hierarchical.cpp:1423] No inverse offers to send out!
I0107 04:29:59.335705 31129 hierarchical.cpp:1079] Performed allocation for 0 slaves in 341248ns
I0107 04:29:59.336469 31132 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:48027
I0107 04:29:59.337051 31132 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:48027
I0107 04:29:59.337710 31118 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 04:29:59.337709 31132 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:48027
I0107 04:29:59.339460 31119 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 04:29:59.339967 31120 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:57394
I0107 04:29:59.340237 31120 master.cpp:2636] Processing REQUEST call for framework 65ba95ba-f17c-49b6-a21e-40c532d29cc8-0000 (default)
I0107 04:29:59.340410 31130 hierarchical.cpp:579] Received resource request from framework 65ba95ba-f17c-49b6-a21e-40c532d29cc8-0000
I0107 04:29:59.340788 31132 master.cpp:930] Master terminating
I0107 04:29:59.340986 31119 hierarchical.cpp:321] Removed framework 65ba95ba-f17c-49b6-a21e-40c532d29cc8-0000
E0107 04:29:59.342111 31122 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (475 ms)
[----------] 22 tests from ContentType/SchedulerTest (13955 ms total)
[----------] Global test environment tear-down
[==========] 923 tests from 120 test cases ran. (674003 ms total)
[ PASSED ] 922 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DiskUsageCollectorTest.File
1 FAILED TEST
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-1452138811-29974
Untagged: mesos-1452138811-29974:latest
Deleted: 825d0b34a4690972e49ef80faedb49de250499ada4a86ed41fb52c4bbac17f4f
Deleted: 4c78661d2f87dee78f947eca5935ea42f56213ee0f9f43dc6ddc84b2d3067d77
Deleted: d54e56816e47584b8faf65fd9c7b548c6259a419302d9ad48e41b8101392a028
Deleted: b4b8ad1dc7a8706be381c298ce7341123c515667047b0c169a0099c149237e87
Deleted: 791e82fdec121a13b193251fccc238e5ab49d7652d0d2d8d03de91aced5e86d4
Deleted: da37d7ed3b9a87a7e9005b31f65e140ba06e8de733b2b3449d5fe2ea9bd7e68e
Deleted: 24c56b3a05e479a477b2a337ebaf322d6b93d2c9f819911517e89331bc8c9546
Deleted: 2e09ea81410d5764da87353979f53a92b6a5f6f47e01697b1e05a3a801242e4f
Deleted: 8ae28a00f8ce9c7ba604a29f9729e418d64909ceb9ca3abd824e858596ad12b3
Deleted: af3ec58e3b0d16568957a705cfde0dbad0ff58c7e7401f13ae9f453da3096986
Deleted: 96a6982787904e13df19509171df7e38dd1892794d8943079bcc76a9b0463692
Deleted: d853583bead3253a6af8a2c56f020f6d2f376826b0e6458817ecb44ef702f31d
Deleted: 28a62600a4116118b439a8c9d84af970da3ba827cc8bd1290f1d3977f5267935
Error handling URL https://reviews.apache.org/api/review-requests/41963/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 52abf8de380cf7a3c3d8a2e5616b3d34d7b6b277
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10629
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10629/>
------------------------------------------
[...truncated 167413 lines...]
[ OK ] ContentType/SchedulerTest.Message/1 (681 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0107 03:34:32.713248 31096 leveldb.cpp:174] Opened db in 124.406175ms
I0107 03:34:32.755214 31096 leveldb.cpp:181] Compacted db in 41.894465ms
I0107 03:34:32.755297 31096 leveldb.cpp:196] Created db iterator in 26724ns
I0107 03:34:32.755333 31096 leveldb.cpp:202] Seeked to beginning of db in 2482ns
I0107 03:34:32.755359 31096 leveldb.cpp:271] Iterated through 0 keys in the db in 482ns
I0107 03:34:32.755427 31096 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 03:34:32.757218 31118 recover.cpp:447] Starting replica recovery
I0107 03:34:32.757494 31118 recover.cpp:473] Replica is in EMPTY status
I0107 03:34:32.758687 31123 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12966)@172.17.0.5:44990
I0107 03:34:32.759098 31116 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 03:34:32.759542 31129 recover.cpp:564] Updating replica status to STARTING
I0107 03:34:32.759969 31118 master.cpp:365] Master 7121910a-a4b4-41e2-a6be-eee549ccd203 (d5186ce46002) started on 172.17.0.5:44990
I0107 03:34:32.759992 31118 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/SAxpSj/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/SAxpSj/master" --zk_session_timeout="10secs"
I0107 03:34:32.760285 31118 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 03:34:32.760296 31118 master.cpp:417] Master only allowing authenticated slaves to register
I0107 03:34:32.760301 31118 credentials.hpp:35] Loading credentials for authentication from '/tmp/SAxpSj/credentials'
I0107 03:34:32.760609 31118 master.cpp:456] Using default 'crammd5' authenticator
I0107 03:34:32.760740 31118 master.cpp:493] Authorization enabled
I0107 03:34:32.760893 31123 whitelist_watcher.cpp:77] No whitelist given
I0107 03:34:32.760933 31120 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 03:34:32.762712 31121 master.cpp:1629] The newly elected leader is master@172.17.0.5:44990 with id 7121910a-a4b4-41e2-a6be-eee549ccd203
I0107 03:34:32.762751 31121 master.cpp:1642] Elected as the leading master!
I0107 03:34:32.762773 31121 master.cpp:1387] Recovering from registrar
I0107 03:34:32.763023 31128 registrar.cpp:307] Recovering registrar
I0107 03:34:32.788800 31119 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 29.049583ms
I0107 03:34:32.788885 31119 replica.cpp:320] Persisted replica status to STARTING
I0107 03:34:32.789177 31118 recover.cpp:473] Replica is in STARTING status
I0107 03:34:32.790303 31125 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12967)@172.17.0.5:44990
I0107 03:34:32.790822 31130 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 03:34:32.791333 31123 recover.cpp:564] Updating replica status to VOTING
I0107 03:34:32.831470 31126 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.890523ms
I0107 03:34:32.831547 31126 replica.cpp:320] Persisted replica status to VOTING
I0107 03:34:32.831814 31125 recover.cpp:578] Successfully joined the Paxos group
I0107 03:34:32.832116 31125 recover.cpp:462] Recover process terminated
I0107 03:34:32.832819 31124 log.cpp:659] Attempting to start the writer
I0107 03:34:32.834249 31115 replica.cpp:493] Replica received implicit promise request from (12968)@172.17.0.5:44990 with proposal 1
I0107 03:34:32.864806 31115 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.514999ms
I0107 03:34:32.864853 31115 replica.cpp:342] Persisted promised to 1
I0107 03:34:32.865563 31128 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 03:34:32.867102 31128 replica.cpp:388] Replica received explicit promise request from (12969)@172.17.0.5:44990 for position 0 with proposal 2
I0107 03:34:32.898284 31128 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 31.133943ms
I0107 03:34:32.898331 31128 replica.cpp:712] Persisted action at 0
I0107 03:34:32.899667 31116 replica.cpp:537] Replica received write request for position 0 from (12970)@172.17.0.5:44990
I0107 03:34:32.899739 31116 leveldb.cpp:436] Reading position from leveldb took 32293ns
I0107 03:34:32.937809 31116 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 38.012222ms
I0107 03:34:32.937862 31116 replica.cpp:712] Persisted action at 0
I0107 03:34:32.938652 31118 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 03:34:32.964025 31118 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 25.329223ms
I0107 03:34:32.964083 31118 replica.cpp:712] Persisted action at 0
I0107 03:34:32.964112 31118 replica.cpp:697] Replica learned NOP action at position 0
I0107 03:34:32.964751 31127 log.cpp:675] Writer started with ending position 0
I0107 03:34:32.965886 31125 leveldb.cpp:436] Reading position from leveldb took 43620ns
I0107 03:34:32.966898 31126 registrar.cpp:340] Successfully fetched the registry (0B) in 203.819776ms
I0107 03:34:32.967021 31126 registrar.cpp:439] Applied 1 operations in 33037ns; attempting to update the 'registry'
I0107 03:34:32.967705 31115 log.cpp:683] Attempting to append 170 bytes to the log
I0107 03:34:32.967825 31130 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 03:34:32.969331 31122 replica.cpp:537] Replica received write request for position 1 from (12971)@172.17.0.5:44990
I0107 03:34:33.003957 31122 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 34.529678ms
I0107 03:34:33.004024 31122 replica.cpp:712] Persisted action at 1
I0107 03:34:33.004828 31130 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 03:34:33.033941 31130 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 29.060885ms
I0107 03:34:33.034018 31130 replica.cpp:712] Persisted action at 1
I0107 03:34:33.034049 31130 replica.cpp:697] Replica learned APPEND action at position 1
I0107 03:34:33.035576 31124 registrar.cpp:484] Successfully updated the 'registry' in 68.436992ms
I0107 03:34:33.035801 31124 registrar.cpp:370] Successfully recovered registrar
I0107 03:34:33.035869 31127 log.cpp:702] Attempting to truncate the log to 1
I0107 03:34:33.036360 31121 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 03:34:33.036383 31125 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 03:34:33.035995 31122 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 03:34:33.037490 31119 replica.cpp:537] Replica received write request for position 2 from (12972)@172.17.0.5:44990
I0107 03:34:33.081989 31119 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 44.428195ms
I0107 03:34:33.082077 31119 replica.cpp:712] Persisted action at 2
I0107 03:34:33.083534 31119 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 03:34:33.116415 31119 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 32.828843ms
I0107 03:34:33.116551 31119 leveldb.cpp:399] Deleting ~1 keys from leveldb took 66002ns
I0107 03:34:33.116574 31119 replica.cpp:712] Persisted action at 2
I0107 03:34:33.116618 31119 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 03:34:33.128180 31096 scheduler.cpp:154] Version: 0.27.0
I0107 03:34:33.128978 31119 scheduler.cpp:236] New master detected at master@172.17.0.5:44990
I0107 03:34:33.130511 31122 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:44990
I0107 03:34:33.132763 31128 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 03:34:33.133255 31117 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:45654
I0107 03:34:33.133436 31117 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 03:34:33.133493 31117 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 03:34:33.133785 31117 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 03:34:33.134210 31121 hierarchical.cpp:260] Added framework 7121910a-a4b4-41e2-a6be-eee549ccd203-0000
I0107 03:34:33.134238 31124 master.hpp:1662] Sending heartbeat to 7121910a-a4b4-41e2-a6be-eee549ccd203-0000
I0107 03:34:33.134277 31121 hierarchical.cpp:1329] No resources available to allocate!
I0107 03:34:33.134311 31121 hierarchical.cpp:1423] No inverse offers to send out!
I0107 03:34:33.134337 31121 hierarchical.cpp:1079] Performed allocation for 0 slaves in 99856ns
I0107 03:34:33.134955 31121 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:44990
I0107 03:34:33.135385 31121 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:44990
I0107 03:34:33.135967 31118 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 03:34:33.136052 31130 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:44990
I0107 03:34:33.137452 31119 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 03:34:33.137866 31119 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:45655
I0107 03:34:33.137984 31119 master.cpp:2636] Processing REQUEST call for framework 7121910a-a4b4-41e2-a6be-eee549ccd203-0000 (default)
I0107 03:34:33.138177 31121 hierarchical.cpp:579] Received resource request from framework 7121910a-a4b4-41e2-a6be-eee549ccd203-0000
I0107 03:34:33.138537 31096 master.cpp:930] Master terminating
I0107 03:34:33.138769 31124 hierarchical.cpp:321] Removed framework 7121910a-a4b4-41e2-a6be-eee549ccd203-0000
E0107 03:34:33.139780 31125 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (556 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0107 03:34:33.252970 31096 leveldb.cpp:174] Opened db in 107.614389ms
I0107 03:34:33.292935 31096 leveldb.cpp:181] Compacted db in 39.888534ms
I0107 03:34:33.292996 31096 leveldb.cpp:196] Created db iterator in 19754ns
I0107 03:34:33.293010 31096 leveldb.cpp:202] Seeked to beginning of db in 1536ns
I0107 03:34:33.293020 31096 leveldb.cpp:271] Iterated through 0 keys in the db in 298ns
I0107 03:34:33.293062 31096 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 03:34:33.293830 31128 recover.cpp:447] Starting replica recovery
I0107 03:34:33.294358 31128 recover.cpp:473] Replica is in EMPTY status
I0107 03:34:33.295356 31117 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12980)@172.17.0.5:44990
I0107 03:34:33.295896 31124 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 03:34:33.296394 31118 recover.cpp:564] Updating replica status to STARTING
I0107 03:34:33.296762 31120 master.cpp:365] Master 6dd7c428-c54c-43d8-ac66-8dda5c551cef (d5186ce46002) started on 172.17.0.5:44990
I0107 03:34:33.296788 31120 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/mprxsM/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/mprxsM/master" --zk_session_timeout="10secs"
I0107 03:34:33.297045 31120 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 03:34:33.297055 31120 master.cpp:417] Master only allowing authenticated slaves to register
I0107 03:34:33.297061 31120 credentials.hpp:35] Loading credentials for authentication from '/tmp/mprxsM/credentials'
I0107 03:34:33.297338 31120 master.cpp:456] Using default 'crammd5' authenticator
I0107 03:34:33.297451 31120 master.cpp:493] Authorization enabled
I0107 03:34:33.297600 31117 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 03:34:33.297616 31115 whitelist_watcher.cpp:77] No whitelist given
I0107 03:34:33.299159 31129 master.cpp:1629] The newly elected leader is master@172.17.0.5:44990 with id 6dd7c428-c54c-43d8-ac66-8dda5c551cef
I0107 03:34:33.299275 31129 master.cpp:1642] Elected as the leading master!
I0107 03:34:33.299300 31129 master.cpp:1387] Recovering from registrar
I0107 03:34:33.299453 31121 registrar.cpp:307] Recovering registrar
I0107 03:34:33.318192 31116 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 21.675185ms
I0107 03:34:33.318254 31116 replica.cpp:320] Persisted replica status to STARTING
I0107 03:34:33.318511 31128 recover.cpp:473] Replica is in STARTING status
I0107 03:34:33.319538 31128 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12981)@172.17.0.5:44990
I0107 03:34:33.319902 31116 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 03:34:33.320551 31130 recover.cpp:564] Updating replica status to VOTING
I0107 03:34:33.343682 31116 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.84763ms
I0107 03:34:33.343760 31116 replica.cpp:320] Persisted replica status to VOTING
I0107 03:34:33.343963 31125 recover.cpp:578] Successfully joined the Paxos group
I0107 03:34:33.344182 31125 recover.cpp:462] Recover process terminated
I0107 03:34:33.344689 31116 log.cpp:659] Attempting to start the writer
I0107 03:34:33.346174 31125 replica.cpp:493] Replica received implicit promise request from (12982)@172.17.0.5:44990 with proposal 1
I0107 03:34:33.368757 31125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.508536ms
I0107 03:34:33.368859 31125 replica.cpp:342] Persisted promised to 1
I0107 03:34:33.369884 31125 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 03:34:33.371258 31119 replica.cpp:388] Replica received explicit promise request from (12983)@172.17.0.5:44990 for position 0 with proposal 2
I0107 03:34:33.393900 31119 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 22.575679ms
I0107 03:34:33.393987 31119 replica.cpp:712] Persisted action at 0
I0107 03:34:33.395462 31125 replica.cpp:537] Replica received write request for position 0 from (12984)@172.17.0.5:44990
I0107 03:34:33.395544 31125 leveldb.cpp:436] Reading position from leveldb took 39347ns
I0107 03:34:33.425209 31125 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 29.601471ms
I0107 03:34:33.425299 31125 replica.cpp:712] Persisted action at 0
I0107 03:34:33.426533 31129 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 03:34:33.470257 31129 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 43.671921ms
I0107 03:34:33.470341 31129 replica.cpp:712] Persisted action at 0
I0107 03:34:33.470372 31129 replica.cpp:697] Replica learned NOP action at position 0
I0107 03:34:33.471179 31118 log.cpp:675] Writer started with ending position 0
I0107 03:34:33.472347 31128 leveldb.cpp:436] Reading position from leveldb took 50595ns
I0107 03:34:33.473523 31116 registrar.cpp:340] Successfully fetched the registry (0B) in 174.03008ms
I0107 03:34:33.473690 31116 registrar.cpp:439] Applied 1 operations in 55175ns; attempting to update the 'registry'
I0107 03:34:33.474519 31126 log.cpp:683] Attempting to append 170 bytes to the log
I0107 03:34:33.474659 31129 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 03:34:33.475476 31127 replica.cpp:537] Replica received write request for position 1 from (12985)@172.17.0.5:44990
I0107 03:34:33.503849 31127 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 28.313627ms
I0107 03:34:33.503921 31127 replica.cpp:712] Persisted action at 1
I0107 03:34:33.504916 31126 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 03:34:33.535702 31126 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 30.746859ms
I0107 03:34:33.535739 31126 replica.cpp:712] Persisted action at 1
I0107 03:34:33.535759 31126 replica.cpp:697] Replica learned APPEND action at position 1
I0107 03:34:33.536845 31128 registrar.cpp:484] Successfully updated the 'registry' in 63.009792ms
I0107 03:34:33.536973 31128 registrar.cpp:370] Successfully recovered registrar
I0107 03:34:33.537114 31117 log.cpp:702] Attempting to truncate the log to 1
I0107 03:34:33.537361 31118 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 03:34:33.537434 31117 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 03:34:33.537469 31118 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 03:34:33.538327 31130 replica.cpp:537] Replica received write request for position 2 from (12986)@172.17.0.5:44990
I0107 03:34:33.569425 31130 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 31.042949ms
I0107 03:34:33.569512 31130 replica.cpp:712] Persisted action at 2
I0107 03:34:33.570719 31124 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 03:34:33.595043 31124 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.124174ms
I0107 03:34:33.595224 31124 leveldb.cpp:399] Deleting ~1 keys from leveldb took 86455ns
I0107 03:34:33.595257 31124 replica.cpp:712] Persisted action at 2
I0107 03:34:33.595296 31124 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 03:34:33.599004 31096 scheduler.cpp:154] Version: 0.27.0
I0107 03:34:33.599820 31127 scheduler.cpp:236] New master detected at master@172.17.0.5:44990
I0107 03:34:33.601234 31118 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.5:44990
I0107 03:34:33.603260 31126 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 03:34:33.603740 31128 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:45661
I0107 03:34:33.604070 31128 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 03:34:33.604130 31128 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 03:34:33.604423 31128 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 03:34:33.604853 31121 hierarchical.cpp:260] Added framework 6dd7c428-c54c-43d8-ac66-8dda5c551cef-0000
I0107 03:34:33.604923 31121 hierarchical.cpp:1329] No resources available to allocate!
I0107 03:34:33.604943 31128 master.hpp:1662] Sending heartbeat to 6dd7c428-c54c-43d8-ac66-8dda5c551cef-0000
I0107 03:34:33.604959 31121 hierarchical.cpp:1423] No inverse offers to send out!
I0107 03:34:33.604986 31121 hierarchical.cpp:1079] Performed allocation for 0 slaves in 105976ns
I0107 03:34:33.606186 31122 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.5:44990
I0107 03:34:33.606655 31122 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.5:44990
I0107 03:34:33.607200 31120 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 03:34:33.607481 31128 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.5:44990
I0107 03:34:33.608990 31123 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 03:34:33.609417 31121 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.5:45662
I0107 03:34:33.609704 31121 master.cpp:2636] Processing REQUEST call for framework 6dd7c428-c54c-43d8-ac66-8dda5c551cef-0000 (default)
I0107 03:34:33.609891 31119 hierarchical.cpp:579] Received resource request from framework 6dd7c428-c54c-43d8-ac66-8dda5c551cef-0000
I0107 03:34:33.610283 31115 master.cpp:930] Master terminating
I0107 03:34:33.610946 31124 hierarchical.cpp:321] Removed framework 6dd7c428-c54c-43d8-ac66-8dda5c551cef-0000
E0107 03:34:33.615695 31124 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (473 ms)
[----------] 22 tests from ContentType/SchedulerTest (18621 ms total)
[----------] Global test environment tear-down
2016-01-07 03:34:33,864:31096(0x2b5202774700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:36709] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
[==========] 923 tests from 120 test cases ran. (901250 ms total)
[ PASSED ] 922 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DiskUsageCollectorTest.File
1 FAILED TEST
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-1452135045-18967
Untagged: mesos-1452135045-18967:latest
Deleted: c3a1ba384c96138f56c772330ced238281d35c32bd692215c6ca14191c741b2d
Deleted: 67fe27601555a1d8c9eddb5c9a12b13e7a64b8796a37a9649a34eee148de6c43
Deleted: 33702f666d1e99152663209303f4ed45dd09c8c1c91cefc9b1550eb68e6a5114
Deleted: 9dc5a6260708eb152c96acdcd1e0001687d9c8f2665fcf272028d437e64a43ed
Deleted: 7c97a38cbb70ea7d4340d113c90ef84a280f95d9db4e1e0fd8b4c7b2223ea9cb
Deleted: a68283425dd902abbf43762f6e4b5904f4509306623bd90c53ecbf23581bb4e3
Deleted: fd0bac1355bd9a27814170b436ac6aefe75aacaac6c362d4a3c30abfff2bdcf3
Deleted: 63911d2286749c00344e58ed4708245a2cfbea1ef6f299cd0168bc8e145c3e82
Deleted: e92900f30f3061a81925cb552e4afe860160f734f5911c054a4c21053fe22c1d
Deleted: 42e6829fd0c10183ccf11364551cd93a672a7edd0fc11162e52e27484f5fb271
Deleted: ec58f47e06076acc7246178850f3c85df4120a871e974d0c2020684c3347b056
Deleted: 765e7764e40dc3ce6022c37c130afb40b9f70608f31eda08d46a51f648646e45
Deleted: 69ea42bff1bba3bdbea64c79b30e962213b79cc77d7e66374c58f2f19eaf2584
Error handling URL https://reviews.apache.org/api/review-requests/41963/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard c258d8af79e20053e99aaf85491412f8ad58ab2e
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10628
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10628/changes>
Changes:
[adam] Updated master help message for acls.
[yujie.jay] Added user facing documentation for containerizers.
------------------------------------------
[...truncated 162926 lines...]
I0107 02:26:56.089622 31123 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_GOKAzP/slaves/075e696f-de37-47e2-85d2-6a12218864dd-S0/frameworks/075e696f-de37-47e2-85d2-6a12218864dd-0000' for gc 6.99999896376296days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (119 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0107 02:26:56.099406 31099 leveldb.cpp:174] Opened db in 3.42938ms
I0107 02:26:56.100855 31099 leveldb.cpp:181] Compacted db in 1.393082ms
I0107 02:26:56.100926 31099 leveldb.cpp:196] Created db iterator in 22662ns
I0107 02:26:56.100947 31099 leveldb.cpp:202] Seeked to beginning of db in 2208ns
I0107 02:26:56.100960 31099 leveldb.cpp:271] Iterated through 0 keys in the db in 370ns
I0107 02:26:56.101002 31099 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 02:26:56.102048 31120 recover.cpp:447] Starting replica recovery
I0107 02:26:56.102411 31120 recover.cpp:473] Replica is in EMPTY status
I0107 02:26:56.104342 31133 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12959)@172.17.0.3:44927
I0107 02:26:56.105258 31118 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 02:26:56.105592 31123 master.cpp:365] Master 4ad48e64-9832-4824-a4d6-fa8026db3662 (0686e6d6375c) started on 172.17.0.3:44927
I0107 02:26:56.105643 31123 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/4M47kv/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/4M47kv/master" --zk_session_timeout="10secs"
I0107 02:26:56.106133 31123 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 02:26:56.106160 31123 master.cpp:417] Master only allowing authenticated slaves to register
I0107 02:26:56.106178 31123 credentials.hpp:35] Loading credentials for authentication from '/tmp/4M47kv/credentials'
I0107 02:26:56.106415 31132 recover.cpp:564] Updating replica status to STARTING
I0107 02:26:56.106688 31123 master.cpp:456] Using default 'crammd5' authenticator
I0107 02:26:56.106912 31123 master.cpp:493] Authorization enabled
I0107 02:26:56.107118 31127 whitelist_watcher.cpp:77] No whitelist given
I0107 02:26:56.107214 31126 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 02:26:56.107337 31133 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 736931ns
I0107 02:26:56.107368 31133 replica.cpp:320] Persisted replica status to STARTING
I0107 02:26:56.107759 31122 recover.cpp:473] Replica is in STARTING status
I0107 02:26:56.109266 31123 master.cpp:1629] The newly elected leader is master@172.17.0.3:44927 with id 4ad48e64-9832-4824-a4d6-fa8026db3662
I0107 02:26:56.109313 31123 master.cpp:1642] Elected as the leading master!
I0107 02:26:56.109345 31123 master.cpp:1387] Recovering from registrar
I0107 02:26:56.109529 31122 registrar.cpp:307] Recovering registrar
I0107 02:26:56.109609 31127 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12960)@172.17.0.3:44927
I0107 02:26:56.109922 31132 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 02:26:56.110546 31127 recover.cpp:564] Updating replica status to VOTING
I0107 02:26:56.111199 31122 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 463626ns
I0107 02:26:56.111224 31122 replica.cpp:320] Persisted replica status to VOTING
I0107 02:26:56.111320 31132 recover.cpp:578] Successfully joined the Paxos group
I0107 02:26:56.111515 31132 recover.cpp:462] Recover process terminated
I0107 02:26:56.111915 31119 log.cpp:659] Attempting to start the writer
I0107 02:26:56.113083 31118 replica.cpp:493] Replica received implicit promise request from (12961)@172.17.0.3:44927 with proposal 1
I0107 02:26:56.113546 31118 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 427980ns
I0107 02:26:56.113569 31118 replica.cpp:342] Persisted promised to 1
I0107 02:26:56.114068 31120 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 02:26:56.115111 31124 replica.cpp:388] Replica received explicit promise request from (12962)@172.17.0.3:44927 for position 0 with proposal 2
I0107 02:26:56.115623 31124 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 474072ns
I0107 02:26:56.115648 31124 replica.cpp:712] Persisted action at 0
I0107 02:26:56.116705 31128 replica.cpp:537] Replica received write request for position 0 from (12963)@172.17.0.3:44927
I0107 02:26:56.116763 31128 leveldb.cpp:436] Reading position from leveldb took 27476ns
I0107 02:26:56.117326 31128 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 526865ns
I0107 02:26:56.117352 31128 replica.cpp:712] Persisted action at 0
I0107 02:26:56.117951 31130 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 02:26:56.118486 31130 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 502879ns
I0107 02:26:56.118510 31130 replica.cpp:712] Persisted action at 0
I0107 02:26:56.118527 31130 replica.cpp:697] Replica learned NOP action at position 0
I0107 02:26:56.119061 31127 log.cpp:675] Writer started with ending position 0
I0107 02:26:56.120033 31133 leveldb.cpp:436] Reading position from leveldb took 24104ns
I0107 02:26:56.120894 31119 registrar.cpp:340] Successfully fetched the registry (0B) in 11.239168ms
I0107 02:26:56.120995 31119 registrar.cpp:439] Applied 1 operations in 23975ns; attempting to update the 'registry'
I0107 02:26:56.121770 31129 log.cpp:683] Attempting to append 170 bytes to the log
I0107 02:26:56.121986 31131 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 02:26:56.122638 31119 replica.cpp:537] Replica received write request for position 1 from (12964)@172.17.0.3:44927
I0107 02:26:56.123350 31119 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 674722ns
I0107 02:26:56.123383 31119 replica.cpp:712] Persisted action at 1
I0107 02:26:56.124080 31131 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 02:26:56.124691 31131 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 582282ns
I0107 02:26:56.124716 31131 replica.cpp:712] Persisted action at 1
I0107 02:26:56.124733 31131 replica.cpp:697] Replica learned APPEND action at position 1
I0107 02:26:56.125795 31120 registrar.cpp:484] Successfully updated the 'registry' in 4.728064ms
I0107 02:26:56.125962 31120 registrar.cpp:370] Successfully recovered registrar
I0107 02:26:56.126109 31121 log.cpp:702] Attempting to truncate the log to 1
I0107 02:26:56.126371 31128 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 02:26:56.126730 31132 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 02:26:56.127054 31125 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 02:26:56.127385 31125 replica.cpp:537] Replica received write request for position 2 from (12965)@172.17.0.3:44927
I0107 02:26:56.127985 31125 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 552710ns
I0107 02:26:56.128018 31125 replica.cpp:712] Persisted action at 2
I0107 02:26:56.128669 31124 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 02:26:56.129277 31124 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 569927ns
I0107 02:26:56.129349 31124 leveldb.cpp:399] Deleting ~1 keys from leveldb took 39986ns
I0107 02:26:56.129372 31124 replica.cpp:712] Persisted action at 2
I0107 02:26:56.129401 31124 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 02:26:56.137370 31099 scheduler.cpp:154] Version: 0.27.0
I0107 02:26:56.138180 31127 scheduler.cpp:236] New master detected at master@172.17.0.3:44927
I0107 02:26:56.139706 31124 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:44927
I0107 02:26:56.141944 31127 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 02:26:56.142568 31131 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:59820
I0107 02:26:56.142782 31131 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 02:26:56.142889 31131 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 02:26:56.143231 31131 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 02:26:56.143682 31118 hierarchical.cpp:260] Added framework 4ad48e64-9832-4824-a4d6-fa8026db3662-0000
I0107 02:26:56.143707 31125 master.hpp:1662] Sending heartbeat to 4ad48e64-9832-4824-a4d6-fa8026db3662-0000
I0107 02:26:56.143890 31118 hierarchical.cpp:1329] No resources available to allocate!
I0107 02:26:56.144170 31118 hierarchical.cpp:1423] No inverse offers to send out!
I0107 02:26:56.144243 31118 hierarchical.cpp:1079] Performed allocation for 0 slaves in 423065ns
I0107 02:26:56.144681 31131 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:44927
I0107 02:26:56.145254 31131 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:44927
I0107 02:26:56.146056 31126 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 02:26:56.146270 31128 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:44927
I0107 02:26:56.148382 31120 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 02:26:56.148921 31131 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:59821
I0107 02:26:56.149075 31131 master.cpp:2636] Processing REQUEST call for framework 4ad48e64-9832-4824-a4d6-fa8026db3662-0000 (default)
I0107 02:26:56.149261 31125 hierarchical.cpp:579] Received resource request from framework 4ad48e64-9832-4824-a4d6-fa8026db3662-0000
I0107 02:26:56.149700 31119 master.cpp:930] Master terminating
I0107 02:26:56.149966 31118 hierarchical.cpp:321] Removed framework 4ad48e64-9832-4824-a4d6-fa8026db3662-0000
E0107 02:26:56.151255 31125 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (62 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0107 02:26:56.160745 31099 leveldb.cpp:174] Opened db in 3.200895ms
I0107 02:26:56.161840 31099 leveldb.cpp:181] Compacted db in 1.054793ms
I0107 02:26:56.161903 31099 leveldb.cpp:196] Created db iterator in 18057ns
I0107 02:26:56.161924 31099 leveldb.cpp:202] Seeked to beginning of db in 1645ns
I0107 02:26:56.161936 31099 leveldb.cpp:271] Iterated through 0 keys in the db in 557ns
I0107 02:26:56.161972 31099 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 02:26:56.162416 31118 recover.cpp:447] Starting replica recovery
I0107 02:26:56.162801 31126 recover.cpp:473] Replica is in EMPTY status
I0107 02:26:56.164022 31123 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12973)@172.17.0.3:44927
I0107 02:26:56.164733 31123 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 02:26:56.165364 31124 recover.cpp:564] Updating replica status to STARTING
I0107 02:26:56.166501 31118 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 607806ns
I0107 02:26:56.166542 31118 replica.cpp:320] Persisted replica status to STARTING
I0107 02:26:56.166652 31131 master.cpp:365] Master 0aea668b-7a93-4114-8f01-cc306b2f1d15 (0686e6d6375c) started on 172.17.0.3:44927
I0107 02:26:56.166844 31128 recover.cpp:473] Replica is in STARTING status
I0107 02:26:56.166710 31131 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/xAylc4/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/xAylc4/master" --zk_session_timeout="10secs"
I0107 02:26:56.167230 31131 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 02:26:56.167254 31131 master.cpp:417] Master only allowing authenticated slaves to register
I0107 02:26:56.167273 31131 credentials.hpp:35] Loading credentials for authentication from '/tmp/xAylc4/credentials'
I0107 02:26:56.167668 31131 master.cpp:456] Using default 'crammd5' authenticator
I0107 02:26:56.167860 31131 master.cpp:493] Authorization enabled
I0107 02:26:56.168002 31118 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12974)@172.17.0.3:44927
I0107 02:26:56.168087 31132 whitelist_watcher.cpp:77] No whitelist given
I0107 02:26:56.168311 31123 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 02:26:56.168601 31133 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 02:26:56.168962 31130 recover.cpp:564] Updating replica status to VOTING
I0107 02:26:56.169708 31122 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 507943ns
I0107 02:26:56.169739 31122 replica.cpp:320] Persisted replica status to VOTING
I0107 02:26:56.169936 31121 recover.cpp:578] Successfully joined the Paxos group
I0107 02:26:56.170197 31121 recover.cpp:462] Recover process terminated
I0107 02:26:56.170364 31124 master.cpp:1629] The newly elected leader is master@172.17.0.3:44927 with id 0aea668b-7a93-4114-8f01-cc306b2f1d15
I0107 02:26:56.170399 31124 master.cpp:1642] Elected as the leading master!
I0107 02:26:56.170421 31124 master.cpp:1387] Recovering from registrar
I0107 02:26:56.170573 31130 registrar.cpp:307] Recovering registrar
I0107 02:26:56.171077 31119 log.cpp:659] Attempting to start the writer
I0107 02:26:56.172199 31122 replica.cpp:493] Replica received implicit promise request from (12975)@172.17.0.3:44927 with proposal 1
I0107 02:26:56.172674 31122 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 442091ns
I0107 02:26:56.172699 31122 replica.cpp:342] Persisted promised to 1
I0107 02:26:56.173250 31125 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 02:26:56.174407 31127 replica.cpp:388] Replica received explicit promise request from (12976)@172.17.0.3:44927 for position 0 with proposal 2
I0107 02:26:56.174896 31127 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 441359ns
I0107 02:26:56.174922 31127 replica.cpp:712] Persisted action at 0
I0107 02:26:56.175920 31126 replica.cpp:537] Replica received write request for position 0 from (12977)@172.17.0.3:44927
I0107 02:26:56.175983 31126 leveldb.cpp:436] Reading position from leveldb took 26803ns
I0107 02:26:56.176661 31126 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 639873ns
I0107 02:26:56.176688 31126 replica.cpp:712] Persisted action at 0
I0107 02:26:56.177374 31127 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 02:26:56.178107 31127 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 698764ns
I0107 02:26:56.178134 31127 replica.cpp:712] Persisted action at 0
I0107 02:26:56.178153 31127 replica.cpp:697] Replica learned NOP action at position 0
I0107 02:26:56.178680 31120 log.cpp:675] Writer started with ending position 0
I0107 02:26:56.179656 31118 leveldb.cpp:436] Reading position from leveldb took 27444ns
I0107 02:26:56.180608 31131 registrar.cpp:340] Successfully fetched the registry (0B) in 9.96608ms
I0107 02:26:56.180732 31131 registrar.cpp:439] Applied 1 operations in 25860ns; attempting to update the 'registry'
I0107 02:26:56.181553 31130 log.cpp:683] Attempting to append 170 bytes to the log
I0107 02:26:56.181684 31124 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 02:26:56.182478 31121 replica.cpp:537] Replica received write request for position 1 from (12978)@172.17.0.3:44927
I0107 02:26:56.183210 31121 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 682762ns
I0107 02:26:56.183240 31121 replica.cpp:712] Persisted action at 1
I0107 02:26:56.183946 31128 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 02:26:56.184650 31128 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 663306ns
I0107 02:26:56.184681 31128 replica.cpp:712] Persisted action at 1
I0107 02:26:56.184708 31128 replica.cpp:697] Replica learned APPEND action at position 1
I0107 02:26:56.185732 31131 registrar.cpp:484] Successfully updated the 'registry' in 4.933888ms
I0107 02:26:56.185948 31131 registrar.cpp:370] Successfully recovered registrar
I0107 02:26:56.186044 31132 log.cpp:702] Attempting to truncate the log to 1
I0107 02:26:56.186297 31128 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 02:26:56.186697 31127 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 02:26:56.186728 31122 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 02:26:56.187399 31122 replica.cpp:537] Replica received write request for position 2 from (12979)@172.17.0.3:44927
I0107 02:26:56.188015 31122 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 572604ns
I0107 02:26:56.188047 31122 replica.cpp:712] Persisted action at 2
I0107 02:26:56.188892 31128 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 02:26:56.189504 31128 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 573579ns
I0107 02:26:56.189569 31128 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33357ns
I0107 02:26:56.189594 31128 replica.cpp:712] Persisted action at 2
I0107 02:26:56.189616 31128 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 02:26:56.197279 31099 scheduler.cpp:154] Version: 0.27.0
I0107 02:26:56.198025 31132 scheduler.cpp:236] New master detected at master@172.17.0.3:44927
I0107 02:26:56.199210 31120 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:44927
I0107 02:26:56.201205 31125 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 02:26:56.201715 31120 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:59822
I0107 02:26:56.202118 31120 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 02:26:56.202184 31120 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 02:26:56.202527 31120 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 02:26:56.203022 31131 hierarchical.cpp:260] Added framework 0aea668b-7a93-4114-8f01-cc306b2f1d15-0000
I0107 02:26:56.203094 31131 hierarchical.cpp:1329] No resources available to allocate!
I0107 02:26:56.203193 31129 master.hpp:1662] Sending heartbeat to 0aea668b-7a93-4114-8f01-cc306b2f1d15-0000
I0107 02:26:56.203269 31131 hierarchical.cpp:1423] No inverse offers to send out!
I0107 02:26:56.203464 31131 hierarchical.cpp:1079] Performed allocation for 0 slaves in 404394ns
I0107 02:26:56.204545 31126 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:44927
I0107 02:26:56.205180 31126 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:44927
I0107 02:26:56.205884 31125 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 02:26:56.205895 31126 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:44927
I0107 02:26:56.207767 31122 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 02:26:56.208370 31120 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:59823
I0107 02:26:56.208641 31120 master.cpp:2636] Processing REQUEST call for framework 0aea668b-7a93-4114-8f01-cc306b2f1d15-0000 (default)
I0107 02:26:56.208855 31123 hierarchical.cpp:579] Received resource request from framework 0aea668b-7a93-4114-8f01-cc306b2f1d15-0000
I0107 02:26:56.209199 31099 master.cpp:930] Master terminating
I0107 02:26:56.209430 31133 hierarchical.cpp:321] Removed framework 0aea668b-7a93-4114-8f01-cc306b2f1d15-0000
E0107 02:26:56.211168 31125 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (61 ms)
[----------] 22 tests from ContentType/SchedulerTest (4208 ms total)
[----------] Global test environment tear-down
[==========] 923 tests from 120 test cases ran. (331375 ms total)
[ PASSED ] 922 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DiskUsageCollectorTest.File
1 FAILED TEST
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-1452131938-28916
Untagged: mesos-1452131938-28916:latest
Deleted: 495ee21efed90ecab70f8c90a92a7ea092c6fb5b75afceb5be5e7b8205d6f61d
Deleted: 0a123eec71fac66a68f864b6c0577196c39bc4943a9ff5bbb6d3907397534eec
Deleted: a2ad5fe95ab7d87b609bc1b07b2738f7db68306da8fd81a14360ad303acfd7c0
Deleted: 28f7d1a0fdbd8b76b0991e8e508126c159f6adb36edcbe6ccac0f6ec17b581cc
Deleted: ee1804b797bafe56c6827766b778cee869b247450ea260a09a8c39a7d36adc82
Deleted: 912550ca010b4eaa1da1befec9f97284959835ad7d59b5d863ef20ed348c7e28
Deleted: e57df00c393a684ec10ead4377d467cb99e0c3a55b6cbf5e961b81cd095657e1
Deleted: f58c44c4d1c5c60a3d7797c9cc9df5c8991de4a4ba9b8167d464eb516e9cd9ec
Deleted: ebe51c7064d0dc552647bc125e60ace47cd4e922d04a28343c74f6b2d1dd7705
Deleted: 12e9a5c2a9a182d4e6e61a8ee3a781f468faa375b06c5818eb6fc42a6be65641
Deleted: d86ccb94454b5b145ca7abd63910786b1145d60887b14b57d323a570cc4780f7
Deleted: ffcb9a90c749256eabe26942d6f6347c6f31d144b22be906145b944656189eb3
Deleted: 3d70d9b7330b79bef07a4b2401478159f55436b661d53deba85c5859956e53fa
Error handling URL https://reviews.apache.org/api/review-requests/41963/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard c258d8af79e20053e99aaf85491412f8ad58ab2e
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10627
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10627/>
------------------------------------------
[...truncated 163104 lines...]
I0107 01:37:44.761262 31130 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_T110hT/slaves/ab7a0118-b435-4214-b4e1-4d99347255b7-S0/frameworks/ab7a0118-b435-4214-b4e1-4d99347255b7-0000' for gc 6.99999119072889days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (118 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0107 01:37:44.769491 31103 leveldb.cpp:174] Opened db in 3.089882ms
I0107 01:37:44.770742 31103 leveldb.cpp:181] Compacted db in 1.208268ms
I0107 01:37:44.770812 31103 leveldb.cpp:196] Created db iterator in 22922ns
I0107 01:37:44.770860 31103 leveldb.cpp:202] Seeked to beginning of db in 2360ns
I0107 01:37:44.770874 31103 leveldb.cpp:271] Iterated through 0 keys in the db in 455ns
I0107 01:37:44.770916 31103 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 01:37:44.771420 31123 recover.cpp:447] Starting replica recovery
I0107 01:37:44.771656 31123 recover.cpp:473] Replica is in EMPTY status
I0107 01:37:44.772965 31122 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12954)@172.17.0.2:51128
I0107 01:37:44.773407 31126 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 01:37:44.773957 31137 recover.cpp:564] Updating replica status to STARTING
I0107 01:37:44.774727 31125 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 524448ns
I0107 01:37:44.774760 31125 replica.cpp:320] Persisted replica status to STARTING
I0107 01:37:44.774991 31125 recover.cpp:473] Replica is in STARTING status
I0107 01:37:44.775245 31137 master.cpp:365] Master 9bb7f08b-bca8-4399-87eb-b54a69ff1b11 (61dd45284c44) started on 172.17.0.2:51128
I0107 01:37:44.775277 31137 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/0m7aEr/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/0m7aEr/master" --zk_session_timeout="10secs"
I0107 01:37:44.775607 31137 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 01:37:44.775630 31137 master.cpp:417] Master only allowing authenticated slaves to register
I0107 01:37:44.775648 31137 credentials.hpp:35] Loading credentials for authentication from '/tmp/0m7aEr/credentials'
I0107 01:37:44.776021 31137 master.cpp:456] Using default 'crammd5' authenticator
I0107 01:37:44.776109 31124 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12955)@172.17.0.2:51128
I0107 01:37:44.776206 31137 master.cpp:493] Authorization enabled
I0107 01:37:44.776417 31125 whitelist_watcher.cpp:77] No whitelist given
I0107 01:37:44.776443 31131 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 01:37:44.776768 31130 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 01:37:44.777432 31133 recover.cpp:564] Updating replica status to VOTING
I0107 01:37:44.778372 31127 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 436907ns
I0107 01:37:44.778408 31127 replica.cpp:320] Persisted replica status to VOTING
I0107 01:37:44.778592 31132 recover.cpp:578] Successfully joined the Paxos group
I0107 01:37:44.778976 31132 recover.cpp:462] Recover process terminated
I0107 01:37:44.779088 31127 master.cpp:1629] The newly elected leader is master@172.17.0.2:51128 with id 9bb7f08b-bca8-4399-87eb-b54a69ff1b11
I0107 01:37:44.779130 31127 master.cpp:1642] Elected as the leading master!
I0107 01:37:44.779160 31127 master.cpp:1387] Recovering from registrar
I0107 01:37:44.779376 31128 registrar.cpp:307] Recovering registrar
I0107 01:37:44.780105 31131 log.cpp:659] Attempting to start the writer
I0107 01:37:44.781263 31123 replica.cpp:493] Replica received implicit promise request from (12956)@172.17.0.2:51128 with proposal 1
I0107 01:37:44.781688 31123 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 391742ns
I0107 01:37:44.781714 31123 replica.cpp:342] Persisted promised to 1
I0107 01:37:44.782359 31132 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 01:37:44.783722 31129 replica.cpp:388] Replica received explicit promise request from (12957)@172.17.0.2:51128 for position 0 with proposal 2
I0107 01:37:44.784167 31129 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 400811ns
I0107 01:37:44.784193 31129 replica.cpp:712] Persisted action at 0
I0107 01:37:44.785342 31122 replica.cpp:537] Replica received write request for position 0 from (12958)@172.17.0.2:51128
I0107 01:37:44.785408 31122 leveldb.cpp:436] Reading position from leveldb took 28789ns
I0107 01:37:44.785872 31122 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 412185ns
I0107 01:37:44.785903 31122 replica.cpp:712] Persisted action at 0
I0107 01:37:44.786520 31124 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 01:37:44.787034 31124 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 477102ns
I0107 01:37:44.787062 31124 replica.cpp:712] Persisted action at 0
I0107 01:37:44.787091 31124 replica.cpp:697] Replica learned NOP action at position 0
I0107 01:37:44.787765 31130 log.cpp:675] Writer started with ending position 0
I0107 01:37:44.788704 31127 leveldb.cpp:436] Reading position from leveldb took 34557ns
I0107 01:37:44.789706 31124 registrar.cpp:340] Successfully fetched the registry (0B) in 10.274048ms
I0107 01:37:44.789813 31124 registrar.cpp:439] Applied 1 operations in 21174ns; attempting to update the 'registry'
I0107 01:37:44.790575 31133 log.cpp:683] Attempting to append 170 bytes to the log
I0107 01:37:44.790702 31132 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 01:37:44.791544 31133 replica.cpp:537] Replica received write request for position 1 from (12959)@172.17.0.2:51128
I0107 01:37:44.791959 31133 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 369104ns
I0107 01:37:44.791990 31133 replica.cpp:712] Persisted action at 1
I0107 01:37:44.793068 31137 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 01:37:44.793678 31137 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 569847ns
I0107 01:37:44.793715 31137 replica.cpp:712] Persisted action at 1
I0107 01:37:44.793742 31137 replica.cpp:697] Replica learned APPEND action at position 1
I0107 01:37:44.794859 31123 registrar.cpp:484] Successfully updated the 'registry' in 4.905728ms
I0107 01:37:44.795032 31123 registrar.cpp:370] Successfully recovered registrar
I0107 01:37:44.795193 31134 log.cpp:702] Attempting to truncate the log to 1
I0107 01:37:44.795446 31133 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 01:37:44.795649 31128 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 01:37:44.795706 31123 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 01:37:44.796571 31131 replica.cpp:537] Replica received write request for position 2 from (12960)@172.17.0.2:51128
I0107 01:37:44.797080 31131 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 463026ns
I0107 01:37:44.797111 31131 replica.cpp:712] Persisted action at 2
I0107 01:37:44.797932 31131 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 01:37:44.798483 31131 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 512268ns
I0107 01:37:44.798547 31131 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33114ns
I0107 01:37:44.798573 31131 replica.cpp:712] Persisted action at 2
I0107 01:37:44.798595 31131 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 01:37:44.806439 31103 scheduler.cpp:154] Version: 0.27.0
I0107 01:37:44.807073 31132 scheduler.cpp:236] New master detected at master@172.17.0.2:51128
I0107 01:37:44.808362 31134 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:51128
I0107 01:37:44.810401 31130 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 01:37:44.810999 31136 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:34008
I0107 01:37:44.811262 31136 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 01:37:44.811345 31136 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 01:37:44.811691 31136 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 01:37:44.812202 31134 hierarchical.cpp:260] Added framework 9bb7f08b-bca8-4399-87eb-b54a69ff1b11-0000
I0107 01:37:44.812243 31131 master.hpp:1662] Sending heartbeat to 9bb7f08b-bca8-4399-87eb-b54a69ff1b11-0000
I0107 01:37:44.812280 31134 hierarchical.cpp:1329] No resources available to allocate!
I0107 01:37:44.812327 31134 hierarchical.cpp:1423] No inverse offers to send out!
I0107 01:37:44.812363 31134 hierarchical.cpp:1079] Performed allocation for 0 slaves in 123522ns
I0107 01:37:44.813158 31129 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:51128
I0107 01:37:44.813805 31129 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:51128
I0107 01:37:44.814860 31130 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 01:37:44.814991 31129 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:51128
I0107 01:37:44.816898 31124 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 01:37:44.817384 31137 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:34009
I0107 01:37:44.817510 31137 master.cpp:2636] Processing REQUEST call for framework 9bb7f08b-bca8-4399-87eb-b54a69ff1b11-0000 (default)
I0107 01:37:44.817734 31131 hierarchical.cpp:579] Received resource request from framework 9bb7f08b-bca8-4399-87eb-b54a69ff1b11-0000
I0107 01:37:44.818136 31126 master.cpp:930] Master terminating
I0107 01:37:44.818397 31127 hierarchical.cpp:321] Removed framework 9bb7f08b-bca8-4399-87eb-b54a69ff1b11-0000
E0107 01:37:44.819530 31129 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (61 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0107 01:37:44.830662 31103 leveldb.cpp:174] Opened db in 3.258311ms
I0107 01:37:44.831719 31103 leveldb.cpp:181] Compacted db in 1.017536ms
I0107 01:37:44.831784 31103 leveldb.cpp:196] Created db iterator in 16902ns
I0107 01:37:44.831812 31103 leveldb.cpp:202] Seeked to beginning of db in 1967ns
I0107 01:37:44.831852 31103 leveldb.cpp:271] Iterated through 0 keys in the db in 503ns
I0107 01:37:44.831889 31103 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0107 01:37:44.832288 31129 recover.cpp:447] Starting replica recovery
I0107 01:37:44.832617 31127 recover.cpp:473] Replica is in EMPTY status
I0107 01:37:44.833784 31128 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (12968)@172.17.0.2:51128
I0107 01:37:44.834254 31126 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0107 01:37:44.834872 31134 recover.cpp:564] Updating replica status to STARTING
I0107 01:37:44.835590 31123 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 552684ns
I0107 01:37:44.835626 31123 replica.cpp:320] Persisted replica status to STARTING
I0107 01:37:44.835865 31125 master.cpp:365] Master 438bc522-fc27-4013-95de-34a04a2282c9 (61dd45284c44) started on 172.17.0.2:51128
I0107 01:37:44.835880 31130 recover.cpp:473] Replica is in STARTING status
I0107 01:37:44.836051 31125 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ZZhxHi/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/ZZhxHi/master" --zk_session_timeout="10secs"
I0107 01:37:44.836452 31125 master.cpp:414] Master allowing unauthenticated frameworks to register
I0107 01:37:44.836472 31125 master.cpp:417] Master only allowing authenticated slaves to register
I0107 01:37:44.836489 31125 credentials.hpp:35] Loading credentials for authentication from '/tmp/ZZhxHi/credentials'
I0107 01:37:44.836952 31125 master.cpp:456] Using default 'crammd5' authenticator
I0107 01:37:44.837126 31125 master.cpp:493] Authorization enabled
I0107 01:37:44.837194 31136 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (12969)@172.17.0.2:51128
I0107 01:37:44.837374 31128 hierarchical.cpp:147] Initialized hierarchical allocator process
I0107 01:37:44.837354 31126 whitelist_watcher.cpp:77] No whitelist given
I0107 01:37:44.837657 31123 recover.cpp:193] Received a recover response from a replica in STARTING status
I0107 01:37:44.838310 31124 recover.cpp:564] Updating replica status to VOTING
I0107 01:37:44.838984 31136 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 466857ns
I0107 01:37:44.839014 31136 replica.cpp:320] Persisted replica status to VOTING
I0107 01:37:44.839148 31134 recover.cpp:578] Successfully joined the Paxos group
I0107 01:37:44.839517 31134 recover.cpp:462] Recover process terminated
I0107 01:37:44.839777 31137 master.cpp:1629] The newly elected leader is master@172.17.0.2:51128 with id 438bc522-fc27-4013-95de-34a04a2282c9
I0107 01:37:44.839843 31137 master.cpp:1642] Elected as the leading master!
I0107 01:37:44.839876 31137 master.cpp:1387] Recovering from registrar
I0107 01:37:44.840082 31122 registrar.cpp:307] Recovering registrar
I0107 01:37:44.840750 31137 log.cpp:659] Attempting to start the writer
I0107 01:37:44.842128 31122 replica.cpp:493] Replica received implicit promise request from (12970)@172.17.0.2:51128 with proposal 1
I0107 01:37:44.842492 31122 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 320082ns
I0107 01:37:44.842524 31122 replica.cpp:342] Persisted promised to 1
I0107 01:37:44.843195 31137 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0107 01:37:44.844614 31131 replica.cpp:388] Replica received explicit promise request from (12971)@172.17.0.2:51128 for position 0 with proposal 2
I0107 01:37:44.845016 31131 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 353879ns
I0107 01:37:44.845048 31131 replica.cpp:712] Persisted action at 0
I0107 01:37:44.846231 31133 replica.cpp:537] Replica received write request for position 0 from (12972)@172.17.0.2:51128
I0107 01:37:44.846299 31133 leveldb.cpp:436] Reading position from leveldb took 30241ns
I0107 01:37:44.846660 31133 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 313748ns
I0107 01:37:44.846693 31133 replica.cpp:712] Persisted action at 0
I0107 01:37:44.847348 31122 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0107 01:37:44.847720 31122 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 328167ns
I0107 01:37:44.847751 31122 replica.cpp:712] Persisted action at 0
I0107 01:37:44.847774 31122 replica.cpp:697] Replica learned NOP action at position 0
I0107 01:37:44.848448 31122 log.cpp:675] Writer started with ending position 0
I0107 01:37:44.849648 31128 leveldb.cpp:436] Reading position from leveldb took 32239ns
I0107 01:37:44.850664 31131 registrar.cpp:340] Successfully fetched the registry (0B) in 10.534912ms
I0107 01:37:44.850807 31131 registrar.cpp:439] Applied 1 operations in 35319ns; attempting to update the 'registry'
I0107 01:37:44.851706 31133 log.cpp:683] Attempting to append 170 bytes to the log
I0107 01:37:44.851874 31124 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0107 01:37:44.852771 31124 replica.cpp:537] Replica received write request for position 1 from (12973)@172.17.0.2:51128
I0107 01:37:44.853196 31124 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 357456ns
I0107 01:37:44.853229 31124 replica.cpp:712] Persisted action at 1
I0107 01:37:44.853961 31123 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0107 01:37:44.854367 31123 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 367824ns
I0107 01:37:44.854398 31123 replica.cpp:712] Persisted action at 1
I0107 01:37:44.854420 31123 replica.cpp:697] Replica learned APPEND action at position 1
I0107 01:37:44.855473 31134 registrar.cpp:484] Successfully updated the 'registry' in 4.563968ms
I0107 01:37:44.855666 31134 registrar.cpp:370] Successfully recovered registrar
I0107 01:37:44.855746 31123 log.cpp:702] Attempting to truncate the log to 1
I0107 01:37:44.855909 31137 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0107 01:37:44.856303 31124 master.cpp:1439] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0107 01:37:44.856350 31131 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0107 01:37:44.857015 31123 replica.cpp:537] Replica received write request for position 2 from (12974)@172.17.0.2:51128
I0107 01:37:44.857415 31123 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 352294ns
I0107 01:37:44.857446 31123 replica.cpp:712] Persisted action at 2
I0107 01:37:44.858256 31129 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0107 01:37:44.858671 31129 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 375373ns
I0107 01:37:44.858736 31129 leveldb.cpp:399] Deleting ~1 keys from leveldb took 32970ns
I0107 01:37:44.858760 31129 replica.cpp:712] Persisted action at 2
I0107 01:37:44.858783 31129 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0107 01:37:44.867028 31103 scheduler.cpp:154] Version: 0.27.0
I0107 01:37:44.867637 31137 scheduler.cpp:236] New master detected at master@172.17.0.2:51128
I0107 01:37:44.868810 31122 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:51128
I0107 01:37:44.870983 31131 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 01:37:44.871783 31135 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:34010
I0107 01:37:44.872210 31135 master.cpp:1891] Received subscription request for HTTP framework 'default'
I0107 01:37:44.872273 31135 master.cpp:1668] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0107 01:37:44.872591 31135 master.cpp:1982] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0107 01:37:44.873075 31132 hierarchical.cpp:260] Added framework 438bc522-fc27-4013-95de-34a04a2282c9-0000
I0107 01:37:44.873141 31132 hierarchical.cpp:1329] No resources available to allocate!
I0107 01:37:44.873172 31132 hierarchical.cpp:1423] No inverse offers to send out!
I0107 01:37:44.873183 31137 master.hpp:1662] Sending heartbeat to 438bc522-fc27-4013-95de-34a04a2282c9-0000
I0107 01:37:44.873194 31132 hierarchical.cpp:1079] Performed allocation for 0 slaves in 89057ns
I0107 01:37:44.874259 31122 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:51128
I0107 01:37:44.874778 31122 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:51128
I0107 01:37:44.875610 31135 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0107 01:37:44.875601 31122 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:51128
I0107 01:37:44.877450 31123 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0107 01:37:44.877990 31124 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:34011
I0107 01:37:44.878254 31124 master.cpp:2636] Processing REQUEST call for framework 438bc522-fc27-4013-95de-34a04a2282c9-0000 (default)
I0107 01:37:44.878443 31137 hierarchical.cpp:579] Received resource request from framework 438bc522-fc27-4013-95de-34a04a2282c9-0000
I0107 01:37:44.878962 31133 master.cpp:930] Master terminating
I0107 01:37:44.879366 31123 hierarchical.cpp:321] Removed framework 438bc522-fc27-4013-95de-34a04a2282c9-0000
E0107 01:37:44.880338 31122 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (60 ms)
[----------] 22 tests from ContentType/SchedulerTest (4194 ms total)
[----------] Global test environment tear-down
[==========] 923 tests from 120 test cases ran. (336987 ms total)
[ PASSED ] 922 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DiskUsageCollectorTest.File
1 FAILED TEST
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-1452128997-23698
Untagged: mesos-1452128997-23698:latest
Deleted: d76cbd38f6338735d1cbe4d26557977248bb21cf3c8fab49522374449aebd3c5
Deleted: 091769a42f2300974787f4c1bda440b4b6c7886728fea9a302d9b085ee382d61
Deleted: a4fb30a1d640593724d6a80688c7e29a07aa99688adba2524c6ff8a0518b5480
Deleted: 2ec3cced55e5c85b0eb7cf435af5b00d57cd538fbd208592e4c35746908bc95d
Deleted: 2fc381eac130ddb6fe4a39060f63f772abc1ef47b782ec6437da2027c3c59765
Deleted: c3805386d27f4d436da1350aad6a34e2ae78c32afedf018d7569e43266f5e679
Deleted: 51e4c2945109ac724fcd233de903960681664c8f9b354bdc0fcac4b1cdc7953a
Deleted: 2f9346f7576fecb5f9fedbf28e8f39e60c987ee5444c83904e917de4ff938490
Deleted: 7fa8e318b5ed7111f0de9adfcc04bc631db9eb2c6b5eeab27e097164b149269d
Deleted: 491308399dceaac5f58033934974d42f08d36247256e7fac2e5e73b6995ba1d1
Deleted: b467e35cc5c20dfc556bc198475da44475874dfb3ff69d75e904a9a49c92b907
Deleted: 4ef163f26c00a40cb7ff871f65727fd39ba92e730545620163f77c1f0941c6da
Deleted: ba6c4a6e1f8ade86301576030d394a9119d94366ab832c09f0b7bdc3b3deb87c
Error handling URL https://reviews.apache.org/api/review-requests/41963/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 80a10db85b79de7d0bc4dd57b70aa2731acefd23
Build step 'Execute shell' marked build as failure