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/10/13 11:54:39 UTC

Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #921

See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/921/changes>

Changes:

[mpark] Changed secret field in `Credential` from `bytes` to `string`

------------------------------------------
[...truncated 137652 lines...]
I1013 09:54:28.553485 30601 slave.cpp:3721] Cleaning up framework b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
I1013 09:54:28.553521 30599 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_wRAnsK/slaves/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-S0/frameworks/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000/executors/default' for gc 6.99999359463111days in the future
I1013 09:54:28.553673 30604 status_update_manager.cpp:284] Closing status update streams for framework b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
I1013 09:54:28.553737 30606 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_wRAnsK/slaves/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-S0/frameworks/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000' for gc 6.99999359203556days in the future
I1013 09:54:28.553738 30604 status_update_manager.cpp:530] Cleaning up status update stream for task e99b57ba-21f7-48e7-a5ca-6b30bf56941d of framework b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
[       OK ] ContentType/SchedulerTest.Message/1 (640 ms)
[ RUN      ] ContentType/SchedulerTest.Request/0
Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_n99C9B'
I1013 09:54:28.663244 30579 leveldb.cpp:176] Opened db in 104.020401ms
I1013 09:54:28.705338 30579 leveldb.cpp:183] Compacted db in 42.050441ms
I1013 09:54:28.705405 30579 leveldb.cpp:198] Created db iterator in 20999ns
I1013 09:54:28.705427 30579 leveldb.cpp:204] Seeked to beginning of db in 2390ns
I1013 09:54:28.705442 30579 leveldb.cpp:273] Iterated through 0 keys in the db in 264ns
I1013 09:54:28.705483 30579 replica.cpp:746] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1013 09:54:28.705940 30601 recover.cpp:449] Starting replica recovery
I1013 09:54:28.706272 30601 recover.cpp:475] Replica is in EMPTY status
I1013 09:54:28.707350 30609 replica.cpp:642] Replica in EMPTY status received a broadcasted recover request from (9953)@172.17.6.112:56612
I1013 09:54:28.707788 30600 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1013 09:54:28.708353 30604 recover.cpp:566] Updating replica status to STARTING
I1013 09:54:28.709435 30607 master.cpp:376] Master 7a1c3c9c-ef37-490d-90df-63aab52ad653 (e582ef081920) started on 172.17.6.112:56612
I1013 09:54:28.709467 30607 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_n99C9B/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_n99C9B/master" --zk_session_timeout="10secs"
I1013 09:54:28.709847 30607 master.cpp:425] Master allowing unauthenticated frameworks to register
I1013 09:54:28.709869 30607 master.cpp:428] Master only allowing authenticated slaves to register
I1013 09:54:28.709883 30607 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_0_n99C9B/credentials'
I1013 09:54:28.710216 30607 master.cpp:467] Using default 'crammd5' authenticator
I1013 09:54:28.710372 30607 master.cpp:504] Authorization enabled
I1013 09:54:28.710633 30605 whitelist_watcher.cpp:79] No whitelist given
I1013 09:54:28.710654 30603 hierarchical.hpp:468] Initialized hierarchical allocator process
I1013 09:54:28.712260 30611 master.cpp:1603] The newly elected leader is master@172.17.6.112:56612 with id 7a1c3c9c-ef37-490d-90df-63aab52ad653
I1013 09:54:28.712301 30611 master.cpp:1616] Elected as the leading master!
I1013 09:54:28.712330 30611 master.cpp:1376] Recovering from registrar
I1013 09:54:28.712508 30608 registrar.cpp:309] Recovering registrar
I1013 09:54:28.738459 30602 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 29.906476ms
I1013 09:54:28.738500 30602 replica.cpp:323] Persisted replica status to STARTING
I1013 09:54:28.738740 30602 recover.cpp:475] Replica is in STARTING status
I1013 09:54:28.740015 30599 replica.cpp:642] Replica in STARTING status received a broadcasted recover request from (9954)@172.17.6.112:56612
I1013 09:54:28.740504 30599 recover.cpp:195] Received a recover response from a replica in STARTING status
I1013 09:54:28.741129 30608 recover.cpp:566] Updating replica status to VOTING
I1013 09:54:28.772092 30610 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 30.730037ms
I1013 09:54:28.772136 30610 replica.cpp:323] Persisted replica status to VOTING
I1013 09:54:28.772267 30610 recover.cpp:580] Successfully joined the Paxos group
I1013 09:54:28.772457 30610 recover.cpp:464] Recover process terminated
I1013 09:54:28.772976 30604 log.cpp:661] Attempting to start the writer
I1013 09:54:28.774461 30610 replica.cpp:478] Replica received implicit promise request from (9955)@172.17.6.112:56612 with proposal 1
I1013 09:54:28.806444 30610 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 31.952781ms
I1013 09:54:28.806483 30610 replica.cpp:345] Persisted promised to 1
I1013 09:54:28.807368 30611 coordinator.cpp:231] Coordinator attemping to fill missing position
I1013 09:54:28.808745 30599 replica.cpp:378] Replica received explicit promise request from (9956)@172.17.6.112:56612 for position 0 with proposal 2
I1013 09:54:28.834035 30599 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 25.237888ms
I1013 09:54:28.834074 30599 replica.cpp:681] Persisted action at 0
I1013 09:54:28.835542 30601 replica.cpp:512] Replica received write request for position 0 from (9957)@172.17.6.112:56612
I1013 09:54:28.835625 30601 leveldb.cpp:438] Reading position from leveldb took 39584ns
I1013 09:54:28.859215 30601 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 23.503196ms
I1013 09:54:28.859262 30601 replica.cpp:681] Persisted action at 0
I1013 09:54:28.860091 30611 replica.cpp:660] Replica received learned notice for position 0 from @0.0.0.0:0
I1013 09:54:28.884397 30611 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 24.267478ms
I1013 09:54:28.884443 30611 replica.cpp:681] Persisted action at 0
I1013 09:54:28.884469 30611 replica.cpp:666] Replica learned NOP action at position 0
I1013 09:54:28.885243 30607 log.cpp:677] Writer started with ending position 0
I1013 09:54:28.886538 30598 leveldb.cpp:438] Reading position from leveldb took 39326ns
I1013 09:54:28.887596 30602 registrar.cpp:342] Successfully fetched the registry (0B) in 175.02592ms
I1013 09:54:28.887711 30602 registrar.cpp:441] Applied 1 operations in 24277ns; attempting to update the 'registry'
I1013 09:54:28.888509 30601 log.cpp:685] Attempting to append 176 bytes to the log
I1013 09:54:28.888663 30604 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I1013 09:54:28.889478 30612 replica.cpp:512] Replica received write request for position 1 from (9958)@172.17.6.112:56612
I1013 09:54:28.909436 30612 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 19.910012ms
I1013 09:54:28.909474 30612 replica.cpp:681] Persisted action at 1
I1013 09:54:28.910313 30608 replica.cpp:660] Replica received learned notice for position 1 from @0.0.0.0:0
I1013 09:54:28.934578 30608 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 24.167702ms
I1013 09:54:28.934618 30608 replica.cpp:681] Persisted action at 1
I1013 09:54:28.934641 30608 replica.cpp:666] Replica learned APPEND action at position 1
I1013 09:54:28.935854 30606 registrar.cpp:486] Successfully updated the 'registry' in 48.077824ms
I1013 09:54:28.936049 30606 registrar.cpp:372] Successfully recovered registrar
I1013 09:54:28.936148 30605 log.cpp:704] Attempting to truncate the log to 1
I1013 09:54:28.936430 30603 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I1013 09:54:28.936465 30612 master.cpp:1413] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1013 09:54:28.937325 30612 replica.cpp:512] Replica received write request for position 2 from (9959)@172.17.6.112:56612
I1013 09:54:28.959728 30612 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 22.359688ms
I1013 09:54:28.959772 30612 replica.cpp:681] Persisted action at 2
I1013 09:54:28.960585 30609 replica.cpp:660] Replica received learned notice for position 2 from @0.0.0.0:0
I1013 09:54:28.985482 30609 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 24.857067ms
I1013 09:54:28.985560 30609 leveldb.cpp:401] Deleting ~1 keys from leveldb took 40068ns
I1013 09:54:28.985585 30609 replica.cpp:681] Persisted action at 2
I1013 09:54:28.985612 30609 replica.cpp:666] Replica learned TRUNCATE action at position 2
I1013 09:54:28.987684 30579 scheduler.cpp:157] Version: 0.26.0
I1013 09:54:28.988404 30599 scheduler.cpp:240] New master detected at master@172.17.6.112:56612
I1013 09:54:28.989692 30602 scheduler.cpp:302] Sending SUBSCRIBE call to master@172.17.6.112:56612
I1013 09:54:28.991109 30600 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1013 09:54:28.991312 30600 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.6.112:52517
I1013 09:54:28.991514 30600 master.cpp:1865] Received subscription request for HTTP framework 'default'
I1013 09:54:28.991595 30600 master.cpp:1642] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1013 09:54:28.991881 30600 master.cpp:1957] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I1013 09:54:28.992254 30606 hierarchical.hpp:515] Added framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
I1013 09:54:28.992388 30599 master.hpp:1431] Sending heartbeat to 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
I1013 09:54:28.992414 30606 hierarchical.hpp:1328] No resources available to allocate!
I1013 09:54:28.992445 30606 hierarchical.hpp:1423] No inverse offers to send out!
I1013 09:54:28.992470 30606 hierarchical.hpp:1223] Performed allocation for 0 slaves in 69697ns
I1013 09:54:28.993254 30608 scheduler.cpp:461] Enqueuing event SUBSCRIBED received from master@172.17.6.112:56612
I1013 09:54:28.993791 30608 scheduler.cpp:461] Enqueuing event HEARTBEAT received from master@172.17.6.112:56612
I1013 09:54:28.994580 30605 master_maintenance_tests.cpp:179] Ignoring HEARTBEAT event
I1013 09:54:28.994729 30608 scheduler.cpp:302] Sending REQUEST call to master@172.17.6.112:56612
I1013 09:54:28.996095 30605 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1013 09:54:28.996304 30605 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.6.112:52518
I1013 09:54:28.996426 30605 master.cpp:2618] Processing REQUEST call for framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000 (default)
I1013 09:54:28.996623 30607 hierarchical.hpp:801] Received resource request from framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
I1013 09:54:28.997299 30607 master.cpp:919] Master terminating
I1013 09:54:28.998073 30612 hierarchical.hpp:552] Removed framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
E1013 09:54:28.999025 30599 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
[       OK ] ContentType/SchedulerTest.Request/0 (446 ms)
[ RUN      ] ContentType/SchedulerTest.Request/1
Using temporary directory '/tmp/ContentType_SchedulerTest_Request_1_IOTT2f'
I1013 09:54:29.114292 30579 leveldb.cpp:176] Opened db in 108.89338ms
I1013 09:54:29.131445 30579 leveldb.cpp:183] Compacted db in 17.119405ms
I1013 09:54:29.131508 30579 leveldb.cpp:198] Created db iterator in 18611ns
I1013 09:54:29.131528 30579 leveldb.cpp:204] Seeked to beginning of db in 2198ns
I1013 09:54:29.131541 30579 leveldb.cpp:273] Iterated through 0 keys in the db in 327ns
I1013 09:54:29.131579 30579 replica.cpp:746] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1013 09:54:29.132011 30600 recover.cpp:449] Starting replica recovery
I1013 09:54:29.132294 30600 recover.cpp:475] Replica is in EMPTY status
I1013 09:54:29.133361 30607 replica.cpp:642] Replica in EMPTY status received a broadcasted recover request from (9963)@172.17.6.112:56612
I1013 09:54:29.133882 30606 recover.cpp:195] Received a recover response from a replica in EMPTY status
I1013 09:54:29.134403 30605 recover.cpp:566] Updating replica status to STARTING
I1013 09:54:29.135359 30601 master.cpp:376] Master 3902d08a-ee72-4d02-9fdb-e011529f7f17 (e582ef081920) started on 172.17.6.112:56612
I1013 09:54:29.135391 30601 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_IOTT2f/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_IOTT2f/master" --zk_session_timeout="10secs"
I1013 09:54:29.135715 30601 master.cpp:425] Master allowing unauthenticated frameworks to register
I1013 09:54:29.135728 30601 master.cpp:428] Master only allowing authenticated slaves to register
I1013 09:54:29.135738 30601 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_1_IOTT2f/credentials'
I1013 09:54:29.136035 30601 master.cpp:467] Using default 'crammd5' authenticator
I1013 09:54:29.136157 30601 master.cpp:504] Authorization enabled
I1013 09:54:29.136363 30607 whitelist_watcher.cpp:79] No whitelist given
I1013 09:54:29.136391 30600 hierarchical.hpp:468] Initialized hierarchical allocator process
I1013 09:54:29.137504 30612 master.cpp:1603] The newly elected leader is master@172.17.6.112:56612 with id 3902d08a-ee72-4d02-9fdb-e011529f7f17
I1013 09:54:29.137588 30612 master.cpp:1616] Elected as the leading master!
I1013 09:54:29.137616 30612 master.cpp:1376] Recovering from registrar
I1013 09:54:29.137743 30606 registrar.cpp:309] Recovering registrar
I1013 09:54:29.164644 30608 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 30.02999ms
I1013 09:54:29.164680 30608 replica.cpp:323] Persisted replica status to STARTING
I1013 09:54:29.164876 30604 recover.cpp:475] Replica is in STARTING status
I1013 09:54:29.165794 30604 replica.cpp:642] Replica in STARTING status received a broadcasted recover request from (9964)@172.17.6.112:56612
I1013 09:54:29.166326 30599 recover.cpp:195] Received a recover response from a replica in STARTING status
I1013 09:54:29.166795 30604 recover.cpp:566] Updating replica status to VOTING
I1013 09:54:29.198084 30600 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 31.055317ms
I1013 09:54:29.198122 30600 replica.cpp:323] Persisted replica status to VOTING
I1013 09:54:29.198242 30610 recover.cpp:580] Successfully joined the Paxos group
I1013 09:54:29.198513 30610 recover.cpp:464] Recover process terminated
I1013 09:54:29.199028 30603 log.cpp:661] Attempting to start the writer
I1013 09:54:29.200359 30598 replica.cpp:478] Replica received implicit promise request from (9965)@172.17.6.112:56612 with proposal 1
I1013 09:54:29.231551 30598 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 31.14805ms
I1013 09:54:29.231590 30598 replica.cpp:345] Persisted promised to 1
I1013 09:54:29.232381 30606 coordinator.cpp:231] Coordinator attemping to fill missing position
I1013 09:54:29.233794 30605 replica.cpp:378] Replica received explicit promise request from (9966)@172.17.6.112:56612 for position 0 with proposal 2
I1013 09:54:29.265003 30605 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 31.161823ms
I1013 09:54:29.265043 30605 replica.cpp:681] Persisted action at 0
I1013 09:54:29.266396 30604 replica.cpp:512] Replica received write request for position 0 from (9967)@172.17.6.112:56612
I1013 09:54:29.266463 30604 leveldb.cpp:438] Reading position from leveldb took 29881ns
I1013 09:54:29.298465 30604 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 31.945579ms
I1013 09:54:29.298506 30604 replica.cpp:681] Persisted action at 0
I1013 09:54:29.299437 30607 replica.cpp:660] Replica received learned notice for position 0 from @0.0.0.0:0
I1013 09:54:29.331912 30607 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 32.435504ms
I1013 09:54:29.331951 30607 replica.cpp:681] Persisted action at 0
I1013 09:54:29.332010 30607 replica.cpp:666] Replica learned NOP action at position 0
I1013 09:54:29.332717 30599 log.cpp:677] Writer started with ending position 0
I1013 09:54:29.333890 30598 leveldb.cpp:438] Reading position from leveldb took 33892ns
I1013 09:54:29.334928 30608 registrar.cpp:342] Successfully fetched the registry (0B) in 197.13408ms
I1013 09:54:29.335055 30608 registrar.cpp:441] Applied 1 operations in 23024ns; attempting to update the 'registry'
I1013 09:54:29.335877 30613 log.cpp:685] Attempting to append 176 bytes to the log
I1013 09:54:29.336154 30613 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I1013 09:54:29.337092 30605 replica.cpp:512] Replica received write request for position 1 from (9968)@172.17.6.112:56612
I1013 09:54:29.373751 30605 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 36.598268ms
I1013 09:54:29.373824 30605 replica.cpp:681] Persisted action at 1
I1013 09:54:29.374878 30600 replica.cpp:660] Replica received learned notice for position 1 from @0.0.0.0:0
I1013 09:54:29.407166 30600 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 32.242494ms
I1013 09:54:29.407205 30600 replica.cpp:681] Persisted action at 1
I1013 09:54:29.407232 30600 replica.cpp:666] Replica learned APPEND action at position 1
I1013 09:54:29.408697 30605 registrar.cpp:486] Successfully updated the 'registry' in 73.55904ms
I1013 09:54:29.408880 30605 registrar.cpp:372] Successfully recovered registrar
I1013 09:54:29.409063 30606 log.cpp:704] Attempting to truncate the log to 1
I1013 09:54:29.409343 30598 master.cpp:1413] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
I1013 09:54:29.409557 30598 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I1013 09:54:29.410567 30601 replica.cpp:512] Replica received write request for position 2 from (9969)@172.17.6.112:56612
2015-10-13 09:54:29,434:30579(0x2b490798c700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:37094] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1013 09:54:29.440696 30601 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 30.078115ms
I1013 09:54:29.440740 30601 replica.cpp:681] Persisted action at 2
I1013 09:54:29.441627 30603 replica.cpp:660] Replica received learned notice for position 2 from @0.0.0.0:0
I1013 09:54:29.475014 30603 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 33.346137ms
I1013 09:54:29.475103 30603 leveldb.cpp:401] Deleting ~1 keys from leveldb took 43793ns
I1013 09:54:29.475131 30603 replica.cpp:681] Persisted action at 2
I1013 09:54:29.475164 30603 replica.cpp:666] Replica learned TRUNCATE action at position 2
I1013 09:54:29.480897 30579 scheduler.cpp:157] Version: 0.26.0
I1013 09:54:29.482127 30604 scheduler.cpp:240] New master detected at master@172.17.6.112:56612
I1013 09:54:29.483683 30598 scheduler.cpp:302] Sending SUBSCRIBE call to master@172.17.6.112:56612
I1013 09:54:29.485712 30606 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1013 09:54:29.485985 30606 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.6.112:52520
I1013 09:54:29.486440 30606 master.cpp:1865] Received subscription request for HTTP framework 'default'
I1013 09:54:29.486542 30606 master.cpp:1642] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1013 09:54:29.486865 30606 master.cpp:1957] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I1013 09:54:29.487325 30613 hierarchical.hpp:515] Added framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
I1013 09:54:29.487368 30613 hierarchical.hpp:1328] No resources available to allocate!
I1013 09:54:29.487390 30613 hierarchical.hpp:1423] No inverse offers to send out!
I1013 09:54:29.487409 30613 hierarchical.hpp:1223] Performed allocation for 0 slaves in 51138ns
I1013 09:54:29.487475 30611 master.hpp:1431] Sending heartbeat to 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
I1013 09:54:29.488737 30598 scheduler.cpp:461] Enqueuing event SUBSCRIBED received from master@172.17.6.112:56612
I1013 09:54:29.489276 30598 scheduler.cpp:461] Enqueuing event HEARTBEAT received from master@172.17.6.112:56612
I1013 09:54:29.490145 30610 master_maintenance_tests.cpp:179] Ignoring HEARTBEAT event
I1013 09:54:29.490180 30598 scheduler.cpp:302] Sending REQUEST call to master@172.17.6.112:56612
I1013 09:54:29.491829 30610 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1013 09:54:29.492202 30610 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.6.112:52521
I1013 09:54:29.492483 30610 master.cpp:2618] Processing REQUEST call for framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000 (default)
I1013 09:54:29.492667 30602 hierarchical.hpp:801] Received resource request from framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
I1013 09:54:29.493089 30579 master.cpp:919] Master terminating
I1013 09:54:29.493330 30605 hierarchical.hpp:552] Removed framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
E1013 09:54:29.494372 30606 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
[       OK ] ContentType/SchedulerTest.Request/1 (495 ms)
[----------] 22 tests from ContentType/SchedulerTest (14188 ms total)

