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/08/17 01:16:40 UTC
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent,centos:7,docker||Hadoop #709
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent,OS=centos%3A7,label_exp=docker%7C%7CHadoop/709/changes>
Changes:
[vinodkone] Logged Scheduler HTTP API Requests in the master.
[vinodkone] Added more logging to the scheduler library.
------------------------------------------
[...truncated 119637 lines...]
I0816 23:17:31.040223 28823 slave.cpp:5094] Terminating task dbfa3d17-a23d-41d2-aac7-e36a740f0c9c
I0816 23:17:31.041010 28823 slave.cpp:564] Slave terminating
I0816 23:17:31.041354 28823 slave.cpp:1959] Asked to shut down framework 20150816-231730-3170963884-43501-28791-0000 by @0.0.0.0:0
I0816 23:17:31.041558 28823 slave.cpp:1984] Shutting down framework 20150816-231730-3170963884-43501-28791-0000
I0816 23:17:31.041896 28823 slave.cpp:3503] Cleaning up executor 'default' of framework 20150816-231730-3170963884-43501-28791-0000
I0816 23:17:31.042533 28823 slave.cpp:3592] Cleaning up framework 20150816-231730-3170963884-43501-28791-0000
I0816 23:17:31.042759 28820 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_ZgzCSX/slaves/20150816-231730-3170963884-43501-28791-S0/frameworks/20150816-231730-3170963884-43501-28791-0000/executors/default/runs/9a7738ad-57fa-4ceb-a2b9-686cba7180ca' for gc 6.99999951041778days in the future
I0816 23:17:31.043351 28820 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_ZgzCSX/slaves/20150816-231730-3170963884-43501-28791-S0/frameworks/20150816-231730-3170963884-43501-28791-0000/executors/default' for gc 6.99999950839111days in the future
I0816 23:17:31.043689 28820 status_update_manager.cpp:284] Closing status update streams for framework 20150816-231730-3170963884-43501-28791-0000
I0816 23:17:31.043779 28820 status_update_manager.cpp:530] Cleaning up status update stream for task dbfa3d17-a23d-41d2-aac7-e36a740f0c9c of framework 20150816-231730-3170963884-43501-28791-0000
I0816 23:17:31.044090 28813 gc.cpp:56] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_ZgzCSX/slaves/20150816-231730-3170963884-43501-28791-S0/frameworks/20150816-231730-3170963884-43501-28791-0000' for gc 6.99999949479111days in the future
[ OK ] ContentType/SchedulerTest.Message/1 (138 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_XCjeZ0'
I0816 23:17:31.052975 28791 leveldb.cpp:176] Opened db in 2.557515ms
I0816 23:17:31.053910 28791 leveldb.cpp:183] Compacted db in 789593ns
I0816 23:17:31.054039 28791 leveldb.cpp:198] Created db iterator in 20702ns
I0816 23:17:31.054219 28791 leveldb.cpp:204] Seeked to beginning of db in 2443ns
I0816 23:17:31.054325 28791 leveldb.cpp:273] Iterated through 0 keys in the db in 478ns
I0816 23:17:31.054502 28791 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0816 23:17:31.055794 28824 recover.cpp:449] Starting replica recovery
I0816 23:17:31.056430 28824 recover.cpp:475] Replica is in EMPTY status
I0816 23:17:31.057747 28824 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0816 23:17:31.058665 28812 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0816 23:17:31.059424 28823 recover.cpp:566] Updating replica status to STARTING
I0816 23:17:31.059902 28824 master.cpp:378] Master 20150816-231731-3170963884-43501-28791 (f3a9451c4cf3) started on 172.17.1.189:43501
I0816 23:17:31.060251 28819 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 560753ns
I0816 23:17:31.060346 28819 replica.cpp:323] Persisted replica status to STARTING
I0816 23:17:31.060086 28824 master.cpp:380] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ContentType_SchedulerTest_Request_0_XCjeZ0/credentials" --framework_sorter="drf" --help="false" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.24.0/_inst/share/mesos/webui" --work_dir="/tmp/ContentType_SchedulerTest_Request_0_XCjeZ0/master" --zk_session_timeout="10secs"
I0816 23:17:31.060647 28824 master.cpp:427] Master allowing unauthenticated frameworks to register
I0816 23:17:31.060684 28824 master.cpp:430] Master only allowing authenticated slaves to register
I0816 23:17:31.060698 28824 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_0_XCjeZ0/credentials'
I0816 23:17:31.060837 28819 recover.cpp:475] Replica is in STARTING status
I0816 23:17:31.061097 28824 master.cpp:469] Using default 'crammd5' authenticator
I0816 23:17:31.061821 28824 master.cpp:506] Authorization enabled
I0816 23:17:31.062140 28815 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0816 23:17:31.062588 28813 recover.cpp:195] Received a recover response from a replica in STARTING status
I0816 23:17:31.063361 28813 hierarchical.hpp:346] Initialized hierarchical allocator process
I0816 23:17:31.063518 28813 whitelist_watcher.cpp:79] No whitelist given
I0816 23:17:31.063710 28813 recover.cpp:566] Updating replica status to VOTING
I0816 23:17:31.064995 28821 master.cpp:1525] The newly elected leader is master@172.17.1.189:43501 with id 20150816-231731-3170963884-43501-28791
I0816 23:17:31.065104 28821 master.cpp:1538] Elected as the leading master!
I0816 23:17:31.065295 28821 master.cpp:1308] Recovering from registrar
I0816 23:17:31.065553 28817 registrar.cpp:311] Recovering registrar
I0816 23:17:31.065217 28824 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 670276ns
I0816 23:17:31.065691 28824 replica.cpp:323] Persisted replica status to VOTING
I0816 23:17:31.065898 28824 recover.cpp:580] Successfully joined the Paxos group
I0816 23:17:31.066138 28824 recover.cpp:464] Recover process terminated
I0816 23:17:31.066892 28825 log.cpp:661] Attempting to start the writer
I0816 23:17:31.068886 28812 replica.cpp:477] Replica received implicit promise request with proposal 1
I0816 23:17:31.070206 28812 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 1.283802ms
I0816 23:17:31.070250 28812 replica.cpp:345] Persisted promised to 1
I0816 23:17:31.071293 28812 coordinator.cpp:231] Coordinator attemping to fill missing position
I0816 23:17:31.072914 28813 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0816 23:17:31.073424 28813 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 389202ns
I0816 23:17:31.073532 28813 replica.cpp:679] Persisted action at 0
I0816 23:17:31.074834 28812 replica.cpp:511] Replica received write request for position 0
I0816 23:17:31.074898 28812 leveldb.cpp:438] Reading position from leveldb took 32910ns
I0816 23:17:31.075289 28812 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 337972ns
I0816 23:17:31.075320 28812 replica.cpp:679] Persisted action at 0
I0816 23:17:31.076035 28813 replica.cpp:658] Replica received learned notice for position 0
I0816 23:17:31.076385 28813 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 319519ns
I0816 23:17:31.076416 28813 replica.cpp:679] Persisted action at 0
I0816 23:17:31.076442 28813 replica.cpp:664] Replica learned NOP action at position 0
I0816 23:17:31.077333 28819 log.cpp:677] Writer started with ending position 0
I0816 23:17:31.078739 28811 leveldb.cpp:438] Reading position from leveldb took 34286ns
I0816 23:17:31.082345 28811 registrar.cpp:344] Successfully fetched the registry (0B) in 16.726016ms
I0816 23:17:31.082486 28811 registrar.cpp:443] Applied 1 operations in 32426ns; attempting to update the 'registry'
I0816 23:17:31.085695 28814 log.cpp:685] Attempting to append 178 bytes to the log
I0816 23:17:31.085945 28814 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0816 23:17:31.086993 28811 replica.cpp:511] Replica received write request for position 1
I0816 23:17:31.087520 28811 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 483448ns
I0816 23:17:31.087555 28811 replica.cpp:679] Persisted action at 1
I0816 23:17:31.088665 28822 replica.cpp:658] Replica received learned notice for position 1
I0816 23:17:31.089217 28822 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 419287ns
I0816 23:17:31.089345 28822 replica.cpp:679] Persisted action at 1
I0816 23:17:31.089478 28822 replica.cpp:664] Replica learned APPEND action at position 1
I0816 23:17:31.096542 28816 registrar.cpp:488] Successfully updated the 'registry' in 13.9712ms
I0816 23:17:31.096724 28816 registrar.cpp:374] Successfully recovered registrar
I0816 23:17:31.097434 28821 log.cpp:704] Attempting to truncate the log to 1
I0816 23:17:31.097599 28816 master.cpp:1335] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I0816 23:17:31.097725 28823 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0816 23:17:31.098968 28821 replica.cpp:511] Replica received write request for position 2
I0816 23:17:31.099483 28821 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 473232ns
I0816 23:17:31.099515 28821 replica.cpp:679] Persisted action at 2
I0816 23:17:31.100327 28814 replica.cpp:658] Replica received learned notice for position 2
I0816 23:17:31.100708 28814 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 350371ns
I0816 23:17:31.100772 28814 leveldb.cpp:401] Deleting ~1 keys from leveldb took 34696ns
I0816 23:17:31.100802 28814 replica.cpp:679] Persisted action at 2
I0816 23:17:31.100852 28814 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0816 23:17:31.108292 28791 scheduler.cpp:157] Version: 0.24.0
I0816 23:17:31.111857 28820 scheduler.cpp:241] New master detected at master@172.17.1.189:43501
I0816 23:17:31.113121 28820 scheduler.cpp:303] Sending SUBSCRIBE call to master@172.17.1.189:43501
I0816 23:17:31.114980 28817 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0816 23:17:31.115277 28817 http.cpp:319] HTTP POST for /master/api/v1/scheduler from 172.17.1.189:41638
I0816 23:17:31.115510 28817 master.cpp:1783] Received subscription request for HTTP framework 'default'
I0816 23:17:31.115598 28817 master.cpp:1564] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0816 23:17:31.115916 28817 master.cpp:1875] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0816 23:17:31.116341 28818 hierarchical.hpp:391] Added framework 20150816-231731-3170963884-43501-28791-0000
I0816 23:17:31.116359 28817 master.hpp:1308] Sending heartbeat to 20150816-231731-3170963884-43501-28791-0000
I0816 23:17:31.116521 28818 hierarchical.hpp:1008] No resources available to allocate!
I0816 23:17:31.116623 28818 hierarchical.hpp:908] Performed allocation for 0 slaves in 169105ns
I0816 23:17:31.117503 28811 scheduler.cpp:454] Enqueuing event SUBSCRIBED received from master@172.17.1.189:43501
I0816 23:17:31.118244 28823 scheduler.cpp:454] Enqueuing event HEARTBEAT received from master@172.17.1.189:43501
I0816 23:17:31.118665 28821 scheduler_tests.cpp:113] Ignoring HEARTBEAT event
I0816 23:17:31.119316 28824 scheduler.cpp:303] Sending REQUEST call to master@172.17.1.189:43501
I0816 23:17:31.120908 28825 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0816 23:17:31.121181 28825 http.cpp:319] HTTP POST for /master/api/v1/scheduler from 172.17.1.189:41639
I0816 23:17:31.121297 28825 master.cpp:2486] Processing REQUEST call for framework 20150816-231731-3170963884-43501-28791-0000 (default)
I0816 23:17:31.121539 28815 hierarchical.hpp:666] Received resource request from framework 20150816-231731-3170963884-43501-28791-0000
I0816 23:17:31.121985 28813 master.cpp:860] Master terminating
I0816 23:17:31.123162 28813 hierarchical.hpp:428] Removed framework 20150816-231731-3170963884-43501-28791-0000
E0816 23:17:31.123795 28813 scheduler.cpp:428] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (79 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
Using temporary directory '/tmp/ContentType_SchedulerTest_Request_1_4SaZm2'
I0816 23:17:31.131410 28791 leveldb.cpp:176] Opened db in 2.080455ms
I0816 23:17:31.132832 28791 leveldb.cpp:183] Compacted db in 1.380304ms
I0816 23:17:31.132889 28791 leveldb.cpp:198] Created db iterator in 21118ns
I0816 23:17:31.133014 28791 leveldb.cpp:204] Seeked to beginning of db in 2387ns
I0816 23:17:31.133038 28791 leveldb.cpp:273] Iterated through 0 keys in the db in 367ns
I0816 23:17:31.133096 28791 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0816 23:17:31.133761 28814 recover.cpp:449] Starting replica recovery
I0816 23:17:31.134057 28814 recover.cpp:475] Replica is in EMPTY status
I0816 23:17:31.135463 28810 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0816 23:17:31.137058 28823 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0816 23:17:31.137869 28824 recover.cpp:566] Updating replica status to STARTING
I0816 23:17:31.138294 28812 master.cpp:378] Master 20150816-231731-3170963884-43501-28791 (f3a9451c4cf3) started on 172.17.1.189:43501
I0816 23:17:31.138445 28812 master.cpp:380] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ContentType_SchedulerTest_Request_1_4SaZm2/credentials" --framework_sorter="drf" --help="false" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.24.0/_inst/share/mesos/webui" --work_dir="/tmp/ContentType_SchedulerTest_Request_1_4SaZm2/master" --zk_session_timeout="10secs"
I0816 23:17:31.139091 28812 master.cpp:427] Master allowing unauthenticated frameworks to register
I0816 23:17:31.139225 28812 master.cpp:430] Master only allowing authenticated slaves to register
I0816 23:17:31.139320 28812 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_Request_1_4SaZm2/credentials'
I0816 23:17:31.139107 28817 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 706096ns
I0816 23:17:31.139456 28817 replica.cpp:323] Persisted replica status to STARTING
I0816 23:17:31.139842 28812 master.cpp:469] Using default 'crammd5' authenticator
I0816 23:17:31.139853 28817 recover.cpp:475] Replica is in STARTING status
I0816 23:17:31.140095 28812 master.cpp:506] Authorization enabled
I0816 23:17:31.140969 28810 hierarchical.hpp:346] Initialized hierarchical allocator process
I0816 23:17:31.141042 28825 whitelist_watcher.cpp:79] No whitelist given
I0816 23:17:31.141492 28817 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0816 23:17:31.141980 28821 recover.cpp:195] Received a recover response from a replica in STARTING status
I0816 23:17:31.142488 28821 recover.cpp:566] Updating replica status to VOTING
I0816 23:17:31.143126 28821 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 363250ns
I0816 23:17:31.143312 28821 replica.cpp:323] Persisted replica status to VOTING
I0816 23:17:31.143584 28822 recover.cpp:580] Successfully joined the Paxos group
I0816 23:17:31.143851 28822 recover.cpp:464] Recover process terminated
I0816 23:17:31.144505 28821 master.cpp:1525] The newly elected leader is master@172.17.1.189:43501 with id 20150816-231731-3170963884-43501-28791
I0816 23:17:31.144549 28821 master.cpp:1538] Elected as the leading master!
I0816 23:17:31.144579 28821 master.cpp:1308] Recovering from registrar
I0816 23:17:31.144841 28813 registrar.cpp:311] Recovering registrar
I0816 23:17:31.145665 28820 log.cpp:661] Attempting to start the writer
I0816 23:17:31.146898 28821 replica.cpp:477] Replica received implicit promise request with proposal 1
I0816 23:17:31.147299 28821 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 369709ns
I0816 23:17:31.147325 28821 replica.cpp:345] Persisted promised to 1
I0816 23:17:31.147950 28818 coordinator.cpp:231] Coordinator attemping to fill missing position
I0816 23:17:31.149188 28818 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0816 23:17:31.149565 28818 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 337786ns
I0816 23:17:31.149590 28818 replica.cpp:679] Persisted action at 0
I0816 23:17:31.150715 28810 replica.cpp:511] Replica received write request for position 0
I0816 23:17:31.150779 28810 leveldb.cpp:438] Reading position from leveldb took 32784ns
I0816 23:17:31.151120 28810 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 290527ns
I0816 23:17:31.151145 28810 replica.cpp:679] Persisted action at 0
I0816 23:17:31.151743 28810 replica.cpp:658] Replica received learned notice for position 0
I0816 23:17:31.152160 28810 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 392440ns
I0816 23:17:31.152264 28810 replica.cpp:679] Persisted action at 0
I0816 23:17:31.152390 28810 replica.cpp:664] Replica learned NOP action at position 0
I0816 23:17:31.153126 28810 log.cpp:677] Writer started with ending position 0
I0816 23:17:31.154252 28810 leveldb.cpp:438] Reading position from leveldb took 27432ns
I0816 23:17:31.157572 28810 registrar.cpp:344] Successfully fetched the registry (0B) in 12.606976ms
I0816 23:17:31.157713 28810 registrar.cpp:443] Applied 1 operations in 32260ns; attempting to update the 'registry'
I0816 23:17:31.160043 28817 log.cpp:685] Attempting to append 178 bytes to the log
I0816 23:17:31.160303 28818 coordinator.cpp:341] Coordinator attempting to write APPEND action at position 1
I0816 23:17:31.161242 28825 replica.cpp:511] Replica received write request for position 1
I0816 23:17:31.161664 28825 leveldb.cpp:343] Persisting action (197 bytes) to leveldb took 387353ns
I0816 23:17:31.161691 28825 replica.cpp:679] Persisted action at 1
I0816 23:17:31.162490 28820 replica.cpp:658] Replica received learned notice for position 1
I0816 23:17:31.162801 28820 leveldb.cpp:343] Persisting action (199 bytes) to leveldb took 283128ns
I0816 23:17:31.162837 28820 replica.cpp:679] Persisted action at 1
I0816 23:17:31.162868 28820 replica.cpp:664] Replica learned APPEND action at position 1
I0816 23:17:31.164122 28818 registrar.cpp:488] Successfully updated the 'registry' in 6.349056ms
I0816 23:17:31.164299 28818 registrar.cpp:374] Successfully recovered registrar
I0816 23:17:31.164427 28824 log.cpp:704] Attempting to truncate the log to 1
I0816 23:17:31.164638 28815 master.cpp:1335] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I0816 23:17:31.164751 28821 coordinator.cpp:341] Coordinator attempting to write TRUNCATE action at position 2
I0816 23:17:31.165642 28825 replica.cpp:511] Replica received write request for position 2
I0816 23:17:31.166010 28825 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 335033ns
I0816 23:17:31.166035 28825 replica.cpp:679] Persisted action at 2
I0816 23:17:31.166648 28825 replica.cpp:658] Replica received learned notice for position 2
I0816 23:17:31.166970 28825 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 294494ns
I0816 23:17:31.167038 28825 leveldb.cpp:401] Deleting ~1 keys from leveldb took 42732ns
I0816 23:17:31.167062 28825 replica.cpp:679] Persisted action at 2
I0816 23:17:31.167105 28825 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0816 23:17:31.176028 28791 scheduler.cpp:157] Version: 0.24.0
I0816 23:17:31.179354 28815 scheduler.cpp:241] New master detected at master@172.17.1.189:43501
I0816 23:17:31.180956 28819 scheduler.cpp:303] Sending SUBSCRIBE call to master@172.17.1.189:43501
I0816 23:17:31.183012 28811 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0816 23:17:31.183341 28811 http.cpp:319] HTTP POST for /master/api/v1/scheduler from 172.17.1.189:41640
I0816 23:17:31.183784 28811 master.cpp:1783] Received subscription request for HTTP framework 'default'
I0816 23:17:31.184041 28811 master.cpp:1564] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0816 23:17:31.184543 28811 master.cpp:1875] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0816 23:17:31.185025 28821 hierarchical.hpp:391] Added framework 20150816-231731-3170963884-43501-28791-0000
I0816 23:17:31.185063 28821 hierarchical.hpp:1008] No resources available to allocate!
I0816 23:17:31.185080 28821 hierarchical.hpp:908] Performed allocation for 0 slaves in 27291ns
I0816 23:17:31.185158 28811 master.hpp:1308] Sending heartbeat to 20150816-231731-3170963884-43501-28791-0000
I0816 23:17:31.186316 28811 scheduler.cpp:454] Enqueuing event SUBSCRIBED received from master@172.17.1.189:43501
I0816 23:17:31.186849 28811 scheduler.cpp:454] Enqueuing event HEARTBEAT received from master@172.17.1.189:43501
I0816 23:17:31.187870 28823 scheduler.cpp:303] Sending REQUEST call to master@172.17.1.189:43501
I0816 23:17:31.188308 28813 scheduler_tests.cpp:113] Ignoring HEARTBEAT event
I0816 23:17:31.189769 28813 process.cpp:3043] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0816 23:17:31.189956 28813 http.cpp:319] HTTP POST for /master/api/v1/scheduler from 172.17.1.189:41641
I0816 23:17:31.190228 28813 master.cpp:2486] Processing REQUEST call for framework 20150816-231731-3170963884-43501-28791-0000 (default)
I0816 23:17:31.190359 28814 hierarchical.hpp:666] Received resource request from framework 20150816-231731-3170963884-43501-28791-0000
I0816 23:17:31.190635 28816 master.cpp:860] Master terminating
I0816 23:17:31.191082 28816 hierarchical.hpp:428] Removed framework 20150816-231731-3170963884-43501-28791-0000
E0816 23:17:31.192560 28824 scheduler.cpp:428] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (71 ms)
[----------] 20 tests from ContentType/SchedulerTest (4365 ms total)
[----------] Global test environment tear-down
[==========] 737 tests from 101 test cases ran. (301066 ms total)
[ PASSED ] 736 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ContentType/HttpApiTest.UpdatePidToHttpSchedulerWithoutForce/1, where GetParam() = "application/json"
1 FAILED TEST
YOU HAVE 8 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.24.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1439765533-12779
Untagged: mesos-1439765533-12779:latest
Deleted: 2bbdc22192b2831f691dbd1be511e6f9df5f47485e435a96606f3f20d5b9a5e6
Deleted: 28e60206757d3e429c4c616bc8dbef6acd1b9ee79fd0397606e15875897ba81d
Deleted: 57e9300cc221006b8aee71b4d681563e74caec16b006def75ca7986804b09b7a
Deleted: b52ccb0b51cc4b8105df2b5ac90c9c80d36a70145a302ad1a098b81ed6f3d902
Deleted: 8740eb1183bc4901cdd843e4dd85ffff80feaf7926116d3523d65c09b3f5893f
Deleted: 811033996baf125f992ff284f8f31a2f06269ab58c47f0ac569ab4a53b84df70
Deleted: 0e6122509f086b9a5ca51fa5f15d400ad2b002a0d937474369f8e0353ca9d5f7
Deleted: 410f333a44841952a7e31f750a1191e33e5435dadd631e60729615d959f7d976
Deleted: 4bf608e2d5199f4db9341f9506ccfbaf2000664929f0a27edc3800ecd2c1d6e1
Deleted: 3a0dc2b7582490361511271f2d8dede9df59ceb3d4d9a573a9460a4c811bd2cd
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent,centos:7,docker||Hadoop #709
Posted by Vinod Kone <vi...@apache.org>.
filed https://issues.apache.org/jira/browse/MESOS-3275
On Sun, Aug 16, 2015 at 4:16 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent,OS=centos%3A7,label_exp=docker%7C%7CHadoop/709/changes
> >
>
> Changes:
>
> [vinodkone] Logged Scheduler HTTP API Requests in the master.
>
> [vinodkone] Added more logging to the scheduler library.
>
> ------------------------------------------
> [...truncated 119637 lines...]
> I0816 23:17:31.040223 28823 slave.cpp:5094] Terminating task
> dbfa3d17-a23d-41d2-aac7-e36a740f0c9c
> I0816 23:17:31.041010 28823 slave.cpp:564] Slave terminating
> I0816 23:17:31.041354 28823 slave.cpp:1959] Asked to shut down framework
> 20150816-231730-3170963884-43501-28791-0000 by @0.0.0.0:0
> I0816 23:17:31.041558 28823 slave.cpp:1984] Shutting down framework
> 20150816-231730-3170963884-43501-28791-0000
> I0816 23:17:31.041896 28823 slave.cpp:3503] Cleaning up executor 'default'
> of framework 20150816-231730-3170963884-43501-28791-0000
> I0816 23:17:31.042533 28823 slave.cpp:3592] Cleaning up framework
> 20150816-231730-3170963884-43501-28791-0000
> I0816 23:17:31.042759 28820 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_ZgzCSX/slaves/20150816-231730-3170963884-43501-28791-S0/frameworks/20150816-231730-3170963884-43501-28791-0000/executors/default/runs/9a7738ad-57fa-4ceb-a2b9-686cba7180ca'
> for gc 6.99999951041778days in the future
> I0816 23:17:31.043351 28820 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_ZgzCSX/slaves/20150816-231730-3170963884-43501-28791-S0/frameworks/20150816-231730-3170963884-43501-28791-0000/executors/default'
> for gc 6.99999950839111days in the future
> I0816 23:17:31.043689 28820 status_update_manager.cpp:284] Closing status
> update streams for framework 20150816-231730-3170963884-43501-28791-0000
> I0816 23:17:31.043779 28820 status_update_manager.cpp:530] Cleaning up
> status update stream for task dbfa3d17-a23d-41d2-aac7-e36a740f0c9c of
> framework 20150816-231730-3170963884-43501-28791-0000
> I0816 23:17:31.044090 28813 gc.cpp:56] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_ZgzCSX/slaves/20150816-231730-3170963884-43501-28791-S0/frameworks/20150816-231730-3170963884-43501-28791-0000'
> for gc 6.99999949479111days in the future
> [ OK ] ContentType/SchedulerTest.Message/1 (138 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_0_XCjeZ0'
> I0816 23:17:31.052975 28791 leveldb.cpp:176] Opened db in 2.557515ms
> I0816 23:17:31.053910 28791 leveldb.cpp:183] Compacted db in 789593ns
> I0816 23:17:31.054039 28791 leveldb.cpp:198] Created db iterator in 20702ns
> I0816 23:17:31.054219 28791 leveldb.cpp:204] Seeked to beginning of db in
> 2443ns
> I0816 23:17:31.054325 28791 leveldb.cpp:273] Iterated through 0 keys in
> the db in 478ns
> I0816 23:17:31.054502 28791 replica.cpp:744] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0816 23:17:31.055794 28824 recover.cpp:449] Starting replica recovery
> I0816 23:17:31.056430 28824 recover.cpp:475] Replica is in EMPTY status
> I0816 23:17:31.057747 28824 replica.cpp:641] Replica in EMPTY status
> received a broadcasted recover request
> I0816 23:17:31.058665 28812 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I0816 23:17:31.059424 28823 recover.cpp:566] Updating replica status to
> STARTING
> I0816 23:17:31.059902 28824 master.cpp:378] Master
> 20150816-231731-3170963884-43501-28791 (f3a9451c4cf3) started on
> 172.17.1.189:43501
> I0816 23:17:31.060251 28819 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 560753ns
> I0816 23:17:31.060346 28819 replica.cpp:323] Persisted replica status to
> STARTING
> I0816 23:17:31.060086 28824 master.cpp:380] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ContentType_SchedulerTest_Request_0_XCjeZ0/credentials"
> --framework_sorter="drf" --help="false" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.24.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ContentType_SchedulerTest_Request_0_XCjeZ0/master"
> --zk_session_timeout="10secs"
> I0816 23:17:31.060647 28824 master.cpp:427] Master allowing
> unauthenticated frameworks to register
> I0816 23:17:31.060684 28824 master.cpp:430] Master only allowing
> authenticated slaves to register
> I0816 23:17:31.060698 28824 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerTest_Request_0_XCjeZ0/credentials'
> I0816 23:17:31.060837 28819 recover.cpp:475] Replica is in STARTING status
> I0816 23:17:31.061097 28824 master.cpp:469] Using default 'crammd5'
> authenticator
> I0816 23:17:31.061821 28824 master.cpp:506] Authorization enabled
> I0816 23:17:31.062140 28815 replica.cpp:641] Replica in STARTING status
> received a broadcasted recover request
> I0816 23:17:31.062588 28813 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I0816 23:17:31.063361 28813 hierarchical.hpp:346] Initialized hierarchical
> allocator process
> I0816 23:17:31.063518 28813 whitelist_watcher.cpp:79] No whitelist given
> I0816 23:17:31.063710 28813 recover.cpp:566] Updating replica status to
> VOTING
> I0816 23:17:31.064995 28821 master.cpp:1525] The newly elected leader is
> master@172.17.1.189:43501 with id 20150816-231731-3170963884-43501-28791
> I0816 23:17:31.065104 28821 master.cpp:1538] Elected as the leading master!
> I0816 23:17:31.065295 28821 master.cpp:1308] Recovering from registrar
> I0816 23:17:31.065553 28817 registrar.cpp:311] Recovering registrar
> I0816 23:17:31.065217 28824 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 670276ns
> I0816 23:17:31.065691 28824 replica.cpp:323] Persisted replica status to
> VOTING
> I0816 23:17:31.065898 28824 recover.cpp:580] Successfully joined the Paxos
> group
> I0816 23:17:31.066138 28824 recover.cpp:464] Recover process terminated
> I0816 23:17:31.066892 28825 log.cpp:661] Attempting to start the writer
> I0816 23:17:31.068886 28812 replica.cpp:477] Replica received implicit
> promise request with proposal 1
> I0816 23:17:31.070206 28812 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 1.283802ms
> I0816 23:17:31.070250 28812 replica.cpp:345] Persisted promised to 1
> I0816 23:17:31.071293 28812 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I0816 23:17:31.072914 28813 replica.cpp:378] Replica received explicit
> promise request for position 0 with proposal 2
> I0816 23:17:31.073424 28813 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 389202ns
> I0816 23:17:31.073532 28813 replica.cpp:679] Persisted action at 0
> I0816 23:17:31.074834 28812 replica.cpp:511] Replica received write
> request for position 0
> I0816 23:17:31.074898 28812 leveldb.cpp:438] Reading position from leveldb
> took 32910ns
> I0816 23:17:31.075289 28812 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 337972ns
> I0816 23:17:31.075320 28812 replica.cpp:679] Persisted action at 0
> I0816 23:17:31.076035 28813 replica.cpp:658] Replica received learned
> notice for position 0
> I0816 23:17:31.076385 28813 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 319519ns
> I0816 23:17:31.076416 28813 replica.cpp:679] Persisted action at 0
> I0816 23:17:31.076442 28813 replica.cpp:664] Replica learned NOP action at
> position 0
> I0816 23:17:31.077333 28819 log.cpp:677] Writer started with ending
> position 0
> I0816 23:17:31.078739 28811 leveldb.cpp:438] Reading position from leveldb
> took 34286ns
> I0816 23:17:31.082345 28811 registrar.cpp:344] Successfully fetched the
> registry (0B) in 16.726016ms
> I0816 23:17:31.082486 28811 registrar.cpp:443] Applied 1 operations in
> 32426ns; attempting to update the 'registry'
> I0816 23:17:31.085695 28814 log.cpp:685] Attempting to append 178 bytes to
> the log
> I0816 23:17:31.085945 28814 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I0816 23:17:31.086993 28811 replica.cpp:511] Replica received write
> request for position 1
> I0816 23:17:31.087520 28811 leveldb.cpp:343] Persisting action (197 bytes)
> to leveldb took 483448ns
> I0816 23:17:31.087555 28811 replica.cpp:679] Persisted action at 1
> I0816 23:17:31.088665 28822 replica.cpp:658] Replica received learned
> notice for position 1
> I0816 23:17:31.089217 28822 leveldb.cpp:343] Persisting action (199 bytes)
> to leveldb took 419287ns
> I0816 23:17:31.089345 28822 replica.cpp:679] Persisted action at 1
> I0816 23:17:31.089478 28822 replica.cpp:664] Replica learned APPEND action
> at position 1
> I0816 23:17:31.096542 28816 registrar.cpp:488] Successfully updated the
> 'registry' in 13.9712ms
> I0816 23:17:31.096724 28816 registrar.cpp:374] Successfully recovered
> registrar
> I0816 23:17:31.097434 28821 log.cpp:704] Attempting to truncate the log to
> 1
> I0816 23:17:31.097599 28816 master.cpp:1335] Recovered 0 slaves from the
> Registry (139B) ; allowing 10mins for slaves to re-register
> I0816 23:17:31.097725 28823 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I0816 23:17:31.098968 28821 replica.cpp:511] Replica received write
> request for position 2
> I0816 23:17:31.099483 28821 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 473232ns
> I0816 23:17:31.099515 28821 replica.cpp:679] Persisted action at 2
> I0816 23:17:31.100327 28814 replica.cpp:658] Replica received learned
> notice for position 2
> I0816 23:17:31.100708 28814 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 350371ns
> I0816 23:17:31.100772 28814 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 34696ns
> I0816 23:17:31.100802 28814 replica.cpp:679] Persisted action at 2
> I0816 23:17:31.100852 28814 replica.cpp:664] Replica learned TRUNCATE
> action at position 2
> I0816 23:17:31.108292 28791 scheduler.cpp:157] Version: 0.24.0
> I0816 23:17:31.111857 28820 scheduler.cpp:241] New master detected at
> master@172.17.1.189:43501
> I0816 23:17:31.113121 28820 scheduler.cpp:303] Sending SUBSCRIBE call to
> master@172.17.1.189:43501
> I0816 23:17:31.114980 28817 process.cpp:3043] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0816 23:17:31.115277 28817 http.cpp:319] HTTP POST for
> /master/api/v1/scheduler from 172.17.1.189:41638
> I0816 23:17:31.115510 28817 master.cpp:1783] Received subscription request
> for HTTP framework 'default'
> I0816 23:17:31.115598 28817 master.cpp:1564] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0816 23:17:31.115916 28817 master.cpp:1875] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0816 23:17:31.116341 28818 hierarchical.hpp:391] Added framework
> 20150816-231731-3170963884-43501-28791-0000
> I0816 23:17:31.116359 28817 master.hpp:1308] Sending heartbeat to
> 20150816-231731-3170963884-43501-28791-0000
> I0816 23:17:31.116521 28818 hierarchical.hpp:1008] No resources available
> to allocate!
> I0816 23:17:31.116623 28818 hierarchical.hpp:908] Performed allocation for
> 0 slaves in 169105ns
> I0816 23:17:31.117503 28811 scheduler.cpp:454] Enqueuing event SUBSCRIBED
> received from master@172.17.1.189:43501
> I0816 23:17:31.118244 28823 scheduler.cpp:454] Enqueuing event HEARTBEAT
> received from master@172.17.1.189:43501
> I0816 23:17:31.118665 28821 scheduler_tests.cpp:113] Ignoring HEARTBEAT
> event
> I0816 23:17:31.119316 28824 scheduler.cpp:303] Sending REQUEST call to
> master@172.17.1.189:43501
> I0816 23:17:31.120908 28825 process.cpp:3043] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0816 23:17:31.121181 28825 http.cpp:319] HTTP POST for
> /master/api/v1/scheduler from 172.17.1.189:41639
> I0816 23:17:31.121297 28825 master.cpp:2486] Processing REQUEST call for
> framework 20150816-231731-3170963884-43501-28791-0000 (default)
> I0816 23:17:31.121539 28815 hierarchical.hpp:666] Received resource
> request from framework 20150816-231731-3170963884-43501-28791-0000
> I0816 23:17:31.121985 28813 master.cpp:860] Master terminating
> I0816 23:17:31.123162 28813 hierarchical.hpp:428] Removed framework
> 20150816-231731-3170963884-43501-28791-0000
> E0816 23:17:31.123795 28813 scheduler.cpp:428] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (79 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> Using temporary directory '/tmp/ContentType_SchedulerTest_Request_1_4SaZm2'
> I0816 23:17:31.131410 28791 leveldb.cpp:176] Opened db in 2.080455ms
> I0816 23:17:31.132832 28791 leveldb.cpp:183] Compacted db in 1.380304ms
> I0816 23:17:31.132889 28791 leveldb.cpp:198] Created db iterator in 21118ns
> I0816 23:17:31.133014 28791 leveldb.cpp:204] Seeked to beginning of db in
> 2387ns
> I0816 23:17:31.133038 28791 leveldb.cpp:273] Iterated through 0 keys in
> the db in 367ns
> I0816 23:17:31.133096 28791 replica.cpp:744] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0816 23:17:31.133761 28814 recover.cpp:449] Starting replica recovery
> I0816 23:17:31.134057 28814 recover.cpp:475] Replica is in EMPTY status
> I0816 23:17:31.135463 28810 replica.cpp:641] Replica in EMPTY status
> received a broadcasted recover request
> I0816 23:17:31.137058 28823 recover.cpp:195] Received a recover response
> from a replica in EMPTY status
> I0816 23:17:31.137869 28824 recover.cpp:566] Updating replica status to
> STARTING
> I0816 23:17:31.138294 28812 master.cpp:378] Master
> 20150816-231731-3170963884-43501-28791 (f3a9451c4cf3) started on
> 172.17.1.189:43501
> I0816 23:17:31.138445 28812 master.cpp:380] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/ContentType_SchedulerTest_Request_1_4SaZm2/credentials"
> --framework_sorter="drf" --help="false" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_slave_ping_timeouts="5" --quiet="false"
> --recovery_slave_removal_limit="100%" --registry="replicated_log"
> --registry_fetch_timeout="1mins" --registry_store_timeout="25secs"
> --registry_strict="true" --root_submissions="true"
> --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.24.0/_inst/share/mesos/webui"
> --work_dir="/tmp/ContentType_SchedulerTest_Request_1_4SaZm2/master"
> --zk_session_timeout="10secs"
> I0816 23:17:31.139091 28812 master.cpp:427] Master allowing
> unauthenticated frameworks to register
> I0816 23:17:31.139225 28812 master.cpp:430] Master only allowing
> authenticated slaves to register
> I0816 23:17:31.139320 28812 credentials.hpp:37] Loading credentials for
> authentication from
> '/tmp/ContentType_SchedulerTest_Request_1_4SaZm2/credentials'
> I0816 23:17:31.139107 28817 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 706096ns
> I0816 23:17:31.139456 28817 replica.cpp:323] Persisted replica status to
> STARTING
> I0816 23:17:31.139842 28812 master.cpp:469] Using default 'crammd5'
> authenticator
> I0816 23:17:31.139853 28817 recover.cpp:475] Replica is in STARTING status
> I0816 23:17:31.140095 28812 master.cpp:506] Authorization enabled
> I0816 23:17:31.140969 28810 hierarchical.hpp:346] Initialized hierarchical
> allocator process
> I0816 23:17:31.141042 28825 whitelist_watcher.cpp:79] No whitelist given
> I0816 23:17:31.141492 28817 replica.cpp:641] Replica in STARTING status
> received a broadcasted recover request
> I0816 23:17:31.141980 28821 recover.cpp:195] Received a recover response
> from a replica in STARTING status
> I0816 23:17:31.142488 28821 recover.cpp:566] Updating replica status to
> VOTING
> I0816 23:17:31.143126 28821 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 363250ns
> I0816 23:17:31.143312 28821 replica.cpp:323] Persisted replica status to
> VOTING
> I0816 23:17:31.143584 28822 recover.cpp:580] Successfully joined the Paxos
> group
> I0816 23:17:31.143851 28822 recover.cpp:464] Recover process terminated
> I0816 23:17:31.144505 28821 master.cpp:1525] The newly elected leader is
> master@172.17.1.189:43501 with id 20150816-231731-3170963884-43501-28791
> I0816 23:17:31.144549 28821 master.cpp:1538] Elected as the leading
> master!
> I0816 23:17:31.144579 28821 master.cpp:1308] Recovering from registrar
> I0816 23:17:31.144841 28813 registrar.cpp:311] Recovering registrar
> I0816 23:17:31.145665 28820 log.cpp:661] Attempting to start the writer
> I0816 23:17:31.146898 28821 replica.cpp:477] Replica received implicit
> promise request with proposal 1
> I0816 23:17:31.147299 28821 leveldb.cpp:306] Persisting metadata (8 bytes)
> to leveldb took 369709ns
> I0816 23:17:31.147325 28821 replica.cpp:345] Persisted promised to 1
> I0816 23:17:31.147950 28818 coordinator.cpp:231] Coordinator attemping to
> fill missing position
> I0816 23:17:31.149188 28818 replica.cpp:378] Replica received explicit
> promise request for position 0 with proposal 2
> I0816 23:17:31.149565 28818 leveldb.cpp:343] Persisting action (8 bytes)
> to leveldb took 337786ns
> I0816 23:17:31.149590 28818 replica.cpp:679] Persisted action at 0
> I0816 23:17:31.150715 28810 replica.cpp:511] Replica received write
> request for position 0
> I0816 23:17:31.150779 28810 leveldb.cpp:438] Reading position from leveldb
> took 32784ns
> I0816 23:17:31.151120 28810 leveldb.cpp:343] Persisting action (14 bytes)
> to leveldb took 290527ns
> I0816 23:17:31.151145 28810 replica.cpp:679] Persisted action at 0
> I0816 23:17:31.151743 28810 replica.cpp:658] Replica received learned
> notice for position 0
> I0816 23:17:31.152160 28810 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 392440ns
> I0816 23:17:31.152264 28810 replica.cpp:679] Persisted action at 0
> I0816 23:17:31.152390 28810 replica.cpp:664] Replica learned NOP action at
> position 0
> I0816 23:17:31.153126 28810 log.cpp:677] Writer started with ending
> position 0
> I0816 23:17:31.154252 28810 leveldb.cpp:438] Reading position from leveldb
> took 27432ns
> I0816 23:17:31.157572 28810 registrar.cpp:344] Successfully fetched the
> registry (0B) in 12.606976ms
> I0816 23:17:31.157713 28810 registrar.cpp:443] Applied 1 operations in
> 32260ns; attempting to update the 'registry'
> I0816 23:17:31.160043 28817 log.cpp:685] Attempting to append 178 bytes to
> the log
> I0816 23:17:31.160303 28818 coordinator.cpp:341] Coordinator attempting to
> write APPEND action at position 1
> I0816 23:17:31.161242 28825 replica.cpp:511] Replica received write
> request for position 1
> I0816 23:17:31.161664 28825 leveldb.cpp:343] Persisting action (197 bytes)
> to leveldb took 387353ns
> I0816 23:17:31.161691 28825 replica.cpp:679] Persisted action at 1
> I0816 23:17:31.162490 28820 replica.cpp:658] Replica received learned
> notice for position 1
> I0816 23:17:31.162801 28820 leveldb.cpp:343] Persisting action (199 bytes)
> to leveldb took 283128ns
> I0816 23:17:31.162837 28820 replica.cpp:679] Persisted action at 1
> I0816 23:17:31.162868 28820 replica.cpp:664] Replica learned APPEND action
> at position 1
> I0816 23:17:31.164122 28818 registrar.cpp:488] Successfully updated the
> 'registry' in 6.349056ms
> I0816 23:17:31.164299 28818 registrar.cpp:374] Successfully recovered
> registrar
> I0816 23:17:31.164427 28824 log.cpp:704] Attempting to truncate the log to
> 1
> I0816 23:17:31.164638 28815 master.cpp:1335] Recovered 0 slaves from the
> Registry (139B) ; allowing 10mins for slaves to re-register
> I0816 23:17:31.164751 28821 coordinator.cpp:341] Coordinator attempting to
> write TRUNCATE action at position 2
> I0816 23:17:31.165642 28825 replica.cpp:511] Replica received write
> request for position 2
> I0816 23:17:31.166010 28825 leveldb.cpp:343] Persisting action (16 bytes)
> to leveldb took 335033ns
> I0816 23:17:31.166035 28825 replica.cpp:679] Persisted action at 2
> I0816 23:17:31.166648 28825 replica.cpp:658] Replica received learned
> notice for position 2
> I0816 23:17:31.166970 28825 leveldb.cpp:343] Persisting action (18 bytes)
> to leveldb took 294494ns
> I0816 23:17:31.167038 28825 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 42732ns
> I0816 23:17:31.167062 28825 replica.cpp:679] Persisted action at 2
> I0816 23:17:31.167105 28825 replica.cpp:664] Replica learned TRUNCATE
> action at position 2
> I0816 23:17:31.176028 28791 scheduler.cpp:157] Version: 0.24.0
> I0816 23:17:31.179354 28815 scheduler.cpp:241] New master detected at
> master@172.17.1.189:43501
> I0816 23:17:31.180956 28819 scheduler.cpp:303] Sending SUBSCRIBE call to
> master@172.17.1.189:43501
> I0816 23:17:31.183012 28811 process.cpp:3043] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0816 23:17:31.183341 28811 http.cpp:319] HTTP POST for
> /master/api/v1/scheduler from 172.17.1.189:41640
> I0816 23:17:31.183784 28811 master.cpp:1783] Received subscription request
> for HTTP framework 'default'
> I0816 23:17:31.184041 28811 master.cpp:1564] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0816 23:17:31.184543 28811 master.cpp:1875] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0816 23:17:31.185025 28821 hierarchical.hpp:391] Added framework
> 20150816-231731-3170963884-43501-28791-0000
> I0816 23:17:31.185063 28821 hierarchical.hpp:1008] No resources available
> to allocate!
> I0816 23:17:31.185080 28821 hierarchical.hpp:908] Performed allocation for
> 0 slaves in 27291ns
> I0816 23:17:31.185158 28811 master.hpp:1308] Sending heartbeat to
> 20150816-231731-3170963884-43501-28791-0000
> I0816 23:17:31.186316 28811 scheduler.cpp:454] Enqueuing event SUBSCRIBED
> received from master@172.17.1.189:43501
> I0816 23:17:31.186849 28811 scheduler.cpp:454] Enqueuing event HEARTBEAT
> received from master@172.17.1.189:43501
> I0816 23:17:31.187870 28823 scheduler.cpp:303] Sending REQUEST call to
> master@172.17.1.189:43501
> I0816 23:17:31.188308 28813 scheduler_tests.cpp:113] Ignoring HEARTBEAT
> event
> I0816 23:17:31.189769 28813 process.cpp:3043] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0816 23:17:31.189956 28813 http.cpp:319] HTTP POST for
> /master/api/v1/scheduler from 172.17.1.189:41641
> I0816 23:17:31.190228 28813 master.cpp:2486] Processing REQUEST call for
> framework 20150816-231731-3170963884-43501-28791-0000 (default)
> I0816 23:17:31.190359 28814 hierarchical.hpp:666] Received resource
> request from framework 20150816-231731-3170963884-43501-28791-0000
> I0816 23:17:31.190635 28816 master.cpp:860] Master terminating
> I0816 23:17:31.191082 28816 hierarchical.hpp:428] Removed framework
> 20150816-231731-3170963884-43501-28791-0000
> E0816 23:17:31.192560 28824 scheduler.cpp:428] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (71 ms)
> [----------] 20 tests from ContentType/SchedulerTest (4365 ms total)
>
> [----------] Global test environment tear-down
> [==========] 737 tests from 101 test cases ran. (301066 ms total)
> [ PASSED ] 736 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ]
> ContentType/HttpApiTest.UpdatePidToHttpSchedulerWithoutForce/1, where
> GetParam() = "application/json"
>
> 1 FAILED TEST
> YOU HAVE 8 DISABLED TESTS
>
> make[4]: *** [check-local] Error 1
> make[4]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.24.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.24.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1439765533-12779
> Untagged: mesos-1439765533-12779:latest
> Deleted: 2bbdc22192b2831f691dbd1be511e6f9df5f47485e435a96606f3f20d5b9a5e6
> Deleted: 28e60206757d3e429c4c616bc8dbef6acd1b9ee79fd0397606e15875897ba81d
> Deleted: 57e9300cc221006b8aee71b4d681563e74caec16b006def75ca7986804b09b7a
> Deleted: b52ccb0b51cc4b8105df2b5ac90c9c80d36a70145a302ad1a098b81ed6f3d902
> Deleted: 8740eb1183bc4901cdd843e4dd85ffff80feaf7926116d3523d65c09b3f5893f
> Deleted: 811033996baf125f992ff284f8f31a2f06269ab58c47f0ac569ab4a53b84df70
> Deleted: 0e6122509f086b9a5ca51fa5f15d400ad2b002a0d937474369f8e0353ca9d5f7
> Deleted: 410f333a44841952a7e31f750a1191e33e5435dadd631e60729615d959f7d976
> Deleted: 4bf608e2d5199f4db9341f9506ccfbaf2000664929f0a27edc3800ecd2c1d6e1
> Deleted: 3a0dc2b7582490361511271f2d8dede9df59ceb3d4d9a573a9460a4c811bd2cd
> Build step 'Execute shell' marked build as failure
>
Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent,centos:7,docker||Hadoop #710
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent,OS=centos%3A7,label_exp=docker%7C%7CHadoop/710/changes>