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/22 19:35:23 UTC
Build failed in Jenkins: Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #839
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/839/changes>
Changes:
[yan] Some leftover fix from the provisioner unification.
------------------------------------------
[...truncated 130903 lines...]
W0922 17:32:11.669666 28460 slave.cpp:3181] Master disconnected! Waiting for a new master to be elected
E0922 17:32:11.670172 28452 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
I0922 17:32:11.674759 28453 slave.cpp:3434] Executor 'default' of framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000 exited with status 0
I0922 17:32:11.674878 28453 slave.cpp:2711] Handling status update TASK_LOST (UUID: 968f6e5a-b787-4830-8d05-809e497dd419) for task de0a9040-4798-449c-841e-380dade88cf5 of framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000 from @0.0.0.0:0
I0922 17:32:11.675067 28453 slave.cpp:5141] Terminating task de0a9040-4798-449c-841e-380dade88cf5
I0922 17:32:11.675688 28453 slave.cpp:579] Slave terminating
I0922 17:32:11.675768 28453 slave.cpp:1974] Asked to shut down framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000 by @0.0.0.0:0
I0922 17:32:11.675812 28453 slave.cpp:1999] Shutting down framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000
I0922 17:32:11.675971 28453 slave.cpp:3538] Cleaning up executor 'default' of framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000
I0922 17:32:11.676231 28449 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_O1LYs2/slaves/679318a6-b07b-4c7a-96c8-6be9be37d777-S0/frameworks/679318a6-b07b-4c7a-96c8-6be9be37d777-0000/executors/default/runs/98633566-0590-4708-b25f-0fd405d2ab9a' for gc 6.99999217443259days in the future
I0922 17:32:11.676414 28453 slave.cpp:3627] Cleaning up framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000
I0922 17:32:11.676416 28449 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_O1LYs2/slaves/679318a6-b07b-4c7a-96c8-6be9be37d777-S0/frameworks/679318a6-b07b-4c7a-96c8-6be9be37d777-0000/executors/default' for gc 6.99999217231407days in the future
I0922 17:32:11.676626 28457 status_update_manager.cpp:284] Closing status update streams for framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000
I0922 17:32:11.676683 28457 status_update_manager.cpp:530] Cleaning up status update stream for task de0a9040-4798-449c-841e-380dade88cf5 of framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000
I0922 17:32:11.676795 28458 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_O1LYs2/slaves/679318a6-b07b-4c7a-96c8-6be9be37d777-S0/frameworks/679318a6-b07b-4c7a-96c8-6be9be37d777-0000' for gc 6.99999216812741days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (108 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_aC3pBp'
I0922 17:32:11.683815 28430 leveldb.cpp:176] Opened db in 2.477017ms
I0922 17:32:11.684849 28430 leveldb.cpp:183] Compacted db in 1.000668ms
I0922 17:32:11.684900 28430 leveldb.cpp:198] Created db iterator in 18993ns
I0922 17:32:11.684917 28430 leveldb.cpp:204] Seeked to beginning of db in 1926ns
I0922 17:32:11.684924 28430 leveldb.cpp:273] Iterated through 0 keys in the db in 322ns
I0922 17:32:11.684965 28430 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0922 17:32:11.685330 28450 recover.cpp:449] Starting replica recovery
I0922 17:32:11.685606 28450 recover.cpp:475] Replica is in EMPTY status
I0922 17:32:11.687515 28455 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0922 17:32:11.688010 28456 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0922 17:32:11.688596 28458 recover.cpp:566] Updating replica status to STARTING
I0922 17:32:11.689322 28461 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 529449ns
I0922 17:32:11.689352 28461 replica.cpp:323] Persisted replica status to STARTING
I0922 17:32:11.689615 28455 recover.cpp:475] Replica is in STARTING status
I0922 17:32:11.689854 28453 master.cpp:370] Master 7fe9efff-3f39-4666-b3e0-f796d2e7ced4 (ec5aa1e3f113) started on 172.17.2.62:56841
I0922 17:32:11.689888 28453 master.cpp:372] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ContentType_SchedulerTest_Request_0_aC3pBp/credentials" --framework_sorter="drf" --help="false" --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.25.0/_inst/share/mesos/webui" --work_dir="/tmp/ContentType_SchedulerTest_Request_0_aC3pBp/master" --zk_session_timeout="10secs"
I0922 17:32:11.690251 28453 master.cpp:419] Master allowing unauthenticated frameworks to register
I0922 17:32:11.690268 28453 master.cpp:422] Master only allowing authenticated slaves to register
I0922 17:32:11.690282 28453 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_0_aC3pBp/credentials'
I0922 17:32:11.690687 28452 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0922 17:32:11.690803 28453 master.cpp:461] Using default 'crammd5' authenticator
I0922 17:32:11.690997 28453 master.cpp:498] Authorization enabled
I0922 17:32:11.691154 28459 recover.cpp:195] Received a recover response from a replica in STARTING status
I0922 17:32:11.691272 28458 hierarchical.hpp:464] Initialized hierarchical allocator process
I0922 17:32:11.691272 28456 whitelist_watcher.cpp:79] No whitelist given
I0922 17:32:11.691694 28456 recover.cpp:566] Updating replica status to VOTING
I0922 17:32:11.692412 28457 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 405932ns
I0922 17:32:11.692442 28457 replica.cpp:323] Persisted replica status to VOTING
I0922 17:32:11.692625 28458 recover.cpp:580] Successfully joined the Paxos group
I0922 17:32:11.692797 28452 master.cpp:1597] The newly elected leader is master@172.17.2.62:56841 with id 7fe9efff-3f39-4666-b3e0-f796d2e7ced4
I0922 17:32:11.692831 28452 master.cpp:1610] Elected as the leading master!
I0922 17:32:11.692853 28452 master.cpp:1370] Recovering from registrar
I0922 17:32:11.692937 28458 recover.cpp:464] Recover process terminated
I0922 17:32:11.692991 28453 registrar.cpp:309] Recovering registrar
I0922 17:32:11.693634 28455 log.cpp:661] Attempting to start the writer
I0922 17:32:11.694921 28464 replica.cpp:477] Replica received implicit promise request with proposal 1
I0922 17:32:11.695412 28464 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 466101ns
I0922 17:32:11.695436 28464 replica.cpp:345] Persisted promised to 1
I0922 17:32:11.696022 28458 coordinator.cpp:231] Coordinator attemping to fill missing position
I0922 17:32:11.697191 28456 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0922 17:32:11.697574 28456 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 348861ns
I0922 17:32:11.697597 28456 replica.cpp:679] Persisted action at 0
I0922 17:32:11.698516 28449 replica.cpp:511] Replica received write request for position 0
I0922 17:32:11.698609 28449 leveldb.cpp:438] Reading position from leveldb took 63381ns
I0922 17:32:11.699031 28449 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 375697ns
I0922 17:32:11.699053 28449 replica.cpp:679] Persisted action at 0
I0922 17:32:11.699652 28450 replica.cpp:658] Replica received learned notice for position 0
I0922 17:32:11.700026 28450 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 347184ns
I0922 17:32:11.700048 28450 replica.cpp:679] Persisted action at 0
I0922 17:32:11.700063 28450 replica.cpp:664] Replica learned NOP action at position 0
I0922 17:32:11.700775 28457 log.cpp:677] Writer started with ending position 0
I0922 17:32:11.701774 28452 leveldb.cpp:438] Reading position from leveldb took 25932ns
I0922 17:32:11.702639 28453 registrar.cpp:342] Successfully fetched the registry (0B) in 9.586944ms
I0922 17:32:11.702744 28453 registrar.cpp:441] Applied 1 operations in 23899ns; attempting to update the 'registry'
I0922 17:32:11.703392 28457 log.cpp:685] Attempting to append 174 bytes to the log
I0922 17:32:11.703511 28464 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0922 17:32:11.704135 28464 replica.cpp:511] Replica received write request for position 1
I0922 17:32:11.704458 28464 leveldb.cpp:343] Persisting action (193 bytes) to leveldb took 294133ns
I0922 17:32:11.704481 28464 replica.cpp:679] Persisted action at 1
I0922 17:32:11.705051 28450 replica.cpp:658] Replica received learned notice for position 1
I0922 17:32:11.705416 28450 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 342726ns
I0922 17:32:11.705440 28450 replica.cpp:679] Persisted action at 1
I0922 17:32:11.705454 28450 replica.cpp:664] Replica learned APPEND action at position 1
I0922 17:32:11.706307 28462 registrar.cpp:486] Successfully updated the 'registry' in 3.494912ms
I0922 17:32:11.706449 28462 registrar.cpp:372] Successfully recovered registrar
I0922 17:32:11.706521 28464 log.cpp:704] Attempting to truncate the log to 1
I0922 17:32:11.706763 28452 master.cpp:1407] Recovered 0 slaves from the Registry (135B) ; allowing 10mins for slaves to re-register
I0922 17:32:11.706946 28459 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0922 17:32:11.707692 28452 replica.cpp:511] Replica received write request for position 2
I0922 17:32:11.708045 28452 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 321750ns
I0922 17:32:11.708066 28452 replica.cpp:679] Persisted action at 2
I0922 17:32:11.708642 28461 replica.cpp:658] Replica received learned notice for position 2
I0922 17:32:11.709002 28461 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 330650ns
I0922 17:32:11.709046 28461 leveldb.cpp:401] Deleting ~1 keys from leveldb took 23556ns
I0922 17:32:11.709069 28461 replica.cpp:679] Persisted action at 2
I0922 17:32:11.709095 28461 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0922 17:32:11.717655 28430 scheduler.cpp:157] Version: 0.25.0
I0922 17:32:11.718233 28450 scheduler.cpp:240] New master detected at master@172.17.2.62:56841
I0922 17:32:11.719460 28452 scheduler.cpp:302] Sending SUBSCRIBE call to master@172.17.2.62:56841
I0922 17:32:11.721127 28458 process.cpp:3021] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0922 17:32:11.721343 28458 http.cpp:335] HTTP POST for /master/api/v1/scheduler from 172.17.2.62:43052
I0922 17:32:11.721547 28458 master.cpp:1859] Received subscription request for HTTP framework 'default'
I0922 17:32:11.721644 28458 master.cpp:1636] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0922 17:32:11.721920 28458 master.cpp:1951] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0922 17:32:11.722363 28454 hierarchical.hpp:511] Added framework 7fe9efff-3f39-4666-b3e0-f796d2e7ced4-0000
I0922 17:32:11.722396 28456 master.hpp:1431] Sending heartbeat to 7fe9efff-3f39-4666-b3e0-f796d2e7ced4-0000
I0922 17:32:11.722544 28454 hierarchical.hpp:1299] No resources available to allocate!
I0922 17:32:11.722602 28454 hierarchical.hpp:1394] No inverse offers to send out!
I0922 17:32:11.722627 28454 hierarchical.hpp:1194] Performed allocation for 0 slaves in 93379ns
I0922 17:32:11.723692 28452 scheduler.cpp:461] Enqueuing event SUBSCRIBED received from master@172.17.2.62:56841
I0922 17:32:11.724251 28452 scheduler.cpp:461] Enqueuing event HEARTBEAT received from master@172.17.2.62:56841
I0922 17:32:11.725080 28453 master_maintenance_tests.cpp:179] Ignoring HEARTBEAT event
I0922 17:32:11.725119 28452 scheduler.cpp:302] Sending REQUEST call to master@172.17.2.62:56841
I0922 17:32:11.726732 28461 process.cpp:3021] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0922 17:32:11.726927 28461 http.cpp:335] HTTP POST for /master/api/v1/scheduler from 172.17.2.62:43053
I0922 17:32:11.727061 28461 master.cpp:2612] Processing REQUEST call for framework 7fe9efff-3f39-4666-b3e0-f796d2e7ced4-0000 (default)
I0922 17:32:11.727264 28452 hierarchical.hpp:797] Received resource request from framework 7fe9efff-3f39-4666-b3e0-f796d2e7ced4-0000
I0922 17:32:11.727532 28430 master.cpp:913] Master terminating
I0922 17:32:11.727746 28455 hierarchical.hpp:548] Removed framework 7fe9efff-3f39-4666-b3e0-f796d2e7ced4-0000
E0922 17:32:11.729722 28453 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_sgrMSc'
I0922 17:32:11.736222 28430 leveldb.cpp:176] Opened db in 2.396188ms
I0922 17:32:11.737220 28430 leveldb.cpp:183] Compacted db in 967368ns
I0922 17:32:11.737267 28430 leveldb.cpp:198] Created db iterator in 20356ns
I0922 17:32:11.737283 28430 leveldb.cpp:204] Seeked to beginning of db in 2245ns
I0922 17:32:11.737290 28430 leveldb.cpp:273] Iterated through 0 keys in the db in 313ns
I0922 17:32:11.737329 28430 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0922 17:32:11.737782 28459 recover.cpp:449] Starting replica recovery
I0922 17:32:11.738109 28459 recover.cpp:475] Replica is in EMPTY status
I0922 17:32:11.739254 28457 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0922 17:32:11.739773 28464 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0922 17:32:11.740413 28453 recover.cpp:566] Updating replica status to STARTING
I0922 17:32:11.741190 28452 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 554748ns
I0922 17:32:11.741225 28452 replica.cpp:323] Persisted replica status to STARTING
I0922 17:32:11.741484 28456 master.cpp:370] Master 5b053d9b-09d6-40d9-9345-b48bb8c42907 (ec5aa1e3f113) started on 172.17.2.62:56841
I0922 17:32:11.741499 28452 recover.cpp:475] Replica is in STARTING status
I0922 17:32:11.741516 28456 master.cpp:372] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ContentType_SchedulerTest_Request_1_sgrMSc/credentials" --framework_sorter="drf" --help="false" --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.25.0/_inst/share/mesos/webui" --work_dir="/tmp/ContentType_SchedulerTest_Request_1_sgrMSc/master" --zk_session_timeout="10secs"
I0922 17:32:11.741909 28456 master.cpp:419] Master allowing unauthenticated frameworks to register
I0922 17:32:11.741925 28456 master.cpp:422] Master only allowing authenticated slaves to register
I0922 17:32:11.741937 28456 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_1_sgrMSc/credentials'
I0922 17:32:11.742231 28456 master.cpp:461] Using default 'crammd5' authenticator
I0922 17:32:11.742377 28456 master.cpp:498] Authorization enabled
I0922 17:32:11.742514 28454 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0922 17:32:11.742635 28461 hierarchical.hpp:464] Initialized hierarchical allocator process
I0922 17:32:11.742635 28460 whitelist_watcher.cpp:79] No whitelist given
I0922 17:32:11.743051 28464 recover.cpp:195] Received a recover response from a replica in STARTING status
I0922 17:32:11.743643 28460 recover.cpp:566] Updating replica status to VOTING
I0922 17:32:11.744099 28462 master.cpp:1597] The newly elected leader is master@172.17.2.62:56841 with id 5b053d9b-09d6-40d9-9345-b48bb8c42907
I0922 17:32:11.744108 28464 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 302983ns
I0922 17:32:11.744130 28462 master.cpp:1610] Elected as the leading master!
I0922 17:32:11.744129 28464 replica.cpp:323] Persisted replica status to VOTING
I0922 17:32:11.744148 28462 master.cpp:1370] Recovering from registrar
I0922 17:32:11.744232 28457 recover.cpp:580] Successfully joined the Paxos group
I0922 17:32:11.744293 28461 registrar.cpp:309] Recovering registrar
I0922 17:32:11.744514 28457 recover.cpp:464] Recover process terminated
I0922 17:32:11.745136 28458 log.cpp:661] Attempting to start the writer
I0922 17:32:11.746587 28464 replica.cpp:477] Replica received implicit promise request with proposal 1
I0922 17:32:11.747120 28464 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 496323ns
I0922 17:32:11.747154 28464 replica.cpp:345] Persisted promised to 1
I0922 17:32:11.747902 28461 coordinator.cpp:231] Coordinator attemping to fill missing position
I0922 17:32:11.749243 28457 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0922 17:32:11.749675 28457 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 390543ns
I0922 17:32:11.749701 28457 replica.cpp:679] Persisted action at 0
I0922 17:32:11.750936 28453 replica.cpp:511] Replica received write request for position 0
I0922 17:32:11.750990 28453 leveldb.cpp:438] Reading position from leveldb took 28740ns
I0922 17:32:11.751354 28453 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 321213ns
I0922 17:32:11.751377 28453 replica.cpp:679] Persisted action at 0
I0922 17:32:11.751983 28463 replica.cpp:658] Replica received learned notice for position 0
I0922 17:32:11.752364 28463 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 345456ns
I0922 17:32:11.752393 28463 replica.cpp:679] Persisted action at 0
I0922 17:32:11.752418 28463 replica.cpp:664] Replica learned NOP action at position 0
I0922 17:32:11.753047 28449 log.cpp:677] Writer started with ending position 0
I0922 17:32:11.754304 28450 leveldb.cpp:438] Reading position from leveldb took 33462ns
I0922 17:32:11.755394 28452 registrar.cpp:342] Successfully fetched the registry (0B) in 11.051264ms
I0922 17:32:11.755508 28452 registrar.cpp:441] Applied 1 operations in 22989ns; attempting to update the 'registry'
I0922 17:32:11.756356 28450 log.cpp:685] Attempting to append 174 bytes to the log
I0922 17:32:11.756520 28458 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0922 17:32:11.757511 28450 replica.cpp:511] Replica received write request for position 1
I0922 17:32:11.758038 28450 leveldb.cpp:343] Persisting action (193 bytes) to leveldb took 486870ns
I0922 17:32:11.758069 28450 replica.cpp:679] Persisted action at 1
I0922 17:32:11.759572 28461 replica.cpp:658] Replica received learned notice for position 1
I0922 17:32:11.759994 28461 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 388381ns
I0922 17:32:11.760025 28461 replica.cpp:679] Persisted action at 1
I0922 17:32:11.760048 28461 replica.cpp:664] Replica learned APPEND action at position 1
I0922 17:32:11.761176 28452 registrar.cpp:486] Successfully updated the 'registry' in 5.595136ms
I0922 17:32:11.761317 28452 registrar.cpp:372] Successfully recovered registrar
I0922 17:32:11.761417 28464 log.cpp:704] Attempting to truncate the log to 1
I0922 17:32:11.761764 28461 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0922 17:32:11.761775 28453 master.cpp:1407] Recovered 0 slaves from the Registry (135B) ; allowing 10mins for slaves to re-register
I0922 17:32:11.762728 28451 replica.cpp:511] Replica received write request for position 2
I0922 17:32:11.763176 28451 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 405560ns
I0922 17:32:11.763207 28451 replica.cpp:679] Persisted action at 2
I0922 17:32:11.763919 28459 replica.cpp:658] Replica received learned notice for position 2
I0922 17:32:11.764309 28459 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 358530ns
I0922 17:32:11.764371 28459 leveldb.cpp:401] Deleting ~1 keys from leveldb took 32758ns
I0922 17:32:11.764395 28459 replica.cpp:679] Persisted action at 2
I0922 17:32:11.764418 28459 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0922 17:32:11.772625 28430 scheduler.cpp:157] Version: 0.25.0
I0922 17:32:11.773272 28459 scheduler.cpp:240] New master detected at master@172.17.2.62:56841
I0922 17:32:11.774359 28460 scheduler.cpp:302] Sending SUBSCRIBE call to master@172.17.2.62:56841
I0922 17:32:11.776207 28454 process.cpp:3021] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0922 17:32:11.776437 28454 http.cpp:335] HTTP POST for /master/api/v1/scheduler from 172.17.2.62:43054
I0922 17:32:11.776769 28454 master.cpp:1859] Received subscription request for HTTP framework 'default'
I0922 17:32:11.776849 28454 master.cpp:1636] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0922 17:32:11.777098 28454 master.cpp:1951] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0922 17:32:11.777488 28449 hierarchical.hpp:511] Added framework 5b053d9b-09d6-40d9-9345-b48bb8c42907-0000
I0922 17:32:11.777515 28449 hierarchical.hpp:1299] No resources available to allocate!
I0922 17:32:11.777529 28449 hierarchical.hpp:1394] No inverse offers to send out!
I0922 17:32:11.777539 28449 hierarchical.hpp:1194] Performed allocation for 0 slaves in 29655ns
I0922 17:32:11.777673 28449 master.hpp:1431] Sending heartbeat to 5b053d9b-09d6-40d9-9345-b48bb8c42907-0000
I0922 17:32:11.778769 28454 scheduler.cpp:461] Enqueuing event SUBSCRIBED received from master@172.17.2.62:56841
I0922 17:32:11.779206 28454 scheduler.cpp:461] Enqueuing event HEARTBEAT received from master@172.17.2.62:56841
I0922 17:32:11.779758 28452 master_maintenance_tests.cpp:179] Ignoring HEARTBEAT event
I0922 17:32:11.779799 28454 scheduler.cpp:302] Sending REQUEST call to master@172.17.2.62:56841
I0922 17:32:11.781327 28455 process.cpp:3021] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0922 17:32:11.781468 28455 http.cpp:335] HTTP POST for /master/api/v1/scheduler from 172.17.2.62:43055
I0922 17:32:11.781723 28455 master.cpp:2612] Processing REQUEST call for framework 5b053d9b-09d6-40d9-9345-b48bb8c42907-0000 (default)
I0922 17:32:11.781973 28457 hierarchical.hpp:797] Received resource request from framework 5b053d9b-09d6-40d9-9345-b48bb8c42907-0000
I0922 17:32:11.782176 28462 master.cpp:913] Master terminating
I0922 17:32:11.782327 28458 hierarchical.hpp:548] Removed framework 5b053d9b-09d6-40d9-9345-b48bb8c42907-0000
E0922 17:32:11.784400 28456 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (55 ms)
[----------] 22 tests from ContentType/SchedulerTest (4019 ms total)
[----------] Global test environment tear-down
[==========] 792 tests from 108 test cases ran. (321041 ms total)
[ PASSED ] 791 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ContentType/ExecutorHttpApiTest.DefaultAccept/0, where GetParam() = application/x-protobuf
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.25.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1442941607-9179
Untagged: mesos-1442941607-9179:latest
Deleted: 9ac0349a88149bb1ffc840974a917b64f90456fa6c32933296c17389d4cbf6c1
Deleted: 918c3cb1f1270b0bda2fc3ce47499ad7c77dca3baef9b23976f8c0061ec82703
Deleted: 906a045c0651f40c29491ceb62efab585522cf6c7ed65aae2aee5a1b03624910
Deleted: 0660ff78140c00cc1e1a9b23bc24d79bb49559ac92ba287aca43b6b2bbca5ba7
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #839
Posted by Vinod Kone <vi...@apache.org>.
+anand, can you take a look?
On Tue, Sep 22, 2015 at 10:35 AM, 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/839/changes
> >
>
> Changes:
>
> [yan] Some leftover fix from the provisioner unification.
>
> ------------------------------------------
> [...truncated 130903 lines...]
> W0922 17:32:11.669666 28460 slave.cpp:3181] Master disconnected! Waiting
> for a new master to be elected
> E0922 17:32:11.670172 28452 scheduler.cpp:435] End-Of-File received from
> master. The master closed the event stream
> I0922 17:32:11.674759 28453 slave.cpp:3434] Executor 'default' of
> framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000 exited with status 0
> I0922 17:32:11.674878 28453 slave.cpp:2711] Handling status update
> TASK_LOST (UUID: 968f6e5a-b787-4830-8d05-809e497dd419) for task
> de0a9040-4798-449c-841e-380dade88cf5 of framework
> 679318a6-b07b-4c7a-96c8-6be9be37d777-0000 from @0.0.0.0:0
> I0922 17:32:11.675067 28453 slave.cpp:5141] Terminating task
> de0a9040-4798-449c-841e-380dade88cf5
> I0922 17:32:11.675688 28453 slave.cpp:579] Slave terminating
> I0922 17:32:11.675768 28453 slave.cpp:1974] Asked to shut down framework
> 679318a6-b07b-4c7a-96c8-6be9be37d777-0000 by @0.0.0.0:0
> I0922 17:32:11.675812 28453 slave.cpp:1999] Shutting down framework
> 679318a6-b07b-4c7a-96c8-6be9be37d777-0000
> I0922 17:32:11.675971 28453 slave.cpp:3538] Cleaning up executor 'default'
> of framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000
> I0922 17:32:11.676231 28449 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_O1LYs2/slaves/679318a6-b07b-4c7a-96c8-6be9be37d777-S0/frameworks/679318a6-b07b-4c7a-96c8-6be9be37d777-0000/executors/default/runs/98633566-0590-4708-b25f-0fd405d2ab9a'
> for gc 6.99999217443259days in the future
> I0922 17:32:11.676414 28453 slave.cpp:3627] Cleaning up framework
> 679318a6-b07b-4c7a-96c8-6be9be37d777-0000
> I0922 17:32:11.676416 28449 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_O1LYs2/slaves/679318a6-b07b-4c7a-96c8-6be9be37d777-S0/frameworks/679318a6-b07b-4c7a-96c8-6be9be37d777-0000/executors/default'
> for gc 6.99999217231407days in the future
> I0922 17:32:11.676626 28457 status_update_manager.cpp:284] Closing status
> update streams for framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000
> I0922 17:32:11.676683 28457 status_update_manager.cpp:530] Cleaning up
> status update stream for task de0a9040-4798-449c-841e-380dade88cf5 of
> framework 679318a6-b07b-4c7a-96c8-6be9be37d777-0000
> I0922 17:32:11.676795 28458 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_O1LYs2/slaves/679318a6-b07b-4c7a-96c8-6be9be37d777-S0/frameworks/679318a6-b07b-4c7a-96c8-6be9be37d777-0000'
> for gc 6.99999216812741days in the future
> [ OK ] ContentType/SchedulerTest.Message/1 (108 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_aC3pBp'
> I0922 17:32:11.683815 28430 leveldb.cpp:176] Opened db in 2.477017ms
> I0922 17:32:11.684849 28430 leveldb.cpp:183] Compacted db in 1.000668ms
> I0922 17:32:11.684900 28430 leveldb.cpp:198] Created db iterator in 18993ns
> I0922 17:32:11.684917 28430 leveldb.cpp:204] Seeked to beginning of db in
> 1926ns
> I0922 17:32:11.684924 28430 leveldb.cpp:273] Iterated through 0 keys in
> the db in 322ns
> I0922 17:32:11.684965 28430 replica.cpp:744] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0922 17:32:11.685330 28450 recover.cpp:449] Starting replica recovery
> I0922 17:32:11.685606 28450 recover.cpp:475] Replica is in EMPTY status
> I0922 17:32:11.687515 28455 replica.cpp:641] Replica in EMPTY status
> received a broadcasted recover request
> I0922 17:32:11.688010 28456 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I0922 17:32:11.688596 28458 recover.cpp:566] Updating replica status to
> STARTING
> I0922 17:32:11.689322 28461 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 529449ns
> I0922 17:32:11.689352 28461 replica.cpp:323] Persisted replica status to
> STARTING
> I0922 17:32:11.689615 28455 recover.cpp:475] Replica is in STARTING status
> I0922 17:32:11.689854 28453 master.cpp:370] Master
> 7fe9efff-3f39-4666-b3e0-f796d2e7ced4 (ec5aa1e3f113) started on
> 172.17.2.62:56841
> I0922 17:32:11.689888 28453 master.cpp:372] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ContentType_SchedulerTest_Request_0_aC3pBp/credentials"
> --framework_sorter="drf" --help="false" --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.25.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ContentType_SchedulerTest_Request_0_aC3pBp/master"
> --zk_session_timeout="10secs"
> I0922 17:32:11.690251 28453 master.cpp:419] Master allowing
> unauthenticated frameworks to register
> I0922 17:32:11.690268 28453 master.cpp:422] Master only allowing
> authenticated slaves to register
> I0922 17:32:11.690282 28453 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerTest_Request_0_aC3pBp/credentials'
> I0922 17:32:11.690687 28452 replica.cpp:641] Replica in STARTING status
> received a broadcasted recover request
> I0922 17:32:11.690803 28453 master.cpp:461] Using default 'crammd5'
> authenticator
> I0922 17:32:11.690997 28453 master.cpp:498] Authorization enabled
> I0922 17:32:11.691154 28459 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I0922 17:32:11.691272 28458 hierarchical.hpp:464] Initialized hierarchical
> allocator process
> I0922 17:32:11.691272 28456 whitelist_watcher.cpp:79] No whitelist given
> I0922 17:32:11.691694 28456 recover.cpp:566] Updating replica status to
> VOTING
> I0922 17:32:11.692412 28457 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 405932ns
> I0922 17:32:11.692442 28457 replica.cpp:323] Persisted replica status to
> VOTING
> I0922 17:32:11.692625 28458 recover.cpp:580] Successfully joined the Paxos
> group
> I0922 17:32:11.692797 28452 master.cpp:1597] The newly elected leader is
> master@172.17.2.62:56841 with id 7fe9efff-3f39-4666-b3e0-f796d2e7ced4
> I0922 17:32:11.692831 28452 master.cpp:1610] Elected as the leading master!
> I0922 17:32:11.692853 28452 master.cpp:1370] Recovering from registrar
> I0922 17:32:11.692937 28458 recover.cpp:464] Recover process terminated
> I0922 17:32:11.692991 28453 registrar.cpp:309] Recovering registrar
> I0922 17:32:11.693634 28455 log.cpp:661] Attempting to start the writer
> I0922 17:32:11.694921 28464 replica.cpp:477] Replica received implicit
> promise request with proposal 1
> I0922 17:32:11.695412 28464 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 466101ns
> I0922 17:32:11.695436 28464 replica.cpp:345] Persisted promised to 1
> I0922 17:32:11.696022 28458 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I0922 17:32:11.697191 28456 replica.cpp:378] Replica received explicit
> promise request for position 0 with proposal 2
> I0922 17:32:11.697574 28456 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 348861ns
> I0922 17:32:11.697597 28456 replica.cpp:679] Persisted action at 0
> I0922 17:32:11.698516 28449 replica.cpp:511] Replica received write
> request for position 0
> I0922 17:32:11.698609 28449 leveldb.cpp:438] Reading position from leveldb
> took 63381ns
> I0922 17:32:11.699031 28449 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 375697ns
> I0922 17:32:11.699053 28449 replica.cpp:679] Persisted action at 0
> I0922 17:32:11.699652 28450 replica.cpp:658] Replica received learned
> notice for position 0
> I0922 17:32:11.700026 28450 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 347184ns
> I0922 17:32:11.700048 28450 replica.cpp:679] Persisted action at 0
> I0922 17:32:11.700063 28450 replica.cpp:664] Replica learned NOP action at
> position 0
> I0922 17:32:11.700775 28457 log.cpp:677] Writer started with ending
> position 0
> I0922 17:32:11.701774 28452 leveldb.cpp:438] Reading position from leveldb
> took 25932ns
> I0922 17:32:11.702639 28453 registrar.cpp:342] Successfully fetched the
> registry (0B) in 9.586944ms
> I0922 17:32:11.702744 28453 registrar.cpp:441] Applied 1 operations in
> 23899ns; attempting to update the 'registry'
> I0922 17:32:11.703392 28457 log.cpp:685] Attempting to append 174 bytes to
> the log
> I0922 17:32:11.703511 28464 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I0922 17:32:11.704135 28464 replica.cpp:511] Replica received write
> request for position 1
> I0922 17:32:11.704458 28464 leveldb.cpp:343] Persisting action (193 bytes)
> to leveldb took 294133ns
> I0922 17:32:11.704481 28464 replica.cpp:679] Persisted action at 1
> I0922 17:32:11.705051 28450 replica.cpp:658] Replica received learned
> notice for position 1
> I0922 17:32:11.705416 28450 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 342726ns
> I0922 17:32:11.705440 28450 replica.cpp:679] Persisted action at 1
> I0922 17:32:11.705454 28450 replica.cpp:664] Replica learned APPEND action
> at position 1
> I0922 17:32:11.706307 28462 registrar.cpp:486] Successfully updated the
> 'registry' in 3.494912ms
> I0922 17:32:11.706449 28462 registrar.cpp:372] Successfully recovered
> registrar
> I0922 17:32:11.706521 28464 log.cpp:704] Attempting to truncate the log to
> 1
> I0922 17:32:11.706763 28452 master.cpp:1407] Recovered 0 slaves from the
> Registry (135B) ; allowing 10mins for slaves to re-register
> I0922 17:32:11.706946 28459 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I0922 17:32:11.707692 28452 replica.cpp:511] Replica received write
> request for position 2
> I0922 17:32:11.708045 28452 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 321750ns
> I0922 17:32:11.708066 28452 replica.cpp:679] Persisted action at 2
> I0922 17:32:11.708642 28461 replica.cpp:658] Replica received learned
> notice for position 2
> I0922 17:32:11.709002 28461 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 330650ns
> I0922 17:32:11.709046 28461 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 23556ns
> I0922 17:32:11.709069 28461 replica.cpp:679] Persisted action at 2
> I0922 17:32:11.709095 28461 replica.cpp:664] Replica learned TRUNCATE
> action at position 2
> I0922 17:32:11.717655 28430 scheduler.cpp:157] Version: 0.25.0
> I0922 17:32:11.718233 28450 scheduler.cpp:240] New master detected at
> master@172.17.2.62:56841
> I0922 17:32:11.719460 28452 scheduler.cpp:302] Sending SUBSCRIBE call to
> master@172.17.2.62:56841
> I0922 17:32:11.721127 28458 process.cpp:3021] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0922 17:32:11.721343 28458 http.cpp:335] HTTP POST for
> /master/api/v1/scheduler from 172.17.2.62:43052
> I0922 17:32:11.721547 28458 master.cpp:1859] Received subscription request
> for HTTP framework 'default'
> I0922 17:32:11.721644 28458 master.cpp:1636] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0922 17:32:11.721920 28458 master.cpp:1951] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0922 17:32:11.722363 28454 hierarchical.hpp:511] Added framework
> 7fe9efff-3f39-4666-b3e0-f796d2e7ced4-0000
> I0922 17:32:11.722396 28456 master.hpp:1431] Sending heartbeat to
> 7fe9efff-3f39-4666-b3e0-f796d2e7ced4-0000
> I0922 17:32:11.722544 28454 hierarchical.hpp:1299] No resources available
> to allocate!
> I0922 17:32:11.722602 28454 hierarchical.hpp:1394] No inverse offers to
> send out!
> I0922 17:32:11.722627 28454 hierarchical.hpp:1194] Performed allocation
> for 0 slaves in 93379ns
> I0922 17:32:11.723692 28452 scheduler.cpp:461] Enqueuing event SUBSCRIBED
> received from master@172.17.2.62:56841
> I0922 17:32:11.724251 28452 scheduler.cpp:461] Enqueuing event HEARTBEAT
> received from master@172.17.2.62:56841
> I0922 17:32:11.725080 28453 master_maintenance_tests.cpp:179] Ignoring
> HEARTBEAT event
> I0922 17:32:11.725119 28452 scheduler.cpp:302] Sending REQUEST call to
> master@172.17.2.62:56841
> I0922 17:32:11.726732 28461 process.cpp:3021] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0922 17:32:11.726927 28461 http.cpp:335] HTTP POST for
> /master/api/v1/scheduler from 172.17.2.62:43053
> I0922 17:32:11.727061 28461 master.cpp:2612] Processing REQUEST call for
> framework 7fe9efff-3f39-4666-b3e0-f796d2e7ced4-0000 (default)
> I0922 17:32:11.727264 28452 hierarchical.hpp:797] Received resource
> request from framework 7fe9efff-3f39-4666-b3e0-f796d2e7ced4-0000
> I0922 17:32:11.727532 28430 master.cpp:913] Master terminating
> I0922 17:32:11.727746 28455 hierarchical.hpp:548] Removed framework
> 7fe9efff-3f39-4666-b3e0-f796d2e7ced4-0000
> E0922 17:32:11.729722 28453 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_sgrMSc'
> I0922 17:32:11.736222 28430 leveldb.cpp:176] Opened db in 2.396188ms
> I0922 17:32:11.737220 28430 leveldb.cpp:183] Compacted db in 967368ns
> I0922 17:32:11.737267 28430 leveldb.cpp:198] Created db iterator in 20356ns
> I0922 17:32:11.737283 28430 leveldb.cpp:204] Seeked to beginning of db in
> 2245ns
> I0922 17:32:11.737290 28430 leveldb.cpp:273] Iterated through 0 keys in
> the db in 313ns
> I0922 17:32:11.737329 28430 replica.cpp:744] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0922 17:32:11.737782 28459 recover.cpp:449] Starting replica recovery
> I0922 17:32:11.738109 28459 recover.cpp:475] Replica is in EMPTY status
> I0922 17:32:11.739254 28457 replica.cpp:641] Replica in EMPTY status
> received a broadcasted recover request
> I0922 17:32:11.739773 28464 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I0922 17:32:11.740413 28453 recover.cpp:566] Updating replica status to
> STARTING
> I0922 17:32:11.741190 28452 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 554748ns
> I0922 17:32:11.741225 28452 replica.cpp:323] Persisted replica status to
> STARTING
> I0922 17:32:11.741484 28456 master.cpp:370] Master
> 5b053d9b-09d6-40d9-9345-b48bb8c42907 (ec5aa1e3f113) started on
> 172.17.2.62:56841
> I0922 17:32:11.741499 28452 recover.cpp:475] Replica is in STARTING status
> I0922 17:32:11.741516 28456 master.cpp:372] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ContentType_SchedulerTest_Request_1_sgrMSc/credentials"
> --framework_sorter="drf" --help="false" --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.25.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ContentType_SchedulerTest_Request_1_sgrMSc/master"
> --zk_session_timeout="10secs"
> I0922 17:32:11.741909 28456 master.cpp:419] Master allowing
> unauthenticated frameworks to register
> I0922 17:32:11.741925 28456 master.cpp:422] Master only allowing
> authenticated slaves to register
> I0922 17:32:11.741937 28456 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerTest_Request_1_sgrMSc/credentials'
> I0922 17:32:11.742231 28456 master.cpp:461] Using default 'crammd5'
> authenticator
> I0922 17:32:11.742377 28456 master.cpp:498] Authorization enabled
> I0922 17:32:11.742514 28454 replica.cpp:641] Replica in STARTING status
> received a broadcasted recover request
> I0922 17:32:11.742635 28461 hierarchical.hpp:464] Initialized hierarchical
> allocator process
> I0922 17:32:11.742635 28460 whitelist_watcher.cpp:79] No whitelist given
> I0922 17:32:11.743051 28464 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I0922 17:32:11.743643 28460 recover.cpp:566] Updating replica status to
> VOTING
> I0922 17:32:11.744099 28462 master.cpp:1597] The newly elected leader is
> master@172.17.2.62:56841 with id 5b053d9b-09d6-40d9-9345-b48bb8c42907
> I0922 17:32:11.744108 28464 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 302983ns
> I0922 17:32:11.744130 28462 master.cpp:1610] Elected as the leading master!
> I0922 17:32:11.744129 28464 replica.cpp:323] Persisted replica status to
> VOTING
> I0922 17:32:11.744148 28462 master.cpp:1370] Recovering from registrar
> I0922 17:32:11.744232 28457 recover.cpp:580] Successfully joined the Paxos
> group
> I0922 17:32:11.744293 28461 registrar.cpp:309] Recovering registrar
> I0922 17:32:11.744514 28457 recover.cpp:464] Recover process terminated
> I0922 17:32:11.745136 28458 log.cpp:661] Attempting to start the writer
> I0922 17:32:11.746587 28464 replica.cpp:477] Replica received implicit
> promise request with proposal 1
> I0922 17:32:11.747120 28464 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 496323ns
> I0922 17:32:11.747154 28464 replica.cpp:345] Persisted promised to 1
> I0922 17:32:11.747902 28461 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I0922 17:32:11.749243 28457 replica.cpp:378] Replica received explicit
> promise request for position 0 with proposal 2
> I0922 17:32:11.749675 28457 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 390543ns
> I0922 17:32:11.749701 28457 replica.cpp:679] Persisted action at 0
> I0922 17:32:11.750936 28453 replica.cpp:511] Replica received write
> request for position 0
> I0922 17:32:11.750990 28453 leveldb.cpp:438] Reading position from leveldb
> took 28740ns
> I0922 17:32:11.751354 28453 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 321213ns
> I0922 17:32:11.751377 28453 replica.cpp:679] Persisted action at 0
> I0922 17:32:11.751983 28463 replica.cpp:658] Replica received learned
> notice for position 0
> I0922 17:32:11.752364 28463 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 345456ns
> I0922 17:32:11.752393 28463 replica.cpp:679] Persisted action at 0
> I0922 17:32:11.752418 28463 replica.cpp:664] Replica learned NOP action at
> position 0
> I0922 17:32:11.753047 28449 log.cpp:677] Writer started with ending
> position 0
> I0922 17:32:11.754304 28450 leveldb.cpp:438] Reading position from leveldb
> took 33462ns
> I0922 17:32:11.755394 28452 registrar.cpp:342] Successfully fetched the
> registry (0B) in 11.051264ms
> I0922 17:32:11.755508 28452 registrar.cpp:441] Applied 1 operations in
> 22989ns; attempting to update the 'registry'
> I0922 17:32:11.756356 28450 log.cpp:685] Attempting to append 174 bytes to
> the log
> I0922 17:32:11.756520 28458 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I0922 17:32:11.757511 28450 replica.cpp:511] Replica received write
> request for position 1
> I0922 17:32:11.758038 28450 leveldb.cpp:343] Persisting action (193 bytes)
> to leveldb took 486870ns
> I0922 17:32:11.758069 28450 replica.cpp:679] Persisted action at 1
> I0922 17:32:11.759572 28461 replica.cpp:658] Replica received learned
> notice for position 1
> I0922 17:32:11.759994 28461 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 388381ns
> I0922 17:32:11.760025 28461 replica.cpp:679] Persisted action at 1
> I0922 17:32:11.760048 28461 replica.cpp:664] Replica learned APPEND action
> at position 1
> I0922 17:32:11.761176 28452 registrar.cpp:486] Successfully updated the
> 'registry' in 5.595136ms
> I0922 17:32:11.761317 28452 registrar.cpp:372] Successfully recovered
> registrar
> I0922 17:32:11.761417 28464 log.cpp:704] Attempting to truncate the log to
> 1
> I0922 17:32:11.761764 28461 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I0922 17:32:11.761775 28453 master.cpp:1407] Recovered 0 slaves from the
> Registry (135B) ; allowing 10mins for slaves to re-register
> I0922 17:32:11.762728 28451 replica.cpp:511] Replica received write
> request for position 2
> I0922 17:32:11.763176 28451 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 405560ns
> I0922 17:32:11.763207 28451 replica.cpp:679] Persisted action at 2
> I0922 17:32:11.763919 28459 replica.cpp:658] Replica received learned
> notice for position 2
> I0922 17:32:11.764309 28459 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 358530ns
> I0922 17:32:11.764371 28459 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 32758ns
> I0922 17:32:11.764395 28459 replica.cpp:679] Persisted action at 2
> I0922 17:32:11.764418 28459 replica.cpp:664] Replica learned TRUNCATE
> action at position 2
> I0922 17:32:11.772625 28430 scheduler.cpp:157] Version: 0.25.0
> I0922 17:32:11.773272 28459 scheduler.cpp:240] New master detected at
> master@172.17.2.62:56841
> I0922 17:32:11.774359 28460 scheduler.cpp:302] Sending SUBSCRIBE call to
> master@172.17.2.62:56841
> I0922 17:32:11.776207 28454 process.cpp:3021] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0922 17:32:11.776437 28454 http.cpp:335] HTTP POST for
> /master/api/v1/scheduler from 172.17.2.62:43054
> I0922 17:32:11.776769 28454 master.cpp:1859] Received subscription request
> for HTTP framework 'default'
> I0922 17:32:11.776849 28454 master.cpp:1636] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0922 17:32:11.777098 28454 master.cpp:1951] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0922 17:32:11.777488 28449 hierarchical.hpp:511] Added framework
> 5b053d9b-09d6-40d9-9345-b48bb8c42907-0000
> I0922 17:32:11.777515 28449 hierarchical.hpp:1299] No resources available
> to allocate!
> I0922 17:32:11.777529 28449 hierarchical.hpp:1394] No inverse offers to
> send out!
> I0922 17:32:11.777539 28449 hierarchical.hpp:1194] Performed allocation
> for 0 slaves in 29655ns
> I0922 17:32:11.777673 28449 master.hpp:1431] Sending heartbeat to
> 5b053d9b-09d6-40d9-9345-b48bb8c42907-0000
> I0922 17:32:11.778769 28454 scheduler.cpp:461] Enqueuing event SUBSCRIBED
> received from master@172.17.2.62:56841
> I0922 17:32:11.779206 28454 scheduler.cpp:461] Enqueuing event HEARTBEAT
> received from master@172.17.2.62:56841
> I0922 17:32:11.779758 28452 master_maintenance_tests.cpp:179] Ignoring
> HEARTBEAT event
> I0922 17:32:11.779799 28454 scheduler.cpp:302] Sending REQUEST call to
> master@172.17.2.62:56841
> I0922 17:32:11.781327 28455 process.cpp:3021] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0922 17:32:11.781468 28455 http.cpp:335] HTTP POST for
> /master/api/v1/scheduler from 172.17.2.62:43055
> I0922 17:32:11.781723 28455 master.cpp:2612] Processing REQUEST call for
> framework 5b053d9b-09d6-40d9-9345-b48bb8c42907-0000 (default)
> I0922 17:32:11.781973 28457 hierarchical.hpp:797] Received resource
> request from framework 5b053d9b-09d6-40d9-9345-b48bb8c42907-0000
> I0922 17:32:11.782176 28462 master.cpp:913] Master terminating
> I0922 17:32:11.782327 28458 hierarchical.hpp:548] Removed framework
> 5b053d9b-09d6-40d9-9345-b48bb8c42907-0000
> E0922 17:32:11.784400 28456 scheduler.cpp:435] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (55 ms)
> [----------] 22 tests from ContentType/SchedulerTest (4019 ms total)
>
> [----------] Global test environment tear-down
> [==========] 792 tests from 108 test cases ran. (321041 ms total)
> [ PASSED ] 791 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] ContentType/ExecutorHttpApiTest.DefaultAccept/0, where
> GetParam() = application/x-protobuf
>
> 1 FAILED TEST
> YOU HAVE 8 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> make[4]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.25.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.25.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1442941607-9179
> Untagged: mesos-1442941607-9179:latest
> Deleted: 9ac0349a88149bb1ffc840974a917b64f90456fa6c32933296c17389d4cbf6c1
> Deleted: 918c3cb1f1270b0bda2fc3ce47499ad7c77dca3baef9b23976f8c0061ec82703
> Deleted: 906a045c0651f40c29491ceb62efab585522cf6c7ed65aae2aee5a1b03624910
> Deleted: 0660ff78140c00cc1e1a9b23bc24d79bb49559ac92ba287aca43b6b2bbca5ba7
> Build step 'Execute shell' marked build as failure
>
Jenkins build is back to normal : Mesos » gcc,--verbose,ubuntu:14.04,docker||Hadoop #846
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/846/changes>