[----------] Global test environment tear-down
[==========] 813 tests from 111 test cases ran. (620229 ms total)
[  PASSED  ] 812 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] RegistryClientTest.SimpleGetBlob

 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-1444727823-7187
Untagged: mesos-1444727823-7187:latest
Deleted: bfa131481b91e3b7acd20b0e63b61b872535f9f1835857213f008cce56e79e4f
Deleted: cc440e607c2b99f040f43ef1c841cb0e032c56028d632cc543e3ee3411a7e6ad
Deleted: ef4ee3db0b39dc5454909804dc05253019ef07355f8b62b6f7c33679d4a3bc81
Deleted: 9593edf873dbc2ca73367935818aefaf39942a40bc4b69ca0462a6df7ef8273b
Deleted: 87bbf42b32d09c96ba86589acd91fc478789830f6f0d7fd0805fe63131b3b955
Deleted: 5ebb4251fcd49af7c7a99b548d7d10db2c2972ec33a6e2c72fb5b3394f897723
Deleted: 924da152427e7203f4fdd02ac828909758294aba73e92d9c6861f533db173efd
Deleted: d9523d03898d58b924db6fabf7b92d3db39271fed4ad92654d0b857863627be1
Deleted: 93572403a6f65e1ca4101d8da4f51c022082ea1d564b5d65da06eadbbac809c0
Deleted: 42f1e345a58ef7210820d14fdced1f870e46c06818d08a4cd32d9151b395d5cd
Deleted: 1aebef5035a2ac4e53730b8f87904fea11a80f33207d5c5683ffcb3d9724b2a2
Deleted: 7f20a981a3df28d616550c77ac7a74273d68d3d091b3ea46db55c325db686994
Deleted: fc5f3b5d146902a42f317f76c92f32a992554cd29163a3266113804c5ef2941d
Build step 'Execute shell' marked build as failure

Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #921

Posted by Jojy Varghese <jo...@mesosphere.io>.

Acked.

From the logs it looks like ssl socket RST. I will try to reproduce the issue on my ubuntu 14.04. 

-Jojy


