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/03/31 00:55:51 UTC
Build failed in Jenkins: Mesos » clang,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1908
See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1908/changes>
Changes:
[mpark] Used Windows-compatible memory fence in libprocess logging.
[mpark] Conditioned out Windows-incompatible includes in stout.
[mpark] Conditioned out Windows-incompatible includes in libprocess.
------------------------------------------
[...truncated 179151 lines...]
I0330 22:47:38.193208 32398 http.cpp:313] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:48396
I0330 22:47:38.193461 32398 master.cpp:2785] Processing REQUEST call for framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default)
I0330 22:47:38.193586 32387 hierarchical.cpp:592] Received resource request from framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000
I0330 22:47:38.203701 32386 master.cpp:1269] Framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default) disconnected
I0330 22:47:38.203749 32386 master.cpp:2642] Disconnecting framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default)
I0330 22:47:38.203774 32386 master.cpp:2666] Deactivating framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default)
I0330 22:47:38.203856 32386 master.cpp:1293] Giving framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default) 0ns to failover
I0330 22:47:38.203898 32392 hierarchical.cpp:378] Deactivated framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000
I0330 22:47:38.206979 32392 master.cpp:5360] Framework failover timeout, removing framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default)
I0330 22:47:38.207022 32392 master.cpp:6093] Removing framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default)
I0330 22:47:38.207392 32392 hierarchical.cpp:329] Removed framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000
I0330 22:47:38.214709 32366 master.cpp:1083] Master terminating
[ OK ] ContentType/SchedulerTest.Request/1 (680 ms)
[ RUN ] ContentType/SchedulerTest.SchedulerReconnect/0
I0330 22:47:38.221040 32366 cluster.cpp:139] Creating default 'local' authorizer
I0330 22:47:38.325374 32366 leveldb.cpp:174] Opened db in 104.011212ms
I0330 22:47:38.384241 32366 leveldb.cpp:181] Compacted db in 58.824777ms
I0330 22:47:38.384357 32366 leveldb.cpp:196] Created db iterator in 40245ns
I0330 22:47:38.384379 32366 leveldb.cpp:202] Seeked to beginning of db in 10852ns
I0330 22:47:38.384392 32366 leveldb.cpp:271] Iterated through 0 keys in the db in 6645ns
I0330 22:47:38.384449 32366 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0330 22:47:38.385085 32388 recover.cpp:447] Starting replica recovery
I0330 22:47:38.385383 32388 recover.cpp:473] Replica is in EMPTY status
I0330 22:47:38.386994 32388 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (16437)@172.17.0.2:49204
I0330 22:47:38.387356 32388 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0330 22:47:38.388244 32397 recover.cpp:564] Updating replica status to STARTING
I0330 22:47:38.396265 32390 master.cpp:376] Master 8953e67c-ba7b-4d41-8f18-92f13275e90f (91dee098ed28) started on 172.17.0.2:49204
I0330 22:47:38.396451 32390 master.cpp:378] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/7ZrRHB/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_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui" --work_dir="/tmp/7ZrRHB/master" --zk_session_timeout="10secs"
I0330 22:47:38.397060 32390 master.cpp:429] Master allowing unauthenticated frameworks to register
I0330 22:47:38.397140 32390 master.cpp:432] Master only allowing authenticated slaves to register
I0330 22:47:38.397239 32390 credentials.hpp:37] Loading credentials for authentication from '/tmp/7ZrRHB/credentials'
I0330 22:47:38.397698 32390 master.cpp:474] Using default 'crammd5' authenticator
I0330 22:47:38.397943 32390 master.cpp:545] Using default 'basic' HTTP authenticator
I0330 22:47:38.398196 32390 master.cpp:583] Authorization enabled
I0330 22:47:38.398568 32386 hierarchical.cpp:144] Initialized hierarchical allocator process
I0330 22:47:38.398658 32386 whitelist_watcher.cpp:77] No whitelist given
I0330 22:47:38.402395 32390 master.cpp:1826] The newly elected leader is master@172.17.0.2:49204 with id 8953e67c-ba7b-4d41-8f18-92f13275e90f
I0330 22:47:38.402453 32390 master.cpp:1839] Elected as the leading master!
I0330 22:47:38.402467 32390 master.cpp:1526] Recovering from registrar
I0330 22:47:38.402866 32390 registrar.cpp:307] Recovering registrar
I0330 22:47:38.442379 32397 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 53.964059ms
I0330 22:47:38.442478 32397 replica.cpp:320] Persisted replica status to STARTING
I0330 22:47:38.442842 32397 recover.cpp:473] Replica is in STARTING status
I0330 22:47:38.444898 32394 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (16439)@172.17.0.2:49204
I0330 22:47:38.445298 32394 recover.cpp:193] Received a recover response from a replica in STARTING status
I0330 22:47:38.446038 32394 recover.cpp:564] Updating replica status to VOTING
I0330 22:47:38.477344 32394 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 31.119208ms
I0330 22:47:38.477433 32394 replica.cpp:320] Persisted replica status to VOTING
I0330 22:47:38.477674 32394 recover.cpp:578] Successfully joined the Paxos group
I0330 22:47:38.477880 32394 recover.cpp:462] Recover process terminated
I0330 22:47:38.478603 32394 log.cpp:659] Attempting to start the writer
I0330 22:47:38.480128 32395 replica.cpp:493] Replica received implicit promise request from (16440)@172.17.0.2:49204 with proposal 1
I0330 22:47:38.543083 32395 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 62.934321ms
I0330 22:47:38.543176 32395 replica.cpp:342] Persisted promised to 1
I0330 22:47:38.544517 32395 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0330 22:47:38.546247 32395 replica.cpp:388] Replica received explicit promise request from (16441)@172.17.0.2:49204 for position 0 with proposal 2
I0330 22:47:38.575716 32395 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 29.451252ms
I0330 22:47:38.575810 32395 replica.cpp:712] Persisted action at 0
I0330 22:47:38.582515 32385 replica.cpp:537] Replica received write request for position 0 from (16442)@172.17.0.2:49204
I0330 22:47:38.582748 32385 leveldb.cpp:436] Reading position from leveldb took 91273ns
I0330 22:47:38.642376 32385 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 59.508162ms
I0330 22:47:38.642469 32385 replica.cpp:712] Persisted action at 0
I0330 22:47:38.643568 32385 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0330 22:47:38.693547 32385 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 49.980364ms
I0330 22:47:38.693647 32385 replica.cpp:712] Persisted action at 0
I0330 22:47:38.693696 32385 replica.cpp:697] Replica learned NOP action at position 0
I0330 22:47:38.694994 32385 log.cpp:675] Writer started with ending position 0
I0330 22:47:38.696504 32385 leveldb.cpp:436] Reading position from leveldb took 87465ns
I0330 22:47:38.698161 32397 registrar.cpp:340] Successfully fetched the registry (0B) in 295.18336ms
I0330 22:47:38.698472 32397 registrar.cpp:439] Applied 1 operations in 118341ns; attempting to update the 'registry'
I0330 22:47:38.700197 32385 log.cpp:683] Attempting to append 170 bytes to the log
I0330 22:47:38.700597 32397 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0330 22:47:38.701895 32396 replica.cpp:537] Replica received write request for position 1 from (16443)@172.17.0.2:49204
I0330 22:47:38.744640 32396 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 42.723392ms
I0330 22:47:38.744741 32396 replica.cpp:712] Persisted action at 1
I0330 22:47:38.745800 32386 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0330 22:47:38.803349 32386 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 57.54218ms
I0330 22:47:38.803438 32386 replica.cpp:712] Persisted action at 1
I0330 22:47:38.803472 32386 replica.cpp:697] Replica learned APPEND action at position 1
I0330 22:47:38.805336 32386 registrar.cpp:484] Successfully updated the 'registry' in 106.720768ms
I0330 22:47:38.805469 32386 registrar.cpp:370] Successfully recovered registrar
I0330 22:47:38.805723 32386 log.cpp:702] Attempting to truncate the log to 1
I0330 22:47:38.806151 32386 master.cpp:1634] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0330 22:47:38.806248 32386 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0330 22:47:38.806646 32386 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0330 22:47:38.807665 32386 replica.cpp:537] Replica received write request for position 2 from (16444)@172.17.0.2:49204
I0330 22:47:38.844012 32386 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 35.973249ms
I0330 22:47:38.844104 32386 replica.cpp:712] Persisted action at 2
I0330 22:47:38.852344 32386 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0330 22:47:38.911080 32386 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 58.702863ms
I0330 22:47:38.911234 32386 leveldb.cpp:399] Deleting ~1 keys from leveldb took 82323ns
I0330 22:47:38.911262 32386 replica.cpp:712] Persisted action at 2
I0330 22:47:38.911293 32386 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0330 22:47:38.918992 32366 scheduler.cpp:172] Version: 0.29.0
I0330 22:47:38.919694 32392 scheduler.cpp:466] New master detected at master@172.17.0.2:49204
I0330 22:47:38.921468 32392 scheduler.cpp:355] Connected with the master at http://172.17.0.2:49204/master/api/v1/scheduler
I0330 22:47:38.923288 32395 scheduler.cpp:437] Re-detecting master
I0330 22:47:38.923557 32395 scheduler.cpp:388] Ignoring disconnection attempt from stale connection
I0330 22:47:38.923593 32395 scheduler.cpp:388] Ignoring disconnection attempt from stale connection
I0330 22:47:38.923820 32396 scheduler.cpp:466] New master detected at master@172.17.0.2:49204
I0330 22:47:38.925801 32392 scheduler.cpp:355] Connected with the master at http://172.17.0.2:49204/master/api/v1/scheduler
I0330 22:47:38.927692 32396 scheduler.cpp:441] Lost leading master
I0330 22:47:38.927963 32396 scheduler.cpp:388] Ignoring disconnection attempt from stale connection
I0330 22:47:38.927996 32396 scheduler.cpp:388] Ignoring disconnection attempt from stale connection
I0330 22:47:38.928875 32394 scheduler.cpp:275] Ignoring reconnect request from scheduler since we are disconnected
I0330 22:47:38.950101 32366 master.cpp:1083] Master terminating
[ OK ] ContentType/SchedulerTest.SchedulerReconnect/0 (792 ms)
[ RUN ] ContentType/SchedulerTest.SchedulerReconnect/1
I0330 22:47:39.016577 32366 cluster.cpp:139] Creating default 'local' authorizer
I0330 22:47:39.154433 32366 leveldb.cpp:174] Opened db in 137.311383ms
I0330 22:47:39.246587 32366 leveldb.cpp:181] Compacted db in 92.10769ms
I0330 22:47:39.246696 32366 leveldb.cpp:196] Created db iterator in 48175ns
I0330 22:47:39.246722 32366 leveldb.cpp:202] Seeked to beginning of db in 12608ns
I0330 22:47:39.246737 32366 leveldb.cpp:271] Iterated through 0 keys in the db in 7425ns
I0330 22:47:39.246786 32366 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0330 22:47:39.247653 32384 recover.cpp:447] Starting replica recovery
I0330 22:47:39.247934 32384 recover.cpp:473] Replica is in EMPTY status
I0330 22:47:39.249524 32384 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (16447)@172.17.0.2:49204
I0330 22:47:39.250095 32384 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0330 22:47:39.250779 32395 recover.cpp:564] Updating replica status to STARTING
I0330 22:47:39.268630 32399 master.cpp:376] Master 9101479d-940d-43db-ae88-78f308766ba4 (91dee098ed28) started on 172.17.0.2:49204
I0330 22:47:39.268908 32399 master.cpp:378] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/Kh07zs/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_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui" --work_dir="/tmp/Kh07zs/master" --zk_session_timeout="10secs"
I0330 22:47:39.269350 32399 master.cpp:429] Master allowing unauthenticated frameworks to register
I0330 22:47:39.269368 32399 master.cpp:432] Master only allowing authenticated slaves to register
I0330 22:47:39.269379 32399 credentials.hpp:37] Loading credentials for authentication from '/tmp/Kh07zs/credentials'
I0330 22:47:39.280360 32399 master.cpp:474] Using default 'crammd5' authenticator
I0330 22:47:39.280609 32399 master.cpp:545] Using default 'basic' HTTP authenticator
I0330 22:47:39.280783 32399 master.cpp:583] Authorization enabled
I0330 22:47:39.283335 32399 hierarchical.cpp:144] Initialized hierarchical allocator process
I0330 22:47:39.283432 32399 whitelist_watcher.cpp:77] No whitelist given
I0330 22:47:39.284203 32390 master.cpp:1826] The newly elected leader is master@172.17.0.2:49204 with id 9101479d-940d-43db-ae88-78f308766ba4
I0330 22:47:39.284243 32390 master.cpp:1839] Elected as the leading master!
I0330 22:47:39.284260 32390 master.cpp:1526] Recovering from registrar
I0330 22:47:39.284515 32390 registrar.cpp:307] Recovering registrar
I0330 22:47:39.289958 32395 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 38.664094ms
I0330 22:47:39.290030 32395 replica.cpp:320] Persisted replica status to STARTING
I0330 22:47:39.290321 32395 recover.cpp:473] Replica is in STARTING status
I0330 22:47:39.292207 32395 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (16450)@172.17.0.2:49204
I0330 22:47:39.292583 32395 recover.cpp:193] Received a recover response from a replica in STARTING status
I0330 22:47:39.293308 32395 recover.cpp:564] Updating replica status to VOTING
I0330 22:47:39.329697 32395 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 36.19885ms
I0330 22:47:39.329797 32395 replica.cpp:320] Persisted replica status to VOTING
I0330 22:47:39.330039 32395 recover.cpp:578] Successfully joined the Paxos group
I0330 22:47:39.330245 32395 recover.cpp:462] Recover process terminated
I0330 22:47:39.331040 32395 log.cpp:659] Attempting to start the writer
I0330 22:47:39.332527 32390 replica.cpp:493] Replica received implicit promise request from (16451)@172.17.0.2:49204 with proposal 1
I0330 22:47:39.363349 32390 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 30.806977ms
I0330 22:47:39.363436 32390 replica.cpp:342] Persisted promised to 1
I0330 22:47:39.364817 32397 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0330 22:47:39.366557 32397 replica.cpp:388] Replica received explicit promise request from (16452)@172.17.0.2:49204 for position 0 with proposal 2
I0330 22:47:39.413787 32397 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 47.210188ms
I0330 22:47:39.413885 32397 replica.cpp:712] Persisted action at 0
I0330 22:47:39.415698 32397 replica.cpp:537] Replica received write request for position 0 from (16453)@172.17.0.2:49204
I0330 22:47:39.415781 32397 leveldb.cpp:436] Reading position from leveldb took 55837ns
I0330 22:47:39.430840 32397 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 15.042471ms
I0330 22:47:39.430933 32397 replica.cpp:712] Persisted action at 0
I0330 22:47:39.440426 32384 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0330 22:47:39.464510 32384 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 24.048902ms
I0330 22:47:39.464607 32384 replica.cpp:712] Persisted action at 0
I0330 22:47:39.464642 32384 replica.cpp:697] Replica learned NOP action at position 0
I0330 22:47:39.465505 32384 log.cpp:675] Writer started with ending position 0
I0330 22:47:39.466753 32398 leveldb.cpp:436] Reading position from leveldb took 71157ns
I0330 22:47:39.467986 32398 registrar.cpp:340] Successfully fetched the registry (0B) in 183.427072ms
I0330 22:47:39.468129 32398 registrar.cpp:439] Applied 1 operations in 47944ns; attempting to update the 'registry'
I0330 22:47:39.469229 32384 log.cpp:683] Attempting to append 170 bytes to the log
I0330 22:47:39.469336 32386 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0330 22:47:39.470084 32389 replica.cpp:537] Replica received write request for position 1 from (16454)@172.17.0.2:49204
I0330 22:47:39.507150 32389 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 37.05426ms
I0330 22:47:39.507246 32389 replica.cpp:712] Persisted action at 1
I0330 22:47:39.508015 32398 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0330 22:47:39.540444 32398 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 32.423177ms
I0330 22:47:39.540539 32398 replica.cpp:712] Persisted action at 1
I0330 22:47:39.540575 32398 replica.cpp:697] Replica learned APPEND action at position 1
I0330 22:47:39.541998 32386 registrar.cpp:484] Successfully updated the 'registry' in 73.794816ms
I0330 22:47:39.542155 32386 registrar.cpp:370] Successfully recovered registrar
I0330 22:47:39.542222 32398 log.cpp:702] Attempting to truncate the log to 1
I0330 22:47:39.542420 32398 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0330 22:47:39.542605 32386 master.cpp:1634] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0330 22:47:39.542834 32386 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0330 22:47:39.543644 32393 replica.cpp:537] Replica received write request for position 2 from (16455)@172.17.0.2:49204
I0330 22:47:39.614894 32393 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 71.232083ms
I0330 22:47:39.614990 32393 replica.cpp:712] Persisted action at 2
I0330 22:47:39.615694 32393 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0330 22:47:39.666344 32393 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 50.646216ms
I0330 22:47:39.666508 32393 leveldb.cpp:399] Deleting ~1 keys from leveldb took 85679ns
I0330 22:47:39.666535 32393 replica.cpp:712] Persisted action at 2
I0330 22:47:39.666568 32393 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0330 22:47:39.675284 32366 scheduler.cpp:172] Version: 0.29.0
I0330 22:47:39.676090 32397 scheduler.cpp:466] New master detected at master@172.17.0.2:49204
I0330 22:47:39.678237 32393 scheduler.cpp:355] Connected with the master at http://172.17.0.2:49204/master/api/v1/scheduler
I0330 22:47:39.680200 32397 scheduler.cpp:437] Re-detecting master
I0330 22:47:39.680426 32397 scheduler.cpp:388] Ignoring disconnection attempt from stale connection
I0330 22:47:39.680462 32397 scheduler.cpp:388] Ignoring disconnection attempt from stale connection
I0330 22:47:39.680797 32397 scheduler.cpp:466] New master detected at master@172.17.0.2:49204
I0330 22:47:39.682622 32395 scheduler.cpp:355] Connected with the master at http://172.17.0.2:49204/master/api/v1/scheduler
I0330 22:47:39.684255 32387 scheduler.cpp:441] Lost leading master
I0330 22:47:39.684458 32387 scheduler.cpp:388] Ignoring disconnection attempt from stale connection
I0330 22:47:39.684496 32387 scheduler.cpp:388] Ignoring disconnection attempt from stale connection
I0330 22:47:39.688269 32389 scheduler.cpp:275] Ignoring reconnect request from scheduler since we are disconnected
I0330 22:47:39.732667 32391 master.cpp:1083] Master terminating
[ OK ] ContentType/SchedulerTest.SchedulerReconnect/1 (773 ms)
[----------] 28 tests from ContentType/SchedulerTest (24256 ms total)
[----------] Global test environment tear-down
E0330 22:47:39.980386 32366 environment.cpp:778] Failed to remove '/tmp/LogZooKeeperTest_WriteRead_K57Vpl': No such file or directory
E0330 22:47:39.980465 32366 environment.cpp:778] Failed to remove '/tmp/LogZooKeeperTest_LostZooKeeper_SFKpjA': No such file or directory
../../src/tests/environment.cpp:790: Failure
Failed
Tests completed with child processes remaining:
-+- 32366 /mesos/mesos-0.29.0/_build/src/.libs/lt-mesos-tests
\-+- 7627 sh -c /mesos/mesos-0.29.0/_build/src/mesos-executor
\--- 7641 /mesos/mesos-0.29.0/_build/src/.libs/lt-mesos-executor
[==========] 1054 tests from 132 test cases ran. (778398 ms total)
[ PASSED ] 1053 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] MesosContainerizerSlaveRecoveryTest.ResourceStatistics
1 FAILED TEST
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
I0330 22:47:40.783821 7663 exec.cpp:472] Slave exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with slave b8ddcbf8-9193-492d-b309-10c5e1cc2aa0-S0
make[4]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[3]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[2]: *** [check] Error 2
make[1]: Leaving directory `/mesos/mesos-0.29.0/_build'
make[1]: *** [check-recursive] Error 1
make: *** [distcheck] Error 1
+ docker rmi mesos-1459375353-29982
Untagged: mesos-1459375353-29982:latest
Deleted: 0a6961c4d5bee2905a451ae8c7552221edcb8152f9bc299c5a57e351e344a5f9
Deleted: 64e0dbcb7fd28739db2c0c347cdace88608f189cde745f2f2922bacda7c2cbe0
Deleted: c5dc3f6479b6af003cc71f2cd920ec43848a42324614c408357715ad239ec955
Deleted: 5fcf61cd3a43ee747a21549fe21dcb9bba8685ac1a044ce25d731f3fa31bcc08
Deleted: 6e550c5ad18489ed4eada61081ed7ea3f02143d8df27c584db42c1a57b8ee3c8
Deleted: a68b9fcfaac2b4eb656b9cfbf9227847eaf710951e296c3d8a99906b97e23efb
Deleted: a0c3da83616030918a708b2e477610981813e832f0a87dc9b36ff291dcdc1642
Deleted: 5d07eaa1cffa43716724c512680d08abefa0201c6322a486eb82e38c3d13675d
Deleted: 0d2e3d4b9eb49b2926eca3d664fefe9d31494faa7623f896098f553c225cef8f
Deleted: cf589496e8aae72e570366720c10f325f644de6031d12e0042d3aec045db1864
Deleted: 846721e192ec5f107d452506ad1783f8d34466e05dc5d351d8346bc2a449e044
Deleted: 20d342ff0d743d204ed6bfada3af61c40caeac832bddc8576e705d958d3119b6
Deleted: a10ab2f6e1321a28f62d53f0d3eb963fcf4bc7557f0ee0d1f34c4d7eed26614e
Deleted: c1ada944d8b2fc8ab4a4edca8d1ae6fd5b427db840e6e3febd74d1dce6905c16
Deleted: feec27612c04dc15c06b72c65c60eaa69b64cb59cc7c431e333255e86d94f242
Deleted: c73fec5e201e7a85f4603f6a9f10c3fd022e31281d41ba66609b342a3eebd1b0
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » clang,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1909
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1909/changes>
Re: Build failed in Jenkins: Mesos » clang,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1908
Posted by Michael Park <mp...@apache.org>.
MESOS-5048 <https://issues.apache.org/jira/browse/MESOS-5048>
On 30 March 2016 at 18:55, Apache Jenkins Server <je...@builds.apache.org>
wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1908/changes
> >
>
> Changes:
>
> [mpark] Used Windows-compatible memory fence in libprocess logging.
>
> [mpark] Conditioned out Windows-incompatible includes in stout.
>
> [mpark] Conditioned out Windows-incompatible includes in libprocess.
>
> ------------------------------------------
> [...truncated 179151 lines...]
> I0330 22:47:38.193208 32398 http.cpp:313] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:48396
> I0330 22:47:38.193461 32398 master.cpp:2785] Processing REQUEST call for
> framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default)
> I0330 22:47:38.193586 32387 hierarchical.cpp:592] Received resource
> request from framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000
> I0330 22:47:38.203701 32386 master.cpp:1269] Framework
> 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default) disconnected
> I0330 22:47:38.203749 32386 master.cpp:2642] Disconnecting framework
> 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default)
> I0330 22:47:38.203774 32386 master.cpp:2666] Deactivating framework
> 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default)
> I0330 22:47:38.203856 32386 master.cpp:1293] Giving framework
> 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default) 0ns to failover
> I0330 22:47:38.203898 32392 hierarchical.cpp:378] Deactivated framework
> 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000
> I0330 22:47:38.206979 32392 master.cpp:5360] Framework failover timeout,
> removing framework 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default)
> I0330 22:47:38.207022 32392 master.cpp:6093] Removing framework
> 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000 (default)
> I0330 22:47:38.207392 32392 hierarchical.cpp:329] Removed framework
> 10f7cd4b-7961-4be0-8933-0f673ed95cad-0000
> I0330 22:47:38.214709 32366 master.cpp:1083] Master terminating
> [ OK ] ContentType/SchedulerTest.Request/1 (680 ms)
> [ RUN ] ContentType/SchedulerTest.SchedulerReconnect/0
> I0330 22:47:38.221040 32366 cluster.cpp:139] Creating default 'local'
> authorizer
> I0330 22:47:38.325374 32366 leveldb.cpp:174] Opened db in 104.011212ms
> I0330 22:47:38.384241 32366 leveldb.cpp:181] Compacted db in 58.824777ms
> I0330 22:47:38.384357 32366 leveldb.cpp:196] Created db iterator in 40245ns
> I0330 22:47:38.384379 32366 leveldb.cpp:202] Seeked to beginning of db in
> 10852ns
> I0330 22:47:38.384392 32366 leveldb.cpp:271] Iterated through 0 keys in
> the db in 6645ns
> I0330 22:47:38.384449 32366 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0330 22:47:38.385085 32388 recover.cpp:447] Starting replica recovery
> I0330 22:47:38.385383 32388 recover.cpp:473] Replica is in EMPTY status
> I0330 22:47:38.386994 32388 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (16437)@172.17.0.2:49204
> I0330 22:47:38.387356 32388 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0330 22:47:38.388244 32397 recover.cpp:564] Updating replica status to
> STARTING
> I0330 22:47:38.396265 32390 master.cpp:376] Master
> 8953e67c-ba7b-4d41-8f18-92f13275e90f (91dee098ed28) started on
> 172.17.0.2:49204
> I0330 22:47:38.396451 32390 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/7ZrRHB/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_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui"
> --work_dir="/tmp/7ZrRHB/master" --zk_session_timeout="10secs"
> I0330 22:47:38.397060 32390 master.cpp:429] Master allowing
> unauthenticated frameworks to register
> I0330 22:47:38.397140 32390 master.cpp:432] Master only allowing
> authenticated slaves to register
> I0330 22:47:38.397239 32390 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/7ZrRHB/credentials'
> I0330 22:47:38.397698 32390 master.cpp:474] Using default 'crammd5'
> authenticator
> I0330 22:47:38.397943 32390 master.cpp:545] Using default 'basic' HTTP
> authenticator
> I0330 22:47:38.398196 32390 master.cpp:583] Authorization enabled
> I0330 22:47:38.398568 32386 hierarchical.cpp:144] Initialized hierarchical
> allocator process
> I0330 22:47:38.398658 32386 whitelist_watcher.cpp:77] No whitelist given
> I0330 22:47:38.402395 32390 master.cpp:1826] The newly elected leader is
> master@172.17.0.2:49204 with id 8953e67c-ba7b-4d41-8f18-92f13275e90f
> I0330 22:47:38.402453 32390 master.cpp:1839] Elected as the leading master!
> I0330 22:47:38.402467 32390 master.cpp:1526] Recovering from registrar
> I0330 22:47:38.402866 32390 registrar.cpp:307] Recovering registrar
> I0330 22:47:38.442379 32397 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 53.964059ms
> I0330 22:47:38.442478 32397 replica.cpp:320] Persisted replica status to
> STARTING
> I0330 22:47:38.442842 32397 recover.cpp:473] Replica is in STARTING status
> I0330 22:47:38.444898 32394 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (16439)@172.17.0.2:49204
> I0330 22:47:38.445298 32394 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0330 22:47:38.446038 32394 recover.cpp:564] Updating replica status to
> VOTING
> I0330 22:47:38.477344 32394 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 31.119208ms
> I0330 22:47:38.477433 32394 replica.cpp:320] Persisted replica status to
> VOTING
> I0330 22:47:38.477674 32394 recover.cpp:578] Successfully joined the Paxos
> group
> I0330 22:47:38.477880 32394 recover.cpp:462] Recover process terminated
> I0330 22:47:38.478603 32394 log.cpp:659] Attempting to start the writer
> I0330 22:47:38.480128 32395 replica.cpp:493] Replica received implicit
> promise request from (16440)@172.17.0.2:49204 with proposal 1
> I0330 22:47:38.543083 32395 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 62.934321ms
> I0330 22:47:38.543176 32395 replica.cpp:342] Persisted promised to 1
> I0330 22:47:38.544517 32395 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0330 22:47:38.546247 32395 replica.cpp:388] Replica received explicit
> promise request from (16441)@172.17.0.2:49204 for position 0 with
> proposal 2
> I0330 22:47:38.575716 32395 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 29.451252ms
> I0330 22:47:38.575810 32395 replica.cpp:712] Persisted action at 0
> I0330 22:47:38.582515 32385 replica.cpp:537] Replica received write
> request for position 0 from (16442)@172.17.0.2:49204
> I0330 22:47:38.582748 32385 leveldb.cpp:436] Reading position from leveldb
> took 91273ns
> I0330 22:47:38.642376 32385 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 59.508162ms
> I0330 22:47:38.642469 32385 replica.cpp:712] Persisted action at 0
> I0330 22:47:38.643568 32385 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0330 22:47:38.693547 32385 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 49.980364ms
> I0330 22:47:38.693647 32385 replica.cpp:712] Persisted action at 0
> I0330 22:47:38.693696 32385 replica.cpp:697] Replica learned NOP action at
> position 0
> I0330 22:47:38.694994 32385 log.cpp:675] Writer started with ending
> position 0
> I0330 22:47:38.696504 32385 leveldb.cpp:436] Reading position from leveldb
> took 87465ns
> I0330 22:47:38.698161 32397 registrar.cpp:340] Successfully fetched the
> registry (0B) in 295.18336ms
> I0330 22:47:38.698472 32397 registrar.cpp:439] Applied 1 operations in
> 118341ns; attempting to update the 'registry'
> I0330 22:47:38.700197 32385 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0330 22:47:38.700597 32397 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0330 22:47:38.701895 32396 replica.cpp:537] Replica received write
> request for position 1 from (16443)@172.17.0.2:49204
> I0330 22:47:38.744640 32396 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 42.723392ms
> I0330 22:47:38.744741 32396 replica.cpp:712] Persisted action at 1
> I0330 22:47:38.745800 32386 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0330 22:47:38.803349 32386 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 57.54218ms
> I0330 22:47:38.803438 32386 replica.cpp:712] Persisted action at 1
> I0330 22:47:38.803472 32386 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0330 22:47:38.805336 32386 registrar.cpp:484] Successfully updated the
> 'registry' in 106.720768ms
> I0330 22:47:38.805469 32386 registrar.cpp:370] Successfully recovered
> registrar
> I0330 22:47:38.805723 32386 log.cpp:702] Attempting to truncate the log to
> 1
> I0330 22:47:38.806151 32386 master.cpp:1634] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0330 22:47:38.806248 32386 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0330 22:47:38.806646 32386 hierarchical.cpp:171] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0330 22:47:38.807665 32386 replica.cpp:537] Replica received write
> request for position 2 from (16444)@172.17.0.2:49204
> I0330 22:47:38.844012 32386 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 35.973249ms
> I0330 22:47:38.844104 32386 replica.cpp:712] Persisted action at 2
> I0330 22:47:38.852344 32386 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0330 22:47:38.911080 32386 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 58.702863ms
> I0330 22:47:38.911234 32386 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 82323ns
> I0330 22:47:38.911262 32386 replica.cpp:712] Persisted action at 2
> I0330 22:47:38.911293 32386 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0330 22:47:38.918992 32366 scheduler.cpp:172] Version: 0.29.0
> I0330 22:47:38.919694 32392 scheduler.cpp:466] New master detected at
> master@172.17.0.2:49204
> I0330 22:47:38.921468 32392 scheduler.cpp:355] Connected with the master
> at http://172.17.0.2:49204/master/api/v1/scheduler
> I0330 22:47:38.923288 32395 scheduler.cpp:437] Re-detecting master
> I0330 22:47:38.923557 32395 scheduler.cpp:388] Ignoring disconnection
> attempt from stale connection
> I0330 22:47:38.923593 32395 scheduler.cpp:388] Ignoring disconnection
> attempt from stale connection
> I0330 22:47:38.923820 32396 scheduler.cpp:466] New master detected at
> master@172.17.0.2:49204
> I0330 22:47:38.925801 32392 scheduler.cpp:355] Connected with the master
> at http://172.17.0.2:49204/master/api/v1/scheduler
> I0330 22:47:38.927692 32396 scheduler.cpp:441] Lost leading master
> I0330 22:47:38.927963 32396 scheduler.cpp:388] Ignoring disconnection
> attempt from stale connection
> I0330 22:47:38.927996 32396 scheduler.cpp:388] Ignoring disconnection
> attempt from stale connection
> I0330 22:47:38.928875 32394 scheduler.cpp:275] Ignoring reconnect request
> from scheduler since we are disconnected
> I0330 22:47:38.950101 32366 master.cpp:1083] Master terminating
> [ OK ] ContentType/SchedulerTest.SchedulerReconnect/0 (792 ms)
> [ RUN ] ContentType/SchedulerTest.SchedulerReconnect/1
> I0330 22:47:39.016577 32366 cluster.cpp:139] Creating default 'local'
> authorizer
> I0330 22:47:39.154433 32366 leveldb.cpp:174] Opened db in 137.311383ms
> I0330 22:47:39.246587 32366 leveldb.cpp:181] Compacted db in 92.10769ms
> I0330 22:47:39.246696 32366 leveldb.cpp:196] Created db iterator in 48175ns
> I0330 22:47:39.246722 32366 leveldb.cpp:202] Seeked to beginning of db in
> 12608ns
> I0330 22:47:39.246737 32366 leveldb.cpp:271] Iterated through 0 keys in
> the db in 7425ns
> I0330 22:47:39.246786 32366 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0330 22:47:39.247653 32384 recover.cpp:447] Starting replica recovery
> I0330 22:47:39.247934 32384 recover.cpp:473] Replica is in EMPTY status
> I0330 22:47:39.249524 32384 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (16447)@172.17.0.2:49204
> I0330 22:47:39.250095 32384 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0330 22:47:39.250779 32395 recover.cpp:564] Updating replica status to
> STARTING
> I0330 22:47:39.268630 32399 master.cpp:376] Master
> 9101479d-940d-43db-ae88-78f308766ba4 (91dee098ed28) started on
> 172.17.0.2:49204
> I0330 22:47:39.268908 32399 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/Kh07zs/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_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="100secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.29.0/_inst/share/mesos/webui"
> --work_dir="/tmp/Kh07zs/master" --zk_session_timeout="10secs"
> I0330 22:47:39.269350 32399 master.cpp:429] Master allowing
> unauthenticated frameworks to register
> I0330 22:47:39.269368 32399 master.cpp:432] Master only allowing
> authenticated slaves to register
> I0330 22:47:39.269379 32399 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/Kh07zs/credentials'
> I0330 22:47:39.280360 32399 master.cpp:474] Using default 'crammd5'
> authenticator
> I0330 22:47:39.280609 32399 master.cpp:545] Using default 'basic' HTTP
> authenticator
> I0330 22:47:39.280783 32399 master.cpp:583] Authorization enabled
> I0330 22:47:39.283335 32399 hierarchical.cpp:144] Initialized hierarchical
> allocator process
> I0330 22:47:39.283432 32399 whitelist_watcher.cpp:77] No whitelist given
> I0330 22:47:39.284203 32390 master.cpp:1826] The newly elected leader is
> master@172.17.0.2:49204 with id 9101479d-940d-43db-ae88-78f308766ba4
> I0330 22:47:39.284243 32390 master.cpp:1839] Elected as the leading master!
> I0330 22:47:39.284260 32390 master.cpp:1526] Recovering from registrar
> I0330 22:47:39.284515 32390 registrar.cpp:307] Recovering registrar
> I0330 22:47:39.289958 32395 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 38.664094ms
> I0330 22:47:39.290030 32395 replica.cpp:320] Persisted replica status to
> STARTING
> I0330 22:47:39.290321 32395 recover.cpp:473] Replica is in STARTING status
> I0330 22:47:39.292207 32395 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (16450)@172.17.0.2:49204
> I0330 22:47:39.292583 32395 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0330 22:47:39.293308 32395 recover.cpp:564] Updating replica status to
> VOTING
> I0330 22:47:39.329697 32395 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 36.19885ms
> I0330 22:47:39.329797 32395 replica.cpp:320] Persisted replica status to
> VOTING
> I0330 22:47:39.330039 32395 recover.cpp:578] Successfully joined the Paxos
> group
> I0330 22:47:39.330245 32395 recover.cpp:462] Recover process terminated
> I0330 22:47:39.331040 32395 log.cpp:659] Attempting to start the writer
> I0330 22:47:39.332527 32390 replica.cpp:493] Replica received implicit
> promise request from (16451)@172.17.0.2:49204 with proposal 1
> I0330 22:47:39.363349 32390 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 30.806977ms
> I0330 22:47:39.363436 32390 replica.cpp:342] Persisted promised to 1
> I0330 22:47:39.364817 32397 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0330 22:47:39.366557 32397 replica.cpp:388] Replica received explicit
> promise request from (16452)@172.17.0.2:49204 for position 0 with
> proposal 2
> I0330 22:47:39.413787 32397 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 47.210188ms
> I0330 22:47:39.413885 32397 replica.cpp:712] Persisted action at 0
> I0330 22:47:39.415698 32397 replica.cpp:537] Replica received write
> request for position 0 from (16453)@172.17.0.2:49204
> I0330 22:47:39.415781 32397 leveldb.cpp:436] Reading position from leveldb
> took 55837ns
> I0330 22:47:39.430840 32397 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 15.042471ms
> I0330 22:47:39.430933 32397 replica.cpp:712] Persisted action at 0
> I0330 22:47:39.440426 32384 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0330 22:47:39.464510 32384 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 24.048902ms
> I0330 22:47:39.464607 32384 replica.cpp:712] Persisted action at 0
> I0330 22:47:39.464642 32384 replica.cpp:697] Replica learned NOP action at
> position 0
> I0330 22:47:39.465505 32384 log.cpp:675] Writer started with ending
> position 0
> I0330 22:47:39.466753 32398 leveldb.cpp:436] Reading position from leveldb
> took 71157ns
> I0330 22:47:39.467986 32398 registrar.cpp:340] Successfully fetched the
> registry (0B) in 183.427072ms
> I0330 22:47:39.468129 32398 registrar.cpp:439] Applied 1 operations in
> 47944ns; attempting to update the 'registry'
> I0330 22:47:39.469229 32384 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0330 22:47:39.469336 32386 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0330 22:47:39.470084 32389 replica.cpp:537] Replica received write
> request for position 1 from (16454)@172.17.0.2:49204
> I0330 22:47:39.507150 32389 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 37.05426ms
> I0330 22:47:39.507246 32389 replica.cpp:712] Persisted action at 1
> I0330 22:47:39.508015 32398 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0330 22:47:39.540444 32398 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 32.423177ms
> I0330 22:47:39.540539 32398 replica.cpp:712] Persisted action at 1
> I0330 22:47:39.540575 32398 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0330 22:47:39.541998 32386 registrar.cpp:484] Successfully updated the
> 'registry' in 73.794816ms
> I0330 22:47:39.542155 32386 registrar.cpp:370] Successfully recovered
> registrar
> I0330 22:47:39.542222 32398 log.cpp:702] Attempting to truncate the log to
> 1
> I0330 22:47:39.542420 32398 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0330 22:47:39.542605 32386 master.cpp:1634] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0330 22:47:39.542834 32386 hierarchical.cpp:171] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0330 22:47:39.543644 32393 replica.cpp:537] Replica received write
> request for position 2 from (16455)@172.17.0.2:49204
> I0330 22:47:39.614894 32393 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 71.232083ms
> I0330 22:47:39.614990 32393 replica.cpp:712] Persisted action at 2
> I0330 22:47:39.615694 32393 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0330 22:47:39.666344 32393 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 50.646216ms
> I0330 22:47:39.666508 32393 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 85679ns
> I0330 22:47:39.666535 32393 replica.cpp:712] Persisted action at 2
> I0330 22:47:39.666568 32393 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0330 22:47:39.675284 32366 scheduler.cpp:172] Version: 0.29.0
> I0330 22:47:39.676090 32397 scheduler.cpp:466] New master detected at
> master@172.17.0.2:49204
> I0330 22:47:39.678237 32393 scheduler.cpp:355] Connected with the master
> at http://172.17.0.2:49204/master/api/v1/scheduler
> I0330 22:47:39.680200 32397 scheduler.cpp:437] Re-detecting master
> I0330 22:47:39.680426 32397 scheduler.cpp:388] Ignoring disconnection
> attempt from stale connection
> I0330 22:47:39.680462 32397 scheduler.cpp:388] Ignoring disconnection
> attempt from stale connection
> I0330 22:47:39.680797 32397 scheduler.cpp:466] New master detected at
> master@172.17.0.2:49204
> I0330 22:47:39.682622 32395 scheduler.cpp:355] Connected with the master
> at http://172.17.0.2:49204/master/api/v1/scheduler
> I0330 22:47:39.684255 32387 scheduler.cpp:441] Lost leading master
> I0330 22:47:39.684458 32387 scheduler.cpp:388] Ignoring disconnection
> attempt from stale connection
> I0330 22:47:39.684496 32387 scheduler.cpp:388] Ignoring disconnection
> attempt from stale connection
> I0330 22:47:39.688269 32389 scheduler.cpp:275] Ignoring reconnect request
> from scheduler since we are disconnected
> I0330 22:47:39.732667 32391 master.cpp:1083] Master terminating
> [ OK ] ContentType/SchedulerTest.SchedulerReconnect/1 (773 ms)
> [----------] 28 tests from ContentType/SchedulerTest (24256 ms total)
>
> [----------] Global test environment tear-down
> E0330 22:47:39.980386 32366 environment.cpp:778] Failed to remove
> '/tmp/LogZooKeeperTest_WriteRead_K57Vpl': No such file or directory
> E0330 22:47:39.980465 32366 environment.cpp:778] Failed to remove
> '/tmp/LogZooKeeperTest_LostZooKeeper_SFKpjA': No such file or directory
> ../../src/tests/environment.cpp:790: Failure
> Failed
> Tests completed with child processes remaining:
> -+- 32366 /mesos/mesos-0.29.0/_build/src/.libs/lt-mesos-tests
> \-+- 7627 sh -c /mesos/mesos-0.29.0/_build/src/mesos-executor
> \--- 7641 /mesos/mesos-0.29.0/_build/src/.libs/lt-mesos-executor
> [==========] 1054 tests from 132 test cases ran. (778398 ms total)
> [ PASSED ] 1053 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] MesosContainerizerSlaveRecoveryTest.ResourceStatistics
>
> 1 FAILED TEST
> YOU HAVE 6 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> I0330 22:47:40.783821 7663 exec.cpp:472] Slave exited, but framework has
> checkpointing enabled. Waiting 15mins to reconnect with slave
> b8ddcbf8-9193-492d-b309-10c5e1cc2aa0-S0
> make[4]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[3]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[2]: *** [check] Error 2
> make[1]: Leaving directory `/mesos/mesos-0.29.0/_build'
> make[1]: *** [check-recursive] Error 1
> make: *** [distcheck] Error 1
> + docker rmi mesos-1459375353-29982
> Untagged: mesos-1459375353-29982:latest
> Deleted: 0a6961c4d5bee2905a451ae8c7552221edcb8152f9bc299c5a57e351e344a5f9
> Deleted: 64e0dbcb7fd28739db2c0c347cdace88608f189cde745f2f2922bacda7c2cbe0
> Deleted: c5dc3f6479b6af003cc71f2cd920ec43848a42324614c408357715ad239ec955
> Deleted: 5fcf61cd3a43ee747a21549fe21dcb9bba8685ac1a044ce25d731f3fa31bcc08
> Deleted: 6e550c5ad18489ed4eada61081ed7ea3f02143d8df27c584db42c1a57b8ee3c8
> Deleted: a68b9fcfaac2b4eb656b9cfbf9227847eaf710951e296c3d8a99906b97e23efb
> Deleted: a0c3da83616030918a708b2e477610981813e832f0a87dc9b36ff291dcdc1642
> Deleted: 5d07eaa1cffa43716724c512680d08abefa0201c6322a486eb82e38c3d13675d
> Deleted: 0d2e3d4b9eb49b2926eca3d664fefe9d31494faa7623f896098f553c225cef8f
> Deleted: cf589496e8aae72e570366720c10f325f644de6031d12e0042d3aec045db1864
> Deleted: 846721e192ec5f107d452506ad1783f8d34466e05dc5d351d8346bc2a449e044
> Deleted: 20d342ff0d743d204ed6bfada3af61c40caeac832bddc8576e705d958d3119b6
> Deleted: a10ab2f6e1321a28f62d53f0d3eb963fcf4bc7557f0ee0d1f34c4d7eed26614e
> Deleted: c1ada944d8b2fc8ab4a4edca8d1ae6fd5b427db840e6e3febd74d1dce6905c16
> Deleted: feec27612c04dc15c06b72c65c60eaa69b64cb59cc7c431e333255e86d94f242
> Deleted: c73fec5e201e7a85f4603f6a9f10c3fd022e31281d41ba66609b342a3eebd1b0
> Build step 'Execute shell' marked build as failure
>