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 2015/09/25 21:19:42 UTC
Build failed in Jenkins: Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #866
See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/866/changes>
Changes:
[vinodkone] Added WIP note for Executor endpoint in changelog.
------------------------------------------
[...truncated 135082 lines...]
I0925 19:19:58.867365 27431 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_o5iKS7/slaves/b7d45bba-3611-409b-8369-081f7eaf9526-S0/frameworks/b7d45bba-3611-409b-8369-081f7eaf9526-0000/executors/default/runs/02313e80-69d8-4828-9686-2110bdfbb98c' for gc 6.99998996229037days in the future
I0925 19:19:58.867497 27443 slave.cpp:3633] Cleaning up framework b7d45bba-3611-409b-8369-081f7eaf9526-0000
I0925 19:19:58.867549 27431 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_o5iKS7/slaves/b7d45bba-3611-409b-8369-081f7eaf9526-S0/frameworks/b7d45bba-3611-409b-8369-081f7eaf9526-0000/executors/default' for gc 6.99998996019556days in the future
I0925 19:19:58.867701 27431 status_update_manager.cpp:284] Closing status update streams for framework b7d45bba-3611-409b-8369-081f7eaf9526-0000
I0925 19:19:58.867769 27431 status_update_manager.cpp:530] Cleaning up status update stream for task 48a8ae61-83b9-4a04-adbf-571d4bd04dc6 of framework b7d45bba-3611-409b-8369-081f7eaf9526-0000
I0925 19:19:58.867892 27429 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_o5iKS7/slaves/b7d45bba-3611-409b-8369-081f7eaf9526-S0/frameworks/b7d45bba-3611-409b-8369-081f7eaf9526-0000' for gc 6.99998995753482days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (105 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_0WiZpt'
I0925 19:19:58.874938 27410 leveldb.cpp:176] Opened db in 2.181139ms
I0925 19:19:58.875972 27410 leveldb.cpp:183] Compacted db in 1.020045ms
I0925 19:19:58.876032 27410 leveldb.cpp:198] Created db iterator in 30286ns
I0925 19:19:58.876049 27410 leveldb.cpp:204] Seeked to beginning of db in 6353ns
I0925 19:19:58.876056 27410 leveldb.cpp:273] Iterated through 0 keys in the db in 4528ns
I0925 19:19:58.876096 27410 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0925 19:19:58.876503 27443 recover.cpp:449] Starting replica recovery
I0925 19:19:58.876768 27443 recover.cpp:475] Replica is in EMPTY status
I0925 19:19:58.877611 27443 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0925 19:19:58.878178 27430 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0925 19:19:58.878710 27429 recover.cpp:566] Updating replica status to STARTING
I0925 19:19:58.879422 27430 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 553939ns
I0925 19:19:58.879451 27430 replica.cpp:323] Persisted replica status to STARTING
I0925 19:19:58.879633 27440 recover.cpp:475] Replica is in STARTING status
I0925 19:19:58.879942 27439 master.cpp:376] Master 6f63a552-8569-4eb7-b008-a7eb8d94ce25 (f57fd4291168) started on 172.17.1.195:41781
I0925 19:19:58.880043 27439 master.cpp:378] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ContentType_SchedulerTest_Request_0_0WiZpt/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.26.0/_inst/share/mesos/webui" --work_dir="/tmp/ContentType_SchedulerTest_Request_0_0WiZpt/master" --zk_session_timeout="10secs"
I0925 19:19:58.880352 27439 master.cpp:425] Master allowing unauthenticated frameworks to register
I0925 19:19:58.880481 27439 master.cpp:428] Master only allowing authenticated slaves to register
I0925 19:19:58.880525 27431 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0925 19:19:58.880590 27439 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_0_0WiZpt/credentials'
I0925 19:19:58.880944 27439 master.cpp:467] Using default 'crammd5' authenticator
I0925 19:19:58.880975 27428 recover.cpp:195] Received a recover response from a replica in STARTING status
I0925 19:19:58.881064 27439 master.cpp:504] Authorization enabled
I0925 19:19:58.881364 27437 recover.cpp:566] Updating replica status to VOTING
I0925 19:19:58.881379 27429 hierarchical.hpp:468] Initialized hierarchical allocator process
I0925 19:19:58.881484 27441 whitelist_watcher.cpp:79] No whitelist given
I0925 19:19:58.881811 27429 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 327068ns
I0925 19:19:58.881834 27429 replica.cpp:323] Persisted replica status to VOTING
I0925 19:19:58.881989 27429 recover.cpp:580] Successfully joined the Paxos group
I0925 19:19:58.882246 27429 recover.cpp:464] Recover process terminated
I0925 19:19:58.882949 27442 master.cpp:1603] The newly elected leader is master@172.17.1.195:41781 with id 6f63a552-8569-4eb7-b008-a7eb8d94ce25
I0925 19:19:58.882987 27442 master.cpp:1616] Elected as the leading master!
I0925 19:19:58.883004 27442 master.cpp:1376] Recovering from registrar
I0925 19:19:58.883150 27432 registrar.cpp:309] Recovering registrar
I0925 19:19:58.883661 27443 log.cpp:661] Attempting to start the writer
I0925 19:19:58.884698 27441 replica.cpp:477] Replica received implicit promise request with proposal 1
I0925 19:19:58.885021 27441 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 312004ns
I0925 19:19:58.885043 27441 replica.cpp:345] Persisted promised to 1
I0925 19:19:58.885730 27434 coordinator.cpp:231] Coordinator attemping to fill missing position
I0925 19:19:58.886766 27435 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0925 19:19:58.887081 27435 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 293830ns
I0925 19:19:58.887104 27435 replica.cpp:679] Persisted action at 0
I0925 19:19:58.888221 27428 replica.cpp:511] Replica received write request for position 0
I0925 19:19:58.888373 27428 leveldb.cpp:438] Reading position from leveldb took 58589ns
I0925 19:19:58.888710 27428 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 298596ns
I0925 19:19:58.888738 27428 replica.cpp:679] Persisted action at 0
I0925 19:19:58.889268 27430 replica.cpp:658] Replica received learned notice for position 0
I0925 19:19:58.889617 27430 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 336967ns
I0925 19:19:58.889643 27430 replica.cpp:679] Persisted action at 0
I0925 19:19:58.889660 27430 replica.cpp:664] Replica learned NOP action at position 0
I0925 19:19:58.890178 27441 log.cpp:677] Writer started with ending position 0
I0925 19:19:58.891095 27440 leveldb.cpp:438] Reading position from leveldb took 58782ns
I0925 19:19:58.891906 27439 registrar.cpp:342] Successfully fetched the registry (0B) in 8.706048ms
I0925 19:19:58.892015 27439 registrar.cpp:441] Applied 1 operations in 36481ns; attempting to update the 'registry'
I0925 19:19:58.892539 27430 log.cpp:685] Attempting to append 176 bytes to the log
I0925 19:19:58.892684 27435 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0925 19:19:58.893260 27428 replica.cpp:511] Replica received write request for position 1
I0925 19:19:58.893628 27428 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 350945ns
I0925 19:19:58.893651 27428 replica.cpp:679] Persisted action at 1
I0925 19:19:58.894168 27431 replica.cpp:658] Replica received learned notice for position 1
I0925 19:19:58.894533 27431 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 351907ns
I0925 19:19:58.894556 27431 replica.cpp:679] Persisted action at 1
I0925 19:19:58.894570 27431 replica.cpp:664] Replica learned APPEND action at position 1
I0925 19:19:58.895359 27435 registrar.cpp:486] Successfully updated the 'registry' in 3.286016ms
I0925 19:19:58.895473 27435 registrar.cpp:372] Successfully recovered registrar
I0925 19:19:58.895572 27436 log.cpp:704] Attempting to truncate the log to 1
I0925 19:19:58.895714 27428 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0925 19:19:58.895859 27442 master.cpp:1413] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I0925 19:19:58.896517 27437 replica.cpp:511] Replica received write request for position 2
I0925 19:19:58.896885 27437 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 351340ns
I0925 19:19:58.896908 27437 replica.cpp:679] Persisted action at 2
I0925 19:19:58.897373 27431 replica.cpp:658] Replica received learned notice for position 2
I0925 19:19:58.897768 27431 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 383736ns
I0925 19:19:58.897825 27431 leveldb.cpp:401] Deleting ~1 keys from leveldb took 43136ns
I0925 19:19:58.897847 27431 replica.cpp:679] Persisted action at 2
I0925 19:19:58.897872 27431 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0925 19:19:58.907860 27410 scheduler.cpp:157] Version: 0.26.0
I0925 19:19:58.909023 27435 scheduler.cpp:240] New master detected at master@172.17.1.195:41781
I0925 19:19:58.910362 27437 scheduler.cpp:302] Sending SUBSCRIBE call to master@172.17.1.195:41781
I0925 19:19:58.912052 27436 process.cpp:3021] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 19:19:58.912335 27436 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.1.195:56046
I0925 19:19:58.912533 27436 master.cpp:1865] Received subscription request for HTTP framework 'default'
I0925 19:19:58.912561 27436 master.cpp:1642] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0925 19:19:58.912809 27436 master.cpp:1957] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0925 19:19:58.913220 27435 hierarchical.hpp:515] Added framework 6f63a552-8569-4eb7-b008-a7eb8d94ce25-0000
I0925 19:19:58.913265 27435 hierarchical.hpp:1326] No resources available to allocate!
I0925 19:19:58.913291 27435 hierarchical.hpp:1421] No inverse offers to send out!
I0925 19:19:58.913303 27435 hierarchical.hpp:1221] Performed allocation for 0 slaves in 66041ns
I0925 19:19:58.913447 27428 master.hpp:1431] Sending heartbeat to 6f63a552-8569-4eb7-b008-a7eb8d94ce25-0000
I0925 19:19:58.914116 27431 scheduler.cpp:461] Enqueuing event SUBSCRIBED received from master@172.17.1.195:41781
I0925 19:19:58.914531 27431 scheduler.cpp:461] Enqueuing event HEARTBEAT received from master@172.17.1.195:41781
I0925 19:19:58.915366 27443 master_maintenance_tests.cpp:179] Ignoring HEARTBEAT event
I0925 19:19:58.915485 27434 scheduler.cpp:302] Sending REQUEST call to master@172.17.1.195:41781
I0925 19:19:58.916662 27436 process.cpp:3021] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 19:19:58.916954 27436 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.1.195:56047
I0925 19:19:58.917075 27436 master.cpp:2618] Processing REQUEST call for framework 6f63a552-8569-4eb7-b008-a7eb8d94ce25-0000 (default)
I0925 19:19:58.917347 27433 hierarchical.hpp:801] Received resource request from framework 6f63a552-8569-4eb7-b008-a7eb8d94ce25-0000
I0925 19:19:58.917631 27430 master.cpp:919] Master terminating
I0925 19:19:58.917881 27434 hierarchical.hpp:552] Removed framework 6f63a552-8569-4eb7-b008-a7eb8d94ce25-0000
E0925 19:19:58.919014 27428 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (52 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
Using temporary directory '/tmp/ContentType_SchedulerTest_Request_1_67yruV'
I0925 19:19:58.927153 27410 leveldb.cpp:176] Opened db in 2.3357ms
I0925 19:19:58.927978 27410 leveldb.cpp:183] Compacted db in 808619ns
I0925 19:19:58.928027 27410 leveldb.cpp:198] Created db iterator in 27108ns
I0925 19:19:58.928052 27410 leveldb.cpp:204] Seeked to beginning of db in 21503ns
I0925 19:19:58.928073 27410 leveldb.cpp:273] Iterated through 0 keys in the db in 9316ns
I0925 19:19:58.928135 27410 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0925 19:19:58.928688 27437 recover.cpp:449] Starting replica recovery
I0925 19:19:58.928951 27437 recover.cpp:475] Replica is in EMPTY status
I0925 19:19:58.930186 27430 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0925 19:19:58.930393 27435 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0925 19:19:58.931129 27439 recover.cpp:566] Updating replica status to STARTING
I0925 19:19:58.931751 27439 master.cpp:376] Master 47f734c8-fc60-401b-a023-708247890958 (f57fd4291168) started on 172.17.1.195:41781
I0925 19:19:58.931877 27429 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 651311ns
I0925 19:19:58.931910 27429 replica.cpp:323] Persisted replica status to STARTING
I0925 19:19:58.931788 27439 master.cpp:378] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ContentType_SchedulerTest_Request_1_67yruV/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.26.0/_inst/share/mesos/webui" --work_dir="/tmp/ContentType_SchedulerTest_Request_1_67yruV/master" --zk_session_timeout="10secs"
I0925 19:19:58.932114 27439 master.cpp:425] Master allowing unauthenticated frameworks to register
I0925 19:19:58.932124 27439 master.cpp:428] Master only allowing authenticated slaves to register
I0925 19:19:58.932131 27439 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_1_67yruV/credentials'
I0925 19:19:58.932137 27428 recover.cpp:475] Replica is in STARTING status
I0925 19:19:58.932391 27439 master.cpp:467] Using default 'crammd5' authenticator
I0925 19:19:58.932520 27439 master.cpp:504] Authorization enabled
I0925 19:19:58.932739 27434 whitelist_watcher.cpp:79] No whitelist given
I0925 19:19:58.932777 27442 hierarchical.hpp:468] Initialized hierarchical allocator process
I0925 19:19:58.933187 27443 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0925 19:19:58.933696 27428 recover.cpp:195] Received a recover response from a replica in STARTING status
I0925 19:19:58.934219 27434 recover.cpp:566] Updating replica status to VOTING
I0925 19:19:58.934450 27434 master.cpp:1603] The newly elected leader is master@172.17.1.195:41781 with id 47f734c8-fc60-401b-a023-708247890958
I0925 19:19:58.934516 27434 master.cpp:1616] Elected as the leading master!
I0925 19:19:58.934535 27434 master.cpp:1376] Recovering from registrar
I0925 19:19:58.934660 27435 registrar.cpp:309] Recovering registrar
I0925 19:19:58.934677 27428 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 363516ns
I0925 19:19:58.934705 27428 replica.cpp:323] Persisted replica status to VOTING
I0925 19:19:58.934862 27433 recover.cpp:580] Successfully joined the Paxos group
I0925 19:19:58.935127 27433 recover.cpp:464] Recover process terminated
I0925 19:19:58.935648 27432 log.cpp:661] Attempting to start the writer
I0925 19:19:58.936688 27442 replica.cpp:477] Replica received implicit promise request with proposal 1
I0925 19:19:58.937001 27442 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 297340ns
I0925 19:19:58.937023 27442 replica.cpp:345] Persisted promised to 1
I0925 19:19:58.937662 27442 coordinator.cpp:231] Coordinator attemping to fill missing position
I0925 19:19:58.938869 27442 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0925 19:19:58.939180 27442 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 287084ns
I0925 19:19:58.939208 27442 replica.cpp:679] Persisted action at 0
I0925 19:19:58.940155 27432 replica.cpp:511] Replica received write request for position 0
I0925 19:19:58.940227 27432 leveldb.cpp:438] Reading position from leveldb took 45464ns
I0925 19:19:58.940560 27432 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 294193ns
I0925 19:19:58.940630 27432 replica.cpp:679] Persisted action at 0
I0925 19:19:58.941150 27439 replica.cpp:658] Replica received learned notice for position 0
I0925 19:19:58.941444 27439 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 281925ns
I0925 19:19:58.941467 27439 replica.cpp:679] Persisted action at 0
I0925 19:19:58.941480 27439 replica.cpp:664] Replica learned NOP action at position 0
I0925 19:19:58.942062 27431 log.cpp:677] Writer started with ending position 0
I0925 19:19:58.943099 27438 leveldb.cpp:438] Reading position from leveldb took 92638ns
I0925 19:19:58.944039 27438 registrar.cpp:342] Successfully fetched the registry (0B) in 9.340928ms
I0925 19:19:58.944149 27438 registrar.cpp:441] Applied 1 operations in 35111ns; attempting to update the 'registry'
I0925 19:19:58.944828 27437 log.cpp:685] Attempting to append 176 bytes to the log
I0925 19:19:58.944928 27436 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0925 19:19:58.945694 27437 replica.cpp:511] Replica received write request for position 1
I0925 19:19:58.946032 27437 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 320087ns
I0925 19:19:58.946053 27437 replica.cpp:679] Persisted action at 1
I0925 19:19:58.946627 27441 replica.cpp:658] Replica received learned notice for position 1
I0925 19:19:58.946948 27441 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 306869ns
I0925 19:19:58.946972 27441 replica.cpp:679] Persisted action at 1
I0925 19:19:58.946991 27441 replica.cpp:664] Replica learned APPEND action at position 1
I0925 19:19:58.947918 27435 registrar.cpp:486] Successfully updated the 'registry' in 3.650048ms
I0925 19:19:58.948065 27435 registrar.cpp:372] Successfully recovered registrar
I0925 19:19:58.948199 27440 log.cpp:704] Attempting to truncate the log to 1
I0925 19:19:58.948369 27431 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0925 19:19:58.948417 27439 master.cpp:1413] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I0925 19:19:58.949136 27440 replica.cpp:511] Replica received write request for position 2
I0925 19:19:58.949443 27440 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 288335ns
I0925 19:19:58.949468 27440 replica.cpp:679] Persisted action at 2
I0925 19:19:58.949954 27430 replica.cpp:658] Replica received learned notice for position 2
I0925 19:19:58.950275 27430 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 308229ns
I0925 19:19:58.950330 27430 leveldb.cpp:401] Deleting ~1 keys from leveldb took 42022ns
I0925 19:19:58.950364 27430 replica.cpp:679] Persisted action at 2
I0925 19:19:58.950387 27430 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0925 19:19:58.959220 27410 scheduler.cpp:157] Version: 0.26.0
I0925 19:19:58.959782 27434 scheduler.cpp:240] New master detected at master@172.17.1.195:41781
I0925 19:19:58.960824 27443 scheduler.cpp:302] Sending SUBSCRIBE call to master@172.17.1.195:41781
I0925 19:19:58.962537 27440 process.cpp:3021] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 19:19:58.962748 27440 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.1.195:56048
I0925 19:19:58.963075 27440 master.cpp:1865] Received subscription request for HTTP framework 'default'
I0925 19:19:58.963102 27440 master.cpp:1642] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0925 19:19:58.963371 27431 master.cpp:1957] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0925 19:19:58.963747 27442 hierarchical.hpp:515] Added framework 47f734c8-fc60-401b-a023-708247890958-0000
I0925 19:19:58.963780 27442 hierarchical.hpp:1326] No resources available to allocate!
I0925 19:19:58.963803 27442 hierarchical.hpp:1421] No inverse offers to send out!
I0925 19:19:58.963819 27442 hierarchical.hpp:1221] Performed allocation for 0 slaves in 58822ns
I0925 19:19:58.963853 27442 master.hpp:1431] Sending heartbeat to 47f734c8-fc60-401b-a023-708247890958-0000
I0925 19:19:58.964740 27438 scheduler.cpp:461] Enqueuing event SUBSCRIBED received from master@172.17.1.195:41781
I0925 19:19:58.965126 27438 scheduler.cpp:461] Enqueuing event HEARTBEAT received from master@172.17.1.195:41781
I0925 19:19:58.965698 27428 master_maintenance_tests.cpp:179] Ignoring HEARTBEAT event
I0925 19:19:58.965734 27438 scheduler.cpp:302] Sending REQUEST call to master@172.17.1.195:41781
I0925 19:19:58.966987 27428 process.cpp:3021] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 19:19:58.967206 27428 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.1.195:56049
I0925 19:19:58.967437 27428 master.cpp:2618] Processing REQUEST call for framework 47f734c8-fc60-401b-a023-708247890958-0000 (default)
I0925 19:19:58.967689 27431 hierarchical.hpp:801] Received resource request from framework 47f734c8-fc60-401b-a023-708247890958-0000
I0925 19:19:58.968124 27443 master.cpp:919] Master terminating
I0925 19:19:58.968598 27441 hierarchical.hpp:552] Removed framework 47f734c8-fc60-401b-a023-708247890958-0000
E0925 19:19:58.969264 27437 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (49 ms)
[----------] 22 tests from ContentType/SchedulerTest (3995 ms total)
[----------] Global test environment tear-down
[==========] 804 tests from 110 test cases ran. (323152 ms total)
[ PASSED ] 803 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] FetcherCacheTest.LocalUncachedExtract
1 FAILED TEST
YOU HAVE 7 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1443207316-10843
Untagged: mesos-1443207316-10843:latest
Deleted: 7cafaf8a572a6f34cdedddd3239f7fcab2712ea698aa80c7f4ce09579852dd4d
Deleted: 94a4105720f9bf45d7530242694d86e58bd0b6ae780a4ad95e79254b01529a97
Deleted: 8cf0e5ec97a6ed1135d77860a81b7c6bab85c5a7164523ad2db5c3f42234504f
Deleted: 7a63b4909d1a88fcae2e403f86960aab2f3470df780792c62001f0d42e286b06
Deleted: a991b8a445688d9b22e14ad144111a14689f191f8bc09eb9142b9694545f59a1
Deleted: 4610a9cc3ba3d7f8f2436b2cf552a3095e2b40746b3e3d893218c6441f110110
Deleted: 47e15b03be1843eb3c68dea45eea1b68ac5f56c448b6d1b3290dc392be236e3c
Deleted: af0f4f7d726be5aa06c9dc723beea5d89d54bd5cf13c287cce2ebc94b7523166
Deleted: ab001ee06920910e556202efe1b98d885fd2b8c68f678433c881c23a46990f35
Deleted: ac5f01fe5c52cabb9906201cfa9f8cba89aac50abb914a3debb817986799c517
Deleted: 9c6653ba5bbbd505607d65d914b8cc8b6753b739841776178b3946791cb427a4
Deleted: 32b6b6aa07f22bdbd555e6320330a423178d1173b38bbd86e87a79cfe684e101
Deleted: 992078bd72b0a30f380dd7303af6902df811ffc4f4c99f84de90bbab794bcbc4
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #867
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/867/changes>
Re: Build failed in Jenkins: Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #866
Posted by Vinod Kone <vi...@gmail.com>.
bernd?
On Fri, Sep 25, 2015 at 12:19 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/866/changes
> >
>
> Changes:
>
> [vinodkone] Added WIP note for Executor endpoint in changelog.
>
> ------------------------------------------
> [...truncated 135082 lines...]
> I0925 19:19:58.867365 27431 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_o5iKS7/slaves/b7d45bba-3611-409b-8369-081f7eaf9526-S0/frameworks/b7d45bba-3611-409b-8369-081f7eaf9526-0000/executors/default/runs/02313e80-69d8-4828-9686-2110bdfbb98c'
> for gc 6.99998996229037days in the future
> I0925 19:19:58.867497 27443 slave.cpp:3633] Cleaning up framework
> b7d45bba-3611-409b-8369-081f7eaf9526-0000
> I0925 19:19:58.867549 27431 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_o5iKS7/slaves/b7d45bba-3611-409b-8369-081f7eaf9526-S0/frameworks/b7d45bba-3611-409b-8369-081f7eaf9526-0000/executors/default'
> for gc 6.99998996019556days in the future
> I0925 19:19:58.867701 27431 status_update_manager.cpp:284] Closing status
> update streams for framework b7d45bba-3611-409b-8369-081f7eaf9526-0000
> I0925 19:19:58.867769 27431 status_update_manager.cpp:530] Cleaning up
> status update stream for task 48a8ae61-83b9-4a04-adbf-571d4bd04dc6 of
> framework b7d45bba-3611-409b-8369-081f7eaf9526-0000
> I0925 19:19:58.867892 27429 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_o5iKS7/slaves/b7d45bba-3611-409b-8369-081f7eaf9526-S0/frameworks/b7d45bba-3611-409b-8369-081f7eaf9526-0000'
> for gc 6.99998995753482days in the future
> [ OK ] ContentType/SchedulerTest.Message/1 (105 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_0WiZpt'
> I0925 19:19:58.874938 27410 leveldb.cpp:176] Opened db in 2.181139ms
> I0925 19:19:58.875972 27410 leveldb.cpp:183] Compacted db in 1.020045ms
> I0925 19:19:58.876032 27410 leveldb.cpp:198] Created db iterator in 30286ns
> I0925 19:19:58.876049 27410 leveldb.cpp:204] Seeked to beginning of db in
> 6353ns
> I0925 19:19:58.876056 27410 leveldb.cpp:273] Iterated through 0 keys in
> the db in 4528ns
> I0925 19:19:58.876096 27410 replica.cpp:744] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0925 19:19:58.876503 27443 recover.cpp:449] Starting replica recovery
> I0925 19:19:58.876768 27443 recover.cpp:475] Replica is in EMPTY status
> I0925 19:19:58.877611 27443 replica.cpp:641] Replica in EMPTY status
> received a broadcasted recover request
> I0925 19:19:58.878178 27430 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I0925 19:19:58.878710 27429 recover.cpp:566] Updating replica status to
> STARTING
> I0925 19:19:58.879422 27430 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 553939ns
> I0925 19:19:58.879451 27430 replica.cpp:323] Persisted replica status to
> STARTING
> I0925 19:19:58.879633 27440 recover.cpp:475] Replica is in STARTING status
> I0925 19:19:58.879942 27439 master.cpp:376] Master
> 6f63a552-8569-4eb7-b008-a7eb8d94ce25 (f57fd4291168) started on
> 172.17.1.195:41781
> I0925 19:19:58.880043 27439 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ContentType_SchedulerTest_Request_0_0WiZpt/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --initialize_driver_logging="true" --log_auto_initialize="true"
> --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5"
> --quiet="false" --recovery_slave_removal_limit="100%"
> --registry="replicated_log" --registry_fetch_timeout="1mins"
> --registry_store_timeout="25secs" --registry_strict="true"
> --root_submissions="true" --slave_ping_timeout="15secs"
> --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.26.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ContentType_SchedulerTest_Request_0_0WiZpt/master"
> --zk_session_timeout="10secs"
> I0925 19:19:58.880352 27439 master.cpp:425] Master allowing
> unauthenticated frameworks to register
> I0925 19:19:58.880481 27439 master.cpp:428] Master only allowing
> authenticated slaves to register
> I0925 19:19:58.880525 27431 replica.cpp:641] Replica in STARTING status
> received a broadcasted recover request
> I0925 19:19:58.880590 27439 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerTest_Request_0_0WiZpt/credentials'
> I0925 19:19:58.880944 27439 master.cpp:467] Using default 'crammd5'
> authenticator
> I0925 19:19:58.880975 27428 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I0925 19:19:58.881064 27439 master.cpp:504] Authorization enabled
> I0925 19:19:58.881364 27437 recover.cpp:566] Updating replica status to
> VOTING
> I0925 19:19:58.881379 27429 hierarchical.hpp:468] Initialized hierarchical
> allocator process
> I0925 19:19:58.881484 27441 whitelist_watcher.cpp:79] No whitelist given
> I0925 19:19:58.881811 27429 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 327068ns
> I0925 19:19:58.881834 27429 replica.cpp:323] Persisted replica status to
> VOTING
> I0925 19:19:58.881989 27429 recover.cpp:580] Successfully joined the Paxos
> group
> I0925 19:19:58.882246 27429 recover.cpp:464] Recover process terminated
> I0925 19:19:58.882949 27442 master.cpp:1603] The newly elected leader is
> master@172.17.1.195:41781 with id 6f63a552-8569-4eb7-b008-a7eb8d94ce25
> I0925 19:19:58.882987 27442 master.cpp:1616] Elected as the leading master!
> I0925 19:19:58.883004 27442 master.cpp:1376] Recovering from registrar
> I0925 19:19:58.883150 27432 registrar.cpp:309] Recovering registrar
> I0925 19:19:58.883661 27443 log.cpp:661] Attempting to start the writer
> I0925 19:19:58.884698 27441 replica.cpp:477] Replica received implicit
> promise request with proposal 1
> I0925 19:19:58.885021 27441 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 312004ns
> I0925 19:19:58.885043 27441 replica.cpp:345] Persisted promised to 1
> I0925 19:19:58.885730 27434 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I0925 19:19:58.886766 27435 replica.cpp:378] Replica received explicit
> promise request for position 0 with proposal 2
> I0925 19:19:58.887081 27435 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 293830ns
> I0925 19:19:58.887104 27435 replica.cpp:679] Persisted action at 0
> I0925 19:19:58.888221 27428 replica.cpp:511] Replica received write
> request for position 0
> I0925 19:19:58.888373 27428 leveldb.cpp:438] Reading position from leveldb
> took 58589ns
> I0925 19:19:58.888710 27428 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 298596ns
> I0925 19:19:58.888738 27428 replica.cpp:679] Persisted action at 0
> I0925 19:19:58.889268 27430 replica.cpp:658] Replica received learned
> notice for position 0
> I0925 19:19:58.889617 27430 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 336967ns
> I0925 19:19:58.889643 27430 replica.cpp:679] Persisted action at 0
> I0925 19:19:58.889660 27430 replica.cpp:664] Replica learned NOP action at
> position 0
> I0925 19:19:58.890178 27441 log.cpp:677] Writer started with ending
> position 0
> I0925 19:19:58.891095 27440 leveldb.cpp:438] Reading position from leveldb
> took 58782ns
> I0925 19:19:58.891906 27439 registrar.cpp:342] Successfully fetched the
> registry (0B) in 8.706048ms
> I0925 19:19:58.892015 27439 registrar.cpp:441] Applied 1 operations in
> 36481ns; attempting to update the 'registry'
> I0925 19:19:58.892539 27430 log.cpp:685] Attempting to append 176 bytes to
> the log
> I0925 19:19:58.892684 27435 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I0925 19:19:58.893260 27428 replica.cpp:511] Replica received write
> request for position 1
> I0925 19:19:58.893628 27428 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 350945ns
> I0925 19:19:58.893651 27428 replica.cpp:679] Persisted action at 1
> I0925 19:19:58.894168 27431 replica.cpp:658] Replica received learned
> notice for position 1
> I0925 19:19:58.894533 27431 leveldb.cpp:343] Persisting action (197 bytes)
> to leveldb took 351907ns
> I0925 19:19:58.894556 27431 replica.cpp:679] Persisted action at 1
> I0925 19:19:58.894570 27431 replica.cpp:664] Replica learned APPEND action
> at position 1
> I0925 19:19:58.895359 27435 registrar.cpp:486] Successfully updated the
> 'registry' in 3.286016ms
> I0925 19:19:58.895473 27435 registrar.cpp:372] Successfully recovered
> registrar
> I0925 19:19:58.895572 27436 log.cpp:704] Attempting to truncate the log to
> 1
> I0925 19:19:58.895714 27428 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I0925 19:19:58.895859 27442 master.cpp:1413] Recovered 0 slaves from the
> Registry (137B) ; allowing 10mins for slaves to re-register
> I0925 19:19:58.896517 27437 replica.cpp:511] Replica received write
> request for position 2
> I0925 19:19:58.896885 27437 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 351340ns
> I0925 19:19:58.896908 27437 replica.cpp:679] Persisted action at 2
> I0925 19:19:58.897373 27431 replica.cpp:658] Replica received learned
> notice for position 2
> I0925 19:19:58.897768 27431 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 383736ns
> I0925 19:19:58.897825 27431 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 43136ns
> I0925 19:19:58.897847 27431 replica.cpp:679] Persisted action at 2
> I0925 19:19:58.897872 27431 replica.cpp:664] Replica learned TRUNCATE
> action at position 2
> I0925 19:19:58.907860 27410 scheduler.cpp:157] Version: 0.26.0
> I0925 19:19:58.909023 27435 scheduler.cpp:240] New master detected at
> master@172.17.1.195:41781
> I0925 19:19:58.910362 27437 scheduler.cpp:302] Sending SUBSCRIBE call to
> master@172.17.1.195:41781
> I0925 19:19:58.912052 27436 process.cpp:3021] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0925 19:19:58.912335 27436 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.1.195:56046
> I0925 19:19:58.912533 27436 master.cpp:1865] Received subscription request
> for HTTP framework 'default'
> I0925 19:19:58.912561 27436 master.cpp:1642] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0925 19:19:58.912809 27436 master.cpp:1957] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0925 19:19:58.913220 27435 hierarchical.hpp:515] Added framework
> 6f63a552-8569-4eb7-b008-a7eb8d94ce25-0000
> I0925 19:19:58.913265 27435 hierarchical.hpp:1326] No resources available
> to allocate!
> I0925 19:19:58.913291 27435 hierarchical.hpp:1421] No inverse offers to
> send out!
> I0925 19:19:58.913303 27435 hierarchical.hpp:1221] Performed allocation
> for 0 slaves in 66041ns
> I0925 19:19:58.913447 27428 master.hpp:1431] Sending heartbeat to
> 6f63a552-8569-4eb7-b008-a7eb8d94ce25-0000
> I0925 19:19:58.914116 27431 scheduler.cpp:461] Enqueuing event SUBSCRIBED
> received from master@172.17.1.195:41781
> I0925 19:19:58.914531 27431 scheduler.cpp:461] Enqueuing event HEARTBEAT
> received from master@172.17.1.195:41781
> I0925 19:19:58.915366 27443 master_maintenance_tests.cpp:179] Ignoring
> HEARTBEAT event
> I0925 19:19:58.915485 27434 scheduler.cpp:302] Sending REQUEST call to
> master@172.17.1.195:41781
> I0925 19:19:58.916662 27436 process.cpp:3021] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0925 19:19:58.916954 27436 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.1.195:56047
> I0925 19:19:58.917075 27436 master.cpp:2618] Processing REQUEST call for
> framework 6f63a552-8569-4eb7-b008-a7eb8d94ce25-0000 (default)
> I0925 19:19:58.917347 27433 hierarchical.hpp:801] Received resource
> request from framework 6f63a552-8569-4eb7-b008-a7eb8d94ce25-0000
> I0925 19:19:58.917631 27430 master.cpp:919] Master terminating
> I0925 19:19:58.917881 27434 hierarchical.hpp:552] Removed framework
> 6f63a552-8569-4eb7-b008-a7eb8d94ce25-0000
> E0925 19:19:58.919014 27428 scheduler.cpp:435] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (52 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_1_67yruV'
> I0925 19:19:58.927153 27410 leveldb.cpp:176] Opened db in 2.3357ms
> I0925 19:19:58.927978 27410 leveldb.cpp:183] Compacted db in 808619ns
> I0925 19:19:58.928027 27410 leveldb.cpp:198] Created db iterator in 27108ns
> I0925 19:19:58.928052 27410 leveldb.cpp:204] Seeked to beginning of db in
> 21503ns
> I0925 19:19:58.928073 27410 leveldb.cpp:273] Iterated through 0 keys in
> the db in 9316ns
> I0925 19:19:58.928135 27410 replica.cpp:744] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0925 19:19:58.928688 27437 recover.cpp:449] Starting replica recovery
> I0925 19:19:58.928951 27437 recover.cpp:475] Replica is in EMPTY status
> I0925 19:19:58.930186 27430 replica.cpp:641] Replica in EMPTY status
> received a broadcasted recover request
> I0925 19:19:58.930393 27435 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I0925 19:19:58.931129 27439 recover.cpp:566] Updating replica status to
> STARTING
> I0925 19:19:58.931751 27439 master.cpp:376] Master
> 47f734c8-fc60-401b-a023-708247890958 (f57fd4291168) started on
> 172.17.1.195:41781
> I0925 19:19:58.931877 27429 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 651311ns
> I0925 19:19:58.931910 27429 replica.cpp:323] Persisted replica status to
> STARTING
> I0925 19:19:58.931788 27439 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ContentType_SchedulerTest_Request_1_67yruV/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --initialize_driver_logging="true" --log_auto_initialize="true"
> --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5"
> --quiet="false" --recovery_slave_removal_limit="100%"
> --registry="replicated_log" --registry_fetch_timeout="1mins"
> --registry_store_timeout="25secs" --registry_strict="true"
> --root_submissions="true" --slave_ping_timeout="15secs"
> --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.26.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ContentType_SchedulerTest_Request_1_67yruV/master"
> --zk_session_timeout="10secs"
> I0925 19:19:58.932114 27439 master.cpp:425] Master allowing
> unauthenticated frameworks to register
> I0925 19:19:58.932124 27439 master.cpp:428] Master only allowing
> authenticated slaves to register
> I0925 19:19:58.932131 27439 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerTest_Request_1_67yruV/credentials'
> I0925 19:19:58.932137 27428 recover.cpp:475] Replica is in STARTING status
> I0925 19:19:58.932391 27439 master.cpp:467] Using default 'crammd5'
> authenticator
> I0925 19:19:58.932520 27439 master.cpp:504] Authorization enabled
> I0925 19:19:58.932739 27434 whitelist_watcher.cpp:79] No whitelist given
> I0925 19:19:58.932777 27442 hierarchical.hpp:468] Initialized hierarchical
> allocator process
> I0925 19:19:58.933187 27443 replica.cpp:641] Replica in STARTING status
> received a broadcasted recover request
> I0925 19:19:58.933696 27428 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I0925 19:19:58.934219 27434 recover.cpp:566] Updating replica status to
> VOTING
> I0925 19:19:58.934450 27434 master.cpp:1603] The newly elected leader is
> master@172.17.1.195:41781 with id 47f734c8-fc60-401b-a023-708247890958
> I0925 19:19:58.934516 27434 master.cpp:1616] Elected as the leading master!
> I0925 19:19:58.934535 27434 master.cpp:1376] Recovering from registrar
> I0925 19:19:58.934660 27435 registrar.cpp:309] Recovering registrar
> I0925 19:19:58.934677 27428 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 363516ns
> I0925 19:19:58.934705 27428 replica.cpp:323] Persisted replica status to
> VOTING
> I0925 19:19:58.934862 27433 recover.cpp:580] Successfully joined the Paxos
> group
> I0925 19:19:58.935127 27433 recover.cpp:464] Recover process terminated
> I0925 19:19:58.935648 27432 log.cpp:661] Attempting to start the writer
> I0925 19:19:58.936688 27442 replica.cpp:477] Replica received implicit
> promise request with proposal 1
> I0925 19:19:58.937001 27442 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 297340ns
> I0925 19:19:58.937023 27442 replica.cpp:345] Persisted promised to 1
> I0925 19:19:58.937662 27442 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I0925 19:19:58.938869 27442 replica.cpp:378] Replica received explicit
> promise request for position 0 with proposal 2
> I0925 19:19:58.939180 27442 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 287084ns
> I0925 19:19:58.939208 27442 replica.cpp:679] Persisted action at 0
> I0925 19:19:58.940155 27432 replica.cpp:511] Replica received write
> request for position 0
> I0925 19:19:58.940227 27432 leveldb.cpp:438] Reading position from leveldb
> took 45464ns
> I0925 19:19:58.940560 27432 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 294193ns
> I0925 19:19:58.940630 27432 replica.cpp:679] Persisted action at 0
> I0925 19:19:58.941150 27439 replica.cpp:658] Replica received learned
> notice for position 0
> I0925 19:19:58.941444 27439 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 281925ns
> I0925 19:19:58.941467 27439 replica.cpp:679] Persisted action at 0
> I0925 19:19:58.941480 27439 replica.cpp:664] Replica learned NOP action at
> position 0
> I0925 19:19:58.942062 27431 log.cpp:677] Writer started with ending
> position 0
> I0925 19:19:58.943099 27438 leveldb.cpp:438] Reading position from leveldb
> took 92638ns
> I0925 19:19:58.944039 27438 registrar.cpp:342] Successfully fetched the
> registry (0B) in 9.340928ms
> I0925 19:19:58.944149 27438 registrar.cpp:441] Applied 1 operations in
> 35111ns; attempting to update the 'registry'
> I0925 19:19:58.944828 27437 log.cpp:685] Attempting to append 176 bytes to
> the log
> I0925 19:19:58.944928 27436 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I0925 19:19:58.945694 27437 replica.cpp:511] Replica received write
> request for position 1
> I0925 19:19:58.946032 27437 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 320087ns
> I0925 19:19:58.946053 27437 replica.cpp:679] Persisted action at 1
> I0925 19:19:58.946627 27441 replica.cpp:658] Replica received learned
> notice for position 1
> I0925 19:19:58.946948 27441 leveldb.cpp:343] Persisting action (197 bytes)
> to leveldb took 306869ns
> I0925 19:19:58.946972 27441 replica.cpp:679] Persisted action at 1
> I0925 19:19:58.946991 27441 replica.cpp:664] Replica learned APPEND action
> at position 1
> I0925 19:19:58.947918 27435 registrar.cpp:486] Successfully updated the
> 'registry' in 3.650048ms
> I0925 19:19:58.948065 27435 registrar.cpp:372] Successfully recovered
> registrar
> I0925 19:19:58.948199 27440 log.cpp:704] Attempting to truncate the log to
> 1
> I0925 19:19:58.948369 27431 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I0925 19:19:58.948417 27439 master.cpp:1413] Recovered 0 slaves from the
> Registry (137B) ; allowing 10mins for slaves to re-register
> I0925 19:19:58.949136 27440 replica.cpp:511] Replica received write
> request for position 2
> I0925 19:19:58.949443 27440 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 288335ns
> I0925 19:19:58.949468 27440 replica.cpp:679] Persisted action at 2
> I0925 19:19:58.949954 27430 replica.cpp:658] Replica received learned
> notice for position 2
> I0925 19:19:58.950275 27430 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 308229ns
> I0925 19:19:58.950330 27430 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 42022ns
> I0925 19:19:58.950364 27430 replica.cpp:679] Persisted action at 2
> I0925 19:19:58.950387 27430 replica.cpp:664] Replica learned TRUNCATE
> action at position 2
> I0925 19:19:58.959220 27410 scheduler.cpp:157] Version: 0.26.0
> I0925 19:19:58.959782 27434 scheduler.cpp:240] New master detected at
> master@172.17.1.195:41781
> I0925 19:19:58.960824 27443 scheduler.cpp:302] Sending SUBSCRIBE call to
> master@172.17.1.195:41781
> I0925 19:19:58.962537 27440 process.cpp:3021] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0925 19:19:58.962748 27440 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.1.195:56048
> I0925 19:19:58.963075 27440 master.cpp:1865] Received subscription request
> for HTTP framework 'default'
> I0925 19:19:58.963102 27440 master.cpp:1642] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0925 19:19:58.963371 27431 master.cpp:1957] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0925 19:19:58.963747 27442 hierarchical.hpp:515] Added framework
> 47f734c8-fc60-401b-a023-708247890958-0000
> I0925 19:19:58.963780 27442 hierarchical.hpp:1326] No resources available
> to allocate!
> I0925 19:19:58.963803 27442 hierarchical.hpp:1421] No inverse offers to
> send out!
> I0925 19:19:58.963819 27442 hierarchical.hpp:1221] Performed allocation
> for 0 slaves in 58822ns
> I0925 19:19:58.963853 27442 master.hpp:1431] Sending heartbeat to
> 47f734c8-fc60-401b-a023-708247890958-0000
> I0925 19:19:58.964740 27438 scheduler.cpp:461] Enqueuing event SUBSCRIBED
> received from master@172.17.1.195:41781
> I0925 19:19:58.965126 27438 scheduler.cpp:461] Enqueuing event HEARTBEAT
> received from master@172.17.1.195:41781
> I0925 19:19:58.965698 27428 master_maintenance_tests.cpp:179] Ignoring
> HEARTBEAT event
> I0925 19:19:58.965734 27438 scheduler.cpp:302] Sending REQUEST call to
> master@172.17.1.195:41781
> I0925 19:19:58.966987 27428 process.cpp:3021] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0925 19:19:58.967206 27428 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.1.195:56049
> I0925 19:19:58.967437 27428 master.cpp:2618] Processing REQUEST call for
> framework 47f734c8-fc60-401b-a023-708247890958-0000 (default)
> I0925 19:19:58.967689 27431 hierarchical.hpp:801] Received resource
> request from framework 47f734c8-fc60-401b-a023-708247890958-0000
> I0925 19:19:58.968124 27443 master.cpp:919] Master terminating
> I0925 19:19:58.968598 27441 hierarchical.hpp:552] Removed framework
> 47f734c8-fc60-401b-a023-708247890958-0000
> E0925 19:19:58.969264 27437 scheduler.cpp:435] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (49 ms)
> [----------] 22 tests from ContentType/SchedulerTest (3995 ms total)
>
> [----------] Global test environment tear-down
> [==========] 804 tests from 110 test cases ran. (323152 ms total)
> [ PASSED ] 803 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] FetcherCacheTest.LocalUncachedExtract
>
> 1 FAILED TEST
> YOU HAVE 7 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> make[4]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.26.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.26.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1443207316-10843
> Untagged: mesos-1443207316-10843:latest
> Deleted: 7cafaf8a572a6f34cdedddd3239f7fcab2712ea698aa80c7f4ce09579852dd4d
> Deleted: 94a4105720f9bf45d7530242694d86e58bd0b6ae780a4ad95e79254b01529a97
> Deleted: 8cf0e5ec97a6ed1135d77860a81b7c6bab85c5a7164523ad2db5c3f42234504f
> Deleted: 7a63b4909d1a88fcae2e403f86960aab2f3470df780792c62001f0d42e286b06
> Deleted: a991b8a445688d9b22e14ad144111a14689f191f8bc09eb9142b9694545f59a1
> Deleted: 4610a9cc3ba3d7f8f2436b2cf552a3095e2b40746b3e3d893218c6441f110110
> Deleted: 47e15b03be1843eb3c68dea45eea1b68ac5f56c448b6d1b3290dc392be236e3c
> Deleted: af0f4f7d726be5aa06c9dc723beea5d89d54bd5cf13c287cce2ebc94b7523166
> Deleted: ab001ee06920910e556202efe1b98d885fd2b8c68f678433c881c23a46990f35
> Deleted: ac5f01fe5c52cabb9906201cfa9f8cba89aac50abb914a3debb817986799c517
> Deleted: 9c6653ba5bbbd505607d65d914b8cc8b6753b739841776178b3946791cb427a4
> Deleted: 32b6b6aa07f22bdbd555e6320330a423178d1173b38bbd86e87a79cfe684e101
> Deleted: 992078bd72b0a30f380dd7303af6902df811ffc4f4c99f84de90bbab794bcbc4
> Build step 'Execute shell' marked build as failure
>