> On Oct 13, 2015, at 1:24 PM, Benjamin Mahler <be...@gmail.com> wrote:
> 
> +tim, jojy
> 
> Could you guys triage this test failure?
> 
> On Tue, Oct 13, 2015 at 2:54 AM, Apache Jenkins Server <jenkins@builds.apache.org <ma...@builds.apache.org>> wrote:
> See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/921/changes <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/921/changes>>
> 
> Changes:
> 
> [mpark] Changed secret field in `Credential` from `bytes` to `string`
> 
> ------------------------------------------
> [...truncated 137652 lines...]
> I1013 09:54:28.553485 30601 slave.cpp:3721] Cleaning up framework b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
> I1013 09:54:28.553521 30599 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_wRAnsK/slaves/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-S0/frameworks/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000/executors/default' for gc 6.99999359463111days in the future
> I1013 09:54:28.553673 30604 status_update_manager.cpp:284] Closing status update streams for framework b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
> I1013 09:54:28.553737 30606 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_wRAnsK/slaves/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-S0/frameworks/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000' for gc 6.99999359203556days in the future
> I1013 09:54:28.553738 30604 status_update_manager.cpp:530] Cleaning up status update stream for task e99b57ba-21f7-48e7-a5ca-6b30bf56941d of framework b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
> [       OK ] ContentType/SchedulerTest.Message/1 (640 ms)
> [ RUN      ] ContentType/SchedulerTest.Request/0
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_n99C9B'
> I1013 09:54:28.663244 30579 leveldb.cpp:176] Opened db in 104.020401ms
> I1013 09:54:28.705338 30579 leveldb.cpp:183] Compacted db in 42.050441ms
> I1013 09:54:28.705405 30579 leveldb.cpp:198] Created db iterator in 20999ns
> I1013 09:54:28.705427 30579 leveldb.cpp:204] Seeked to beginning of db in 2390ns
> I1013 09:54:28.705442 30579 leveldb.cpp:273] Iterated through 0 keys in the db in 264ns
> I1013 09:54:28.705483 30579 replica.cpp:746] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I1013 09:54:28.705940 30601 recover.cpp:449] Starting replica recovery
> I1013 09:54:28.706272 30601 recover.cpp:475] Replica is in EMPTY status
> I1013 09:54:28.707350 30609 replica.cpp:642] Replica in EMPTY status received a broadcasted recover request from (9953)@172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:28.707788 30600 recover.cpp:195] Received a recover response from a replica in EMPTY status
> I1013 09:54:28.708353 30604 recover.cpp:566] Updating replica status to STARTING
> I1013 09:54:28.709435 30607 master.cpp:376] Master 7a1c3c9c-ef37-490d-90df-63aab52ad653 (e582ef081920) started on 172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:28.709467 30607 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_n99C9B/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_n99C9B/master" --zk_session_timeout="10secs"
> I1013 09:54:28.709847 30607 master.cpp:425] Master allowing unauthenticated frameworks to register
> I1013 09:54:28.709869 30607 master.cpp:428] Master only allowing authenticated slaves to register
> I1013 09:54:28.709883 30607 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_0_n99C9B/credentials'
> I1013 09:54:28.710216 30607 master.cpp:467] Using default 'crammd5' authenticator
> I1013 09:54:28.710372 30607 master.cpp:504] Authorization enabled
> I1013 09:54:28.710633 30605 whitelist_watcher.cpp:79] No whitelist given
> I1013 09:54:28.710654 30603 hierarchical.hpp:468] Initialized hierarchical allocator process
> I1013 09:54:28.712260 30611 master.cpp:1603] The newly elected leader is master@172.17.6.112:56612 <http://master@172.17.6.112:56612/> with id 7a1c3c9c-ef37-490d-90df-63aab52ad653
> I1013 09:54:28.712301 30611 master.cpp:1616] Elected as the leading master!
> I1013 09:54:28.712330 30611 master.cpp:1376] Recovering from registrar
> I1013 09:54:28.712508 30608 registrar.cpp:309] Recovering registrar
> I1013 09:54:28.738459 30602 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 29.906476ms
> I1013 09:54:28.738500 30602 replica.cpp:323] Persisted replica status to STARTING
> I1013 09:54:28.738740 30602 recover.cpp:475] Replica is in STARTING status
> I1013 09:54:28.740015 30599 replica.cpp:642] Replica in STARTING status received a broadcasted recover request from (9954)@172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:28.740504 30599 recover.cpp:195] Received a recover response from a replica in STARTING status
> I1013 09:54:28.741129 30608 recover.cpp:566] Updating replica status to VOTING
> I1013 09:54:28.772092 30610 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 30.730037ms
> I1013 09:54:28.772136 30610 replica.cpp:323] Persisted replica status to VOTING
> I1013 09:54:28.772267 30610 recover.cpp:580] Successfully joined the Paxos group
> I1013 09:54:28.772457 30610 recover.cpp:464] Recover process terminated
> I1013 09:54:28.772976 30604 log.cpp:661] Attempting to start the writer
> I1013 09:54:28.774461 30610 replica.cpp:478] Replica received implicit promise request from (9955)@172.17.6.112:56612 <http://172.17.6.112:56612/> with proposal 1
> I1013 09:54:28.806444 30610 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 31.952781ms
> I1013 09:54:28.806483 30610 replica.cpp:345] Persisted promised to 1
> I1013 09:54:28.807368 30611 coordinator.cpp:231] Coordinator attemping to fill missing position
> I1013 09:54:28.808745 30599 replica.cpp:378] Replica received explicit promise request from (9956)@172.17.6.112:56612 <http://172.17.6.112:56612/> for position 0 with proposal 2
> I1013 09:54:28.834035 30599 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 25.237888ms
> I1013 09:54:28.834074 30599 replica.cpp:681] Persisted action at 0
> I1013 09:54:28.835542 30601 replica.cpp:512] Replica received write request for position 0 from (9957)@172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:28.835625 30601 leveldb.cpp:438] Reading position from leveldb took 39584ns
> I1013 09:54:28.859215 30601 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 23.503196ms
> I1013 09:54:28.859262 30601 replica.cpp:681] Persisted action at 0
> I1013 09:54:28.860091 30611 replica.cpp:660] Replica received learned notice for position 0 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1013 09:54:28.884397 30611 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 24.267478ms
> I1013 09:54:28.884443 30611 replica.cpp:681] Persisted action at 0
> I1013 09:54:28.884469 30611 replica.cpp:666] Replica learned NOP action at position 0
> I1013 09:54:28.885243 30607 log.cpp:677] Writer started with ending position 0
> I1013 09:54:28.886538 30598 leveldb.cpp:438] Reading position from leveldb took 39326ns
> I1013 09:54:28.887596 30602 registrar.cpp:342] Successfully fetched the registry (0B) in 175.02592ms
> I1013 09:54:28.887711 30602 registrar.cpp:441] Applied 1 operations in 24277ns; attempting to update the 'registry'
> I1013 09:54:28.888509 30601 log.cpp:685] Attempting to append 176 bytes to the log
> I1013 09:54:28.888663 30604 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
> I1013 09:54:28.889478 30612 replica.cpp:512] Replica received write request for position 1 from (9958)@172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:28.909436 30612 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 19.910012ms
> I1013 09:54:28.909474 30612 replica.cpp:681] Persisted action at 1
> I1013 09:54:28.910313 30608 replica.cpp:660] Replica received learned notice for position 1 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1013 09:54:28.934578 30608 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 24.167702ms
> I1013 09:54:28.934618 30608 replica.cpp:681] Persisted action at 1
> I1013 09:54:28.934641 30608 replica.cpp:666] Replica learned APPEND action at position 1
> I1013 09:54:28.935854 30606 registrar.cpp:486] Successfully updated the 'registry' in 48.077824ms
> I1013 09:54:28.936049 30606 registrar.cpp:372] Successfully recovered registrar
> I1013 09:54:28.936148 30605 log.cpp:704] Attempting to truncate the log to 1
> I1013 09:54:28.936430 30603 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
> I1013 09:54:28.936465 30612 master.cpp:1413] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
> I1013 09:54:28.937325 30612 replica.cpp:512] Replica received write request for position 2 from (9959)@172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:28.959728 30612 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 22.359688ms
> I1013 09:54:28.959772 30612 replica.cpp:681] Persisted action at 2
> I1013 09:54:28.960585 30609 replica.cpp:660] Replica received learned notice for position 2 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1013 09:54:28.985482 30609 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 24.857067ms
> I1013 09:54:28.985560 30609 leveldb.cpp:401] Deleting ~1 keys from leveldb took 40068ns
> I1013 09:54:28.985585 30609 replica.cpp:681] Persisted action at 2
> I1013 09:54:28.985612 30609 replica.cpp:666] Replica learned TRUNCATE action at position 2
> I1013 09:54:28.987684 30579 scheduler.cpp:157] Version: 0.26.0
> I1013 09:54:28.988404 30599 scheduler.cpp:240] New master detected at master@172.17.6.112:56612 <http://master@172.17.6.112:56612/>
> I1013 09:54:28.989692 30602 scheduler.cpp:302] Sending SUBSCRIBE call to master@172.17.6.112:56612 <http://master@172.17.6.112:56612/>
> I1013 09:54:28.991109 30600 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1013 09:54:28.991312 30600 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.6.112:52517 <http://172.17.6.112:52517/>
> I1013 09:54:28.991514 30600 master.cpp:1865] Received subscription request for HTTP framework 'default'
> I1013 09:54:28.991595 30600 master.cpp:1642] Authorizing framework principal 'test-principal' to receive offers for role '*'
> I1013 09:54:28.991881 30600 master.cpp:1957] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
> I1013 09:54:28.992254 30606 hierarchical.hpp:515] Added framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
> I1013 09:54:28.992388 30599 master.hpp:1431] Sending heartbeat to 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
> I1013 09:54:28.992414 30606 hierarchical.hpp:1328] No resources available to allocate!
> I1013 09:54:28.992445 30606 hierarchical.hpp:1423] No inverse offers to send out!
> I1013 09:54:28.992470 30606 hierarchical.hpp:1223] Performed allocation for 0 slaves in 69697ns
> I1013 09:54:28.993254 30608 scheduler.cpp:461] Enqueuing event SUBSCRIBED received from master@172.17.6.112:56612 <http://master@172.17.6.112:56612/>
> I1013 09:54:28.993791 30608 scheduler.cpp:461] Enqueuing event HEARTBEAT received from master@172.17.6.112:56612 <http://master@172.17.6.112:56612/>
> I1013 09:54:28.994580 30605 master_maintenance_tests.cpp:179] Ignoring HEARTBEAT event
> I1013 09:54:28.994729 30608 scheduler.cpp:302] Sending REQUEST call to master@172.17.6.112:56612 <http://master@172.17.6.112:56612/>
> I1013 09:54:28.996095 30605 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1013 09:54:28.996304 30605 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.6.112:52518 <http://172.17.6.112:52518/>
> I1013 09:54:28.996426 30605 master.cpp:2618] Processing REQUEST call for framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000 (default)
> I1013 09:54:28.996623 30607 hierarchical.hpp:801] Received resource request from framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
> I1013 09:54:28.997299 30607 master.cpp:919] Master terminating
> I1013 09:54:28.998073 30612 hierarchical.hpp:552] Removed framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
> E1013 09:54:28.999025 30599 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
> [       OK ] ContentType/SchedulerTest.Request/0 (446 ms)
> [ RUN      ] ContentType/SchedulerTest.Request/1
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_1_IOTT2f'
> I1013 09:54:29.114292 30579 leveldb.cpp:176] Opened db in 108.89338ms
> I1013 09:54:29.131445 30579 leveldb.cpp:183] Compacted db in 17.119405ms
> I1013 09:54:29.131508 30579 leveldb.cpp:198] Created db iterator in 18611ns
> I1013 09:54:29.131528 30579 leveldb.cpp:204] Seeked to beginning of db in 2198ns
> I1013 09:54:29.131541 30579 leveldb.cpp:273] Iterated through 0 keys in the db in 327ns
> I1013 09:54:29.131579 30579 replica.cpp:746] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I1013 09:54:29.132011 30600 recover.cpp:449] Starting replica recovery
> I1013 09:54:29.132294 30600 recover.cpp:475] Replica is in EMPTY status
> I1013 09:54:29.133361 30607 replica.cpp:642] Replica in EMPTY status received a broadcasted recover request from (9963)@172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:29.133882 30606 recover.cpp:195] Received a recover response from a replica in EMPTY status
> I1013 09:54:29.134403 30605 recover.cpp:566] Updating replica status to STARTING
> I1013 09:54:29.135359 30601 master.cpp:376] Master 3902d08a-ee72-4d02-9fdb-e011529f7f17 (e582ef081920) started on 172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:29.135391 30601 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_IOTT2f/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_IOTT2f/master" --zk_session_timeout="10secs"
> I1013 09:54:29.135715 30601 master.cpp:425] Master allowing unauthenticated frameworks to register
> I1013 09:54:29.135728 30601 master.cpp:428] Master only allowing authenticated slaves to register
> I1013 09:54:29.135738 30601 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_1_IOTT2f/credentials'
> I1013 09:54:29.136035 30601 master.cpp:467] Using default 'crammd5' authenticator
> I1013 09:54:29.136157 30601 master.cpp:504] Authorization enabled
> I1013 09:54:29.136363 30607 whitelist_watcher.cpp:79] No whitelist given
> I1013 09:54:29.136391 30600 hierarchical.hpp:468] Initialized hierarchical allocator process
> I1013 09:54:29.137504 30612 master.cpp:1603] The newly elected leader is master@172.17.6.112:56612 <http://master@172.17.6.112:56612/> with id 3902d08a-ee72-4d02-9fdb-e011529f7f17
> I1013 09:54:29.137588 30612 master.cpp:1616] Elected as the leading master!
> I1013 09:54:29.137616 30612 master.cpp:1376] Recovering from registrar
> I1013 09:54:29.137743 30606 registrar.cpp:309] Recovering registrar
> I1013 09:54:29.164644 30608 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 30.02999ms
> I1013 09:54:29.164680 30608 replica.cpp:323] Persisted replica status to STARTING
> I1013 09:54:29.164876 30604 recover.cpp:475] Replica is in STARTING status
> I1013 09:54:29.165794 30604 replica.cpp:642] Replica in STARTING status received a broadcasted recover request from (9964)@172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:29.166326 30599 recover.cpp:195] Received a recover response from a replica in STARTING status
> I1013 09:54:29.166795 30604 recover.cpp:566] Updating replica status to VOTING
> I1013 09:54:29.198084 30600 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 31.055317ms
> I1013 09:54:29.198122 30600 replica.cpp:323] Persisted replica status to VOTING
> I1013 09:54:29.198242 30610 recover.cpp:580] Successfully joined the Paxos group
> I1013 09:54:29.198513 30610 recover.cpp:464] Recover process terminated
> I1013 09:54:29.199028 30603 log.cpp:661] Attempting to start the writer
> I1013 09:54:29.200359 30598 replica.cpp:478] Replica received implicit promise request from (9965)@172.17.6.112:56612 <http://172.17.6.112:56612/> with proposal 1
> I1013 09:54:29.231551 30598 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 31.14805ms
> I1013 09:54:29.231590 30598 replica.cpp:345] Persisted promised to 1
> I1013 09:54:29.232381 30606 coordinator.cpp:231] Coordinator attemping to fill missing position
> I1013 09:54:29.233794 30605 replica.cpp:378] Replica received explicit promise request from (9966)@172.17.6.112:56612 <http://172.17.6.112:56612/> for position 0 with proposal 2
> I1013 09:54:29.265003 30605 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 31.161823ms
> I1013 09:54:29.265043 30605 replica.cpp:681] Persisted action at 0
> I1013 09:54:29.266396 30604 replica.cpp:512] Replica received write request for position 0 from (9967)@172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:29.266463 30604 leveldb.cpp:438] Reading position from leveldb took 29881ns
> I1013 09:54:29.298465 30604 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 31.945579ms
> I1013 09:54:29.298506 30604 replica.cpp:681] Persisted action at 0
> I1013 09:54:29.299437 30607 replica.cpp:660] Replica received learned notice for position 0 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1013 09:54:29.331912 30607 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 32.435504ms
> I1013 09:54:29.331951 30607 replica.cpp:681] Persisted action at 0
> I1013 09:54:29.332010 30607 replica.cpp:666] Replica learned NOP action at position 0
> I1013 09:54:29.332717 30599 log.cpp:677] Writer started with ending position 0
> I1013 09:54:29.333890 30598 leveldb.cpp:438] Reading position from leveldb took 33892ns
> I1013 09:54:29.334928 30608 registrar.cpp:342] Successfully fetched the registry (0B) in 197.13408ms
> I1013 09:54:29.335055 30608 registrar.cpp:441] Applied 1 operations in 23024ns; attempting to update the 'registry'
> I1013 09:54:29.335877 30613 log.cpp:685] Attempting to append 176 bytes to the log
> I1013 09:54:29.336154 30613 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
> I1013 09:54:29.337092 30605 replica.cpp:512] Replica received write request for position 1 from (9968)@172.17.6.112:56612 <http://172.17.6.112:56612/>
> I1013 09:54:29.373751 30605 leveldb.cpp:343] Persisting action (195 bytes) to leveldb took 36.598268ms
> I1013 09:54:29.373824 30605 replica.cpp:681] Persisted action at 1
> I1013 09:54:29.374878 30600 replica.cpp:660] Replica received learned notice for position 1 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1013 09:54:29.407166 30600 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 32.242494ms
> I1013 09:54:29.407205 30600 replica.cpp:681] Persisted action at 1
> I1013 09:54:29.407232 30600 replica.cpp:666] Replica learned APPEND action at position 1
> I1013 09:54:29.408697 30605 registrar.cpp:486] Successfully updated the 'registry' in 73.55904ms
> I1013 09:54:29.408880 30605 registrar.cpp:372] Successfully recovered registrar
> I1013 09:54:29.409063 30606 log.cpp:704] Attempting to truncate the log to 1
> I1013 09:54:29.409343 30598 master.cpp:1413] Recovered 0 slaves from the Registry (137B) ; allowing 10mins for slaves to re-register
> I1013 09:54:29.409557 30598 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
> I1013 09:54:29.410567 30601 replica.cpp:512] Replica received write request for position 2 from (9969)@172.17.6.112:56612 <http://172.17.6.112:56612/>
> 2015-10-13 09:54:29,434:30579(0x2b490798c700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:37094 <http://127.0.0.1:37094/>] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
> I1013 09:54:29.440696 30601 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 30.078115ms
> I1013 09:54:29.440740 30601 replica.cpp:681] Persisted action at 2
> I1013 09:54:29.441627 30603 replica.cpp:660] Replica received learned notice for position 2 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1013 09:54:29.475014 30603 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 33.346137ms
> I1013 09:54:29.475103 30603 leveldb.cpp:401] Deleting ~1 keys from leveldb took 43793ns
> I1013 09:54:29.475131 30603 replica.cpp:681] Persisted action at 2
> I1013 09:54:29.475164 30603 replica.cpp:666] Replica learned TRUNCATE action at position 2
> I1013 09:54:29.480897 30579 scheduler.cpp:157] Version: 0.26.0
> I1013 09:54:29.482127 30604 scheduler.cpp:240] New master detected at master@172.17.6.112:56612 <http://master@172.17.6.112:56612/>
> I1013 09:54:29.483683 30598 scheduler.cpp:302] Sending SUBSCRIBE call to master@172.17.6.112:56612 <http://master@172.17.6.112:56612/>
> I1013 09:54:29.485712 30606 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1013 09:54:29.485985 30606 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.6.112:52520 <http://172.17.6.112:52520/>
> I1013 09:54:29.486440 30606 master.cpp:1865] Received subscription request for HTTP framework 'default'
> I1013 09:54:29.486542 30606 master.cpp:1642] Authorizing framework principal 'test-principal' to receive offers for role '*'
> I1013 09:54:29.486865 30606 master.cpp:1957] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
> I1013 09:54:29.487325 30613 hierarchical.hpp:515] Added framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
> I1013 09:54:29.487368 30613 hierarchical.hpp:1328] No resources available to allocate!
> I1013 09:54:29.487390 30613 hierarchical.hpp:1423] No inverse offers to send out!
> I1013 09:54:29.487409 30613 hierarchical.hpp:1223] Performed allocation for 0 slaves in 51138ns
> I1013 09:54:29.487475 30611 master.hpp:1431] Sending heartbeat to 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
> I1013 09:54:29.488737 30598 scheduler.cpp:461] Enqueuing event SUBSCRIBED received from master@172.17.6.112:56612 <http://master@172.17.6.112:56612/>
> I1013 09:54:29.489276 30598 scheduler.cpp:461] Enqueuing event HEARTBEAT received from master@172.17.6.112:56612 <http://master@172.17.6.112:56612/>
> I1013 09:54:29.490145 30610 master_maintenance_tests.cpp:179] Ignoring HEARTBEAT event
> I1013 09:54:29.490180 30598 scheduler.cpp:302] Sending REQUEST call to master@172.17.6.112:56612 <http://master@172.17.6.112:56612/>
> I1013 09:54:29.491829 30610 process.cpp:3075] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1013 09:54:29.492202 30610 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.6.112:52521 <http://172.17.6.112:52521/>
> I1013 09:54:29.492483 30610 master.cpp:2618] Processing REQUEST call for framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000 (default)
> I1013 09:54:29.492667 30602 hierarchical.hpp:801] Received resource request from framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
> I1013 09:54:29.493089 30579 master.cpp:919] Master terminating
> I1013 09:54:29.493330 30605 hierarchical.hpp:552] Removed framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
> E1013 09:54:29.494372 30606 scheduler.cpp:435] End-Of-File received from master. The master closed the event stream
> [       OK ] ContentType/SchedulerTest.Request/1 (495 ms)
> [----------] 22 tests from ContentType/SchedulerTest (14188 ms total)
> 
> [----------] Global test environment tear-down
> [==========] 813 tests from 111 test cases ran. (620229 ms total)
> [  PASSED  ] 812 tests.
> [  FAILED  ] 1 test, listed below:
> [  FAILED  ] RegistryClientTest.SimpleGetBlob
> 
>  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-1444727823-7187
> Untagged: mesos-1444727823-7187:latest
> Deleted: bfa131481b91e3b7acd20b0e63b61b872535f9f1835857213f008cce56e79e4f
> Deleted: cc440e607c2b99f040f43ef1c841cb0e032c56028d632cc543e3ee3411a7e6ad
> Deleted: ef4ee3db0b39dc5454909804dc05253019ef07355f8b62b6f7c33679d4a3bc81
> Deleted: 9593edf873dbc2ca73367935818aefaf39942a40bc4b69ca0462a6df7ef8273b
> Deleted: 87bbf42b32d09c96ba86589acd91fc478789830f6f0d7fd0805fe63131b3b955
> Deleted: 5ebb4251fcd49af7c7a99b548d7d10db2c2972ec33a6e2c72fb5b3394f897723
> Deleted: 924da152427e7203f4fdd02ac828909758294aba73e92d9c6861f533db173efd
> Deleted: d9523d03898d58b924db6fabf7b92d3db39271fed4ad92654d0b857863627be1
> Deleted: 93572403a6f65e1ca4101d8da4f51c022082ea1d564b5d65da06eadbbac809c0
> Deleted: 42f1e345a58ef7210820d14fdced1f870e46c06818d08a4cd32d9151b395d5cd
> Deleted: 1aebef5035a2ac4e53730b8f87904fea11a80f33207d5c5683ffcb3d9724b2a2
> Deleted: 7f20a981a3df28d616550c77ac7a74273d68d3d091b3ea46db55c325db686994
> Deleted: fc5f3b5d146902a42f317f76c92f32a992554cd29163a3266113804c5ef2941d
> Build step 'Execute shell' marked build as failure
>

Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #921

