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/10 13:10:07 UTC
Build failed in Jenkins: mesos-reviewbot #10698
See <https://builds.apache.org/job/mesos-reviewbot/10698/>
------------------------------------------
[...truncated 166935 lines...]
I0110 12:09:53.537488 31409 leveldb.cpp:181] Compacted db in 42.101372ms
I0110 12:09:53.537552 31409 leveldb.cpp:196] Created db iterator in 18450ns
I0110 12:09:53.537571 31409 leveldb.cpp:202] Seeked to beginning of db in 1883ns
I0110 12:09:53.537582 31409 leveldb.cpp:271] Iterated through 0 keys in the db in 293ns
I0110 12:09:53.537621 31409 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0110 12:09:53.538337 31440 recover.cpp:447] Starting replica recovery
I0110 12:09:53.538849 31440 recover.cpp:473] Replica is in EMPTY status
I0110 12:09:53.539908 31432 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13484)@172.17.0.2:46483
I0110 12:09:53.540402 31431 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0110 12:09:53.540907 31440 recover.cpp:564] Updating replica status to STARTING
I0110 12:09:53.541546 31433 master.cpp:372] Master a7c5b6ed-cae3-425f-bd25-44e1c25fb9e8 (7ce1946bcc2e) started on 172.17.0.2:46483
I0110 12:09:53.541638 31433 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/X1r1Pd/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --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/X1r1Pd/master" --zk_session_timeout="10secs"
I0110 12:09:53.541992 31433 master.cpp:421] Master allowing unauthenticated frameworks to register
I0110 12:09:53.542019 31433 master.cpp:424] Master only allowing authenticated slaves to register
I0110 12:09:53.542037 31433 credentials.hpp:35] Loading credentials for authentication from '/tmp/X1r1Pd/credentials'
I0110 12:09:53.542455 31433 master.cpp:464] Using default 'crammd5' authenticator
I0110 12:09:53.542625 31433 master.cpp:533] Using default 'basic' HTTP authenticator
I0110 12:09:53.542785 31433 master.cpp:567] Authorization enabled
I0110 12:09:53.543009 31429 whitelist_watcher.cpp:77] No whitelist given
I0110 12:09:53.543064 31441 hierarchical.cpp:147] Initialized hierarchical allocator process
I0110 12:09:53.545040 31442 master.cpp:1715] The newly elected leader is master@172.17.0.2:46483 with id a7c5b6ed-cae3-425f-bd25-44e1c25fb9e8
I0110 12:09:53.545078 31442 master.cpp:1728] Elected as the leading master!
I0110 12:09:53.545096 31442 master.cpp:1473] Recovering from registrar
I0110 12:09:53.545279 31434 registrar.cpp:307] Recovering registrar
I0110 12:09:53.568477 31443 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 27.271685ms
I0110 12:09:53.568516 31443 replica.cpp:320] Persisted replica status to STARTING
I0110 12:09:53.568763 31429 recover.cpp:473] Replica is in STARTING status
I0110 12:09:53.570029 31438 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13486)@172.17.0.2:46483
I0110 12:09:53.570467 31431 recover.cpp:193] Received a recover response from a replica in STARTING status
I0110 12:09:53.570916 31437 recover.cpp:564] Updating replica status to VOTING
I0110 12:09:53.587275 31439 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 16.147257ms
I0110 12:09:53.587313 31439 replica.cpp:320] Persisted replica status to VOTING
I0110 12:09:53.587445 31441 recover.cpp:578] Successfully joined the Paxos group
I0110 12:09:53.587716 31441 recover.cpp:462] Recover process terminated
I0110 12:09:53.588191 31432 log.cpp:659] Attempting to start the writer
I0110 12:09:53.589570 31441 replica.cpp:493] Replica received implicit promise request from (13487)@172.17.0.2:46483 with proposal 1
I0110 12:09:53.604079 31441 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 14.471968ms
I0110 12:09:53.604117 31441 replica.cpp:342] Persisted promised to 1
I0110 12:09:53.604868 31428 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0110 12:09:53.606336 31433 replica.cpp:388] Replica received explicit promise request from (13488)@172.17.0.2:46483 for position 0 with proposal 2
I0110 12:09:53.620787 31433 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 14.404974ms
I0110 12:09:53.620826 31433 replica.cpp:712] Persisted action at 0
I0110 12:09:53.621958 31443 replica.cpp:537] Replica received write request for position 0 from (13489)@172.17.0.2:46483
I0110 12:09:53.622022 31443 leveldb.cpp:436] Reading position from leveldb took 29888ns
I0110 12:09:53.637626 31443 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 15.55908ms
I0110 12:09:53.637658 31443 replica.cpp:712] Persisted action at 0
I0110 12:09:53.638478 31441 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0110 12:09:53.654366 31441 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 15.84654ms
I0110 12:09:53.654409 31441 replica.cpp:712] Persisted action at 0
I0110 12:09:53.654431 31441 replica.cpp:697] Replica learned NOP action at position 0
I0110 12:09:53.655015 31439 log.cpp:675] Writer started with ending position 0
I0110 12:09:53.656038 31431 leveldb.cpp:436] Reading position from leveldb took 29047ns
I0110 12:09:53.657027 31438 registrar.cpp:340] Successfully fetched the registry (0B) in 111.701248ms
I0110 12:09:53.657146 31438 registrar.cpp:439] Applied 1 operations in 40199ns; attempting to update the 'registry'
I0110 12:09:53.657878 31431 log.cpp:683] Attempting to append 170 bytes to the log
I0110 12:09:53.658004 31443 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0110 12:09:53.658733 31442 replica.cpp:537] Replica received write request for position 1 from (13490)@172.17.0.2:46483
I0110 12:09:53.692601 31442 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 33.821199ms
I0110 12:09:53.692639 31442 replica.cpp:712] Persisted action at 1
I0110 12:09:53.693442 31428 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0110 12:09:53.734443 31428 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.962787ms
I0110 12:09:53.734479 31428 replica.cpp:712] Persisted action at 1
I0110 12:09:53.734498 31428 replica.cpp:697] Replica learned APPEND action at position 1
I0110 12:09:53.735561 31434 registrar.cpp:484] Successfully updated the 'registry' in 78.348032ms
I0110 12:09:53.735756 31434 registrar.cpp:370] Successfully recovered registrar
I0110 12:09:53.735831 31441 log.cpp:702] Attempting to truncate the log to 1
I0110 12:09:53.736047 31434 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0110 12:09:53.736315 31438 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0110 12:09:53.736337 31437 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0110 12:09:53.737108 31443 replica.cpp:537] Replica received write request for position 2 from (13491)@172.17.0.2:46483
I0110 12:09:53.776255 31443 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 39.04291ms
I0110 12:09:53.776294 31443 replica.cpp:712] Persisted action at 2
I0110 12:09:53.777223 31441 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0110 12:09:53.813624 31441 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 36.363693ms
I0110 12:09:53.813704 31441 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40091ns
I0110 12:09:53.813729 31441 replica.cpp:712] Persisted action at 2
I0110 12:09:53.813750 31441 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0110 12:09:53.817630 31409 scheduler.cpp:154] Version: 0.27.0
I0110 12:09:53.818454 31438 scheduler.cpp:236] New master detected at master@172.17.0.2:46483
I0110 12:09:53.819619 31431 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:46483
I0110 12:09:53.821576 31433 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 12:09:53.822110 31436 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:54216
I0110 12:09:53.822361 31436 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0110 12:09:53.822427 31436 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0110 12:09:53.822762 31436 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0110 12:09:53.823247 31441 hierarchical.cpp:260] Added framework a7c5b6ed-cae3-425f-bd25-44e1c25fb9e8-0000
I0110 12:09:53.823315 31431 master.hpp:1657] Sending heartbeat to a7c5b6ed-cae3-425f-bd25-44e1c25fb9e8-0000
I0110 12:09:53.823319 31441 hierarchical.cpp:1329] No resources available to allocate!
I0110 12:09:53.823429 31441 hierarchical.cpp:1423] No inverse offers to send out!
I0110 12:09:53.823464 31441 hierarchical.cpp:1079] Performed allocation for 0 slaves in 183995ns
I0110 12:09:53.824388 31434 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:46483
I0110 12:09:53.824985 31434 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:46483
I0110 12:09:53.825814 31428 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0110 12:09:53.825909 31434 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:46483
I0110 12:09:53.827677 31436 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 12:09:53.828215 31438 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:54217
I0110 12:09:53.828354 31438 master.cpp:2722] Processing REQUEST call for framework a7c5b6ed-cae3-425f-bd25-44e1c25fb9e8-0000 (default)
I0110 12:09:53.828598 31435 hierarchical.cpp:579] Received resource request from framework a7c5b6ed-cae3-425f-bd25-44e1c25fb9e8-0000
I0110 12:09:53.829229 31409 master.cpp:1016] Master terminating
I0110 12:09:53.829480 31429 hierarchical.cpp:321] Removed framework a7c5b6ed-cae3-425f-bd25-44e1c25fb9e8-0000
E0110 12:09:53.830893 31428 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (434 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
2016-01-10 12:09:53,933:31409(0x2b0041e6b700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:54888] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0110 12:09:53.957056 31409 leveldb.cpp:174] Opened db in 119.451621ms
I0110 12:09:53.996850 31409 leveldb.cpp:181] Compacted db in 39.751972ms
I0110 12:09:53.996913 31409 leveldb.cpp:196] Created db iterator in 16702ns
I0110 12:09:53.996932 31409 leveldb.cpp:202] Seeked to beginning of db in 1884ns
I0110 12:09:53.996944 31409 leveldb.cpp:271] Iterated through 0 keys in the db in 243ns
I0110 12:09:53.996979 31409 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0110 12:09:53.997377 31433 recover.cpp:447] Starting replica recovery
I0110 12:09:53.997788 31435 recover.cpp:473] Replica is in EMPTY status
I0110 12:09:53.998919 31436 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13499)@172.17.0.2:46483
I0110 12:09:53.999217 31442 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0110 12:09:53.999631 31437 recover.cpp:564] Updating replica status to STARTING
I0110 12:09:54.000223 31440 master.cpp:372] Master c2daf3b3-a5bf-429e-abda-3f313453fffe (7ce1946bcc2e) started on 172.17.0.2:46483
I0110 12:09:54.000247 31440 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/QU7FBT/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --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/QU7FBT/master" --zk_session_timeout="10secs"
I0110 12:09:54.000520 31440 master.cpp:421] Master allowing unauthenticated frameworks to register
I0110 12:09:54.000533 31440 master.cpp:424] Master only allowing authenticated slaves to register
I0110 12:09:54.000540 31440 credentials.hpp:35] Loading credentials for authentication from '/tmp/QU7FBT/credentials'
I0110 12:09:54.000792 31440 master.cpp:464] Using default 'crammd5' authenticator
I0110 12:09:54.000901 31440 master.cpp:533] Using default 'basic' HTTP authenticator
I0110 12:09:54.001036 31440 master.cpp:567] Authorization enabled
I0110 12:09:54.001245 31441 whitelist_watcher.cpp:77] No whitelist given
I0110 12:09:54.001299 31429 hierarchical.cpp:147] Initialized hierarchical allocator process
I0110 12:09:54.002598 31435 master.cpp:1715] The newly elected leader is master@172.17.0.2:46483 with id c2daf3b3-a5bf-429e-abda-3f313453fffe
I0110 12:09:54.002626 31435 master.cpp:1728] Elected as the leading master!
I0110 12:09:54.002640 31435 master.cpp:1473] Recovering from registrar
I0110 12:09:54.002768 31430 registrar.cpp:307] Recovering registrar
I0110 12:09:54.030061 31434 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.299084ms
I0110 12:09:54.030099 31434 replica.cpp:320] Persisted replica status to STARTING
I0110 12:09:54.030347 31437 recover.cpp:473] Replica is in STARTING status
I0110 12:09:54.031158 31442 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13501)@172.17.0.2:46483
I0110 12:09:54.031527 31439 recover.cpp:193] Received a recover response from a replica in STARTING status
I0110 12:09:54.032033 31440 recover.cpp:564] Updating replica status to VOTING
I0110 12:09:54.055181 31443 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.921609ms
I0110 12:09:54.055224 31443 replica.cpp:320] Persisted replica status to VOTING
I0110 12:09:54.055382 31442 recover.cpp:578] Successfully joined the Paxos group
I0110 12:09:54.055656 31442 recover.cpp:462] Recover process terminated
I0110 12:09:54.056237 31429 log.cpp:659] Attempting to start the writer
I0110 12:09:54.057467 31429 replica.cpp:493] Replica received implicit promise request from (13502)@172.17.0.2:46483 with proposal 1
I0110 12:09:54.080170 31429 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.660392ms
I0110 12:09:54.080207 31429 replica.cpp:342] Persisted promised to 1
I0110 12:09:54.080850 31435 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0110 12:09:54.082226 31443 replica.cpp:388] Replica received explicit promise request from (13503)@172.17.0.2:46483 for position 0 with proposal 2
I0110 12:09:54.105325 31443 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 23.049694ms
I0110 12:09:54.105367 31443 replica.cpp:712] Persisted action at 0
I0110 12:09:54.106796 31432 replica.cpp:537] Replica received write request for position 0 from (13504)@172.17.0.2:46483
I0110 12:09:54.106863 31432 leveldb.cpp:436] Reading position from leveldb took 30843ns
I0110 12:09:54.130507 31432 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 23.59626ms
I0110 12:09:54.130550 31432 replica.cpp:712] Persisted action at 0
I0110 12:09:54.131372 31436 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0110 12:09:54.155509 31436 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.035244ms
I0110 12:09:54.155549 31436 replica.cpp:712] Persisted action at 0
I0110 12:09:54.155570 31436 replica.cpp:697] Replica learned NOP action at position 0
I0110 12:09:54.156327 31438 log.cpp:675] Writer started with ending position 0
I0110 12:09:54.157448 31429 leveldb.cpp:436] Reading position from leveldb took 33329ns
I0110 12:09:54.158463 31436 registrar.cpp:340] Successfully fetched the registry (0B) in 155.64928ms
I0110 12:09:54.158581 31436 registrar.cpp:439] Applied 1 operations in 28219ns; attempting to update the 'registry'
I0110 12:09:54.159396 31429 log.cpp:683] Attempting to append 170 bytes to the log
I0110 12:09:54.159535 31432 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0110 12:09:54.160266 31430 replica.cpp:537] Replica received write request for position 1 from (13505)@172.17.0.2:46483
I0110 12:09:54.180708 31430 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.401624ms
I0110 12:09:54.180748 31430 replica.cpp:712] Persisted action at 1
I0110 12:09:54.181488 31429 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0110 12:09:54.205760 31429 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.154654ms
I0110 12:09:54.205799 31429 replica.cpp:712] Persisted action at 1
I0110 12:09:54.205821 31429 replica.cpp:697] Replica learned APPEND action at position 1
I0110 12:09:54.206899 31436 registrar.cpp:484] Successfully updated the 'registry' in 48.246272ms
I0110 12:09:54.207062 31436 registrar.cpp:370] Successfully recovered registrar
I0110 12:09:54.207217 31432 log.cpp:702] Attempting to truncate the log to 1
I0110 12:09:54.207366 31429 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0110 12:09:54.207736 31435 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0110 12:09:54.207833 31430 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0110 12:09:54.208343 31441 replica.cpp:537] Replica received write request for position 2 from (13506)@172.17.0.2:46483
I0110 12:09:54.230950 31441 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.565353ms
I0110 12:09:54.230989 31441 replica.cpp:712] Persisted action at 2
I0110 12:09:54.231809 31434 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0110 12:09:54.256067 31434 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.21834ms
I0110 12:09:54.256235 31434 leveldb.cpp:399] Deleting ~1 keys from leveldb took 124150ns
I0110 12:09:54.256265 31434 replica.cpp:712] Persisted action at 2
I0110 12:09:54.256296 31434 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0110 12:09:54.258734 31409 scheduler.cpp:154] Version: 0.27.0
I0110 12:09:54.259351 31432 scheduler.cpp:236] New master detected at master@172.17.0.2:46483
I0110 12:09:54.260910 31429 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:46483
I0110 12:09:54.262895 31434 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 12:09:54.263422 31439 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:54219
I0110 12:09:54.263816 31439 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0110 12:09:54.263883 31439 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0110 12:09:54.264235 31439 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0110 12:09:54.264659 31429 hierarchical.cpp:260] Added framework c2daf3b3-a5bf-429e-abda-3f313453fffe-0000
I0110 12:09:54.264717 31439 master.hpp:1657] Sending heartbeat to c2daf3b3-a5bf-429e-abda-3f313453fffe-0000
I0110 12:09:54.264806 31429 hierarchical.cpp:1329] No resources available to allocate!
I0110 12:09:54.264873 31429 hierarchical.cpp:1423] No inverse offers to send out!
I0110 12:09:54.264936 31429 hierarchical.cpp:1079] Performed allocation for 0 slaves in 221252ns
I0110 12:09:54.266075 31442 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:46483
I0110 12:09:54.266546 31442 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:46483
I0110 12:09:54.267356 31430 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0110 12:09:54.267454 31442 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:46483
I0110 12:09:54.269304 31432 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 12:09:54.269711 31435 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:54220
I0110 12:09:54.269986 31435 master.cpp:2722] Processing REQUEST call for framework c2daf3b3-a5bf-429e-abda-3f313453fffe-0000 (default)
I0110 12:09:54.270249 31443 hierarchical.cpp:579] Received resource request from framework c2daf3b3-a5bf-429e-abda-3f313453fffe-0000
I0110 12:09:54.271188 31429 master.cpp:1016] Master terminating
I0110 12:09:54.271401 31439 hierarchical.cpp:321] Removed framework c2daf3b3-a5bf-429e-abda-3f313453fffe-0000
E0110 12:09:54.272673 31439 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (441 ms)
[----------] 22 tests from ContentType/SchedulerTest (15538 ms total)
[----------] Global test environment tear-down
[==========] 926 tests from 122 test cases ran. (709693 ms total)
[ PASSED ] 925 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DiskUsageCollectorTest.File
1 FAILED TEST
YOU HAVE 7 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-1452425387-11292
Untagged: mesos-1452425387-11292:latest
Deleted: 86ae34750b00d6816b89afb91ec49201f0fbecf015c00dde5fa8448820879d52
Deleted: 00aeb62b54a6b02a5645e1dd06b8b67cf67664e669f3ca5cfb2b39dba60fb8f2
Deleted: dcdd5d6f99c1c6dd04f851b3ffc9bb1956111c1aeb71380b6379b3db7225cc05
Deleted: 005729181eb51af6363157fbeb316c4cf6b1dc1742c2ed3540b1586b1c558efc
Deleted: 921ff631e6f6ae25b79d9aed79207ddb1403c9b0aae6e8555a907d604339af39
Deleted: 59be0c7a04e61714e72ad6c20c79517808b3a3f9fe7158d55337022c38a49505
Deleted: 7866b1e327c511d18c723404af4866d943c21eea6dae31a3e44c5aac5204111f
Deleted: 159c345d6af0379341efb494ea0ac27d8c8857108078fb83f9ecc58b4e004bcc
Deleted: f74dfefb4d82b951473d6df1e2510ceb2c2afb7f0ef972b990ca1275695c9d5f
Deleted: 1869dc33bdf8a1907ca2153f55a7f5cb8ece86856dab95c9e35f3ca714ec91de
Deleted: 8b365bf10b36fc58e12cfc04bf23dbcbe048d00d3a87e394a93edbcda3e88228
Deleted: 4c9d3360279863989fa037e81030e1ed0b88ac884b5397f3c6c5d4c9babeb30f
Deleted: 49d20aefca7d0498d79d3bb7735847cc85cc1b4ad0050b6ab1ee483eae373f8c
Deleted: 12adb9f31a125e977c87528979d48dd999f843efc6cd5b725c164c4b0cb4fa62
Error handling URL https://reviews.apache.org/api/review-requests/41963/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 468b8ecbe5bcb968a4e802a0cf2fa95da2234af7
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : mesos-reviewbot #10702
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10702/>
Build failed in Jenkins: mesos-reviewbot #10701
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10701/>
------------------------------------------
[...truncated 166850 lines...]
I0110 21:38:32.202957 31420 leveldb.cpp:181] Compacted db in 25.386926ms
I0110 21:38:32.203022 31420 leveldb.cpp:196] Created db iterator in 20029ns
I0110 21:38:32.203042 31420 leveldb.cpp:202] Seeked to beginning of db in 2090ns
I0110 21:38:32.203053 31420 leveldb.cpp:271] Iterated through 0 keys in the db in 430ns
I0110 21:38:32.203094 31420 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0110 21:38:32.203584 31447 recover.cpp:447] Starting replica recovery
I0110 21:38:32.203994 31447 recover.cpp:473] Replica is in EMPTY status
I0110 21:38:32.205212 31442 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13454)@172.17.0.2:51392
I0110 21:38:32.205656 31444 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0110 21:38:32.206245 31440 recover.cpp:564] Updating replica status to STARTING
I0110 21:38:32.207100 31448 master.cpp:372] Master 13c604f9-2ecb-40be-b793-dc5123951c09 (90bfc61c3050) started on 172.17.0.2:51392
I0110 21:38:32.207147 31448 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/NkK8l2/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --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/NkK8l2/master" --zk_session_timeout="10secs"
I0110 21:38:32.207535 31448 master.cpp:421] Master allowing unauthenticated frameworks to register
I0110 21:38:32.207554 31448 master.cpp:424] Master only allowing authenticated slaves to register
I0110 21:38:32.207602 31448 credentials.hpp:35] Loading credentials for authentication from '/tmp/NkK8l2/credentials'
I0110 21:38:32.207968 31448 master.cpp:464] Using default 'crammd5' authenticator
I0110 21:38:32.208163 31448 master.cpp:533] Using default 'basic' HTTP authenticator
I0110 21:38:32.208349 31448 master.cpp:567] Authorization enabled
I0110 21:38:32.208608 31451 hierarchical.cpp:147] Initialized hierarchical allocator process
I0110 21:38:32.208629 31452 whitelist_watcher.cpp:77] No whitelist given
I0110 21:38:32.210429 31439 master.cpp:1715] The newly elected leader is master@172.17.0.2:51392 with id 13c604f9-2ecb-40be-b793-dc5123951c09
I0110 21:38:32.210508 31439 master.cpp:1728] Elected as the leading master!
I0110 21:38:32.210541 31439 master.cpp:1473] Recovering from registrar
I0110 21:38:32.210680 31445 registrar.cpp:307] Recovering registrar
I0110 21:38:32.242791 31442 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 36.355519ms
I0110 21:38:32.242835 31442 replica.cpp:320] Persisted replica status to STARTING
I0110 21:38:32.243068 31442 recover.cpp:473] Replica is in STARTING status
I0110 21:38:32.244026 31447 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13456)@172.17.0.2:51392
I0110 21:38:32.244575 31448 recover.cpp:193] Received a recover response from a replica in STARTING status
I0110 21:38:32.245064 31452 recover.cpp:564] Updating replica status to VOTING
I0110 21:38:32.284500 31450 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.17879ms
I0110 21:38:32.284538 31450 replica.cpp:320] Persisted replica status to VOTING
I0110 21:38:32.284670 31445 recover.cpp:578] Successfully joined the Paxos group
I0110 21:38:32.284904 31445 recover.cpp:462] Recover process terminated
I0110 21:38:32.285454 31442 log.cpp:659] Attempting to start the writer
I0110 21:38:32.286470 31446 replica.cpp:493] Replica received implicit promise request from (13457)@172.17.0.2:51392 with proposal 1
I0110 21:38:32.326263 31446 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.764188ms
I0110 21:38:32.326292 31446 replica.cpp:342] Persisted promised to 1
I0110 21:38:32.326946 31447 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0110 21:38:32.328356 31442 replica.cpp:388] Replica received explicit promise request from (13458)@172.17.0.2:51392 for position 0 with proposal 2
I0110 21:38:32.368096 31442 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.688361ms
I0110 21:38:32.368160 31442 replica.cpp:712] Persisted action at 0
I0110 21:38:32.369488 31442 replica.cpp:537] Replica received write request for position 0 from (13459)@172.17.0.2:51392
I0110 21:38:32.369555 31442 leveldb.cpp:436] Reading position from leveldb took 30799ns
I0110 21:38:32.409816 31442 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.212897ms
I0110 21:38:32.409854 31442 replica.cpp:712] Persisted action at 0
I0110 21:38:32.410694 31450 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0110 21:38:32.451592 31450 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.857134ms
I0110 21:38:32.451629 31450 replica.cpp:712] Persisted action at 0
I0110 21:38:32.451652 31450 replica.cpp:697] Replica learned NOP action at position 0
I0110 21:38:32.452344 31450 log.cpp:675] Writer started with ending position 0
I0110 21:38:32.453517 31441 leveldb.cpp:436] Reading position from leveldb took 31025ns
I0110 21:38:32.454566 31451 registrar.cpp:340] Successfully fetched the registry (0B) in 243.833856ms
I0110 21:38:32.454690 31451 registrar.cpp:439] Applied 1 operations in 30137ns; attempting to update the 'registry'
I0110 21:38:32.455555 31447 log.cpp:683] Attempting to append 170 bytes to the log
I0110 21:38:32.455714 31449 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0110 21:38:32.456684 31454 replica.cpp:537] Replica received write request for position 1 from (13460)@172.17.0.2:51392
I0110 21:38:32.493407 31454 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.678013ms
I0110 21:38:32.493448 31454 replica.cpp:712] Persisted action at 1
I0110 21:38:32.494307 31451 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0110 21:38:32.535280 31451 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.930282ms
I0110 21:38:32.535326 31451 replica.cpp:712] Persisted action at 1
I0110 21:38:32.535351 31451 replica.cpp:697] Replica learned APPEND action at position 1
I0110 21:38:32.536494 31448 registrar.cpp:484] Successfully updated the 'registry' in 81.730048ms
I0110 21:38:32.536682 31448 registrar.cpp:370] Successfully recovered registrar
I0110 21:38:32.536836 31444 log.cpp:702] Attempting to truncate the log to 1
I0110 21:38:32.536988 31447 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0110 21:38:32.537360 31452 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0110 21:38:32.537400 31441 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0110 21:38:32.538168 31444 replica.cpp:537] Replica received write request for position 2 from (13461)@172.17.0.2:51392
I0110 21:38:32.577040 31444 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.826669ms
I0110 21:38:32.577080 31444 replica.cpp:712] Persisted action at 2
I0110 21:38:32.577860 31451 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0110 21:38:32.644194 31451 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 66.223907ms
I0110 21:38:32.644274 31451 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40011ns
I0110 21:38:32.644301 31451 replica.cpp:712] Persisted action at 2
I0110 21:38:32.644323 31451 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0110 21:38:32.648674 31420 scheduler.cpp:154] Version: 0.27.0
I0110 21:38:32.649346 31447 scheduler.cpp:236] New master detected at master@172.17.0.2:51392
I0110 21:38:32.650228 31445 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:51392
I0110 21:38:32.651669 31449 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 21:38:32.652065 31452 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:46486
I0110 21:38:32.652235 31452 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0110 21:38:32.652287 31452 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0110 21:38:32.652506 31452 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0110 21:38:32.652829 31453 hierarchical.cpp:260] Added framework 13c604f9-2ecb-40be-b793-dc5123951c09-0000
I0110 21:38:32.652838 31449 master.hpp:1657] Sending heartbeat to 13c604f9-2ecb-40be-b793-dc5123951c09-0000
I0110 21:38:32.652930 31453 hierarchical.cpp:1329] No resources available to allocate!
I0110 21:38:32.652962 31453 hierarchical.cpp:1423] No inverse offers to send out!
I0110 21:38:32.652987 31453 hierarchical.cpp:1079] Performed allocation for 0 slaves in 90458ns
I0110 21:38:32.653545 31441 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:51392
I0110 21:38:32.653877 31441 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:51392
I0110 21:38:32.654374 31445 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0110 21:38:32.654456 31441 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:51392
I0110 21:38:32.655661 31444 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 21:38:32.655998 31446 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:46487
I0110 21:38:32.656103 31446 master.cpp:2722] Processing REQUEST call for framework 13c604f9-2ecb-40be-b793-dc5123951c09-0000 (default)
I0110 21:38:32.656275 31447 hierarchical.cpp:579] Received resource request from framework 13c604f9-2ecb-40be-b793-dc5123951c09-0000
I0110 21:38:32.656586 31439 master.cpp:1016] Master terminating
I0110 21:38:32.656826 31454 hierarchical.cpp:321] Removed framework 13c604f9-2ecb-40be-b793-dc5123951c09-0000
E0110 21:38:32.658041 31448 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (564 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
2016-01-10 21:38:32,673:31420(0x2af7c3eec700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:41363] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0110 21:38:32.762205 31420 leveldb.cpp:174] Opened db in 98.521592ms
I0110 21:38:32.837056 31420 leveldb.cpp:181] Compacted db in 74.80996ms
I0110 21:38:32.837121 31420 leveldb.cpp:196] Created db iterator in 18562ns
I0110 21:38:32.837173 31420 leveldb.cpp:202] Seeked to beginning of db in 2165ns
I0110 21:38:32.837185 31420 leveldb.cpp:271] Iterated through 0 keys in the db in 230ns
I0110 21:38:32.837223 31420 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0110 21:38:32.838167 31450 recover.cpp:447] Starting replica recovery
I0110 21:38:32.838500 31450 recover.cpp:473] Replica is in EMPTY status
I0110 21:38:32.839716 31443 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13469)@172.17.0.2:51392
I0110 21:38:32.840055 31453 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0110 21:38:32.840489 31451 recover.cpp:564] Updating replica status to STARTING
I0110 21:38:32.841120 31454 master.cpp:372] Master 4d75f681-a459-4e64-b464-e7d81636821a (90bfc61c3050) started on 172.17.0.2:51392
I0110 21:38:32.841168 31454 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/7Tj1Un/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --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/7Tj1Un/master" --zk_session_timeout="10secs"
I0110 21:38:32.841536 31454 master.cpp:421] Master allowing unauthenticated frameworks to register
I0110 21:38:32.841557 31454 master.cpp:424] Master only allowing authenticated slaves to register
I0110 21:38:32.841572 31454 credentials.hpp:35] Loading credentials for authentication from '/tmp/7Tj1Un/credentials'
I0110 21:38:32.841850 31454 master.cpp:464] Using default 'crammd5' authenticator
I0110 21:38:32.841976 31454 master.cpp:533] Using default 'basic' HTTP authenticator
I0110 21:38:32.842111 31454 master.cpp:567] Authorization enabled
I0110 21:38:32.842330 31446 hierarchical.cpp:147] Initialized hierarchical allocator process
I0110 21:38:32.842337 31443 whitelist_watcher.cpp:77] No whitelist given
I0110 21:38:32.843693 31449 master.cpp:1715] The newly elected leader is master@172.17.0.2:51392 with id 4d75f681-a459-4e64-b464-e7d81636821a
I0110 21:38:32.843734 31449 master.cpp:1728] Elected as the leading master!
I0110 21:38:32.843755 31449 master.cpp:1473] Recovering from registrar
I0110 21:38:32.843883 31443 registrar.cpp:307] Recovering registrar
I0110 21:38:32.870789 31444 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.16432ms
I0110 21:38:32.870833 31444 replica.cpp:320] Persisted replica status to STARTING
I0110 21:38:32.871095 31453 recover.cpp:473] Replica is in STARTING status
I0110 21:38:32.872210 31439 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13471)@172.17.0.2:51392
I0110 21:38:32.872519 31446 recover.cpp:193] Received a recover response from a replica in STARTING status
I0110 21:38:32.873175 31441 recover.cpp:564] Updating replica status to VOTING
I0110 21:38:32.904112 31451 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.746171ms
I0110 21:38:32.904170 31451 replica.cpp:320] Persisted replica status to VOTING
I0110 21:38:32.904304 31446 recover.cpp:578] Successfully joined the Paxos group
I0110 21:38:32.904562 31446 recover.cpp:462] Recover process terminated
I0110 21:38:32.905220 31454 log.cpp:659] Attempting to start the writer
I0110 21:38:32.906548 31442 replica.cpp:493] Replica received implicit promise request from (13472)@172.17.0.2:51392 with proposal 1
I0110 21:38:32.937747 31442 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.151052ms
I0110 21:38:32.937791 31442 replica.cpp:342] Persisted promised to 1
I0110 21:38:32.938532 31442 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0110 21:38:32.939880 31441 replica.cpp:388] Replica received explicit promise request from (13473)@172.17.0.2:51392 for position 0 with proposal 2
I0110 21:38:32.970994 31441 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 31.067269ms
I0110 21:38:32.971034 31441 replica.cpp:712] Persisted action at 0
I0110 21:38:32.972390 31441 replica.cpp:537] Replica received write request for position 0 from (13474)@172.17.0.2:51392
I0110 21:38:32.972456 31441 leveldb.cpp:436] Reading position from leveldb took 30030ns
I0110 21:38:33.011144 31441 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 38.625837ms
I0110 21:38:33.011183 31441 replica.cpp:712] Persisted action at 0
I0110 21:38:33.011891 31446 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0110 21:38:33.044575 31446 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 32.642957ms
I0110 21:38:33.044613 31446 replica.cpp:712] Persisted action at 0
I0110 21:38:33.044634 31446 replica.cpp:697] Replica learned NOP action at position 0
I0110 21:38:33.045312 31449 log.cpp:675] Writer started with ending position 0
I0110 21:38:33.046530 31452 leveldb.cpp:436] Reading position from leveldb took 31527ns
I0110 21:38:33.047525 31445 registrar.cpp:340] Successfully fetched the registry (0B) in 203.54304ms
I0110 21:38:33.047659 31445 registrar.cpp:439] Applied 1 operations in 34945ns; attempting to update the 'registry'
I0110 21:38:33.048547 31450 log.cpp:683] Attempting to append 170 bytes to the log
I0110 21:38:33.048691 31439 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0110 21:38:33.049566 31453 replica.cpp:537] Replica received write request for position 1 from (13475)@172.17.0.2:51392
I0110 21:38:33.069697 31453 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 20.086694ms
I0110 21:38:33.069736 31453 replica.cpp:712] Persisted action at 1
I0110 21:38:33.070529 31453 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0110 21:38:33.094807 31453 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 24.236978ms
I0110 21:38:33.094846 31453 replica.cpp:712] Persisted action at 1
I0110 21:38:33.094868 31453 replica.cpp:697] Replica learned APPEND action at position 1
I0110 21:38:33.096016 31454 registrar.cpp:484] Successfully updated the 'registry' in 48.281856ms
I0110 21:38:33.096189 31447 log.cpp:702] Attempting to truncate the log to 1
I0110 21:38:33.096211 31454 registrar.cpp:370] Successfully recovered registrar
I0110 21:38:33.096402 31445 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0110 21:38:33.096832 31441 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0110 21:38:33.096823 31448 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0110 21:38:33.097494 31439 replica.cpp:537] Replica received write request for position 2 from (13476)@172.17.0.2:51392
I0110 21:38:33.119917 31439 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 22.378966ms
I0110 21:38:33.119956 31439 replica.cpp:712] Persisted action at 2
I0110 21:38:33.120740 31444 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0110 21:38:33.145028 31444 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.195664ms
I0110 21:38:33.145117 31444 leveldb.cpp:399] Deleting ~1 keys from leveldb took 47741ns
I0110 21:38:33.145182 31444 replica.cpp:712] Persisted action at 2
I0110 21:38:33.145207 31444 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0110 21:38:33.147570 31420 scheduler.cpp:154] Version: 0.27.0
I0110 21:38:33.148252 31449 scheduler.cpp:236] New master detected at master@172.17.0.2:51392
I0110 21:38:33.149389 31450 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:51392
I0110 21:38:33.151496 31440 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 21:38:33.152092 31447 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:46489
I0110 21:38:33.152500 31447 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0110 21:38:33.152585 31447 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0110 21:38:33.152920 31447 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0110 21:38:33.153332 31446 hierarchical.cpp:260] Added framework 4d75f681-a459-4e64-b464-e7d81636821a-0000
I0110 21:38:33.153398 31446 hierarchical.cpp:1329] No resources available to allocate!
I0110 21:38:33.153437 31446 hierarchical.cpp:1423] No inverse offers to send out!
I0110 21:38:33.153470 31446 hierarchical.cpp:1079] Performed allocation for 0 slaves in 108285ns
I0110 21:38:33.153489 31453 master.hpp:1657] Sending heartbeat to 4d75f681-a459-4e64-b464-e7d81636821a-0000
I0110 21:38:33.154454 31454 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:51392
I0110 21:38:33.154990 31451 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:51392
I0110 21:38:33.155691 31441 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0110 21:38:33.155740 31451 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:51392
I0110 21:38:33.157500 31450 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 21:38:33.157955 31453 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:46490
I0110 21:38:33.158233 31453 master.cpp:2722] Processing REQUEST call for framework 4d75f681-a459-4e64-b464-e7d81636821a-0000 (default)
I0110 21:38:33.158412 31442 hierarchical.cpp:579] Received resource request from framework 4d75f681-a459-4e64-b464-e7d81636821a-0000
I0110 21:38:33.158952 31454 master.cpp:1016] Master terminating
I0110 21:38:33.159283 31452 hierarchical.cpp:321] Removed framework 4d75f681-a459-4e64-b464-e7d81636821a-0000
E0110 21:38:33.160207 31443 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (502 ms)
[----------] 22 tests from ContentType/SchedulerTest (15327 ms total)
[----------] Global test environment tear-down
[==========] 926 tests from 122 test cases ran. (704981 ms total)
[ PASSED ] 925 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DiskUsageCollectorTest.File
1 FAILED TEST
YOU HAVE 7 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-1452459591-13956
Untagged: mesos-1452459591-13956:latest
Deleted: 2a7570b8791d5f6287f3a5a0181cdc473d6714fe13988cadfb68a7649ca296d8
Deleted: ec23c0a5317889f66c5eecd4139dc56164e2b217a8c914050b4b8575f9bb2317
Deleted: 54cb8a59712ed80b6104ef059cbd3c798b88df5bc163a546689e53dccf090f7b
Deleted: 162e2c0664d88cccc64396e33f00b1b77ece96d03fcf1d2350e8490c2f075e66
Deleted: 8f6723a761e3326ea904f4c4d3036adbc01358d6401cb74f81b31f180743dfa2
Deleted: a1f4a810cb866f68f083ad666569439ba864a338fd79b244c40dda1fe7bdf93b
Deleted: 0b1bf4828beedec9e67b178359f7b1acf13285d26e502964021f95386b6b12ac
Deleted: 711334244ddce40895f7824b2822cb4e321ca3ead7b4488aca7d20bece413934
Deleted: 28acee04eb4b7a1b79525a9b627953b9465d9fc4539f6ed2a9bac2d2f5b4ff2b
Deleted: e89aefbb91dd7a7501a1ae23564b6ebda1cb9dcf044f4b26b4c547e2259161e6
Deleted: ca383dcef546165f017fa8eb106fe5c216cc9dd0bfaf57cd4f929541d25c9934
Deleted: e9a7f6f8a9726591a04e69f86ac301fdd9a806db166699ce4b33c0f7d4aae077
Deleted: d73d63d597c1ccd4fd9af73dfabf367d2d9e30d4444b0dc69358b576d36457bc
Deleted: 75b12b80bd040f09311658a717e920f48968a8558dcc1b7faad2a003ef8cad9e
Error handling URL https://reviews.apache.org/api/review-requests/41963/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 468b8ecbe5bcb968a4e802a0cf2fa95da2234af7
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10700
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10700/>
------------------------------------------
[...truncated 166804 lines...]
I0110 20:40:20.376410 31414 leveldb.cpp:174] Opened db in 119.642218ms
I0110 20:40:20.412928 31414 leveldb.cpp:181] Compacted db in 36.475421ms
I0110 20:40:20.412995 31414 leveldb.cpp:196] Created db iterator in 20314ns
I0110 20:40:20.413014 31414 leveldb.cpp:202] Seeked to beginning of db in 2133ns
I0110 20:40:20.413025 31414 leveldb.cpp:271] Iterated through 0 keys in the db in 422ns
I0110 20:40:20.413065 31414 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0110 20:40:20.413460 31434 recover.cpp:447] Starting replica recovery
I0110 20:40:20.413789 31434 recover.cpp:473] Replica is in EMPTY status
I0110 20:40:20.415348 31440 master.cpp:372] Master fbdb0004-d27e-4868-9c9b-a8c0a5b9e8da (0df4558ca006) started on 172.17.0.2:59119
I0110 20:40:20.415796 31442 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13458)@172.17.0.2:59119
I0110 20:40:20.415472 31440 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/9wTdDy/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --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/9wTdDy/master" --zk_session_timeout="10secs"
I0110 20:40:20.415876 31440 master.cpp:421] Master allowing unauthenticated frameworks to register
I0110 20:40:20.415890 31440 master.cpp:424] Master only allowing authenticated slaves to register
I0110 20:40:20.415900 31440 credentials.hpp:35] Loading credentials for authentication from '/tmp/9wTdDy/credentials'
I0110 20:40:20.416106 31435 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0110 20:40:20.416239 31440 master.cpp:464] Using default 'crammd5' authenticator
I0110 20:40:20.416421 31440 master.cpp:533] Using default 'basic' HTTP authenticator
I0110 20:40:20.416549 31440 master.cpp:567] Authorization enabled
I0110 20:40:20.416606 31438 recover.cpp:564] Updating replica status to STARTING
I0110 20:40:20.416771 31448 whitelist_watcher.cpp:77] No whitelist given
I0110 20:40:20.416777 31433 hierarchical.cpp:147] Initialized hierarchical allocator process
I0110 20:40:20.418118 31444 master.cpp:1715] The newly elected leader is master@172.17.0.2:59119 with id fbdb0004-d27e-4868-9c9b-a8c0a5b9e8da
I0110 20:40:20.418164 31444 master.cpp:1728] Elected as the leading master!
I0110 20:40:20.418179 31444 master.cpp:1473] Recovering from registrar
I0110 20:40:20.418306 31439 registrar.cpp:307] Recovering registrar
I0110 20:40:20.454324 31433 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.370172ms
I0110 20:40:20.454367 31433 replica.cpp:320] Persisted replica status to STARTING
I0110 20:40:20.454655 31436 recover.cpp:473] Replica is in STARTING status
I0110 20:40:20.455725 31434 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13460)@172.17.0.2:59119
I0110 20:40:20.456161 31441 recover.cpp:193] Received a recover response from a replica in STARTING status
I0110 20:40:20.456622 31434 recover.cpp:564] Updating replica status to VOTING
I0110 20:40:20.496007 31443 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.157983ms
I0110 20:40:20.496047 31443 replica.cpp:320] Persisted replica status to VOTING
I0110 20:40:20.496191 31446 recover.cpp:578] Successfully joined the Paxos group
I0110 20:40:20.496439 31446 recover.cpp:462] Recover process terminated
I0110 20:40:20.496922 31438 log.cpp:659] Attempting to start the writer
I0110 20:40:20.498481 31437 replica.cpp:493] Replica received implicit promise request from (13461)@172.17.0.2:59119 with proposal 1
I0110 20:40:20.537895 31437 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.372662ms
I0110 20:40:20.537940 31437 replica.cpp:342] Persisted promised to 1
I0110 20:40:20.538683 31445 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0110 20:40:20.540273 31436 replica.cpp:388] Replica received explicit promise request from (13462)@172.17.0.2:59119 for position 0 with proposal 2
I0110 20:40:20.579633 31436 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.307817ms
I0110 20:40:20.579673 31436 replica.cpp:712] Persisted action at 0
I0110 20:40:20.580972 31448 replica.cpp:537] Replica received write request for position 0 from (13463)@172.17.0.2:59119
I0110 20:40:20.581049 31448 leveldb.cpp:436] Reading position from leveldb took 35077ns
I0110 20:40:20.621531 31448 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.431379ms
I0110 20:40:20.621577 31448 replica.cpp:712] Persisted action at 0
I0110 20:40:20.622362 31434 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0110 20:40:20.663148 31434 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.722964ms
I0110 20:40:20.663189 31434 replica.cpp:712] Persisted action at 0
I0110 20:40:20.663211 31434 replica.cpp:697] Replica learned NOP action at position 0
I0110 20:40:20.663872 31441 log.cpp:675] Writer started with ending position 0
I0110 20:40:20.665202 31440 leveldb.cpp:436] Reading position from leveldb took 36582ns
I0110 20:40:20.666293 31440 registrar.cpp:340] Successfully fetched the registry (0B) in 247936us
I0110 20:40:20.666429 31440 registrar.cpp:439] Applied 1 operations in 36657ns; attempting to update the 'registry'
I0110 20:40:20.667246 31435 log.cpp:683] Attempting to append 170 bytes to the log
I0110 20:40:20.667446 31447 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0110 20:40:20.668277 31437 replica.cpp:537] Replica received write request for position 1 from (13464)@172.17.0.2:59119
I0110 20:40:20.710623 31437 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 42.246312ms
I0110 20:40:20.710664 31437 replica.cpp:712] Persisted action at 1
I0110 20:40:20.711529 31443 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0110 20:40:20.752529 31443 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.962404ms
I0110 20:40:20.752569 31443 replica.cpp:712] Persisted action at 1
I0110 20:40:20.752591 31443 replica.cpp:697] Replica learned APPEND action at position 1
I0110 20:40:20.753722 31437 registrar.cpp:484] Successfully updated the 'registry' in 87.218944ms
I0110 20:40:20.753912 31437 registrar.cpp:370] Successfully recovered registrar
I0110 20:40:20.754096 31440 log.cpp:702] Attempting to truncate the log to 1
I0110 20:40:20.754369 31441 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0110 20:40:20.754621 31448 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0110 20:40:20.754654 31446 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0110 20:40:20.755491 31446 replica.cpp:537] Replica received write request for position 2 from (13465)@172.17.0.2:59119
I0110 20:40:20.796809 31446 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 41.268303ms
I0110 20:40:20.796849 31446 replica.cpp:712] Persisted action at 2
I0110 20:40:20.797544 31447 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0110 20:40:20.838649 31447 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 41.060989ms
I0110 20:40:20.838731 31447 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40949ns
I0110 20:40:20.838752 31447 replica.cpp:712] Persisted action at 2
I0110 20:40:20.838778 31447 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0110 20:40:20.845932 31414 scheduler.cpp:154] Version: 0.27.0
I0110 20:40:20.846658 31435 scheduler.cpp:236] New master detected at master@172.17.0.2:59119
I0110 20:40:20.847801 31448 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:59119
I0110 20:40:20.849745 31442 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 20:40:20.850406 31446 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:47236
I0110 20:40:20.850644 31446 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0110 20:40:20.850719 31446 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0110 20:40:20.851040 31446 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0110 20:40:20.851512 31443 hierarchical.cpp:260] Added framework fbdb0004-d27e-4868-9c9b-a8c0a5b9e8da-0000
I0110 20:40:20.851568 31446 master.hpp:1657] Sending heartbeat to fbdb0004-d27e-4868-9c9b-a8c0a5b9e8da-0000
I0110 20:40:20.851727 31443 hierarchical.cpp:1329] No resources available to allocate!
I0110 20:40:20.851776 31443 hierarchical.cpp:1423] No inverse offers to send out!
I0110 20:40:20.851814 31443 hierarchical.cpp:1079] Performed allocation for 0 slaves in 131702ns
I0110 20:40:20.852366 31436 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:59119
I0110 20:40:20.852996 31436 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:59119
I0110 20:40:20.853827 31437 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0110 20:40:20.853905 31436 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:59119
I0110 20:40:20.855581 31440 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 20:40:20.856012 31438 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:47237
I0110 20:40:20.856163 31438 master.cpp:2722] Processing REQUEST call for framework fbdb0004-d27e-4868-9c9b-a8c0a5b9e8da-0000 (default)
I0110 20:40:20.856359 31442 hierarchical.cpp:579] Received resource request from framework fbdb0004-d27e-4868-9c9b-a8c0a5b9e8da-0000
I0110 20:40:20.856693 31438 master.cpp:1016] Master terminating
I0110 20:40:20.856930 31447 hierarchical.cpp:321] Removed framework fbdb0004-d27e-4868-9c9b-a8c0a5b9e8da-0000
E0110 20:40:20.858417 31435 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (608 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0110 20:40:20.984834 31414 leveldb.cpp:174] Opened db in 119.512903ms
I0110 20:40:21.033330 31414 leveldb.cpp:181] Compacted db in 48.45402ms
I0110 20:40:21.033396 31414 leveldb.cpp:196] Created db iterator in 19024ns
I0110 20:40:21.033416 31414 leveldb.cpp:202] Seeked to beginning of db in 2135ns
I0110 20:40:21.033428 31414 leveldb.cpp:271] Iterated through 0 keys in the db in 447ns
I0110 20:40:21.033465 31414 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0110 20:40:21.033912 31444 recover.cpp:447] Starting replica recovery
I0110 20:40:21.034350 31448 recover.cpp:473] Replica is in EMPTY status
I0110 20:40:21.035390 31434 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13473)@172.17.0.2:59119
I0110 20:40:21.035823 31438 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0110 20:40:21.036319 31446 recover.cpp:564] Updating replica status to STARTING
I0110 20:40:21.037547 31442 master.cpp:372] Master a36ac707-9def-4718-aecc-3b6eb9e8fc6e (0df4558ca006) started on 172.17.0.2:59119
I0110 20:40:21.037576 31442 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/9tTlsm/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --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/9tTlsm/master" --zk_session_timeout="10secs"
I0110 20:40:21.037895 31442 master.cpp:421] Master allowing unauthenticated frameworks to register
I0110 20:40:21.037909 31442 master.cpp:424] Master only allowing authenticated slaves to register
I0110 20:40:21.037917 31442 credentials.hpp:35] Loading credentials for authentication from '/tmp/9tTlsm/credentials'
I0110 20:40:21.038280 31442 master.cpp:464] Using default 'crammd5' authenticator
I0110 20:40:21.038426 31442 master.cpp:533] Using default 'basic' HTTP authenticator
I0110 20:40:21.038585 31442 master.cpp:567] Authorization enabled
I0110 20:40:21.038846 31439 whitelist_watcher.cpp:77] No whitelist given
I0110 20:40:21.038892 31445 hierarchical.cpp:147] Initialized hierarchical allocator process
I0110 20:40:21.040619 31441 master.cpp:1715] The newly elected leader is master@172.17.0.2:59119 with id a36ac707-9def-4718-aecc-3b6eb9e8fc6e
I0110 20:40:21.040650 31441 master.cpp:1728] Elected as the leading master!
I0110 20:40:21.040666 31441 master.cpp:1473] Recovering from registrar
I0110 20:40:21.040783 31434 registrar.cpp:307] Recovering registrar
I0110 20:40:21.060201 31448 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.698648ms
I0110 20:40:21.060247 31448 replica.cpp:320] Persisted replica status to STARTING
I0110 20:40:21.060513 31444 recover.cpp:473] Replica is in STARTING status
I0110 20:40:21.061465 31435 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13475)@172.17.0.2:59119
I0110 20:40:21.061835 31436 recover.cpp:193] Received a recover response from a replica in STARTING status
I0110 20:40:21.062252 31444 recover.cpp:564] Updating replica status to VOTING
I0110 20:40:21.085103 31440 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 22.652497ms
I0110 20:40:21.085155 31440 replica.cpp:320] Persisted replica status to VOTING
I0110 20:40:21.085266 31438 recover.cpp:578] Successfully joined the Paxos group
I0110 20:40:21.085453 31438 recover.cpp:462] Recover process terminated
I0110 20:40:21.085923 31439 log.cpp:659] Attempting to start the writer
I0110 20:40:21.087067 31435 replica.cpp:493] Replica received implicit promise request from (13476)@172.17.0.2:59119 with proposal 1
I0110 20:40:21.110291 31435 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23.189261ms
I0110 20:40:21.110330 31435 replica.cpp:342] Persisted promised to 1
I0110 20:40:21.111019 31434 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0110 20:40:21.112380 31433 replica.cpp:388] Replica received explicit promise request from (13477)@172.17.0.2:59119 for position 0 with proposal 2
I0110 20:40:21.147212 31433 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 34.780495ms
I0110 20:40:21.147248 31433 replica.cpp:712] Persisted action at 0
I0110 20:40:21.148566 31434 replica.cpp:537] Replica received write request for position 0 from (13478)@172.17.0.2:59119
I0110 20:40:21.148638 31434 leveldb.cpp:436] Reading position from leveldb took 30486ns
I0110 20:40:21.188992 31434 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.308033ms
I0110 20:40:21.189029 31434 replica.cpp:712] Persisted action at 0
I0110 20:40:21.190413 31434 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0110 20:40:21.230813 31434 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.361087ms
I0110 20:40:21.230857 31434 replica.cpp:712] Persisted action at 0
I0110 20:40:21.230882 31434 replica.cpp:697] Replica learned NOP action at position 0
I0110 20:40:21.231696 31448 log.cpp:675] Writer started with ending position 0
I0110 20:40:21.232925 31441 leveldb.cpp:436] Reading position from leveldb took 35679ns
I0110 20:40:21.233928 31439 registrar.cpp:340] Successfully fetched the registry (0B) in 193.089024ms
I0110 20:40:21.234064 31439 registrar.cpp:439] Applied 1 operations in 29009ns; attempting to update the 'registry'
I0110 20:40:21.234920 31434 log.cpp:683] Attempting to append 170 bytes to the log
I0110 20:40:21.235071 31438 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0110 20:40:21.235987 31436 replica.cpp:537] Replica received write request for position 1 from (13479)@172.17.0.2:59119
I0110 20:40:21.270061 31436 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 34.021165ms
I0110 20:40:21.270104 31436 replica.cpp:712] Persisted action at 1
I0110 20:40:21.270849 31435 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0110 20:40:21.311766 31435 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.876974ms
I0110 20:40:21.311806 31435 replica.cpp:712] Persisted action at 1
I0110 20:40:21.311828 31435 replica.cpp:697] Replica learned APPEND action at position 1
I0110 20:40:21.313055 31434 registrar.cpp:484] Successfully updated the 'registry' in 78.919936ms
I0110 20:40:21.313338 31434 registrar.cpp:370] Successfully recovered registrar
I0110 20:40:21.313376 31446 log.cpp:702] Attempting to truncate the log to 1
I0110 20:40:21.313530 31437 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0110 20:40:21.313858 31445 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0110 20:40:21.313889 31438 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0110 20:40:21.314777 31438 replica.cpp:537] Replica received write request for position 2 from (13480)@172.17.0.2:59119
I0110 20:40:21.370270 31438 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 55.443626ms
I0110 20:40:21.370308 31438 replica.cpp:712] Persisted action at 2
I0110 20:40:21.371110 31434 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0110 20:40:21.412000 31434 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.79079ms
I0110 20:40:21.412081 31434 leveldb.cpp:399] Deleting ~1 keys from leveldb took 41334ns
I0110 20:40:21.412102 31434 replica.cpp:712] Persisted action at 2
I0110 20:40:21.412147 31434 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0110 20:40:21.415335 31414 scheduler.cpp:154] Version: 0.27.0
I0110 20:40:21.416117 31445 scheduler.cpp:236] New master detected at master@172.17.0.2:59119
I0110 20:40:21.417255 31439 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:59119
I0110 20:40:21.419111 31445 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 20:40:21.419646 31441 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:47238
I0110 20:40:21.420033 31441 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0110 20:40:21.420101 31441 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0110 20:40:21.420466 31441 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0110 20:40:21.420905 31435 hierarchical.cpp:260] Added framework a36ac707-9def-4718-aecc-3b6eb9e8fc6e-0000
I0110 20:40:21.420981 31435 hierarchical.cpp:1329] No resources available to allocate!
I0110 20:40:21.421030 31435 hierarchical.cpp:1423] No inverse offers to send out!
I0110 20:40:21.421033 31441 master.hpp:1657] Sending heartbeat to a36ac707-9def-4718-aecc-3b6eb9e8fc6e-0000
I0110 20:40:21.421066 31435 hierarchical.cpp:1079] Performed allocation for 0 slaves in 123244ns
I0110 20:40:21.422056 31444 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:59119
I0110 20:40:21.422564 31444 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:59119
I0110 20:40:21.423425 31436 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0110 20:40:21.423462 31444 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:59119
I0110 20:40:21.425215 31447 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 20:40:21.425669 31438 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:47239
I0110 20:40:21.425945 31438 master.cpp:2722] Processing REQUEST call for framework a36ac707-9def-4718-aecc-3b6eb9e8fc6e-0000 (default)
I0110 20:40:21.426146 31448 hierarchical.cpp:579] Received resource request from framework a36ac707-9def-4718-aecc-3b6eb9e8fc6e-0000
I0110 20:40:21.426494 31434 master.cpp:1016] Master terminating
I0110 20:40:21.426951 31436 hierarchical.cpp:321] Removed framework a36ac707-9def-4718-aecc-3b6eb9e8fc6e-0000
E0110 20:40:21.428213 31439 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (570 ms)
[----------] 22 tests from ContentType/SchedulerTest (14975 ms total)
[----------] Global test environment tear-down
[==========] 926 tests from 122 test cases ran. (708204 ms total)
[ PASSED ] 925 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DiskUsageCollectorTest.File
1 FAILED TEST
YOU HAVE 7 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-1452455986-20948
Untagged: mesos-1452455986-20948:latest
Deleted: c08e77bc807e8e71ae6e89e2e63365263467b42d5cfea8f9b3c9fa0fb7d464ad
Deleted: 2e3c126864d2e6619ffae083c499915f8afb5c1de2763764daf6e8ae5ed1bd30
Deleted: ed02a38150cbcdb4378645a795ec908244e4937334284e8132dbc3aa129675f7
Deleted: 03b7b8619cd5a00500c9e6cd33f691d726552c9abcf00928351b8f1cca7427ca
Deleted: 2f8c81a3bd09e3e690827bb11c041a70c8663956e9a4e2db6e1e694407fb14b2
Deleted: 1a89eb042eca46c289f3b066e18b46041ec77823790b92e20aa21045e210d357
Deleted: 92cbda9c92c7024069180a2694a7551cd683d0c4cb7249b0ff3098b95cc8e7f3
Deleted: 6206585a49e18ee3120d11a509b136297fbe02d22510a19c70438084220970a6
Deleted: 519c664ea156e011f67f778e450f60338bcfb6db021ab76fb9a6b5ec2f5fd782
Deleted: d0b000948a6370fa907d0ab486cdcc1477a8e04fb6ec0d2381dd2b93818c92a3
Deleted: 041de02fce9b7847f6a2385b5dee5bfdd6f3d855a732eeb1ce62aa58c5ff22ef
Deleted: c8e6eba4df4aa493f7662f29b786af8b860e3e26f12f8c8f0c56e1cafa869f5f
Deleted: a4cf35faed8cf970e797b8adfdcaf5e62ec32c69aa6a24338a08531ef8e8f499
Deleted: 1de86c8549ce54041b09a72f4cf20e5e70c9fd62765dd05fc0e396cb0bdf41cf
Error handling URL https://reviews.apache.org/api/review-requests/41963/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 468b8ecbe5bcb968a4e802a0cf2fa95da2234af7
Build step 'Execute shell' marked build as failure
Build failed in Jenkins: mesos-reviewbot #10699
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/mesos-reviewbot/10699/>
------------------------------------------
[...truncated 166576 lines...]
I0110 19:38:41.739047 31415 leveldb.cpp:181] Compacted db in 50.462305ms
I0110 19:38:41.739114 31415 leveldb.cpp:196] Created db iterator in 20719ns
I0110 19:38:41.739163 31415 leveldb.cpp:202] Seeked to beginning of db in 2505ns
I0110 19:38:41.739176 31415 leveldb.cpp:271] Iterated through 0 keys in the db in 318ns
I0110 19:38:41.739220 31415 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0110 19:38:41.739850 31435 recover.cpp:447] Starting replica recovery
I0110 19:38:41.740173 31437 recover.cpp:473] Replica is in EMPTY status
I0110 19:38:41.741869 31436 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13454)@172.17.0.2:52880
I0110 19:38:41.742372 31446 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0110 19:38:41.743103 31440 recover.cpp:564] Updating replica status to STARTING
I0110 19:38:41.743789 31441 master.cpp:372] Master 5f3a4f45-83c7-41e1-89dc-5245479bb0fe (4606a60520a3) started on 172.17.0.2:52880
I0110 19:38:41.743821 31441 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/EmNzhJ/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --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/EmNzhJ/master" --zk_session_timeout="10secs"
I0110 19:38:41.744210 31441 master.cpp:421] Master allowing unauthenticated frameworks to register
I0110 19:38:41.744230 31441 master.cpp:424] Master only allowing authenticated slaves to register
I0110 19:38:41.744247 31441 credentials.hpp:35] Loading credentials for authentication from '/tmp/EmNzhJ/credentials'
I0110 19:38:41.744604 31441 master.cpp:464] Using default 'crammd5' authenticator
I0110 19:38:41.744783 31441 master.cpp:533] Using default 'basic' HTTP authenticator
I0110 19:38:41.744968 31441 master.cpp:567] Authorization enabled
I0110 19:38:41.745379 31443 hierarchical.cpp:147] Initialized hierarchical allocator process
I0110 19:38:41.745414 31449 whitelist_watcher.cpp:77] No whitelist given
I0110 19:38:41.747400 31448 master.cpp:1715] The newly elected leader is master@172.17.0.2:52880 with id 5f3a4f45-83c7-41e1-89dc-5245479bb0fe
I0110 19:38:41.747442 31448 master.cpp:1728] Elected as the leading master!
I0110 19:38:41.747462 31448 master.cpp:1473] Recovering from registrar
I0110 19:38:41.747606 31449 registrar.cpp:307] Recovering registrar
I0110 19:38:41.783800 31437 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.795813ms
I0110 19:38:41.783843 31437 replica.cpp:320] Persisted replica status to STARTING
I0110 19:38:41.784085 31437 recover.cpp:473] Replica is in STARTING status
I0110 19:38:41.785377 31441 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13456)@172.17.0.2:52880
I0110 19:38:41.785686 31448 recover.cpp:193] Received a recover response from a replica in STARTING status
I0110 19:38:41.786239 31440 recover.cpp:564] Updating replica status to VOTING
I0110 19:38:41.825553 31442 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.061059ms
I0110 19:38:41.825598 31442 replica.cpp:320] Persisted replica status to VOTING
I0110 19:38:41.825745 31442 recover.cpp:578] Successfully joined the Paxos group
I0110 19:38:41.826027 31442 recover.cpp:462] Recover process terminated
I0110 19:38:41.826977 31449 log.cpp:659] Attempting to start the writer
I0110 19:38:41.829406 31446 replica.cpp:493] Replica received implicit promise request from (13457)@172.17.0.2:52880 with proposal 1
I0110 19:38:41.867301 31446 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 37.851312ms
I0110 19:38:41.867344 31446 replica.cpp:342] Persisted promised to 1
I0110 19:38:41.868301 31448 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0110 19:38:41.870025 31445 replica.cpp:388] Replica received explicit promise request from (13458)@172.17.0.2:52880 for position 0 with proposal 2
I0110 19:38:41.909163 31445 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 39.080699ms
I0110 19:38:41.909209 31445 replica.cpp:712] Persisted action at 0
I0110 19:38:41.910779 31439 replica.cpp:537] Replica received write request for position 0 from (13459)@172.17.0.2:52880
I0110 19:38:41.910862 31439 leveldb.cpp:436] Reading position from leveldb took 38474ns
2016-01-10 19:38:41,935:31415(0x2b972e16e700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:41230] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I0110 19:38:41.950960 31439 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 40.037213ms
I0110 19:38:41.951006 31439 replica.cpp:712] Persisted action at 0
I0110 19:38:41.951792 31447 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0110 19:38:41.992671 31447 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.782515ms
I0110 19:38:41.992710 31447 replica.cpp:712] Persisted action at 0
I0110 19:38:41.992733 31447 replica.cpp:697] Replica learned NOP action at position 0
I0110 19:38:41.993435 31435 log.cpp:675] Writer started with ending position 0
I0110 19:38:41.994770 31439 leveldb.cpp:436] Reading position from leveldb took 34997ns
I0110 19:38:41.995766 31448 registrar.cpp:340] Successfully fetched the registry (0B) in 248.10624ms
I0110 19:38:41.995949 31448 registrar.cpp:439] Applied 1 operations in 29285ns; attempting to update the 'registry'
I0110 19:38:41.996764 31446 log.cpp:683] Attempting to append 170 bytes to the log
I0110 19:38:41.996968 31444 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0110 19:38:41.997789 31439 replica.cpp:537] Replica received write request for position 1 from (13460)@172.17.0.2:52880
I0110 19:38:42.034482 31439 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 36.647793ms
I0110 19:38:42.034528 31439 replica.cpp:712] Persisted action at 1
I0110 19:38:42.035341 31446 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0110 19:38:42.076227 31446 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.850309ms
I0110 19:38:42.076267 31446 replica.cpp:712] Persisted action at 1
I0110 19:38:42.076292 31446 replica.cpp:697] Replica learned APPEND action at position 1
I0110 19:38:42.077538 31443 registrar.cpp:484] Successfully updated the 'registry' in 81.5168ms
I0110 19:38:42.077731 31443 registrar.cpp:370] Successfully recovered registrar
I0110 19:38:42.077735 31444 log.cpp:702] Attempting to truncate the log to 1
I0110 19:38:42.077939 31449 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0110 19:38:42.078296 31440 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0110 19:38:42.078333 31448 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0110 19:38:42.079157 31441 replica.cpp:537] Replica received write request for position 2 from (13461)@172.17.0.2:52880
I0110 19:38:42.108965 31441 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 29.763821ms
I0110 19:38:42.109012 31441 replica.cpp:712] Persisted action at 2
I0110 19:38:42.109803 31449 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0110 19:38:42.134011 31449 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.167039ms
I0110 19:38:42.134093 31449 leveldb.cpp:399] Deleting ~1 keys from leveldb took 41864ns
I0110 19:38:42.134119 31449 replica.cpp:712] Persisted action at 2
I0110 19:38:42.134171 31449 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0110 19:38:42.139318 31415 scheduler.cpp:154] Version: 0.27.0
I0110 19:38:42.140002 31446 scheduler.cpp:236] New master detected at master@172.17.0.2:52880
I0110 19:38:42.141268 31443 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:52880
I0110 19:38:42.143177 31444 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 19:38:42.143784 31447 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:59891
I0110 19:38:42.144006 31447 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0110 19:38:42.144071 31447 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0110 19:38:42.144392 31447 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0110 19:38:42.144800 31440 hierarchical.cpp:260] Added framework 5f3a4f45-83c7-41e1-89dc-5245479bb0fe-0000
I0110 19:38:42.144875 31440 hierarchical.cpp:1329] No resources available to allocate!
I0110 19:38:42.144881 31447 master.hpp:1657] Sending heartbeat to 5f3a4f45-83c7-41e1-89dc-5245479bb0fe-0000
I0110 19:38:42.145112 31440 hierarchical.cpp:1423] No inverse offers to send out!
I0110 19:38:42.145169 31440 hierarchical.cpp:1079] Performed allocation for 0 slaves in 332149ns
I0110 19:38:42.145869 31434 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:52880
I0110 19:38:42.146486 31434 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:52880
I0110 19:38:42.147192 31446 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0110 19:38:42.147333 31443 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:52880
I0110 19:38:42.148982 31436 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 19:38:42.149521 31445 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:59892
I0110 19:38:42.149665 31445 master.cpp:2722] Processing REQUEST call for framework 5f3a4f45-83c7-41e1-89dc-5245479bb0fe-0000 (default)
I0110 19:38:42.149869 31441 hierarchical.cpp:579] Received resource request from framework 5f3a4f45-83c7-41e1-89dc-5245479bb0fe-0000
I0110 19:38:42.150379 31415 master.cpp:1016] Master terminating
I0110 19:38:42.150658 31445 hierarchical.cpp:321] Removed framework 5f3a4f45-83c7-41e1-89dc-5245479bb0fe-0000
E0110 19:38:42.152245 31435 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (584 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0110 19:38:42.238829 31415 leveldb.cpp:174] Opened db in 80.12376ms
I0110 19:38:42.264894 31415 leveldb.cpp:181] Compacted db in 26.023481ms
I0110 19:38:42.264953 31415 leveldb.cpp:196] Created db iterator in 14758ns
I0110 19:38:42.264973 31415 leveldb.cpp:202] Seeked to beginning of db in 1822ns
I0110 19:38:42.264984 31415 leveldb.cpp:271] Iterated through 0 keys in the db in 220ns
I0110 19:38:42.265025 31415 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0110 19:38:42.265899 31444 recover.cpp:447] Starting replica recovery
I0110 19:38:42.266165 31444 recover.cpp:473] Replica is in EMPTY status
I0110 19:38:42.267118 31448 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13469)@172.17.0.2:52880
I0110 19:38:42.267776 31444 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0110 19:38:42.269419 31434 recover.cpp:564] Updating replica status to STARTING
I0110 19:38:42.269810 31437 master.cpp:372] Master 3bc6e713-5937-4c77-a0b3-6ec086e59f1d (4606a60520a3) started on 172.17.0.2:52880
I0110 19:38:42.269842 31437 master.cpp:374] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/PjvDjf/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --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/PjvDjf/master" --zk_session_timeout="10secs"
I0110 19:38:42.270293 31437 master.cpp:421] Master allowing unauthenticated frameworks to register
I0110 19:38:42.270308 31437 master.cpp:424] Master only allowing authenticated slaves to register
I0110 19:38:42.270316 31437 credentials.hpp:35] Loading credentials for authentication from '/tmp/PjvDjf/credentials'
I0110 19:38:42.270647 31437 master.cpp:464] Using default 'crammd5' authenticator
I0110 19:38:42.270783 31437 master.cpp:533] Using default 'basic' HTTP authenticator
I0110 19:38:42.271121 31437 master.cpp:567] Authorization enabled
I0110 19:38:42.271715 31446 whitelist_watcher.cpp:77] No whitelist given
I0110 19:38:42.271721 31442 hierarchical.cpp:147] Initialized hierarchical allocator process
I0110 19:38:42.273476 31438 master.cpp:1715] The newly elected leader is master@172.17.0.2:52880 with id 3bc6e713-5937-4c77-a0b3-6ec086e59f1d
I0110 19:38:42.273521 31438 master.cpp:1728] Elected as the leading master!
I0110 19:38:42.273543 31438 master.cpp:1473] Recovering from registrar
I0110 19:38:42.273747 31441 registrar.cpp:307] Recovering registrar
I0110 19:38:42.306531 31440 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 36.673985ms
I0110 19:38:42.306573 31440 replica.cpp:320] Persisted replica status to STARTING
I0110 19:38:42.306807 31446 recover.cpp:473] Replica is in STARTING status
I0110 19:38:42.307978 31448 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13471)@172.17.0.2:52880
I0110 19:38:42.308341 31445 recover.cpp:193] Received a recover response from a replica in STARTING status
I0110 19:38:42.309000 31444 recover.cpp:564] Updating replica status to VOTING
I0110 19:38:42.343225 31441 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 34.044733ms
I0110 19:38:42.343262 31441 replica.cpp:320] Persisted replica status to VOTING
I0110 19:38:42.343400 31441 recover.cpp:578] Successfully joined the Paxos group
I0110 19:38:42.343652 31441 recover.cpp:462] Recover process terminated
I0110 19:38:42.344219 31443 log.cpp:659] Attempting to start the writer
I0110 19:38:42.345948 31438 replica.cpp:493] Replica received implicit promise request from (13472)@172.17.0.2:52880 with proposal 1
I0110 19:38:42.385025 31438 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.031656ms
I0110 19:38:42.385067 31438 replica.cpp:342] Persisted promised to 1
I0110 19:38:42.386775 31445 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0110 19:38:42.389096 31446 replica.cpp:388] Replica received explicit promise request from (13473)@172.17.0.2:52880 for position 0 with proposal 2
I0110 19:38:42.426795 31446 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 37.554619ms
I0110 19:38:42.426842 31446 replica.cpp:712] Persisted action at 0
I0110 19:38:42.429080 31439 replica.cpp:537] Replica received write request for position 0 from (13474)@172.17.0.2:52880
I0110 19:38:42.429184 31439 leveldb.cpp:436] Reading position from leveldb took 61013ns
I0110 19:38:42.468643 31439 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 39.412423ms
I0110 19:38:42.468690 31439 replica.cpp:712] Persisted action at 0
I0110 19:38:42.469401 31449 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0110 19:38:42.510426 31449 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 40.986301ms
I0110 19:38:42.510471 31449 replica.cpp:712] Persisted action at 0
I0110 19:38:42.510498 31449 replica.cpp:697] Replica learned NOP action at position 0
I0110 19:38:42.511296 31441 log.cpp:675] Writer started with ending position 0
I0110 19:38:42.512869 31449 leveldb.cpp:436] Reading position from leveldb took 29884ns
I0110 19:38:42.513972 31447 registrar.cpp:340] Successfully fetched the registry (0B) in 240.168192ms
I0110 19:38:42.514163 31447 registrar.cpp:439] Applied 1 operations in 24465ns; attempting to update the 'registry'
I0110 19:38:42.515065 31437 log.cpp:683] Attempting to append 170 bytes to the log
I0110 19:38:42.515722 31435 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0110 19:38:42.516752 31443 replica.cpp:537] Replica received write request for position 1 from (13475)@172.17.0.2:52880
I0110 19:38:42.552160 31443 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 35.352009ms
I0110 19:38:42.552206 31443 replica.cpp:712] Persisted action at 1
I0110 19:38:42.553058 31441 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0110 19:38:42.594059 31441 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 40.955091ms
I0110 19:38:42.594110 31441 replica.cpp:712] Persisted action at 1
I0110 19:38:42.594246 31441 replica.cpp:697] Replica learned APPEND action at position 1
I0110 19:38:42.595350 31444 registrar.cpp:484] Successfully updated the 'registry' in 81.107968ms
I0110 19:38:42.595541 31444 registrar.cpp:370] Successfully recovered registrar
I0110 19:38:42.595615 31449 log.cpp:702] Attempting to truncate the log to 1
I0110 19:38:42.595774 31441 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0110 19:38:42.596106 31449 master.cpp:1525] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0110 19:38:42.596179 31434 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0110 19:38:42.596961 31443 replica.cpp:537] Replica received write request for position 2 from (13476)@172.17.0.2:52880
I0110 19:38:42.635570 31443 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 38.562996ms
I0110 19:38:42.635607 31443 replica.cpp:712] Persisted action at 2
I0110 19:38:42.636337 31437 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0110 19:38:42.677417 31437 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 40.95121ms
I0110 19:38:42.677491 31437 leveldb.cpp:399] Deleting ~1 keys from leveldb took 38142ns
I0110 19:38:42.677517 31437 replica.cpp:712] Persisted action at 2
I0110 19:38:42.677539 31437 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0110 19:38:42.687461 31415 scheduler.cpp:154] Version: 0.27.0
I0110 19:38:42.688098 31443 scheduler.cpp:236] New master detected at master@172.17.0.2:52880
I0110 19:38:42.689272 31435 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:52880
I0110 19:38:42.691481 31436 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 19:38:42.692313 31441 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:59893
I0110 19:38:42.692701 31441 master.cpp:1977] Received subscription request for HTTP framework 'default'
I0110 19:38:42.692765 31441 master.cpp:1754] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0110 19:38:42.693120 31439 master.cpp:2068] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0110 19:38:42.693627 31445 hierarchical.cpp:260] Added framework 3bc6e713-5937-4c77-a0b3-6ec086e59f1d-0000
I0110 19:38:42.693842 31445 hierarchical.cpp:1329] No resources available to allocate!
I0110 19:38:42.693940 31442 master.hpp:1657] Sending heartbeat to 3bc6e713-5937-4c77-a0b3-6ec086e59f1d-0000
I0110 19:38:42.693984 31445 hierarchical.cpp:1423] No inverse offers to send out!
I0110 19:38:42.694018 31445 hierarchical.cpp:1079] Performed allocation for 0 slaves in 360855ns
I0110 19:38:42.694777 31435 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:52880
I0110 19:38:42.695399 31435 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:52880
I0110 19:38:42.697247 31440 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0110 19:38:42.697263 31443 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:52880
I0110 19:38:42.699259 31442 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0110 19:38:42.699775 31438 http.cpp:315] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:59894
I0110 19:38:42.700160 31438 master.cpp:2722] Processing REQUEST call for framework 3bc6e713-5937-4c77-a0b3-6ec086e59f1d-0000 (default)
I0110 19:38:42.700392 31447 hierarchical.cpp:579] Received resource request from framework 3bc6e713-5937-4c77-a0b3-6ec086e59f1d-0000
I0110 19:38:42.700965 31415 master.cpp:1016] Master terminating
I0110 19:38:42.701359 31443 hierarchical.cpp:321] Removed framework 3bc6e713-5937-4c77-a0b3-6ec086e59f1d-0000
E0110 19:38:42.702430 31441 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (551 ms)
[----------] 22 tests from ContentType/SchedulerTest (15437 ms total)
[----------] Global test environment tear-down
[==========] 926 tests from 122 test cases ran. (707580 ms total)
[ PASSED ] 925 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] DiskUsageCollectorTest.File
1 FAILED TEST
YOU HAVE 7 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-1452452388-14735
Untagged: mesos-1452452388-14735:latest
Deleted: 061b29a17b9932bf30f5ccdb7e6912aac23b8529371f68c4dc1bee4ff1b6c5f4
Deleted: 7d5201ff6071135d9afa7f1701ca7d10417e546eeac231274148f5e1658be1cb
Deleted: 60ea54e12d5bebfb60fee0c1d79a4f5ef07f6a0470c4ec8ee2355ac49f383ab7
Deleted: 596e3b67dfa6d650008a5eaf9004547b4d934690c9cdd75e812491aa10ceeb32
Deleted: 6b0bf1b1a1ff40bc6214f43b13d5136524cad25d0a5b85cc61b47d045f7b100e
Deleted: 18530b354dd82575070d853cfb62e9e4e42765137acce0e687605a3e42dc3ae2
Deleted: ea1e2129130dfc397520b036c4f9a6b9a55d6f1de1306ab51a40e51817dd9288
Deleted: 67d2679c121d6077f017c2475504ec20fe99324a68e0320a8a677fb3da0004ea
Deleted: c17278515b011f5dcd7a407e330c1082aa0929008d2c7186b00a01dc8d17abb1
Deleted: e1853b4f0e1ffd10f23561a0a046f751f1f4714794b7295e78f2c725fc191566
Deleted: 92ff803ed069bb5085be3b464cd9707c59135b7fdae2143ff8403e5dc8de99e5
Deleted: 70803e08ea408905814b89918e3fc350fd81bdc53a24f1fe43c406853d191b59
Deleted: 32dbf3576cf0108b860413c6f3b07893a61d940d73faca1f5d5d25984f0d24f7
Deleted: 4476a5658eb7594b575a1fe16c6d979a5e988c1b9e62cdcdf1abacf9b241a2f9
Error handling URL https://reviews.apache.org/api/review-requests/41963/reviews/: INTERNAL SERVER ERROR
git clean -fd
git reset --hard 468b8ecbe5bcb968a4e802a0cf2fa95da2234af7
Build step 'Execute shell' marked build as failure