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/15 22:27:21 UTC
Build failed in Jenkins: Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1496
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1496/changes>
Changes:
[joris.van.remoortere] Stout: Added ref-qualifiers to Option::get().
------------------------------------------
[...truncated 156386 lines...]
I0115 21:27:23.287348 31538 status_update_manager.cpp:282] Closing status update streams for framework c2783d6e-a412-48c8-93ec-91a6e3fac67e-0000
I0115 21:27:23.287497 31536 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_7Vjlj8/slaves/c2783d6e-a412-48c8-93ec-91a6e3fac67e-S0/frameworks/c2783d6e-a412-48c8-93ec-91a6e3fac67e-0000' for gc 6.99999667346074days in the future
I0115 21:27:23.287562 31538 status_update_manager.cpp:528] Cleaning up status update stream for task de90e210-f7b8-4037-918f-c93723584af3 of framework c2783d6e-a412-48c8-93ec-91a6e3fac67e-0000
[ OK ] ContentType/SchedulerTest.Message/1 (112 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0115 21:27:23.297211 31507 leveldb.cpp:174] Opened db in 3.350748ms
I0115 21:27:23.298276 31507 leveldb.cpp:181] Compacted db in 1.015243ms
I0115 21:27:23.298364 31507 leveldb.cpp:196] Created db iterator in 33917ns
I0115 21:27:23.298380 31507 leveldb.cpp:202] Seeked to beginning of db in 1515ns
I0115 21:27:23.298389 31507 leveldb.cpp:271] Iterated through 0 keys in the db in 177ns
I0115 21:27:23.298437 31507 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0115 21:27:23.299082 31535 recover.cpp:447] Starting replica recovery
I0115 21:27:23.299552 31535 recover.cpp:473] Replica is in EMPTY status
I0115 21:27:23.301113 31530 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13814)@172.17.0.4:52665
I0115 21:27:23.301512 31526 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0115 21:27:23.302068 31540 master.cpp:374] Master d806cbcd-c800-48cb-948d-ec1e15af6302 (4e6fbf10d387) started on 172.17.0.4:52665
I0115 21:27:23.302238 31536 recover.cpp:564] Updating replica status to STARTING
I0115 21:27:23.302094 31540 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/s5Iqr2/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="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/s5Iqr2/master" --zk_session_timeout="10secs"
I0115 21:27:23.302583 31540 master.cpp:423] Master allowing unauthenticated frameworks to register
I0115 21:27:23.302600 31540 master.cpp:426] Master only allowing authenticated slaves to register
I0115 21:27:23.302613 31540 credentials.hpp:35] Loading credentials for authentication from '/tmp/s5Iqr2/credentials'
I0115 21:27:23.303025 31530 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 646308ns
I0115 21:27:23.303056 31540 master.cpp:466] Using default 'crammd5' authenticator
I0115 21:27:23.303107 31530 replica.cpp:320] Persisted replica status to STARTING
I0115 21:27:23.303270 31540 master.cpp:535] Using default 'basic' HTTP authenticator
I0115 21:27:23.303498 31526 recover.cpp:473] Replica is in STARTING status
I0115 21:27:23.303550 31540 master.cpp:569] Authorization enabled
I0115 21:27:23.303792 31531 hierarchical.cpp:147] Initialized hierarchical allocator process
I0115 21:27:23.303829 31536 whitelist_watcher.cpp:77] No whitelist given
I0115 21:27:23.305100 31534 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13816)@172.17.0.4:52665
I0115 21:27:23.305578 31526 recover.cpp:193] Received a recover response from a replica in STARTING status
I0115 21:27:23.306113 31538 recover.cpp:564] Updating replica status to VOTING
I0115 21:27:23.306778 31527 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 426070ns
I0115 21:27:23.306815 31527 replica.cpp:320] Persisted replica status to VOTING
I0115 21:27:23.306962 31526 recover.cpp:578] Successfully joined the Paxos group
I0115 21:27:23.307116 31532 master.cpp:1710] The newly elected leader is master@172.17.0.4:52665 with id d806cbcd-c800-48cb-948d-ec1e15af6302
I0115 21:27:23.307159 31532 master.cpp:1723] Elected as the leading master!
I0115 21:27:23.307188 31532 master.cpp:1468] Recovering from registrar
I0115 21:27:23.307220 31526 recover.cpp:462] Recover process terminated
I0115 21:27:23.307652 31541 registrar.cpp:307] Recovering registrar
I0115 21:27:23.308292 31537 log.cpp:659] Attempting to start the writer
I0115 21:27:23.309715 31527 replica.cpp:493] Replica received implicit promise request from (13817)@172.17.0.4:52665 with proposal 1
I0115 21:27:23.310103 31527 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 353807ns
I0115 21:27:23.310132 31527 replica.cpp:342] Persisted promised to 1
I0115 21:27:23.310890 31540 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0115 21:27:23.312296 31534 replica.cpp:388] Replica received explicit promise request from (13818)@172.17.0.4:52665 for position 0 with proposal 2
I0115 21:27:23.313444 31534 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 1.090827ms
I0115 21:27:23.313489 31534 replica.cpp:712] Persisted action at 0
I0115 21:27:23.314939 31529 replica.cpp:537] Replica received write request for position 0 from (13819)@172.17.0.4:52665
I0115 21:27:23.315101 31529 leveldb.cpp:436] Reading position from leveldb took 114197ns
I0115 21:27:23.315618 31529 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 422964ns
I0115 21:27:23.315670 31529 replica.cpp:712] Persisted action at 0
I0115 21:27:23.316685 31536 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0115 21:27:23.317139 31536 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 419412ns
I0115 21:27:23.317173 31536 replica.cpp:712] Persisted action at 0
I0115 21:27:23.317201 31536 replica.cpp:697] Replica learned NOP action at position 0
I0115 21:27:23.318155 31536 log.cpp:675] Writer started with ending position 0
I0115 21:27:23.319429 31532 leveldb.cpp:436] Reading position from leveldb took 54608ns
I0115 21:27:23.320606 31535 registrar.cpp:340] Successfully fetched the registry (0B) in 12896us
I0115 21:27:23.320775 31535 registrar.cpp:439] Applied 1 operations in 50993ns; attempting to update the 'registry'
I0115 21:27:23.321660 31530 log.cpp:683] Attempting to append 170 bytes to the log
I0115 21:27:23.322019 31538 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0115 21:27:23.323017 31539 replica.cpp:537] Replica received write request for position 1 from (13820)@172.17.0.4:52665
I0115 21:27:23.323528 31539 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 463us
I0115 21:27:23.323560 31539 replica.cpp:712] Persisted action at 1
I0115 21:27:23.324455 31539 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0115 21:27:23.324779 31539 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 292823ns
I0115 21:27:23.324803 31539 replica.cpp:712] Persisted action at 1
I0115 21:27:23.324826 31539 replica.cpp:697] Replica learned APPEND action at position 1
I0115 21:27:23.325934 31540 registrar.cpp:484] Successfully updated the 'registry' in 5.081856ms
I0115 21:27:23.326094 31540 registrar.cpp:370] Successfully recovered registrar
I0115 21:27:23.326228 31535 log.cpp:702] Attempting to truncate the log to 1
I0115 21:27:23.326653 31537 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0115 21:27:23.326675 31539 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0115 21:27:23.326717 31533 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0115 21:27:23.327630 31538 replica.cpp:537] Replica received write request for position 2 from (13821)@172.17.0.4:52665
I0115 21:27:23.328061 31538 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 393096ns
I0115 21:27:23.328089 31538 replica.cpp:712] Persisted action at 2
I0115 21:27:23.328734 31531 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0115 21:27:23.329071 31531 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 305006ns
I0115 21:27:23.329135 31531 leveldb.cpp:399] Deleting ~1 keys from leveldb took 35607ns
I0115 21:27:23.329248 31531 replica.cpp:712] Persisted action at 2
I0115 21:27:23.329367 31531 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0115 21:27:23.339383 31507 scheduler.cpp:154] Version: 0.27.0
I0115 21:27:23.340207 31530 scheduler.cpp:236] New master detected at master@172.17.0.4:52665
I0115 21:27:23.341495 31535 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:52665
I0115 21:27:23.343770 31538 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0115 21:27:23.344214 31531 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:48015
I0115 21:27:23.344393 31531 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0115 21:27:23.344460 31531 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0115 21:27:23.344779 31527 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0115 21:27:23.345146 31532 hierarchical.cpp:259] Added framework d806cbcd-c800-48cb-948d-ec1e15af6302-0000
I0115 21:27:23.345204 31526 master.hpp:1658] Sending heartbeat to d806cbcd-c800-48cb-948d-ec1e15af6302-0000
I0115 21:27:23.345213 31532 hierarchical.cpp:1329] No resources available to allocate!
I0115 21:27:23.345254 31532 hierarchical.cpp:1423] No inverse offers to send out!
I0115 21:27:23.345274 31532 hierarchical.cpp:1079] Performed allocation for 0 slaves in 104520ns
I0115 21:27:23.345928 31535 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:52665
I0115 21:27:23.346312 31535 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:52665
I0115 21:27:23.346946 31530 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0115 21:27:23.347122 31541 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:52665
I0115 21:27:23.348959 31526 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0115 21:27:23.349434 31538 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:48016
I0115 21:27:23.349553 31538 master.cpp:2717] Processing REQUEST call for framework d806cbcd-c800-48cb-948d-ec1e15af6302-0000 (default)
I0115 21:27:23.349714 31540 hierarchical.cpp:579] Received resource request from framework d806cbcd-c800-48cb-948d-ec1e15af6302-0000
I0115 21:27:23.350047 31541 master.cpp:1025] Master terminating
I0115 21:27:23.350213 31527 hierarchical.cpp:320] Removed framework d806cbcd-c800-48cb-948d-ec1e15af6302-0000
E0115 21:27:23.351241 31534 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (65 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0115 21:27:23.361248 31507 leveldb.cpp:174] Opened db in 2.930682ms
I0115 21:27:23.362064 31507 leveldb.cpp:181] Compacted db in 776203ns
I0115 21:27:23.362113 31507 leveldb.cpp:196] Created db iterator in 18434ns
I0115 21:27:23.362133 31507 leveldb.cpp:202] Seeked to beginning of db in 1832ns
I0115 21:27:23.362144 31507 leveldb.cpp:271] Iterated through 0 keys in the db in 222ns
I0115 21:27:23.362185 31507 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0115 21:27:23.362649 31531 recover.cpp:447] Starting replica recovery
I0115 21:27:23.363021 31531 recover.cpp:473] Replica is in EMPTY status
I0115 21:27:23.364255 31538 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13829)@172.17.0.4:52665
I0115 21:27:23.364830 31541 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0115 21:27:23.365386 31535 recover.cpp:564] Updating replica status to STARTING
I0115 21:27:23.366015 31541 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 445571ns
I0115 21:27:23.366153 31541 replica.cpp:320] Persisted replica status to STARTING
I0115 21:27:23.366334 31541 master.cpp:374] Master db133052-d307-48ed-ac50-7265566796c9 (4e6fbf10d387) started on 172.17.0.4:52665
I0115 21:27:23.366672 31527 recover.cpp:473] Replica is in STARTING status
I0115 21:27:23.366518 31541 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/j8VL5F/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="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/j8VL5F/master" --zk_session_timeout="10secs"
I0115 21:27:23.366855 31541 master.cpp:423] Master allowing unauthenticated frameworks to register
I0115 21:27:23.366866 31541 master.cpp:426] Master only allowing authenticated slaves to register
I0115 21:27:23.366873 31541 credentials.hpp:35] Loading credentials for authentication from '/tmp/j8VL5F/credentials'
I0115 21:27:23.367122 31541 master.cpp:466] Using default 'crammd5' authenticator
I0115 21:27:23.367277 31541 master.cpp:535] Using default 'basic' HTTP authenticator
I0115 21:27:23.367519 31541 master.cpp:569] Authorization enabled
I0115 21:27:23.367566 31528 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13830)@172.17.0.4:52665
I0115 21:27:23.367697 31531 whitelist_watcher.cpp:77] No whitelist given
I0115 21:27:23.367718 31528 hierarchical.cpp:147] Initialized hierarchical allocator process
I0115 21:27:23.367887 31526 recover.cpp:193] Received a recover response from a replica in STARTING status
I0115 21:27:23.368361 31539 recover.cpp:564] Updating replica status to VOTING
I0115 21:27:23.368877 31540 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 322970ns
I0115 21:27:23.368902 31540 replica.cpp:320] Persisted replica status to VOTING
I0115 21:27:23.368999 31529 recover.cpp:578] Successfully joined the Paxos group
I0115 21:27:23.369357 31529 recover.cpp:462] Recover process terminated
I0115 21:27:23.369609 31539 master.cpp:1710] The newly elected leader is master@172.17.0.4:52665 with id db133052-d307-48ed-ac50-7265566796c9
I0115 21:27:23.369642 31539 master.cpp:1723] Elected as the leading master!
I0115 21:27:23.369662 31539 master.cpp:1468] Recovering from registrar
I0115 21:27:23.369796 31540 registrar.cpp:307] Recovering registrar
I0115 21:27:23.370324 31537 log.cpp:659] Attempting to start the writer
I0115 21:27:23.371363 31538 replica.cpp:493] Replica received implicit promise request from (13832)@172.17.0.4:52665 with proposal 1
I0115 21:27:23.371675 31538 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 281036ns
I0115 21:27:23.371697 31538 replica.cpp:342] Persisted promised to 1
I0115 21:27:23.372237 31534 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0115 21:27:23.373425 31535 replica.cpp:388] Replica received explicit promise request from (13833)@172.17.0.4:52665 for position 0 with proposal 2
I0115 21:27:23.373729 31535 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 269247ns
I0115 21:27:23.373759 31535 replica.cpp:712] Persisted action at 0
I0115 21:27:23.374781 31532 replica.cpp:537] Replica received write request for position 0 from (13834)@172.17.0.4:52665
I0115 21:27:23.374845 31532 leveldb.cpp:436] Reading position from leveldb took 30693ns
I0115 21:27:23.375159 31532 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 266883ns
I0115 21:27:23.375183 31532 replica.cpp:712] Persisted action at 0
I0115 21:27:23.375746 31539 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0115 21:27:23.376083 31539 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 305860ns
I0115 21:27:23.376107 31539 replica.cpp:712] Persisted action at 0
I0115 21:27:23.376127 31539 replica.cpp:697] Replica learned NOP action at position 0
I0115 21:27:23.376804 31538 log.cpp:675] Writer started with ending position 0
I0115 21:27:23.378089 31535 leveldb.cpp:436] Reading position from leveldb took 34771ns
I0115 21:27:23.379143 31535 registrar.cpp:340] Successfully fetched the registry (0B) in 9.289984ms
I0115 21:27:23.379293 31535 registrar.cpp:439] Applied 1 operations in 38556ns; attempting to update the 'registry'
I0115 21:27:23.380162 31533 log.cpp:683] Attempting to append 170 bytes to the log
I0115 21:27:23.380314 31526 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0115 21:27:23.381167 31530 replica.cpp:537] Replica received write request for position 1 from (13835)@172.17.0.4:52665
I0115 21:27:23.381562 31530 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 345657ns
I0115 21:27:23.381598 31530 replica.cpp:712] Persisted action at 1
I0115 21:27:23.382459 31541 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0115 21:27:23.382913 31541 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 417814ns
I0115 21:27:23.382944 31541 replica.cpp:712] Persisted action at 1
I0115 21:27:23.382966 31541 replica.cpp:697] Replica learned APPEND action at position 1
I0115 21:27:23.384079 31531 registrar.cpp:484] Successfully updated the 'registry' in 4.707072ms
I0115 21:27:23.384244 31531 registrar.cpp:370] Successfully recovered registrar
I0115 21:27:23.384333 31534 log.cpp:702] Attempting to truncate the log to 1
I0115 21:27:23.384737 31538 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0115 21:27:23.384928 31539 hierarchical.cpp:165] Skipping recovery of hierarchical allocator: nothing to recover
I0115 21:27:23.384953 31535 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0115 21:27:23.385924 31537 replica.cpp:537] Replica received write request for position 2 from (13836)@172.17.0.4:52665
I0115 21:27:23.386333 31537 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 364042ns
I0115 21:27:23.386365 31537 replica.cpp:712] Persisted action at 2
I0115 21:27:23.387029 31533 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0115 21:27:23.387504 31533 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 433278ns
I0115 21:27:23.387570 31533 leveldb.cpp:399] Deleting ~1 keys from leveldb took 35877ns
I0115 21:27:23.387591 31533 replica.cpp:712] Persisted action at 2
I0115 21:27:23.387617 31533 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0115 21:27:23.395831 31507 scheduler.cpp:154] Version: 0.27.0
I0115 21:27:23.396633 31536 scheduler.cpp:236] New master detected at master@172.17.0.4:52665
I0115 21:27:23.397802 31538 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:52665
I0115 21:27:23.400193 31540 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0115 21:27:23.400768 31528 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:48017
I0115 21:27:23.401252 31528 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0115 21:27:23.401332 31528 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0115 21:27:23.401623 31528 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0115 21:27:23.402088 31538 hierarchical.cpp:259] Added framework db133052-d307-48ed-ac50-7265566796c9-0000
I0115 21:27:23.402160 31538 hierarchical.cpp:1329] No resources available to allocate!
I0115 21:27:23.402200 31538 hierarchical.cpp:1423] No inverse offers to send out!
I0115 21:27:23.402230 31538 hierarchical.cpp:1079] Performed allocation for 0 slaves in 119921ns
I0115 21:27:23.402261 31538 master.hpp:1658] Sending heartbeat to db133052-d307-48ed-ac50-7265566796c9-0000
I0115 21:27:23.403661 31539 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:52665
I0115 21:27:23.404364 31539 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:52665
I0115 21:27:23.405192 31539 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:52665
I0115 21:27:23.405380 31527 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0115 21:27:23.407523 31526 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0115 21:27:23.408007 31541 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:48018
I0115 21:27:23.408303 31541 master.cpp:2717] Processing REQUEST call for framework db133052-d307-48ed-ac50-7265566796c9-0000 (default)
I0115 21:27:23.408520 31532 hierarchical.cpp:579] Received resource request from framework db133052-d307-48ed-ac50-7265566796c9-0000
I0115 21:27:23.408874 31528 master.cpp:1025] Master terminating
I0115 21:27:23.409123 31531 hierarchical.cpp:320] Removed framework db133052-d307-48ed-ac50-7265566796c9-0000
E0115 21:27:23.410259 31531 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (59 ms)
[----------] 22 tests from ContentType/SchedulerTest (4242 ms total)
[----------] Global test environment tear-down
[==========] 930 tests from 123 test cases ran. (326131 ms total)
[ PASSED ] 929 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] MasterTest.MaxCompletedFrameworksFlag
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-1452891416-1892
Untagged: mesos-1452891416-1892:latest
Deleted: af99b06b60b459e0e0e7678545fec09750c0d7d008a5b48adcf7d96a0a5e2743
Deleted: 064705ae1f10c941a50cc81a8c0f92f1ca2915353d97e64c3c03c4df49191a39
Deleted: 6517afac0ff76aaefcb875b1c18083acb3a883e442602ec77343ea9757708b8c
Deleted: 1a4ae813a3017392ad5d3167a2889832b51c0e1f7398d1b8778d73bc767d136f
Deleted: 08896cdae9fd76d3a24854f60f2e1ade04667063e64e3abf29645145e0fb2083
Deleted: 2ee703ab305378b9d0a34fad914e22c7524757c68591e988bd9b3302456fee65
Deleted: b25e830881c6f4f255dbbba9f60bdace1c64e7cd6449715ccf9d17074811f2a3
Deleted: 14559f0ede62126c5f4a2c135eba25f36905d10a735a986b48ba193a59b09481
Deleted: 74f46eaf67dad83db0c0650c513700f5f27befecedb89dd8470cc6d55e8affeb
Deleted: bf74f853e8fac89f16fc01570b92f92b6f6a393c180215a57e6b77a9031f3b8a
Deleted: f9e486f67b5ea0edef231eb4a55099d076e720506ad6e7d18c8f8807363e77dd
Deleted: 7ff4aef84b24295c5f5aecd8587f9c864c3bfd629001fa5811184250548da474
Deleted: cd291e94bd48117c12127a70840b319c8b1bb2f72d50e470190edfe715b9dd6f
Deleted: e3bd2c3cd4b98286cbcdcff6e9aa99f1c7fa7f2b9221d60e01ef2ab2a6f492c9
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1497
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1497/changes>
Re: Build failed in Jenkins: Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1496
Posted by Benjamin Mahler <bm...@apache.org>.
Much appreciated Greg and sorry for the noise!
We have found what appears to be the issue, a fix will come.
On Fri, Jan 15, 2016 at 1:34 PM, Greg Mann <gr...@mesosphere.io> wrote:
> Didn't see a ticket for this failure, so I created one:
> https://issues.apache.org/jira/browse/MESOS-4409
>
> On Fri, Jan 15, 2016 at 1:27 PM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
> > See <
> >
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1496/changes
> > >
> >
> > Changes:
> >
> > [joris.van.remoortere] Stout: Added ref-qualifiers to Option::get().
> >
> > ------------------------------------------
> > [...truncated 156386 lines...]
> > I0115 21:27:23.287348 31538 status_update_manager.cpp:282] Closing status
> > update streams for framework c2783d6e-a412-48c8-93ec-91a6e3fac67e-0000
> > I0115 21:27:23.287497 31536 gc.cpp:54] Scheduling
> >
> '/tmp/ContentType_SchedulerTest_Message_1_7Vjlj8/slaves/c2783d6e-a412-48c8-93ec-91a6e3fac67e-S0/frameworks/c2783d6e-a412-48c8-93ec-91a6e3fac67e-0000'
> > for gc 6.99999667346074days in the future
> > I0115 21:27:23.287562 31538 status_update_manager.cpp:528] Cleaning up
> > status update stream for task de90e210-f7b8-4037-918f-c93723584af3 of
> > framework c2783d6e-a412-48c8-93ec-91a6e3fac67e-0000
> > [ OK ] ContentType/SchedulerTest.Message/1 (112 ms)
> > [ RUN ] ContentType/SchedulerTest.Request/0
> > I0115 21:27:23.297211 31507 leveldb.cpp:174] Opened db in 3.350748ms
> > I0115 21:27:23.298276 31507 leveldb.cpp:181] Compacted db in 1.015243ms
> > I0115 21:27:23.298364 31507 leveldb.cpp:196] Created db iterator in
> 33917ns
> > I0115 21:27:23.298380 31507 leveldb.cpp:202] Seeked to beginning of db in
> > 1515ns
> > I0115 21:27:23.298389 31507 leveldb.cpp:271] Iterated through 0 keys in
> > the db in 177ns
> > I0115 21:27:23.298437 31507 replica.cpp:779] Replica recovered with log
> > positions 0 -> 0 with 1 holes and 0 unlearned
> > I0115 21:27:23.299082 31535 recover.cpp:447] Starting replica recovery
> > I0115 21:27:23.299552 31535 recover.cpp:473] Replica is in EMPTY status
> > I0115 21:27:23.301113 31530 replica.cpp:673] Replica in EMPTY status
> > received a broadcasted recover request from (13814)@172.17.0.4:52665
> > I0115 21:27:23.301512 31526 recover.cpp:193] Received a recover response
> > from a replica in EMPTY status
> > I0115 21:27:23.302068 31540 master.cpp:374] Master
> > d806cbcd-c800-48cb-948d-ec1e15af6302 (4e6fbf10d387) started on
> > 172.17.0.4:52665
> > I0115 21:27:23.302238 31536 recover.cpp:564] Updating replica status to
> > STARTING
> > I0115 21:27:23.302094 31540 master.cpp:376] Flags at startup: --acls=""
> > --allocation_interval="1secs" --allocator="HierarchicalDRF"
> > --authenticate="false" --authenticate_http="true"
> > --authenticate_slaves="true" --authenticators="crammd5"
> > --authorizers="local" --credentials="/tmp/s5Iqr2/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="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/s5Iqr2/master" --zk_session_timeout="10secs"
> > I0115 21:27:23.302583 31540 master.cpp:423] Master allowing
> > unauthenticated frameworks to register
> > I0115 21:27:23.302600 31540 master.cpp:426] Master only allowing
> > authenticated slaves to register
> > I0115 21:27:23.302613 31540 credentials.hpp:35] Loading credentials for
> > authentication from '/tmp/s5Iqr2/credentials'
> > I0115 21:27:23.303025 31530 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 646308ns
> > I0115 21:27:23.303056 31540 master.cpp:466] Using default 'crammd5'
> > authenticator
> > I0115 21:27:23.303107 31530 replica.cpp:320] Persisted replica status to
> > STARTING
> > I0115 21:27:23.303270 31540 master.cpp:535] Using default 'basic' HTTP
> > authenticator
> > I0115 21:27:23.303498 31526 recover.cpp:473] Replica is in STARTING
> status
> > I0115 21:27:23.303550 31540 master.cpp:569] Authorization enabled
> > I0115 21:27:23.303792 31531 hierarchical.cpp:147] Initialized
> hierarchical
> > allocator process
> > I0115 21:27:23.303829 31536 whitelist_watcher.cpp:77] No whitelist given
> > I0115 21:27:23.305100 31534 replica.cpp:673] Replica in STARTING status
> > received a broadcasted recover request from (13816)@172.17.0.4:52665
> > I0115 21:27:23.305578 31526 recover.cpp:193] Received a recover response
> > from a replica in STARTING status
> > I0115 21:27:23.306113 31538 recover.cpp:564] Updating replica status to
> > VOTING
> > I0115 21:27:23.306778 31527 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 426070ns
> > I0115 21:27:23.306815 31527 replica.cpp:320] Persisted replica status to
> > VOTING
> > I0115 21:27:23.306962 31526 recover.cpp:578] Successfully joined the
> Paxos
> > group
> > I0115 21:27:23.307116 31532 master.cpp:1710] The newly elected leader is
> > master@172.17.0.4:52665 with id d806cbcd-c800-48cb-948d-ec1e15af6302
> > I0115 21:27:23.307159 31532 master.cpp:1723] Elected as the leading
> master!
> > I0115 21:27:23.307188 31532 master.cpp:1468] Recovering from registrar
> > I0115 21:27:23.307220 31526 recover.cpp:462] Recover process terminated
> > I0115 21:27:23.307652 31541 registrar.cpp:307] Recovering registrar
> > I0115 21:27:23.308292 31537 log.cpp:659] Attempting to start the writer
> > I0115 21:27:23.309715 31527 replica.cpp:493] Replica received implicit
> > promise request from (13817)@172.17.0.4:52665 with proposal 1
> > I0115 21:27:23.310103 31527 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 353807ns
> > I0115 21:27:23.310132 31527 replica.cpp:342] Persisted promised to 1
> > I0115 21:27:23.310890 31540 coordinator.cpp:238] Coordinator attempting
> to
> > fill missing positions
> > I0115 21:27:23.312296 31534 replica.cpp:388] Replica received explicit
> > promise request from (13818)@172.17.0.4:52665 for position 0 with
> > proposal 2
> > I0115 21:27:23.313444 31534 leveldb.cpp:341] Persisting action (8 bytes)
> > to leveldb took 1.090827ms
> > I0115 21:27:23.313489 31534 replica.cpp:712] Persisted action at 0
> > I0115 21:27:23.314939 31529 replica.cpp:537] Replica received write
> > request for position 0 from (13819)@172.17.0.4:52665
> > I0115 21:27:23.315101 31529 leveldb.cpp:436] Reading position from
> leveldb
> > took 114197ns
> > I0115 21:27:23.315618 31529 leveldb.cpp:341] Persisting action (14 bytes)
> > to leveldb took 422964ns
> > I0115 21:27:23.315670 31529 replica.cpp:712] Persisted action at 0
> > I0115 21:27:23.316685 31536 replica.cpp:691] Replica received learned
> > notice for position 0 from @0.0.0.0:0
> > I0115 21:27:23.317139 31536 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 419412ns
> > I0115 21:27:23.317173 31536 replica.cpp:712] Persisted action at 0
> > I0115 21:27:23.317201 31536 replica.cpp:697] Replica learned NOP action
> at
> > position 0
> > I0115 21:27:23.318155 31536 log.cpp:675] Writer started with ending
> > position 0
> > I0115 21:27:23.319429 31532 leveldb.cpp:436] Reading position from
> leveldb
> > took 54608ns
> > I0115 21:27:23.320606 31535 registrar.cpp:340] Successfully fetched the
> > registry (0B) in 12896us
> > I0115 21:27:23.320775 31535 registrar.cpp:439] Applied 1 operations in
> > 50993ns; attempting to update the 'registry'
> > I0115 21:27:23.321660 31530 log.cpp:683] Attempting to append 170 bytes
> to
> > the log
> > I0115 21:27:23.322019 31538 coordinator.cpp:348] Coordinator attempting
> to
> > write APPEND action at position 1
> > I0115 21:27:23.323017 31539 replica.cpp:537] Replica received write
> > request for position 1 from (13820)@172.17.0.4:52665
> > I0115 21:27:23.323528 31539 leveldb.cpp:341] Persisting action (189
> bytes)
> > to leveldb took 463us
> > I0115 21:27:23.323560 31539 replica.cpp:712] Persisted action at 1
> > I0115 21:27:23.324455 31539 replica.cpp:691] Replica received learned
> > notice for position 1 from @0.0.0.0:0
> > I0115 21:27:23.324779 31539 leveldb.cpp:341] Persisting action (191
> bytes)
> > to leveldb took 292823ns
> > I0115 21:27:23.324803 31539 replica.cpp:712] Persisted action at 1
> > I0115 21:27:23.324826 31539 replica.cpp:697] Replica learned APPEND
> action
> > at position 1
> > I0115 21:27:23.325934 31540 registrar.cpp:484] Successfully updated the
> > 'registry' in 5.081856ms
> > I0115 21:27:23.326094 31540 registrar.cpp:370] Successfully recovered
> > registrar
> > I0115 21:27:23.326228 31535 log.cpp:702] Attempting to truncate the log
> to
> > 1
> > I0115 21:27:23.326653 31537 coordinator.cpp:348] Coordinator attempting
> to
> > write TRUNCATE action at position 2
> > I0115 21:27:23.326675 31539 master.cpp:1520] Recovered 0 slaves from the
> > Registry (131B) ; allowing 10mins for slaves to re-register
> > I0115 21:27:23.326717 31533 hierarchical.cpp:165] Skipping recovery of
> > hierarchical allocator: nothing to recover
> > I0115 21:27:23.327630 31538 replica.cpp:537] Replica received write
> > request for position 2 from (13821)@172.17.0.4:52665
> > I0115 21:27:23.328061 31538 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 393096ns
> > I0115 21:27:23.328089 31538 replica.cpp:712] Persisted action at 2
> > I0115 21:27:23.328734 31531 replica.cpp:691] Replica received learned
> > notice for position 2 from @0.0.0.0:0
> > I0115 21:27:23.329071 31531 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 305006ns
> > I0115 21:27:23.329135 31531 leveldb.cpp:399] Deleting ~1 keys from
> leveldb
> > took 35607ns
> > I0115 21:27:23.329248 31531 replica.cpp:712] Persisted action at 2
> > I0115 21:27:23.329367 31531 replica.cpp:697] Replica learned TRUNCATE
> > action at position 2
> > I0115 21:27:23.339383 31507 scheduler.cpp:154] Version: 0.27.0
> > I0115 21:27:23.340207 31530 scheduler.cpp:236] New master detected at
> > master@172.17.0.4:52665
> > I0115 21:27:23.341495 31535 scheduler.cpp:298] Sending SUBSCRIBE call to
> > master@172.17.0.4:52665
> > I0115 21:27:23.343770 31538 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0115 21:27:23.344214 31531 http.cpp:504] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.4:48015
> > I0115 21:27:23.344393 31531 master.cpp:1972] Received subscription
> request
> > for HTTP framework 'default'
> > I0115 21:27:23.344460 31531 master.cpp:1749] Authorizing framework
> > principal 'test-principal' to receive offers for role '*'
> > I0115 21:27:23.344779 31527 master.cpp:2063] Subscribing framework
> > 'default' with checkpointing disabled and capabilities [ ]
> > I0115 21:27:23.345146 31532 hierarchical.cpp:259] Added framework
> > d806cbcd-c800-48cb-948d-ec1e15af6302-0000
> > I0115 21:27:23.345204 31526 master.hpp:1658] Sending heartbeat to
> > d806cbcd-c800-48cb-948d-ec1e15af6302-0000
> > I0115 21:27:23.345213 31532 hierarchical.cpp:1329] No resources available
> > to allocate!
> > I0115 21:27:23.345254 31532 hierarchical.cpp:1423] No inverse offers to
> > send out!
> > I0115 21:27:23.345274 31532 hierarchical.cpp:1079] Performed allocation
> > for 0 slaves in 104520ns
> > I0115 21:27:23.345928 31535 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> > received from master@172.17.0.4:52665
> > I0115 21:27:23.346312 31535 scheduler.cpp:457] Enqueuing event HEARTBEAT
> > received from master@172.17.0.4:52665
> > I0115 21:27:23.346946 31530 master_maintenance_tests.cpp:177] Ignoring
> > HEARTBEAT event
> > I0115 21:27:23.347122 31541 scheduler.cpp:298] Sending REQUEST call to
> > master@172.17.0.4:52665
> > I0115 21:27:23.348959 31526 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0115 21:27:23.349434 31538 http.cpp:504] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.4:48016
> > I0115 21:27:23.349553 31538 master.cpp:2717] Processing REQUEST call for
> > framework d806cbcd-c800-48cb-948d-ec1e15af6302-0000 (default)
> > I0115 21:27:23.349714 31540 hierarchical.cpp:579] Received resource
> > request from framework d806cbcd-c800-48cb-948d-ec1e15af6302-0000
> > I0115 21:27:23.350047 31541 master.cpp:1025] Master terminating
> > I0115 21:27:23.350213 31527 hierarchical.cpp:320] Removed framework
> > d806cbcd-c800-48cb-948d-ec1e15af6302-0000
> > E0115 21:27:23.351241 31534 scheduler.cpp:431] End-Of-File received from
> > master. The master closed the event stream
> > [ OK ] ContentType/SchedulerTest.Request/0 (65 ms)
> > [ RUN ] ContentType/SchedulerTest.Request/1
> > I0115 21:27:23.361248 31507 leveldb.cpp:174] Opened db in 2.930682ms
> > I0115 21:27:23.362064 31507 leveldb.cpp:181] Compacted db in 776203ns
> > I0115 21:27:23.362113 31507 leveldb.cpp:196] Created db iterator in
> 18434ns
> > I0115 21:27:23.362133 31507 leveldb.cpp:202] Seeked to beginning of db in
> > 1832ns
> > I0115 21:27:23.362144 31507 leveldb.cpp:271] Iterated through 0 keys in
> > the db in 222ns
> > I0115 21:27:23.362185 31507 replica.cpp:779] Replica recovered with log
> > positions 0 -> 0 with 1 holes and 0 unlearned
> > I0115 21:27:23.362649 31531 recover.cpp:447] Starting replica recovery
> > I0115 21:27:23.363021 31531 recover.cpp:473] Replica is in EMPTY status
> > I0115 21:27:23.364255 31538 replica.cpp:673] Replica in EMPTY status
> > received a broadcasted recover request from (13829)@172.17.0.4:52665
> > I0115 21:27:23.364830 31541 recover.cpp:193] Received a recover response
> > from a replica in EMPTY status
> > I0115 21:27:23.365386 31535 recover.cpp:564] Updating replica status to
> > STARTING
> > I0115 21:27:23.366015 31541 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 445571ns
> > I0115 21:27:23.366153 31541 replica.cpp:320] Persisted replica status to
> > STARTING
> > I0115 21:27:23.366334 31541 master.cpp:374] Master
> > db133052-d307-48ed-ac50-7265566796c9 (4e6fbf10d387) started on
> > 172.17.0.4:52665
> > I0115 21:27:23.366672 31527 recover.cpp:473] Replica is in STARTING
> status
> > I0115 21:27:23.366518 31541 master.cpp:376] Flags at startup: --acls=""
> > --allocation_interval="1secs" --allocator="HierarchicalDRF"
> > --authenticate="false" --authenticate_http="true"
> > --authenticate_slaves="true" --authenticators="crammd5"
> > --authorizers="local" --credentials="/tmp/j8VL5F/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="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/j8VL5F/master" --zk_session_timeout="10secs"
> > I0115 21:27:23.366855 31541 master.cpp:423] Master allowing
> > unauthenticated frameworks to register
> > I0115 21:27:23.366866 31541 master.cpp:426] Master only allowing
> > authenticated slaves to register
> > I0115 21:27:23.366873 31541 credentials.hpp:35] Loading credentials for
> > authentication from '/tmp/j8VL5F/credentials'
> > I0115 21:27:23.367122 31541 master.cpp:466] Using default 'crammd5'
> > authenticator
> > I0115 21:27:23.367277 31541 master.cpp:535] Using default 'basic' HTTP
> > authenticator
> > I0115 21:27:23.367519 31541 master.cpp:569] Authorization enabled
> > I0115 21:27:23.367566 31528 replica.cpp:673] Replica in STARTING status
> > received a broadcasted recover request from (13830)@172.17.0.4:52665
> > I0115 21:27:23.367697 31531 whitelist_watcher.cpp:77] No whitelist given
> > I0115 21:27:23.367718 31528 hierarchical.cpp:147] Initialized
> hierarchical
> > allocator process
> > I0115 21:27:23.367887 31526 recover.cpp:193] Received a recover response
> > from a replica in STARTING status
> > I0115 21:27:23.368361 31539 recover.cpp:564] Updating replica status to
> > VOTING
> > I0115 21:27:23.368877 31540 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 322970ns
> > I0115 21:27:23.368902 31540 replica.cpp:320] Persisted replica status to
> > VOTING
> > I0115 21:27:23.368999 31529 recover.cpp:578] Successfully joined the
> Paxos
> > group
> > I0115 21:27:23.369357 31529 recover.cpp:462] Recover process terminated
> > I0115 21:27:23.369609 31539 master.cpp:1710] The newly elected leader is
> > master@172.17.0.4:52665 with id db133052-d307-48ed-ac50-7265566796c9
> > I0115 21:27:23.369642 31539 master.cpp:1723] Elected as the leading
> master!
> > I0115 21:27:23.369662 31539 master.cpp:1468] Recovering from registrar
> > I0115 21:27:23.369796 31540 registrar.cpp:307] Recovering registrar
> > I0115 21:27:23.370324 31537 log.cpp:659] Attempting to start the writer
> > I0115 21:27:23.371363 31538 replica.cpp:493] Replica received implicit
> > promise request from (13832)@172.17.0.4:52665 with proposal 1
> > I0115 21:27:23.371675 31538 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 281036ns
> > I0115 21:27:23.371697 31538 replica.cpp:342] Persisted promised to 1
> > I0115 21:27:23.372237 31534 coordinator.cpp:238] Coordinator attempting
> to
> > fill missing positions
> > I0115 21:27:23.373425 31535 replica.cpp:388] Replica received explicit
> > promise request from (13833)@172.17.0.4:52665 for position 0 with
> > proposal 2
> > I0115 21:27:23.373729 31535 leveldb.cpp:341] Persisting action (8 bytes)
> > to leveldb took 269247ns
> > I0115 21:27:23.373759 31535 replica.cpp:712] Persisted action at 0
> > I0115 21:27:23.374781 31532 replica.cpp:537] Replica received write
> > request for position 0 from (13834)@172.17.0.4:52665
> > I0115 21:27:23.374845 31532 leveldb.cpp:436] Reading position from
> leveldb
> > took 30693ns
> > I0115 21:27:23.375159 31532 leveldb.cpp:341] Persisting action (14 bytes)
> > to leveldb took 266883ns
> > I0115 21:27:23.375183 31532 replica.cpp:712] Persisted action at 0
> > I0115 21:27:23.375746 31539 replica.cpp:691] Replica received learned
> > notice for position 0 from @0.0.0.0:0
> > I0115 21:27:23.376083 31539 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 305860ns
> > I0115 21:27:23.376107 31539 replica.cpp:712] Persisted action at 0
> > I0115 21:27:23.376127 31539 replica.cpp:697] Replica learned NOP action
> at
> > position 0
> > I0115 21:27:23.376804 31538 log.cpp:675] Writer started with ending
> > position 0
> > I0115 21:27:23.378089 31535 leveldb.cpp:436] Reading position from
> leveldb
> > took 34771ns
> > I0115 21:27:23.379143 31535 registrar.cpp:340] Successfully fetched the
> > registry (0B) in 9.289984ms
> > I0115 21:27:23.379293 31535 registrar.cpp:439] Applied 1 operations in
> > 38556ns; attempting to update the 'registry'
> > I0115 21:27:23.380162 31533 log.cpp:683] Attempting to append 170 bytes
> to
> > the log
> > I0115 21:27:23.380314 31526 coordinator.cpp:348] Coordinator attempting
> to
> > write APPEND action at position 1
> > I0115 21:27:23.381167 31530 replica.cpp:537] Replica received write
> > request for position 1 from (13835)@172.17.0.4:52665
> > I0115 21:27:23.381562 31530 leveldb.cpp:341] Persisting action (189
> bytes)
> > to leveldb took 345657ns
> > I0115 21:27:23.381598 31530 replica.cpp:712] Persisted action at 1
> > I0115 21:27:23.382459 31541 replica.cpp:691] Replica received learned
> > notice for position 1 from @0.0.0.0:0
> > I0115 21:27:23.382913 31541 leveldb.cpp:341] Persisting action (191
> bytes)
> > to leveldb took 417814ns
> > I0115 21:27:23.382944 31541 replica.cpp:712] Persisted action at 1
> > I0115 21:27:23.382966 31541 replica.cpp:697] Replica learned APPEND
> action
> > at position 1
> > I0115 21:27:23.384079 31531 registrar.cpp:484] Successfully updated the
> > 'registry' in 4.707072ms
> > I0115 21:27:23.384244 31531 registrar.cpp:370] Successfully recovered
> > registrar
> > I0115 21:27:23.384333 31534 log.cpp:702] Attempting to truncate the log
> to
> > 1
> > I0115 21:27:23.384737 31538 coordinator.cpp:348] Coordinator attempting
> to
> > write TRUNCATE action at position 2
> > I0115 21:27:23.384928 31539 hierarchical.cpp:165] Skipping recovery of
> > hierarchical allocator: nothing to recover
> > I0115 21:27:23.384953 31535 master.cpp:1520] Recovered 0 slaves from the
> > Registry (131B) ; allowing 10mins for slaves to re-register
> > I0115 21:27:23.385924 31537 replica.cpp:537] Replica received write
> > request for position 2 from (13836)@172.17.0.4:52665
> > I0115 21:27:23.386333 31537 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 364042ns
> > I0115 21:27:23.386365 31537 replica.cpp:712] Persisted action at 2
> > I0115 21:27:23.387029 31533 replica.cpp:691] Replica received learned
> > notice for position 2 from @0.0.0.0:0
> > I0115 21:27:23.387504 31533 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 433278ns
> > I0115 21:27:23.387570 31533 leveldb.cpp:399] Deleting ~1 keys from
> leveldb
> > took 35877ns
> > I0115 21:27:23.387591 31533 replica.cpp:712] Persisted action at 2
> > I0115 21:27:23.387617 31533 replica.cpp:697] Replica learned TRUNCATE
> > action at position 2
> > I0115 21:27:23.395831 31507 scheduler.cpp:154] Version: 0.27.0
> > I0115 21:27:23.396633 31536 scheduler.cpp:236] New master detected at
> > master@172.17.0.4:52665
> > I0115 21:27:23.397802 31538 scheduler.cpp:298] Sending SUBSCRIBE call to
> > master@172.17.0.4:52665
> > I0115 21:27:23.400193 31540 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0115 21:27:23.400768 31528 http.cpp:504] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.4:48017
> > I0115 21:27:23.401252 31528 master.cpp:1972] Received subscription
> request
> > for HTTP framework 'default'
> > I0115 21:27:23.401332 31528 master.cpp:1749] Authorizing framework
> > principal 'test-principal' to receive offers for role '*'
> > I0115 21:27:23.401623 31528 master.cpp:2063] Subscribing framework
> > 'default' with checkpointing disabled and capabilities [ ]
> > I0115 21:27:23.402088 31538 hierarchical.cpp:259] Added framework
> > db133052-d307-48ed-ac50-7265566796c9-0000
> > I0115 21:27:23.402160 31538 hierarchical.cpp:1329] No resources available
> > to allocate!
> > I0115 21:27:23.402200 31538 hierarchical.cpp:1423] No inverse offers to
> > send out!
> > I0115 21:27:23.402230 31538 hierarchical.cpp:1079] Performed allocation
> > for 0 slaves in 119921ns
> > I0115 21:27:23.402261 31538 master.hpp:1658] Sending heartbeat to
> > db133052-d307-48ed-ac50-7265566796c9-0000
> > I0115 21:27:23.403661 31539 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> > received from master@172.17.0.4:52665
> > I0115 21:27:23.404364 31539 scheduler.cpp:457] Enqueuing event HEARTBEAT
> > received from master@172.17.0.4:52665
> > I0115 21:27:23.405192 31539 scheduler.cpp:298] Sending REQUEST call to
> > master@172.17.0.4:52665
> > I0115 21:27:23.405380 31527 master_maintenance_tests.cpp:177] Ignoring
> > HEARTBEAT event
> > I0115 21:27:23.407523 31526 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0115 21:27:23.408007 31541 http.cpp:504] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.4:48018
> > I0115 21:27:23.408303 31541 master.cpp:2717] Processing REQUEST call for
> > framework db133052-d307-48ed-ac50-7265566796c9-0000 (default)
> > I0115 21:27:23.408520 31532 hierarchical.cpp:579] Received resource
> > request from framework db133052-d307-48ed-ac50-7265566796c9-0000
> > I0115 21:27:23.408874 31528 master.cpp:1025] Master terminating
> > I0115 21:27:23.409123 31531 hierarchical.cpp:320] Removed framework
> > db133052-d307-48ed-ac50-7265566796c9-0000
> > E0115 21:27:23.410259 31531 scheduler.cpp:431] End-Of-File received from
> > master. The master closed the event stream
> > [ OK ] ContentType/SchedulerTest.Request/1 (59 ms)
> > [----------] 22 tests from ContentType/SchedulerTest (4242 ms total)
> >
> > [----------] Global test environment tear-down
> > [==========] 930 tests from 123 test cases ran. (326131 ms total)
> > [ PASSED ] 929 tests.
> > [ FAILED ] 1 test, listed below:
> > [ FAILED ] MasterTest.MaxCompletedFrameworksFlag
> >
> > 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-1452891416-1892
> > Untagged: mesos-1452891416-1892:latest
> > Deleted: af99b06b60b459e0e0e7678545fec09750c0d7d008a5b48adcf7d96a0a5e2743
> > Deleted: 064705ae1f10c941a50cc81a8c0f92f1ca2915353d97e64c3c03c4df49191a39
> > Deleted: 6517afac0ff76aaefcb875b1c18083acb3a883e442602ec77343ea9757708b8c
> > Deleted: 1a4ae813a3017392ad5d3167a2889832b51c0e1f7398d1b8778d73bc767d136f
> > Deleted: 08896cdae9fd76d3a24854f60f2e1ade04667063e64e3abf29645145e0fb2083
> > Deleted: 2ee703ab305378b9d0a34fad914e22c7524757c68591e988bd9b3302456fee65
> > Deleted: b25e830881c6f4f255dbbba9f60bdace1c64e7cd6449715ccf9d17074811f2a3
> > Deleted: 14559f0ede62126c5f4a2c135eba25f36905d10a735a986b48ba193a59b09481
> > Deleted: 74f46eaf67dad83db0c0650c513700f5f27befecedb89dd8470cc6d55e8affeb
> > Deleted: bf74f853e8fac89f16fc01570b92f92b6f6a393c180215a57e6b77a9031f3b8a
> > Deleted: f9e486f67b5ea0edef231eb4a55099d076e720506ad6e7d18c8f8807363e77dd
> > Deleted: 7ff4aef84b24295c5f5aecd8587f9c864c3bfd629001fa5811184250548da474
> > Deleted: cd291e94bd48117c12127a70840b319c8b1bb2f72d50e470190edfe715b9dd6f
> > Deleted: e3bd2c3cd4b98286cbcdcff6e9aa99f1c7fa7f2b9221d60e01ef2ab2a6f492c9
> > Build step 'Execute shell' marked build as failure
> >
>
Re: Build failed in Jenkins: Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #1496
Posted by Greg Mann <gr...@mesosphere.io>.
Didn't see a ticket for this failure, so I created one:
https://issues.apache.org/jira/browse/MESOS-4409
On Fri, Jan 15, 2016 at 1:27 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1496/changes
> >
>
> Changes:
>
> [joris.van.remoortere] Stout: Added ref-qualifiers to Option::get().
>
> ------------------------------------------
> [...truncated 156386 lines...]
> I0115 21:27:23.287348 31538 status_update_manager.cpp:282] Closing status
> update streams for framework c2783d6e-a412-48c8-93ec-91a6e3fac67e-0000
> I0115 21:27:23.287497 31536 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_7Vjlj8/slaves/c2783d6e-a412-48c8-93ec-91a6e3fac67e-S0/frameworks/c2783d6e-a412-48c8-93ec-91a6e3fac67e-0000'
> for gc 6.99999667346074days in the future
> I0115 21:27:23.287562 31538 status_update_manager.cpp:528] Cleaning up
> status update stream for task de90e210-f7b8-4037-918f-c93723584af3 of
> framework c2783d6e-a412-48c8-93ec-91a6e3fac67e-0000
> [ OK ] ContentType/SchedulerTest.Message/1 (112 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> I0115 21:27:23.297211 31507 leveldb.cpp:174] Opened db in 3.350748ms
> I0115 21:27:23.298276 31507 leveldb.cpp:181] Compacted db in 1.015243ms
> I0115 21:27:23.298364 31507 leveldb.cpp:196] Created db iterator in 33917ns
> I0115 21:27:23.298380 31507 leveldb.cpp:202] Seeked to beginning of db in
> 1515ns
> I0115 21:27:23.298389 31507 leveldb.cpp:271] Iterated through 0 keys in
> the db in 177ns
> I0115 21:27:23.298437 31507 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0115 21:27:23.299082 31535 recover.cpp:447] Starting replica recovery
> I0115 21:27:23.299552 31535 recover.cpp:473] Replica is in EMPTY status
> I0115 21:27:23.301113 31530 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13814)@172.17.0.4:52665
> I0115 21:27:23.301512 31526 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0115 21:27:23.302068 31540 master.cpp:374] Master
> d806cbcd-c800-48cb-948d-ec1e15af6302 (4e6fbf10d387) started on
> 172.17.0.4:52665
> I0115 21:27:23.302238 31536 recover.cpp:564] Updating replica status to
> STARTING
> I0115 21:27:23.302094 31540 master.cpp:376] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/s5Iqr2/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="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/s5Iqr2/master" --zk_session_timeout="10secs"
> I0115 21:27:23.302583 31540 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0115 21:27:23.302600 31540 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0115 21:27:23.302613 31540 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/s5Iqr2/credentials'
> I0115 21:27:23.303025 31530 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 646308ns
> I0115 21:27:23.303056 31540 master.cpp:466] Using default 'crammd5'
> authenticator
> I0115 21:27:23.303107 31530 replica.cpp:320] Persisted replica status to
> STARTING
> I0115 21:27:23.303270 31540 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0115 21:27:23.303498 31526 recover.cpp:473] Replica is in STARTING status
> I0115 21:27:23.303550 31540 master.cpp:569] Authorization enabled
> I0115 21:27:23.303792 31531 hierarchical.cpp:147] Initialized hierarchical
> allocator process
> I0115 21:27:23.303829 31536 whitelist_watcher.cpp:77] No whitelist given
> I0115 21:27:23.305100 31534 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13816)@172.17.0.4:52665
> I0115 21:27:23.305578 31526 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0115 21:27:23.306113 31538 recover.cpp:564] Updating replica status to
> VOTING
> I0115 21:27:23.306778 31527 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 426070ns
> I0115 21:27:23.306815 31527 replica.cpp:320] Persisted replica status to
> VOTING
> I0115 21:27:23.306962 31526 recover.cpp:578] Successfully joined the Paxos
> group
> I0115 21:27:23.307116 31532 master.cpp:1710] The newly elected leader is
> master@172.17.0.4:52665 with id d806cbcd-c800-48cb-948d-ec1e15af6302
> I0115 21:27:23.307159 31532 master.cpp:1723] Elected as the leading master!
> I0115 21:27:23.307188 31532 master.cpp:1468] Recovering from registrar
> I0115 21:27:23.307220 31526 recover.cpp:462] Recover process terminated
> I0115 21:27:23.307652 31541 registrar.cpp:307] Recovering registrar
> I0115 21:27:23.308292 31537 log.cpp:659] Attempting to start the writer
> I0115 21:27:23.309715 31527 replica.cpp:493] Replica received implicit
> promise request from (13817)@172.17.0.4:52665 with proposal 1
> I0115 21:27:23.310103 31527 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 353807ns
> I0115 21:27:23.310132 31527 replica.cpp:342] Persisted promised to 1
> I0115 21:27:23.310890 31540 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0115 21:27:23.312296 31534 replica.cpp:388] Replica received explicit
> promise request from (13818)@172.17.0.4:52665 for position 0 with
> proposal 2
> I0115 21:27:23.313444 31534 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 1.090827ms
> I0115 21:27:23.313489 31534 replica.cpp:712] Persisted action at 0
> I0115 21:27:23.314939 31529 replica.cpp:537] Replica received write
> request for position 0 from (13819)@172.17.0.4:52665
> I0115 21:27:23.315101 31529 leveldb.cpp:436] Reading position from leveldb
> took 114197ns
> I0115 21:27:23.315618 31529 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 422964ns
> I0115 21:27:23.315670 31529 replica.cpp:712] Persisted action at 0
> I0115 21:27:23.316685 31536 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0115 21:27:23.317139 31536 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 419412ns
> I0115 21:27:23.317173 31536 replica.cpp:712] Persisted action at 0
> I0115 21:27:23.317201 31536 replica.cpp:697] Replica learned NOP action at
> position 0
> I0115 21:27:23.318155 31536 log.cpp:675] Writer started with ending
> position 0
> I0115 21:27:23.319429 31532 leveldb.cpp:436] Reading position from leveldb
> took 54608ns
> I0115 21:27:23.320606 31535 registrar.cpp:340] Successfully fetched the
> registry (0B) in 12896us
> I0115 21:27:23.320775 31535 registrar.cpp:439] Applied 1 operations in
> 50993ns; attempting to update the 'registry'
> I0115 21:27:23.321660 31530 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0115 21:27:23.322019 31538 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0115 21:27:23.323017 31539 replica.cpp:537] Replica received write
> request for position 1 from (13820)@172.17.0.4:52665
> I0115 21:27:23.323528 31539 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 463us
> I0115 21:27:23.323560 31539 replica.cpp:712] Persisted action at 1
> I0115 21:27:23.324455 31539 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0115 21:27:23.324779 31539 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 292823ns
> I0115 21:27:23.324803 31539 replica.cpp:712] Persisted action at 1
> I0115 21:27:23.324826 31539 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0115 21:27:23.325934 31540 registrar.cpp:484] Successfully updated the
> 'registry' in 5.081856ms
> I0115 21:27:23.326094 31540 registrar.cpp:370] Successfully recovered
> registrar
> I0115 21:27:23.326228 31535 log.cpp:702] Attempting to truncate the log to
> 1
> I0115 21:27:23.326653 31537 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0115 21:27:23.326675 31539 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0115 21:27:23.326717 31533 hierarchical.cpp:165] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0115 21:27:23.327630 31538 replica.cpp:537] Replica received write
> request for position 2 from (13821)@172.17.0.4:52665
> I0115 21:27:23.328061 31538 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 393096ns
> I0115 21:27:23.328089 31538 replica.cpp:712] Persisted action at 2
> I0115 21:27:23.328734 31531 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0115 21:27:23.329071 31531 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 305006ns
> I0115 21:27:23.329135 31531 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 35607ns
> I0115 21:27:23.329248 31531 replica.cpp:712] Persisted action at 2
> I0115 21:27:23.329367 31531 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0115 21:27:23.339383 31507 scheduler.cpp:154] Version: 0.27.0
> I0115 21:27:23.340207 31530 scheduler.cpp:236] New master detected at
> master@172.17.0.4:52665
> I0115 21:27:23.341495 31535 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.4:52665
> I0115 21:27:23.343770 31538 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0115 21:27:23.344214 31531 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:48015
> I0115 21:27:23.344393 31531 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0115 21:27:23.344460 31531 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0115 21:27:23.344779 31527 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0115 21:27:23.345146 31532 hierarchical.cpp:259] Added framework
> d806cbcd-c800-48cb-948d-ec1e15af6302-0000
> I0115 21:27:23.345204 31526 master.hpp:1658] Sending heartbeat to
> d806cbcd-c800-48cb-948d-ec1e15af6302-0000
> I0115 21:27:23.345213 31532 hierarchical.cpp:1329] No resources available
> to allocate!
> I0115 21:27:23.345254 31532 hierarchical.cpp:1423] No inverse offers to
> send out!
> I0115 21:27:23.345274 31532 hierarchical.cpp:1079] Performed allocation
> for 0 slaves in 104520ns
> I0115 21:27:23.345928 31535 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.4:52665
> I0115 21:27:23.346312 31535 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.4:52665
> I0115 21:27:23.346946 31530 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0115 21:27:23.347122 31541 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.4:52665
> I0115 21:27:23.348959 31526 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0115 21:27:23.349434 31538 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:48016
> I0115 21:27:23.349553 31538 master.cpp:2717] Processing REQUEST call for
> framework d806cbcd-c800-48cb-948d-ec1e15af6302-0000 (default)
> I0115 21:27:23.349714 31540 hierarchical.cpp:579] Received resource
> request from framework d806cbcd-c800-48cb-948d-ec1e15af6302-0000
> I0115 21:27:23.350047 31541 master.cpp:1025] Master terminating
> I0115 21:27:23.350213 31527 hierarchical.cpp:320] Removed framework
> d806cbcd-c800-48cb-948d-ec1e15af6302-0000
> E0115 21:27:23.351241 31534 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (65 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I0115 21:27:23.361248 31507 leveldb.cpp:174] Opened db in 2.930682ms
> I0115 21:27:23.362064 31507 leveldb.cpp:181] Compacted db in 776203ns
> I0115 21:27:23.362113 31507 leveldb.cpp:196] Created db iterator in 18434ns
> I0115 21:27:23.362133 31507 leveldb.cpp:202] Seeked to beginning of db in
> 1832ns
> I0115 21:27:23.362144 31507 leveldb.cpp:271] Iterated through 0 keys in
> the db in 222ns
> I0115 21:27:23.362185 31507 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0115 21:27:23.362649 31531 recover.cpp:447] Starting replica recovery
> I0115 21:27:23.363021 31531 recover.cpp:473] Replica is in EMPTY status
> I0115 21:27:23.364255 31538 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13829)@172.17.0.4:52665
> I0115 21:27:23.364830 31541 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0115 21:27:23.365386 31535 recover.cpp:564] Updating replica status to
> STARTING
> I0115 21:27:23.366015 31541 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 445571ns
> I0115 21:27:23.366153 31541 replica.cpp:320] Persisted replica status to
> STARTING
> I0115 21:27:23.366334 31541 master.cpp:374] Master
> db133052-d307-48ed-ac50-7265566796c9 (4e6fbf10d387) started on
> 172.17.0.4:52665
> I0115 21:27:23.366672 31527 recover.cpp:473] Replica is in STARTING status
> I0115 21:27:23.366518 31541 master.cpp:376] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/j8VL5F/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="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/j8VL5F/master" --zk_session_timeout="10secs"
> I0115 21:27:23.366855 31541 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0115 21:27:23.366866 31541 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0115 21:27:23.366873 31541 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/j8VL5F/credentials'
> I0115 21:27:23.367122 31541 master.cpp:466] Using default 'crammd5'
> authenticator
> I0115 21:27:23.367277 31541 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0115 21:27:23.367519 31541 master.cpp:569] Authorization enabled
> I0115 21:27:23.367566 31528 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13830)@172.17.0.4:52665
> I0115 21:27:23.367697 31531 whitelist_watcher.cpp:77] No whitelist given
> I0115 21:27:23.367718 31528 hierarchical.cpp:147] Initialized hierarchical
> allocator process
> I0115 21:27:23.367887 31526 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0115 21:27:23.368361 31539 recover.cpp:564] Updating replica status to
> VOTING
> I0115 21:27:23.368877 31540 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 322970ns
> I0115 21:27:23.368902 31540 replica.cpp:320] Persisted replica status to
> VOTING
> I0115 21:27:23.368999 31529 recover.cpp:578] Successfully joined the Paxos
> group
> I0115 21:27:23.369357 31529 recover.cpp:462] Recover process terminated
> I0115 21:27:23.369609 31539 master.cpp:1710] The newly elected leader is
> master@172.17.0.4:52665 with id db133052-d307-48ed-ac50-7265566796c9
> I0115 21:27:23.369642 31539 master.cpp:1723] Elected as the leading master!
> I0115 21:27:23.369662 31539 master.cpp:1468] Recovering from registrar
> I0115 21:27:23.369796 31540 registrar.cpp:307] Recovering registrar
> I0115 21:27:23.370324 31537 log.cpp:659] Attempting to start the writer
> I0115 21:27:23.371363 31538 replica.cpp:493] Replica received implicit
> promise request from (13832)@172.17.0.4:52665 with proposal 1
> I0115 21:27:23.371675 31538 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 281036ns
> I0115 21:27:23.371697 31538 replica.cpp:342] Persisted promised to 1
> I0115 21:27:23.372237 31534 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0115 21:27:23.373425 31535 replica.cpp:388] Replica received explicit
> promise request from (13833)@172.17.0.4:52665 for position 0 with
> proposal 2
> I0115 21:27:23.373729 31535 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 269247ns
> I0115 21:27:23.373759 31535 replica.cpp:712] Persisted action at 0
> I0115 21:27:23.374781 31532 replica.cpp:537] Replica received write
> request for position 0 from (13834)@172.17.0.4:52665
> I0115 21:27:23.374845 31532 leveldb.cpp:436] Reading position from leveldb
> took 30693ns
> I0115 21:27:23.375159 31532 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 266883ns
> I0115 21:27:23.375183 31532 replica.cpp:712] Persisted action at 0
> I0115 21:27:23.375746 31539 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0115 21:27:23.376083 31539 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 305860ns
> I0115 21:27:23.376107 31539 replica.cpp:712] Persisted action at 0
> I0115 21:27:23.376127 31539 replica.cpp:697] Replica learned NOP action at
> position 0
> I0115 21:27:23.376804 31538 log.cpp:675] Writer started with ending
> position 0
> I0115 21:27:23.378089 31535 leveldb.cpp:436] Reading position from leveldb
> took 34771ns
> I0115 21:27:23.379143 31535 registrar.cpp:340] Successfully fetched the
> registry (0B) in 9.289984ms
> I0115 21:27:23.379293 31535 registrar.cpp:439] Applied 1 operations in
> 38556ns; attempting to update the 'registry'
> I0115 21:27:23.380162 31533 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0115 21:27:23.380314 31526 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0115 21:27:23.381167 31530 replica.cpp:537] Replica received write
> request for position 1 from (13835)@172.17.0.4:52665
> I0115 21:27:23.381562 31530 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 345657ns
> I0115 21:27:23.381598 31530 replica.cpp:712] Persisted action at 1
> I0115 21:27:23.382459 31541 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0115 21:27:23.382913 31541 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 417814ns
> I0115 21:27:23.382944 31541 replica.cpp:712] Persisted action at 1
> I0115 21:27:23.382966 31541 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0115 21:27:23.384079 31531 registrar.cpp:484] Successfully updated the
> 'registry' in 4.707072ms
> I0115 21:27:23.384244 31531 registrar.cpp:370] Successfully recovered
> registrar
> I0115 21:27:23.384333 31534 log.cpp:702] Attempting to truncate the log to
> 1
> I0115 21:27:23.384737 31538 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0115 21:27:23.384928 31539 hierarchical.cpp:165] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0115 21:27:23.384953 31535 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0115 21:27:23.385924 31537 replica.cpp:537] Replica received write
> request for position 2 from (13836)@172.17.0.4:52665
> I0115 21:27:23.386333 31537 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 364042ns
> I0115 21:27:23.386365 31537 replica.cpp:712] Persisted action at 2
> I0115 21:27:23.387029 31533 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0115 21:27:23.387504 31533 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 433278ns
> I0115 21:27:23.387570 31533 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 35877ns
> I0115 21:27:23.387591 31533 replica.cpp:712] Persisted action at 2
> I0115 21:27:23.387617 31533 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0115 21:27:23.395831 31507 scheduler.cpp:154] Version: 0.27.0
> I0115 21:27:23.396633 31536 scheduler.cpp:236] New master detected at
> master@172.17.0.4:52665
> I0115 21:27:23.397802 31538 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.4:52665
> I0115 21:27:23.400193 31540 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0115 21:27:23.400768 31528 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:48017
> I0115 21:27:23.401252 31528 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0115 21:27:23.401332 31528 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0115 21:27:23.401623 31528 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0115 21:27:23.402088 31538 hierarchical.cpp:259] Added framework
> db133052-d307-48ed-ac50-7265566796c9-0000
> I0115 21:27:23.402160 31538 hierarchical.cpp:1329] No resources available
> to allocate!
> I0115 21:27:23.402200 31538 hierarchical.cpp:1423] No inverse offers to
> send out!
> I0115 21:27:23.402230 31538 hierarchical.cpp:1079] Performed allocation
> for 0 slaves in 119921ns
> I0115 21:27:23.402261 31538 master.hpp:1658] Sending heartbeat to
> db133052-d307-48ed-ac50-7265566796c9-0000
> I0115 21:27:23.403661 31539 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.4:52665
> I0115 21:27:23.404364 31539 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.4:52665
> I0115 21:27:23.405192 31539 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.4:52665
> I0115 21:27:23.405380 31527 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0115 21:27:23.407523 31526 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0115 21:27:23.408007 31541 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:48018
> I0115 21:27:23.408303 31541 master.cpp:2717] Processing REQUEST call for
> framework db133052-d307-48ed-ac50-7265566796c9-0000 (default)
> I0115 21:27:23.408520 31532 hierarchical.cpp:579] Received resource
> request from framework db133052-d307-48ed-ac50-7265566796c9-0000
> I0115 21:27:23.408874 31528 master.cpp:1025] Master terminating
> I0115 21:27:23.409123 31531 hierarchical.cpp:320] Removed framework
> db133052-d307-48ed-ac50-7265566796c9-0000
> E0115 21:27:23.410259 31531 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (59 ms)
> [----------] 22 tests from ContentType/SchedulerTest (4242 ms total)
>
> [----------] Global test environment tear-down
> [==========] 930 tests from 123 test cases ran. (326131 ms total)
> [ PASSED ] 929 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] MasterTest.MaxCompletedFrameworksFlag
>
> 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-1452891416-1892
> Untagged: mesos-1452891416-1892:latest
> Deleted: af99b06b60b459e0e0e7678545fec09750c0d7d008a5b48adcf7d96a0a5e2743
> Deleted: 064705ae1f10c941a50cc81a8c0f92f1ca2915353d97e64c3c03c4df49191a39
> Deleted: 6517afac0ff76aaefcb875b1c18083acb3a883e442602ec77343ea9757708b8c
> Deleted: 1a4ae813a3017392ad5d3167a2889832b51c0e1f7398d1b8778d73bc767d136f
> Deleted: 08896cdae9fd76d3a24854f60f2e1ade04667063e64e3abf29645145e0fb2083
> Deleted: 2ee703ab305378b9d0a34fad914e22c7524757c68591e988bd9b3302456fee65
> Deleted: b25e830881c6f4f255dbbba9f60bdace1c64e7cd6449715ccf9d17074811f2a3
> Deleted: 14559f0ede62126c5f4a2c135eba25f36905d10a735a986b48ba193a59b09481
> Deleted: 74f46eaf67dad83db0c0650c513700f5f27befecedb89dd8470cc6d55e8affeb
> Deleted: bf74f853e8fac89f16fc01570b92f92b6f6a393c180215a57e6b77a9031f3b8a
> Deleted: f9e486f67b5ea0edef231eb4a55099d076e720506ad6e7d18c8f8807363e77dd
> Deleted: 7ff4aef84b24295c5f5aecd8587f9c864c3bfd629001fa5811184250548da474
> Deleted: cd291e94bd48117c12127a70840b319c8b1bb2f72d50e470190edfe715b9dd6f
> Deleted: e3bd2c3cd4b98286cbcdcff6e9aa99f1c7fa7f2b9221d60e01ef2ab2a6f492c9
> Build step 'Execute shell' marked build as failure
>