Posted by Benjamin Mahler <be...@gmail.com>.

Hm.. can you point me to how RST can be caused by memory pressure? Also, if
that's really the cause, is there a reason we've only ever seen it with the
docker registry client test?

On Tue, Oct 13, 2015 at 2:22 PM, Jojy Varghese <jo...@mesosphere.io> wrote:

> Could not reproduce. Wondering if this is a one-off due to system issues.
> RST could be caused by system memory pressure.
>
> -Jojy
>
> On Oct 13, 2015, at 1:24 PM, Benjamin Mahler <be...@gmail.com>
> wrote:
>
> +tim, jojy
>
> Could you guys triage this test failure?
>
> On Tue, Oct 13, 2015 at 2:54 AM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
>> See <
>> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/921/changes
>> <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu:14.04,label_exp=docker%7C%7CHadoop/921/changes>
>> >
>>
>> Changes:
>>
>> [mpark] Changed secret field in `Credential` from `bytes` to `string`
>>
>> ------------------------------------------
>> [...truncated 137652 lines...]
>> I1013 09:54:28.553485 30601 slave.cpp:3721] Cleaning up framework
>> b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
>> I1013 09:54:28.553521 30599 gc.cpp:56] Scheduling
>> '/tmp/ContentType_SchedulerTest_Message_1_wRAnsK/slaves/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-S0/frameworks/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000/executors/default'
>> for gc 6.99999359463111days in the future
>> I1013 09:54:28.553673 30604 status_update_manager.cpp:284] Closing status
>> update streams for framework b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
>> I1013 09:54:28.553737 30606 gc.cpp:56] Scheduling
>> '/tmp/ContentType_SchedulerTest_Message_1_wRAnsK/slaves/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-S0/frameworks/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000'
>> for gc 6.99999359203556days in the future
>> I1013 09:54:28.553738 30604 status_update_manager.cpp:530] Cleaning up
>> status update stream for task e99b57ba-21f7-48e7-a5ca-6b30bf56941d of
>> framework b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
>> [       OK ] ContentType/SchedulerTest.Message/1 (640 ms)
>> [ RUN      ] ContentType/SchedulerTest.Request/0
>> Using temporary directory
>> '/tmp/ContentType_SchedulerTest_Request_0_n99C9B'
>> I1013 09:54:28.663244 30579 leveldb.cpp:176] Opened db in 104.020401ms
>> I1013 09:54:28.705338 30579 leveldb.cpp:183] Compacted db in 42.050441ms
>> I1013 09:54:28.705405 30579 leveldb.cpp:198] Created db iterator in
>> 20999ns
>> I1013 09:54:28.705427 30579 leveldb.cpp:204] Seeked to beginning of db in
>> 2390ns
>> I1013 09:54:28.705442 30579 leveldb.cpp:273] Iterated through 0 keys in
>> the db in 264ns
>> I1013 09:54:28.705483 30579 replica.cpp:746] Replica recovered with log
>> positions 0 -> 0 with 1 holes and 0 unlearned
>> I1013 09:54:28.705940 30601 recover.cpp:449] Starting replica recovery
>> I1013 09:54:28.706272 30601 recover.cpp:475] Replica is in EMPTY status
>> I1013 09:54:28.707350 30609 replica.cpp:642] Replica in EMPTY status
>> received a broadcasted recover request from (9953)@172.17.6.112:56612
>> I1013 09:54:28.707788 30600 recover.cpp:195] Received a recover response
>> from a replica in EMPTY status
>> I1013 09:54:28.708353 30604 recover.cpp:566] Updating replica status to
>> STARTING
>> I1013 09:54:28.709435 30607 master.cpp:376] Master
>> 7a1c3c9c-ef37-490d-90df-63aab52ad653 (e582ef081920) started on
>> 172.17.6.112:56612
>> I1013 09:54:28.709467 30607 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_n99C9B/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_n99C9B/master"
>> --zk_session_timeout="10secs"
>> I1013 09:54:28.709847 30607 master.cpp:425] Master allowing
>> unauthenticated frameworks to register
>> I1013 09:54:28.709869 30607 master.cpp:428] Master only allowing
>> authenticated slaves to register
>> I1013 09:54:28.709883 30607 credentials.hpp:37] Loading credentials for
>> authentication from
>> '/tmp/ContentType_SchedulerTest_Request_0_n99C9B/credentials'
>> I1013 09:54:28.710216 30607 master.cpp:467] Using default 'crammd5'
>> authenticator
>> I1013 09:54:28.710372 30607 master.cpp:504] Authorization enabled
>> I1013 09:54:28.710633 30605 whitelist_watcher.cpp:79] No whitelist given
>> I1013 09:54:28.710654 30603 hierarchical.hpp:468] Initialized
>> hierarchical allocator process
>> I1013 09:54:28.712260 30611 master.cpp:1603] The newly elected leader is
>> master@172.17.6.112:56612 with id 7a1c3c9c-ef37-490d-90df-63aab52ad653
>> I1013 09:54:28.712301 30611 master.cpp:1616] Elected as the leading
>> master!
>> I1013 09:54:28.712330 30611 master.cpp:1376] Recovering from registrar
>> I1013 09:54:28.712508 30608 registrar.cpp:309] Recovering registrar
>> I1013 09:54:28.738459 30602 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 29.906476ms
>> I1013 09:54:28.738500 30602 replica.cpp:323] Persisted replica status to
>> STARTING
>> I1013 09:54:28.738740 30602 recover.cpp:475] Replica is in STARTING status
>> I1013 09:54:28.740015 30599 replica.cpp:642] Replica in STARTING status
>> received a broadcasted recover request from (9954)@172.17.6.112:56612
>> I1013 09:54:28.740504 30599 recover.cpp:195] Received a recover response
>> from a replica in STARTING status
>> I1013 09:54:28.741129 30608 recover.cpp:566] Updating replica status to
>> VOTING
>> I1013 09:54:28.772092 30610 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 30.730037ms
>> I1013 09:54:28.772136 30610 replica.cpp:323] Persisted replica status to
>> VOTING
>> I1013 09:54:28.772267 30610 recover.cpp:580] Successfully joined the
>> Paxos group
>> I1013 09:54:28.772457 30610 recover.cpp:464] Recover process terminated
>> I1013 09:54:28.772976 30604 log.cpp:661] Attempting to start the writer
>> I1013 09:54:28.774461 30610 replica.cpp:478] Replica received implicit
>> promise request from (9955)@172.17.6.112:56612 with proposal 1
>> I1013 09:54:28.806444 30610 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 31.952781ms
>> I1013 09:54:28.806483 30610 replica.cpp:345] Persisted promised to 1
>> I1013 09:54:28.807368 30611 coordinator.cpp:231] Coordinator attemping to
>> fill missing position
>> I1013 09:54:28.808745 30599 replica.cpp:378] Replica received explicit
>> promise request from (9956)@172.17.6.112:56612 for position 0 with
>> proposal 2
>> I1013 09:54:28.834035 30599 leveldb.cpp:343] Persisting action (8 bytes)
>> to leveldb took 25.237888ms
>> I1013 09:54:28.834074 30599 replica.cpp:681] Persisted action at 0
>> I1013 09:54:28.835542 30601 replica.cpp:512] Replica received write
>> request for position 0 from (9957)@172.17.6.112:56612
>> I1013 09:54:28.835625 30601 leveldb.cpp:438] Reading position from
>> leveldb took 39584ns
>> I1013 09:54:28.859215 30601 leveldb.cpp:343] Persisting action (14 bytes)
>> to leveldb took 23.503196ms
>> I1013 09:54:28.859262 30601 replica.cpp:681] Persisted action at 0
>> I1013 09:54:28.860091 30611 replica.cpp:660] Replica received learned
>> notice for position 0 from @0.0.0.0:0
>> I1013 09:54:28.884397 30611 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 24.267478ms
>> I1013 09:54:28.884443 30611 replica.cpp:681] Persisted action at 0
>> I1013 09:54:28.884469 30611 replica.cpp:666] Replica learned NOP action
>> at position 0
>> I1013 09:54:28.885243 30607 log.cpp:677] Writer started with ending
>> position 0
>> I1013 09:54:28.886538 30598 leveldb.cpp:438] Reading position from
>> leveldb took 39326ns
>> I1013 09:54:28.887596 30602 registrar.cpp:342] Successfully fetched the
>> registry (0B) in 175.02592ms
>> I1013 09:54:28.887711 30602 registrar.cpp:441] Applied 1 operations in
>> 24277ns; attempting to update the 'registry'
>> I1013 09:54:28.888509 30601 log.cpp:685] Attempting to append 176 bytes
>> to the log
>> I1013 09:54:28.888663 30604 coordinator.cpp:341] Coordinator attempting
>> to write APPEND action at position 1
>> I1013 09:54:28.889478 30612 replica.cpp:512] Replica received write
>> request for position 1 from (9958)@172.17.6.112:56612
>> I1013 09:54:28.909436 30612 leveldb.cpp:343] Persisting action (195
>> bytes) to leveldb took 19.910012ms
>> I1013 09:54:28.909474 30612 replica.cpp:681] Persisted action at 1
>> I1013 09:54:28.910313 30608 replica.cpp:660] Replica received learned
>> notice for position 1 from @0.0.0.0:0
>> I1013 09:54:28.934578 30608 leveldb.cpp:343] Persisting action (197
>> bytes) to leveldb took 24.167702ms
>> I1013 09:54:28.934618 30608 replica.cpp:681] Persisted action at 1
>> I1013 09:54:28.934641 30608 replica.cpp:666] Replica learned APPEND
>> action at position 1
>> I1013 09:54:28.935854 30606 registrar.cpp:486] Successfully updated the
>> 'registry' in 48.077824ms
>> I1013 09:54:28.936049 30606 registrar.cpp:372] Successfully recovered
>> registrar
>> I1013 09:54:28.936148 30605 log.cpp:704] Attempting to truncate the log
>> to 1
>> I1013 09:54:28.936430 30603 coordinator.cpp:341] Coordinator attempting
>> to write TRUNCATE action at position 2
>> I1013 09:54:28.936465 30612 master.cpp:1413] Recovered 0 slaves from the
>> Registry (137B) ; allowing 10mins for slaves to re-register
>> I1013 09:54:28.937325 30612 replica.cpp:512] Replica received write
>> request for position 2 from (9959)@172.17.6.112:56612
>> I1013 09:54:28.959728 30612 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 22.359688ms
>> I1013 09:54:28.959772 30612 replica.cpp:681] Persisted action at 2
>> I1013 09:54:28.960585 30609 replica.cpp:660] Replica received learned
>> notice for position 2 from @0.0.0.0:0
>> I1013 09:54:28.985482 30609 leveldb.cpp:343] Persisting action (18 bytes)
>> to leveldb took 24.857067ms
>> I1013 09:54:28.985560 30609 leveldb.cpp:401] Deleting ~1 keys from
>> leveldb took 40068ns
>> I1013 09:54:28.985585 30609 replica.cpp:681] Persisted action at 2
>> I1013 09:54:28.985612 30609 replica.cpp:666] Replica learned TRUNCATE
>> action at position 2
>> I1013 09:54:28.987684 30579 scheduler.cpp:157] Version: 0.26.0
>> I1013 09:54:28.988404 30599 scheduler.cpp:240] New master detected at
>> master@172.17.6.112:56612
>> I1013 09:54:28.989692 30602 scheduler.cpp:302] Sending SUBSCRIBE call to
>> master@172.17.6.112:56612
>> I1013 09:54:28.991109 30600 process.cpp:3075] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I1013 09:54:28.991312 30600 http.cpp:336] HTTP POST for
>> /master/api/v1/scheduler from 172.17.6.112:52517
>> I1013 09:54:28.991514 30600 master.cpp:1865] Received subscription
>> request for HTTP framework 'default'
>> I1013 09:54:28.991595 30600 master.cpp:1642] Authorizing framework
>> principal 'test-principal' to receive offers for role '*'
>> I1013 09:54:28.991881 30600 master.cpp:1957] Subscribing framework
>> 'default' with checkpointing disabled and capabilities [  ]
>> I1013 09:54:28.992254 30606 hierarchical.hpp:515] Added framework
>> 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
>> I1013 09:54:28.992388 30599 master.hpp:1431] Sending heartbeat to
>> 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
>> I1013 09:54:28.992414 30606 hierarchical.hpp:1328] No resources available
>> to allocate!
>> I1013 09:54:28.992445 30606 hierarchical.hpp:1423] No inverse offers to
>> send out!
>> I1013 09:54:28.992470 30606 hierarchical.hpp:1223] Performed allocation
>> for 0 slaves in 69697ns
>> I1013 09:54:28.993254 30608 scheduler.cpp:461] Enqueuing event SUBSCRIBED
>> received from master@172.17.6.112:56612
>> I1013 09:54:28.993791 30608 scheduler.cpp:461] Enqueuing event HEARTBEAT
>> received from master@172.17.6.112:56612
>> I1013 09:54:28.994580 30605 master_maintenance_tests.cpp:179] Ignoring
>> HEARTBEAT event
>> I1013 09:54:28.994729 30608 scheduler.cpp:302] Sending REQUEST call to
>> master@172.17.6.112:56612
>> I1013 09:54:28.996095 30605 process.cpp:3075] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I1013 09:54:28.996304 30605 http.cpp:336] HTTP POST for
>> /master/api/v1/scheduler from 172.17.6.112:52518
>> I1013 09:54:28.996426 30605 master.cpp:2618] Processing REQUEST call for
>> framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000 (default)
>> I1013 09:54:28.996623 30607 hierarchical.hpp:801] Received resource
>> request from framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
>> I1013 09:54:28.997299 30607 master.cpp:919] Master terminating
>> I1013 09:54:28.998073 30612 hierarchical.hpp:552] Removed framework
>> 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
>> E1013 09:54:28.999025 30599 scheduler.cpp:435] End-Of-File received from
>> master. The master closed the event stream
>> [       OK ] ContentType/SchedulerTest.Request/0 (446 ms)
>> [ RUN      ] ContentType/SchedulerTest.Request/1
>> Using temporary directory
>> '/tmp/ContentType_SchedulerTest_Request_1_IOTT2f'
>> I1013 09:54:29.114292 30579 leveldb.cpp:176] Opened db in 108.89338ms
>> I1013 09:54:29.131445 30579 leveldb.cpp:183] Compacted db in 17.119405ms
>> I1013 09:54:29.131508 30579 leveldb.cpp:198] Created db iterator in
>> 18611ns
>> I1013 09:54:29.131528 30579 leveldb.cpp:204] Seeked to beginning of db in
>> 2198ns
>> I1013 09:54:29.131541 30579 leveldb.cpp:273] Iterated through 0 keys in
>> the db in 327ns
>> I1013 09:54:29.131579 30579 replica.cpp:746] Replica recovered with log
>> positions 0 -> 0 with 1 holes and 0 unlearned
>> I1013 09:54:29.132011 30600 recover.cpp:449] Starting replica recovery
>> I1013 09:54:29.132294 30600 recover.cpp:475] Replica is in EMPTY status
>> I1013 09:54:29.133361 30607 replica.cpp:642] Replica in EMPTY status
>> received a broadcasted recover request from (9963)@172.17.6.112:56612
>> I1013 09:54:29.133882 30606 recover.cpp:195] Received a recover response
>> from a replica in EMPTY status
>> I1013 09:54:29.134403 30605 recover.cpp:566] Updating replica status to
>> STARTING
>> I1013 09:54:29.135359 30601 master.cpp:376] Master
>> 3902d08a-ee72-4d02-9fdb-e011529f7f17 (e582ef081920) started on
>> 172.17.6.112:56612
>> I1013 09:54:29.135391 30601 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_IOTT2f/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_IOTT2f/master"
>> --zk_session_timeout="10secs"
>> I1013 09:54:29.135715 30601 master.cpp:425] Master allowing
>> unauthenticated frameworks to register
>> I1013 09:54:29.135728 30601 master.cpp:428] Master only allowing
>> authenticated slaves to register
>> I1013 09:54:29.135738 30601 credentials.hpp:37] Loading credentials for
>> authentication from
>> '/tmp/ContentType_SchedulerTest_Request_1_IOTT2f/credentials'
>> I1013 09:54:29.136035 30601 master.cpp:467] Using default 'crammd5'
>> authenticator
>> I1013 09:54:29.136157 30601 master.cpp:504] Authorization enabled
>> I1013 09:54:29.136363 30607 whitelist_watcher.cpp:79] No whitelist given
>> I1013 09:54:29.136391 30600 hierarchical.hpp:468] Initialized
>> hierarchical allocator process
>> I1013 09:54:29.137504 30612 master.cpp:1603] The newly elected leader is
>> master@172.17.6.112:56612 with id 3902d08a-ee72-4d02-9fdb-e011529f7f17
>> I1013 09:54:29.137588 30612 master.cpp:1616] Elected as the leading
>> master!
>> I1013 09:54:29.137616 30612 master.cpp:1376] Recovering from registrar
>> I1013 09:54:29.137743 30606 registrar.cpp:309] Recovering registrar
>> I1013 09:54:29.164644 30608 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 30.02999ms
>> I1013 09:54:29.164680 30608 replica.cpp:323] Persisted replica status to
>> STARTING
>> I1013 09:54:29.164876 30604 recover.cpp:475] Replica is in STARTING status
>> I1013 09:54:29.165794 30604 replica.cpp:642] Replica in STARTING status
>> received a broadcasted recover request from (9964)@172.17.6.112:56612
>> I1013 09:54:29.166326 30599 recover.cpp:195] Received a recover response
>> from a replica in STARTING status
>> I1013 09:54:29.166795 30604 recover.cpp:566] Updating replica status to
>> VOTING
>> I1013 09:54:29.198084 30600 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 31.055317ms
>> I1013 09:54:29.198122 30600 replica.cpp:323] Persisted replica status to
>> VOTING
>> I1013 09:54:29.198242 30610 recover.cpp:580] Successfully joined the
>> Paxos group
>> I1013 09:54:29.198513 30610 recover.cpp:464] Recover process terminated
>> I1013 09:54:29.199028 30603 log.cpp:661] Attempting to start the writer
>> I1013 09:54:29.200359 30598 replica.cpp:478] Replica received implicit
>> promise request from (9965)@172.17.6.112:56612 with proposal 1
>> I1013 09:54:29.231551 30598 leveldb.cpp:306] Persisting metadata (8
>> bytes) to leveldb took 31.14805ms
>> I1013 09:54:29.231590 30598 replica.cpp:345] Persisted promised to 1
>> I1013 09:54:29.232381 30606 coordinator.cpp:231] Coordinator attemping to
>> fill missing position
>> I1013 09:54:29.233794 30605 replica.cpp:378] Replica received explicit
>> promise request from (9966)@172.17.6.112:56612 for position 0 with
>> proposal 2
>> I1013 09:54:29.265003 30605 leveldb.cpp:343] Persisting action (8 bytes)
>> to leveldb took 31.161823ms
>> I1013 09:54:29.265043 30605 replica.cpp:681] Persisted action at 0
>> I1013 09:54:29.266396 30604 replica.cpp:512] Replica received write
>> request for position 0 from (9967)@172.17.6.112:56612
>> I1013 09:54:29.266463 30604 leveldb.cpp:438] Reading position from
>> leveldb took 29881ns
>> I1013 09:54:29.298465 30604 leveldb.cpp:343] Persisting action (14 bytes)
>> to leveldb took 31.945579ms
>> I1013 09:54:29.298506 30604 replica.cpp:681] Persisted action at 0
>> I1013 09:54:29.299437 30607 replica.cpp:660] Replica received learned
>> notice for position 0 from @0.0.0.0:0
>> I1013 09:54:29.331912 30607 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 32.435504ms
>> I1013 09:54:29.331951 30607 replica.cpp:681] Persisted action at 0
>> I1013 09:54:29.332010 30607 replica.cpp:666] Replica learned NOP action
>> at position 0
>> I1013 09:54:29.332717 30599 log.cpp:677] Writer started with ending
>> position 0
>> I1013 09:54:29.333890 30598 leveldb.cpp:438] Reading position from
>> leveldb took 33892ns
>> I1013 09:54:29.334928 30608 registrar.cpp:342] Successfully fetched the
>> registry (0B) in 197.13408ms
>> I1013 09:54:29.335055 30608 registrar.cpp:441] Applied 1 operations in
>> 23024ns; attempting to update the 'registry'
>> I1013 09:54:29.335877 30613 log.cpp:685] Attempting to append 176 bytes
>> to the log
>> I1013 09:54:29.336154 30613 coordinator.cpp:341] Coordinator attempting
>> to write APPEND action at position 1
>> I1013 09:54:29.337092 30605 replica.cpp:512] Replica received write
>> request for position 1 from (9968)@172.17.6.112:56612
>> I1013 09:54:29.373751 30605 leveldb.cpp:343] Persisting action (195
>> bytes) to leveldb took 36.598268ms
>> I1013 09:54:29.373824 30605 replica.cpp:681] Persisted action at 1
>> I1013 09:54:29.374878 30600 replica.cpp:660] Replica received learned
>> notice for position 1 from @0.0.0.0:0
>> I1013 09:54:29.407166 30600 leveldb.cpp:343] Persisting action (197
>> bytes) to leveldb took 32.242494ms
>> I1013 09:54:29.407205 30600 replica.cpp:681] Persisted action at 1
>> I1013 09:54:29.407232 30600 replica.cpp:666] Replica learned APPEND
>> action at position 1
>> I1013 09:54:29.408697 30605 registrar.cpp:486] Successfully updated the
>> 'registry' in 73.55904ms
>> I1013 09:54:29.408880 30605 registrar.cpp:372] Successfully recovered
>> registrar
>> I1013 09:54:29.409063 30606 log.cpp:704] Attempting to truncate the log
>> to 1
>> I1013 09:54:29.409343 30598 master.cpp:1413] Recovered 0 slaves from the
>> Registry (137B) ; allowing 10mins for slaves to re-register
>> I1013 09:54:29.409557 30598 coordinator.cpp:341] Coordinator attempting
>> to write TRUNCATE action at position 2
>> I1013 09:54:29.410567 30601 replica.cpp:512] Replica received write
>> request for position 2 from (9969)@172.17.6.112:56612
>> 2015-10-13
>> 09:54:29,434:30579(0x2b490798c700):ZOO_ERROR@handle_socket_error_msg@1697:
>> Socket [127.0.0.1:37094] zk retcode=-4, errno=111(Connection refused):
>> server refused to accept the client
>> I1013 09:54:29.440696 30601 leveldb.cpp:343] Persisting action (16 bytes)
>> to leveldb took 30.078115ms
>> I1013 09:54:29.440740 30601 replica.cpp:681] Persisted action at 2
>> I1013 09:54:29.441627 30603 replica.cpp:660] Replica received learned
>> notice for position 2 from @0.0.0.0:0
>> I1013 09:54:29.475014 30603 leveldb.cpp:343] Persisting action (18 bytes)
>> to leveldb took 33.346137ms
>> I1013 09:54:29.475103 30603 leveldb.cpp:401] Deleting ~1 keys from
>> leveldb took 43793ns
>> I1013 09:54:29.475131 30603 replica.cpp:681] Persisted action at 2
>> I1013 09:54:29.475164 30603 replica.cpp:666] Replica learned TRUNCATE
>> action at position 2
>> I1013 09:54:29.480897 30579 scheduler.cpp:157] Version: 0.26.0
>> I1013 09:54:29.482127 30604 scheduler.cpp:240] New master detected at
>> master@172.17.6.112:56612
>> I1013 09:54:29.483683 30598 scheduler.cpp:302] Sending SUBSCRIBE call to
>> master@172.17.6.112:56612
>> I1013 09:54:29.485712 30606 process.cpp:3075] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I1013 09:54:29.485985 30606 http.cpp:336] HTTP POST for
>> /master/api/v1/scheduler from 172.17.6.112:52520
>> I1013 09:54:29.486440 30606 master.cpp:1865] Received subscription
>> request for HTTP framework 'default'
>> I1013 09:54:29.486542 30606 master.cpp:1642] Authorizing framework
>> principal 'test-principal' to receive offers for role '*'
>> I1013 09:54:29.486865 30606 master.cpp:1957] Subscribing framework
>> 'default' with checkpointing disabled and capabilities [  ]
>> I1013 09:54:29.487325 30613 hierarchical.hpp:515] Added framework
>> 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
>> I1013 09:54:29.487368 30613 hierarchical.hpp:1328] No resources available
>> to allocate!
>> I1013 09:54:29.487390 30613 hierarchical.hpp:1423] No inverse offers to
>> send out!
>> I1013 09:54:29.487409 30613 hierarchical.hpp:1223] Performed allocation
>> for 0 slaves in 51138ns
>> I1013 09:54:29.487475 30611 master.hpp:1431] Sending heartbeat to
>> 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
>> I1013 09:54:29.488737 30598 scheduler.cpp:461] Enqueuing event SUBSCRIBED
>> received from master@172.17.6.112:56612
>> I1013 09:54:29.489276 30598 scheduler.cpp:461] Enqueuing event HEARTBEAT
>> received from master@172.17.6.112:56612
>> I1013 09:54:29.490145 30610 master_maintenance_tests.cpp:179] Ignoring
>> HEARTBEAT event
>> I1013 09:54:29.490180 30598 scheduler.cpp:302] Sending REQUEST call to
>> master@172.17.6.112:56612
>> I1013 09:54:29.491829 30610 process.cpp:3075] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I1013 09:54:29.492202 30610 http.cpp:336] HTTP POST for
>> /master/api/v1/scheduler from 172.17.6.112:52521
>> I1013 09:54:29.492483 30610 master.cpp:2618] Processing REQUEST call for
>> framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000 (default)
>> I1013 09:54:29.492667 30602 hierarchical.hpp:801] Received resource
>> request from framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
>> I1013 09:54:29.493089 30579 master.cpp:919] Master terminating
>> I1013 09:54:29.493330 30605 hierarchical.hpp:552] Removed framework
>> 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
>> E1013 09:54:29.494372 30606 scheduler.cpp:435] End-Of-File received from
>> master. The master closed the event stream
>> [       OK ] ContentType/SchedulerTest.Request/1 (495 ms)
>> [----------] 22 tests from ContentType/SchedulerTest (14188 ms total)
>>
>> [----------] Global test environment tear-down
>> [==========] 813 tests from 111 test cases ran. (620229 ms total)
>> [  PASSED  ] 812 tests.
>> [  FAILED  ] 1 test, listed below:
>> [  FAILED  ] RegistryClientTest.SimpleGetBlob
>>
>>  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-1444727823-7187
>> Untagged: mesos-1444727823-7187:latest
>> Deleted: bfa131481b91e3b7acd20b0e63b61b872535f9f1835857213f008cce56e79e4f
>> Deleted: cc440e607c2b99f040f43ef1c841cb0e032c56028d632cc543e3ee3411a7e6ad
>> Deleted: ef4ee3db0b39dc5454909804dc05253019ef07355f8b62b6f7c33679d4a3bc81
>> Deleted: 9593edf873dbc2ca73367935818aefaf39942a40bc4b69ca0462a6df7ef8273b
>> Deleted: 87bbf42b32d09c96ba86589acd91fc478789830f6f0d7fd0805fe63131b3b955
>> Deleted: 5ebb4251fcd49af7c7a99b548d7d10db2c2972ec33a6e2c72fb5b3394f897723
>> Deleted: 924da152427e7203f4fdd02ac828909758294aba73e92d9c6861f533db173efd
>> Deleted: d9523d03898d58b924db6fabf7b92d3db39271fed4ad92654d0b857863627be1
>> Deleted: 93572403a6f65e1ca4101d8da4f51c022082ea1d564b5d65da06eadbbac809c0
>> Deleted: 42f1e345a58ef7210820d14fdced1f870e46c06818d08a4cd32d9151b395d5cd
>> Deleted: 1aebef5035a2ac4e53730b8f87904fea11a80f33207d5c5683ffcb3d9724b2a2
>> Deleted: 7f20a981a3df28d616550c77ac7a74273d68d3d091b3ea46db55c325db686994
>> Deleted: fc5f3b5d146902a42f317f76c92f32a992554cd29163a3266113804c5ef2941d
>> Build step 'Execute shell' marked build as failure
>>
>
>
>

Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #921

Posted by Benjamin Mahler <be...@gmail.com>.

+tim, jojy

Could you guys triage this test failure?

On Tue, Oct 13, 2015 at 2:54 AM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:

> See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/921/changes
> >
>
> Changes:
>
> [mpark] Changed secret field in `Credential` from `bytes` to `string`
>
> ------------------------------------------
> [...truncated 137652 lines...]
> I1013 09:54:28.553485 30601 slave.cpp:3721] Cleaning up framework
> b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
> I1013 09:54:28.553521 30599 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_wRAnsK/slaves/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-S0/frameworks/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000/executors/default'
> for gc 6.99999359463111days in the future
> I1013 09:54:28.553673 30604 status_update_manager.cpp:284] Closing status
> update streams for framework b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
> I1013 09:54:28.553737 30606 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_wRAnsK/slaves/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-S0/frameworks/b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000'
> for gc 6.99999359203556days in the future
> I1013 09:54:28.553738 30604 status_update_manager.cpp:530] Cleaning up
> status update stream for task e99b57ba-21f7-48e7-a5ca-6b30bf56941d of
> framework b85198c2-25fb-4a7f-8fa7-4e11bf7dbbd1-0000
> [       OK ] ContentType/SchedulerTest.Message/1 (640 ms)
> [ RUN      ] ContentType/SchedulerTest.Request/0
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_n99C9B'
> I1013 09:54:28.663244 30579 leveldb.cpp:176] Opened db in 104.020401ms
> I1013 09:54:28.705338 30579 leveldb.cpp:183] Compacted db in 42.050441ms
> I1013 09:54:28.705405 30579 leveldb.cpp:198] Created db iterator in 20999ns
> I1013 09:54:28.705427 30579 leveldb.cpp:204] Seeked to beginning of db in
> 2390ns
> I1013 09:54:28.705442 30579 leveldb.cpp:273] Iterated through 0 keys in
> the db in 264ns
> I1013 09:54:28.705483 30579 replica.cpp:746] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I1013 09:54:28.705940 30601 recover.cpp:449] Starting replica recovery
> I1013 09:54:28.706272 30601 recover.cpp:475] Replica is in EMPTY status
> I1013 09:54:28.707350 30609 replica.cpp:642] Replica in EMPTY status
> received a broadcasted recover request from (9953)@172.17.6.112:56612
> I1013 09:54:28.707788 30600 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I1013 09:54:28.708353 30604 recover.cpp:566] Updating replica status to
> STARTING
> I1013 09:54:28.709435 30607 master.cpp:376] Master
> 7a1c3c9c-ef37-490d-90df-63aab52ad653 (e582ef081920) started on
> 172.17.6.112:56612
> I1013 09:54:28.709467 30607 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_n99C9B/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_n99C9B/master"
> --zk_session_timeout="10secs"
> I1013 09:54:28.709847 30607 master.cpp:425] Master allowing
> unauthenticated frameworks to register
> I1013 09:54:28.709869 30607 master.cpp:428] Master only allowing
> authenticated slaves to register
> I1013 09:54:28.709883 30607 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerTest_Request_0_n99C9B/credentials'
> I1013 09:54:28.710216 30607 master.cpp:467] Using default 'crammd5'
> authenticator
> I1013 09:54:28.710372 30607 master.cpp:504] Authorization enabled
> I1013 09:54:28.710633 30605 whitelist_watcher.cpp:79] No whitelist given
> I1013 09:54:28.710654 30603 hierarchical.hpp:468] Initialized hierarchical
> allocator process
> I1013 09:54:28.712260 30611 master.cpp:1603] The newly elected leader is
> master@172.17.6.112:56612 with id 7a1c3c9c-ef37-490d-90df-63aab52ad653
> I1013 09:54:28.712301 30611 master.cpp:1616] Elected as the leading master!
> I1013 09:54:28.712330 30611 master.cpp:1376] Recovering from registrar
> I1013 09:54:28.712508 30608 registrar.cpp:309] Recovering registrar
> I1013 09:54:28.738459 30602 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 29.906476ms
> I1013 09:54:28.738500 30602 replica.cpp:323] Persisted replica status to
> STARTING
> I1013 09:54:28.738740 30602 recover.cpp:475] Replica is in STARTING status
> I1013 09:54:28.740015 30599 replica.cpp:642] Replica in STARTING status
> received a broadcasted recover request from (9954)@172.17.6.112:56612
> I1013 09:54:28.740504 30599 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I1013 09:54:28.741129 30608 recover.cpp:566] Updating replica status to
> VOTING
> I1013 09:54:28.772092 30610 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 30.730037ms
> I1013 09:54:28.772136 30610 replica.cpp:323] Persisted replica status to
> VOTING
> I1013 09:54:28.772267 30610 recover.cpp:580] Successfully joined the Paxos
> group
> I1013 09:54:28.772457 30610 recover.cpp:464] Recover process terminated
> I1013 09:54:28.772976 30604 log.cpp:661] Attempting to start the writer
> I1013 09:54:28.774461 30610 replica.cpp:478] Replica received implicit
> promise request from (9955)@172.17.6.112:56612 with proposal 1
> I1013 09:54:28.806444 30610 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 31.952781ms
> I1013 09:54:28.806483 30610 replica.cpp:345] Persisted promised to 1
> I1013 09:54:28.807368 30611 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I1013 09:54:28.808745 30599 replica.cpp:378] Replica received explicit
> promise request from (9956)@172.17.6.112:56612 for position 0 with
> proposal 2
> I1013 09:54:28.834035 30599 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 25.237888ms
> I1013 09:54:28.834074 30599 replica.cpp:681] Persisted action at 0
> I1013 09:54:28.835542 30601 replica.cpp:512] Replica received write
> request for position 0 from (9957)@172.17.6.112:56612
> I1013 09:54:28.835625 30601 leveldb.cpp:438] Reading position from leveldb
> took 39584ns
> I1013 09:54:28.859215 30601 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 23.503196ms
> I1013 09:54:28.859262 30601 replica.cpp:681] Persisted action at 0
> I1013 09:54:28.860091 30611 replica.cpp:660] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I1013 09:54:28.884397 30611 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 24.267478ms
> I1013 09:54:28.884443 30611 replica.cpp:681] Persisted action at 0
> I1013 09:54:28.884469 30611 replica.cpp:666] Replica learned NOP action at
> position 0
> I1013 09:54:28.885243 30607 log.cpp:677] Writer started with ending
> position 0
> I1013 09:54:28.886538 30598 leveldb.cpp:438] Reading position from leveldb
> took 39326ns
> I1013 09:54:28.887596 30602 registrar.cpp:342] Successfully fetched the
> registry (0B) in 175.02592ms
> I1013 09:54:28.887711 30602 registrar.cpp:441] Applied 1 operations in
> 24277ns; attempting to update the 'registry'
> I1013 09:54:28.888509 30601 log.cpp:685] Attempting to append 176 bytes to
> the log
> I1013 09:54:28.888663 30604 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I1013 09:54:28.889478 30612 replica.cpp:512] Replica received write
> request for position 1 from (9958)@172.17.6.112:56612
> I1013 09:54:28.909436 30612 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 19.910012ms
> I1013 09:54:28.909474 30612 replica.cpp:681] Persisted action at 1
> I1013 09:54:28.910313 30608 replica.cpp:660] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I1013 09:54:28.934578 30608 leveldb.cpp:343] Persisting action (197 bytes)
> to leveldb took 24.167702ms
> I1013 09:54:28.934618 30608 replica.cpp:681] Persisted action at 1
> I1013 09:54:28.934641 30608 replica.cpp:666] Replica learned APPEND action
> at position 1
> I1013 09:54:28.935854 30606 registrar.cpp:486] Successfully updated the
> 'registry' in 48.077824ms
> I1013 09:54:28.936049 30606 registrar.cpp:372] Successfully recovered
> registrar
> I1013 09:54:28.936148 30605 log.cpp:704] Attempting to truncate the log to
> 1
> I1013 09:54:28.936430 30603 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I1013 09:54:28.936465 30612 master.cpp:1413] Recovered 0 slaves from the
> Registry (137B) ; allowing 10mins for slaves to re-register
> I1013 09:54:28.937325 30612 replica.cpp:512] Replica received write
> request for position 2 from (9959)@172.17.6.112:56612
> I1013 09:54:28.959728 30612 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 22.359688ms
> I1013 09:54:28.959772 30612 replica.cpp:681] Persisted action at 2
> I1013 09:54:28.960585 30609 replica.cpp:660] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I1013 09:54:28.985482 30609 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 24.857067ms
> I1013 09:54:28.985560 30609 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 40068ns
> I1013 09:54:28.985585 30609 replica.cpp:681] Persisted action at 2
> I1013 09:54:28.985612 30609 replica.cpp:666] Replica learned TRUNCATE
> action at position 2
> I1013 09:54:28.987684 30579 scheduler.cpp:157] Version: 0.26.0
> I1013 09:54:28.988404 30599 scheduler.cpp:240] New master detected at
> master@172.17.6.112:56612
> I1013 09:54:28.989692 30602 scheduler.cpp:302] Sending SUBSCRIBE call to
> master@172.17.6.112:56612
> I1013 09:54:28.991109 30600 process.cpp:3075] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1013 09:54:28.991312 30600 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.6.112:52517
> I1013 09:54:28.991514 30600 master.cpp:1865] Received subscription request
> for HTTP framework 'default'
> I1013 09:54:28.991595 30600 master.cpp:1642] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I1013 09:54:28.991881 30600 master.cpp:1957] Subscribing framework
> 'default' with checkpointing disabled and capabilities [  ]
> I1013 09:54:28.992254 30606 hierarchical.hpp:515] Added framework
> 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
> I1013 09:54:28.992388 30599 master.hpp:1431] Sending heartbeat to
> 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
> I1013 09:54:28.992414 30606 hierarchical.hpp:1328] No resources available
> to allocate!
> I1013 09:54:28.992445 30606 hierarchical.hpp:1423] No inverse offers to
> send out!
> I1013 09:54:28.992470 30606 hierarchical.hpp:1223] Performed allocation
> for 0 slaves in 69697ns
> I1013 09:54:28.993254 30608 scheduler.cpp:461] Enqueuing event SUBSCRIBED
> received from master@172.17.6.112:56612
> I1013 09:54:28.993791 30608 scheduler.cpp:461] Enqueuing event HEARTBEAT
> received from master@172.17.6.112:56612
> I1013 09:54:28.994580 30605 master_maintenance_tests.cpp:179] Ignoring
> HEARTBEAT event
> I1013 09:54:28.994729 30608 scheduler.cpp:302] Sending REQUEST call to
> master@172.17.6.112:56612
> I1013 09:54:28.996095 30605 process.cpp:3075] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1013 09:54:28.996304 30605 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.6.112:52518
> I1013 09:54:28.996426 30605 master.cpp:2618] Processing REQUEST call for
> framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000 (default)
> I1013 09:54:28.996623 30607 hierarchical.hpp:801] Received resource
> request from framework 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
> I1013 09:54:28.997299 30607 master.cpp:919] Master terminating
> I1013 09:54:28.998073 30612 hierarchical.hpp:552] Removed framework
> 7a1c3c9c-ef37-490d-90df-63aab52ad653-0000
> E1013 09:54:28.999025 30599 scheduler.cpp:435] End-Of-File received from
> master. The master closed the event stream
> [       OK ] ContentType/SchedulerTest.Request/0 (446 ms)
> [ RUN      ] ContentType/SchedulerTest.Request/1
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_1_IOTT2f'
> I1013 09:54:29.114292 30579 leveldb.cpp:176] Opened db in 108.89338ms
> I1013 09:54:29.131445 30579 leveldb.cpp:183] Compacted db in 17.119405ms
> I1013 09:54:29.131508 30579 leveldb.cpp:198] Created db iterator in 18611ns
> I1013 09:54:29.131528 30579 leveldb.cpp:204] Seeked to beginning of db in
> 2198ns
> I1013 09:54:29.131541 30579 leveldb.cpp:273] Iterated through 0 keys in
> the db in 327ns
> I1013 09:54:29.131579 30579 replica.cpp:746] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I1013 09:54:29.132011 30600 recover.cpp:449] Starting replica recovery
> I1013 09:54:29.132294 30600 recover.cpp:475] Replica is in EMPTY status
> I1013 09:54:29.133361 30607 replica.cpp:642] Replica in EMPTY status
> received a broadcasted recover request from (9963)@172.17.6.112:56612
> I1013 09:54:29.133882 30606 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I1013 09:54:29.134403 30605 recover.cpp:566] Updating replica status to
> STARTING
> I1013 09:54:29.135359 30601 master.cpp:376] Master
> 3902d08a-ee72-4d02-9fdb-e011529f7f17 (e582ef081920) started on
> 172.17.6.112:56612
> I1013 09:54:29.135391 30601 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_IOTT2f/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_IOTT2f/master"
> --zk_session_timeout="10secs"
> I1013 09:54:29.135715 30601 master.cpp:425] Master allowing
> unauthenticated frameworks to register
> I1013 09:54:29.135728 30601 master.cpp:428] Master only allowing
> authenticated slaves to register
> I1013 09:54:29.135738 30601 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerTest_Request_1_IOTT2f/credentials'
> I1013 09:54:29.136035 30601 master.cpp:467] Using default 'crammd5'
> authenticator
> I1013 09:54:29.136157 30601 master.cpp:504] Authorization enabled
> I1013 09:54:29.136363 30607 whitelist_watcher.cpp:79] No whitelist given
> I1013 09:54:29.136391 30600 hierarchical.hpp:468] Initialized hierarchical
> allocator process
> I1013 09:54:29.137504 30612 master.cpp:1603] The newly elected leader is
> master@172.17.6.112:56612 with id 3902d08a-ee72-4d02-9fdb-e011529f7f17
> I1013 09:54:29.137588 30612 master.cpp:1616] Elected as the leading master!
> I1013 09:54:29.137616 30612 master.cpp:1376] Recovering from registrar
> I1013 09:54:29.137743 30606 registrar.cpp:309] Recovering registrar
> I1013 09:54:29.164644 30608 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 30.02999ms
> I1013 09:54:29.164680 30608 replica.cpp:323] Persisted replica status to
> STARTING
> I1013 09:54:29.164876 30604 recover.cpp:475] Replica is in STARTING status
> I1013 09:54:29.165794 30604 replica.cpp:642] Replica in STARTING status
> received a broadcasted recover request from (9964)@172.17.6.112:56612
> I1013 09:54:29.166326 30599 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I1013 09:54:29.166795 30604 recover.cpp:566] Updating replica status to
> VOTING
> I1013 09:54:29.198084 30600 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 31.055317ms
> I1013 09:54:29.198122 30600 replica.cpp:323] Persisted replica status to
> VOTING
> I1013 09:54:29.198242 30610 recover.cpp:580] Successfully joined the Paxos
> group
> I1013 09:54:29.198513 30610 recover.cpp:464] Recover process terminated
> I1013 09:54:29.199028 30603 log.cpp:661] Attempting to start the writer
> I1013 09:54:29.200359 30598 replica.cpp:478] Replica received implicit
> promise request from (9965)@172.17.6.112:56612 with proposal 1
> I1013 09:54:29.231551 30598 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 31.14805ms
> I1013 09:54:29.231590 30598 replica.cpp:345] Persisted promised to 1
> I1013 09:54:29.232381 30606 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I1013 09:54:29.233794 30605 replica.cpp:378] Replica received explicit
> promise request from (9966)@172.17.6.112:56612 for position 0 with
> proposal 2
> I1013 09:54:29.265003 30605 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 31.161823ms
> I1013 09:54:29.265043 30605 replica.cpp:681] Persisted action at 0
> I1013 09:54:29.266396 30604 replica.cpp:512] Replica received write
> request for position 0 from (9967)@172.17.6.112:56612
> I1013 09:54:29.266463 30604 leveldb.cpp:438] Reading position from leveldb
> took 29881ns
> I1013 09:54:29.298465 30604 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 31.945579ms
> I1013 09:54:29.298506 30604 replica.cpp:681] Persisted action at 0
> I1013 09:54:29.299437 30607 replica.cpp:660] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I1013 09:54:29.331912 30607 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 32.435504ms
> I1013 09:54:29.331951 30607 replica.cpp:681] Persisted action at 0
> I1013 09:54:29.332010 30607 replica.cpp:666] Replica learned NOP action at
> position 0
> I1013 09:54:29.332717 30599 log.cpp:677] Writer started with ending
> position 0
> I1013 09:54:29.333890 30598 leveldb.cpp:438] Reading position from leveldb
> took 33892ns
> I1013 09:54:29.334928 30608 registrar.cpp:342] Successfully fetched the
> registry (0B) in 197.13408ms
> I1013 09:54:29.335055 30608 registrar.cpp:441] Applied 1 operations in
> 23024ns; attempting to update the 'registry'
> I1013 09:54:29.335877 30613 log.cpp:685] Attempting to append 176 bytes to
> the log
> I1013 09:54:29.336154 30613 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I1013 09:54:29.337092 30605 replica.cpp:512] Replica received write
> request for position 1 from (9968)@172.17.6.112:56612
> I1013 09:54:29.373751 30605 leveldb.cpp:343] Persisting action (195 bytes)
> to leveldb took 36.598268ms
> I1013 09:54:29.373824 30605 replica.cpp:681] Persisted action at 1
> I1013 09:54:29.374878 30600 replica.cpp:660] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I1013 09:54:29.407166 30600 leveldb.cpp:343] Persisting action (197 bytes)
> to leveldb took 32.242494ms
> I1013 09:54:29.407205 30600 replica.cpp:681] Persisted action at 1
> I1013 09:54:29.407232 30600 replica.cpp:666] Replica learned APPEND action
> at position 1
> I1013 09:54:29.408697 30605 registrar.cpp:486] Successfully updated the
> 'registry' in 73.55904ms
> I1013 09:54:29.408880 30605 registrar.cpp:372] Successfully recovered
> registrar
> I1013 09:54:29.409063 30606 log.cpp:704] Attempting to truncate the log to
> 1
> I1013 09:54:29.409343 30598 master.cpp:1413] Recovered 0 slaves from the
> Registry (137B) ; allowing 10mins for slaves to re-register
> I1013 09:54:29.409557 30598 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I1013 09:54:29.410567 30601 replica.cpp:512] Replica received write
> request for position 2 from (9969)@172.17.6.112:56612
> 2015-10-13
> 09:54:29,434:30579(0x2b490798c700):ZOO_ERROR@handle_socket_error_msg@1697:
> Socket [127.0.0.1:37094] zk retcode=-4, errno=111(Connection refused):
> server refused to accept the client
> I1013 09:54:29.440696 30601 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 30.078115ms
> I1013 09:54:29.440740 30601 replica.cpp:681] Persisted action at 2
> I1013 09:54:29.441627 30603 replica.cpp:660] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I1013 09:54:29.475014 30603 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 33.346137ms
> I1013 09:54:29.475103 30603 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 43793ns
> I1013 09:54:29.475131 30603 replica.cpp:681] Persisted action at 2
> I1013 09:54:29.475164 30603 replica.cpp:666] Replica learned TRUNCATE
> action at position 2
> I1013 09:54:29.480897 30579 scheduler.cpp:157] Version: 0.26.0
> I1013 09:54:29.482127 30604 scheduler.cpp:240] New master detected at
> master@172.17.6.112:56612
> I1013 09:54:29.483683 30598 scheduler.cpp:302] Sending SUBSCRIBE call to
> master@172.17.6.112:56612
> I1013 09:54:29.485712 30606 process.cpp:3075] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1013 09:54:29.485985 30606 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.6.112:52520
> I1013 09:54:29.486440 30606 master.cpp:1865] Received subscription request
> for HTTP framework 'default'
> I1013 09:54:29.486542 30606 master.cpp:1642] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I1013 09:54:29.486865 30606 master.cpp:1957] Subscribing framework
> 'default' with checkpointing disabled and capabilities [  ]
> I1013 09:54:29.487325 30613 hierarchical.hpp:515] Added framework
> 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
> I1013 09:54:29.487368 30613 hierarchical.hpp:1328] No resources available
> to allocate!
> I1013 09:54:29.487390 30613 hierarchical.hpp:1423] No inverse offers to
> send out!
> I1013 09:54:29.487409 30613 hierarchical.hpp:1223] Performed allocation
> for 0 slaves in 51138ns
> I1013 09:54:29.487475 30611 master.hpp:1431] Sending heartbeat to
> 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
> I1013 09:54:29.488737 30598 scheduler.cpp:461] Enqueuing event SUBSCRIBED
> received from master@172.17.6.112:56612
> I1013 09:54:29.489276 30598 scheduler.cpp:461] Enqueuing event HEARTBEAT
> received from master@172.17.6.112:56612
> I1013 09:54:29.490145 30610 master_maintenance_tests.cpp:179] Ignoring
> HEARTBEAT event
> I1013 09:54:29.490180 30598 scheduler.cpp:302] Sending REQUEST call to
> master@172.17.6.112:56612
> I1013 09:54:29.491829 30610 process.cpp:3075] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1013 09:54:29.492202 30610 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.6.112:52521
> I1013 09:54:29.492483 30610 master.cpp:2618] Processing REQUEST call for
> framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000 (default)
> I1013 09:54:29.492667 30602 hierarchical.hpp:801] Received resource
> request from framework 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
> I1013 09:54:29.493089 30579 master.cpp:919] Master terminating
> I1013 09:54:29.493330 30605 hierarchical.hpp:552] Removed framework
> 3902d08a-ee72-4d02-9fdb-e011529f7f17-0000
> E1013 09:54:29.494372 30606 scheduler.cpp:435] End-Of-File received from
> master. The master closed the event stream
> [       OK ] ContentType/SchedulerTest.Request/1 (495 ms)
> [----------] 22 tests from ContentType/SchedulerTest (14188 ms total)
>
> [----------] Global test environment tear-down
> [==========] 813 tests from 111 test cases ran. (620229 ms total)
> [  PASSED  ] 812 tests.
> [  FAILED  ] 1 test, listed below:
> [  FAILED  ] RegistryClientTest.SimpleGetBlob
>
>  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-1444727823-7187
> Untagged: mesos-1444727823-7187:latest
> Deleted: bfa131481b91e3b7acd20b0e63b61b872535f9f1835857213f008cce56e79e4f
> Deleted: cc440e607c2b99f040f43ef1c841cb0e032c56028d632cc543e3ee3411a7e6ad
> Deleted: ef4ee3db0b39dc5454909804dc05253019ef07355f8b62b6f7c33679d4a3bc81
> Deleted: 9593edf873dbc2ca73367935818aefaf39942a40bc4b69ca0462a6df7ef8273b
> Deleted: 87bbf42b32d09c96ba86589acd91fc478789830f6f0d7fd0805fe63131b3b955
> Deleted: 5ebb4251fcd49af7c7a99b548d7d10db2c2972ec33a6e2c72fb5b3394f897723
> Deleted: 924da152427e7203f4fdd02ac828909758294aba73e92d9c6861f533db173efd
> Deleted: d9523d03898d58b924db6fabf7b92d3db39271fed4ad92654d0b857863627be1
> Deleted: 93572403a6f65e1ca4101d8da4f51c022082ea1d564b5d65da06eadbbac809c0
> Deleted: 42f1e345a58ef7210820d14fdced1f870e46c06818d08a4cd32d9151b395d5cd
> Deleted: 1aebef5035a2ac4e53730b8f87904fea11a80f33207d5c5683ffcb3d9724b2a2
> Deleted: 7f20a981a3df28d616550c77ac7a74273d68d3d091b3ea46db55c325db686994
> Deleted: fc5f3b5d146902a42f317f76c92f32a992554cd29163a3266113804c5ef2941d
> Build step 'Execute shell' marked build as failure
>

Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #922

Posted by Apache Jenkins Server <je...@builds.apache.org>.

See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/922/changes>