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/12/01 03:40:07 UTC
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1296
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/1296/changes>
Changes:
[benjamin.mahler] Fixed a segmentation fault in the cgroups::freeze.
------------------------------------------
[...truncated 147166 lines...]
I1201 02:34:19.247105 31780 slave.cpp:3773] Cleaning up framework 1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000
I1201 02:34:19.247177 31791 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_J2f4ap/slaves/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-S0/frameworks/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000/executors/default' for gc 6.99999714068148days in the future
I1201 02:34:19.247334 31784 status_update_manager.cpp:282] Closing status update streams for framework 1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000
I1201 02:34:19.247409 31791 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_J2f4ap/slaves/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-S0/frameworks/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000' for gc 6.99999713849482days in the future
I1201 02:34:19.247490 31784 status_update_manager.cpp:528] Cleaning up status update stream for task f3e62156-97fd-493a-a3e5-9284571d98ab of framework 1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000
[ OK ] ContentType/SchedulerTest.Message/1 (118 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I1201 02:34:19.255559 31760 leveldb.cpp:174] Opened db in 3.050594ms
I1201 02:34:19.256408 31760 leveldb.cpp:181] Compacted db in 808375ns
I1201 02:34:19.256456 31760 leveldb.cpp:196] Created db iterator in 17455ns
I1201 02:34:19.256474 31760 leveldb.cpp:202] Seeked to beginning of db in 1827ns
I1201 02:34:19.256484 31760 leveldb.cpp:271] Iterated through 0 keys in the db in 315ns
I1201 02:34:19.256526 31760 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1201 02:34:19.257169 31792 recover.cpp:447] Starting replica recovery
I1201 02:34:19.258023 31789 recover.cpp:473] Replica is in EMPTY status
I1201 02:34:19.259486 31787 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (11281)@172.17.21.217:48328
I1201 02:34:19.260138 31781 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1201 02:34:19.260823 31793 recover.cpp:564] Updating replica status to STARTING
I1201 02:34:19.261028 31786 master.cpp:365] Master af781e59-a3b4-4c7b-9b12-3c148a5999ae (62ca2bb3ac6c) started on 172.17.21.217:48328
I1201 02:34:19.261060 31786 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/nGa4SZ/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/nGa4SZ/master" --zk_session_timeout="10secs"
I1201 02:34:19.261584 31786 master.cpp:414] Master allowing unauthenticated frameworks to register
I1201 02:34:19.261719 31786 master.cpp:417] Master only allowing authenticated slaves to register
I1201 02:34:19.261735 31786 credentials.hpp:35] Loading credentials for authentication from '/tmp/nGa4SZ/credentials'
I1201 02:34:19.261963 31782 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 658792ns
I1201 02:34:19.261996 31782 replica.cpp:321] Persisted replica status to STARTING
I1201 02:34:19.262101 31786 master.cpp:456] Using default 'crammd5' authenticator
I1201 02:34:19.262249 31786 master.cpp:493] Authorization enabled
I1201 02:34:19.262272 31787 recover.cpp:473] Replica is in STARTING status
I1201 02:34:19.262626 31781 hierarchical.cpp:162] Initialized hierarchical allocator process
I1201 02:34:19.262665 31789 whitelist_watcher.cpp:77] No whitelist given
I1201 02:34:19.263484 31785 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (11282)@172.17.21.217:48328
I1201 02:34:19.264495 31786 recover.cpp:193] Received a recover response from a replica in STARTING status
I1201 02:34:19.264688 31788 master.cpp:1637] The newly elected leader is master@172.17.21.217:48328 with id af781e59-a3b4-4c7b-9b12-3c148a5999ae
I1201 02:34:19.264734 31788 master.cpp:1650] Elected as the leading master!
I1201 02:34:19.264768 31788 master.cpp:1395] Recovering from registrar
I1201 02:34:19.265009 31782 registrar.cpp:307] Recovering registrar
I1201 02:34:19.265298 31788 recover.cpp:564] Updating replica status to VOTING
I1201 02:34:19.265972 31783 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 394581ns
I1201 02:34:19.266001 31783 replica.cpp:321] Persisted replica status to VOTING
I1201 02:34:19.266125 31787 recover.cpp:578] Successfully joined the Paxos group
I1201 02:34:19.266379 31787 recover.cpp:462] Recover process terminated
I1201 02:34:19.266872 31786 log.cpp:659] Attempting to start the writer
I1201 02:34:19.268193 31789 replica.cpp:494] Replica received implicit promise request from (11283)@172.17.21.217:48328 with proposal 1
I1201 02:34:19.268609 31789 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 374122ns
I1201 02:34:19.268636 31789 replica.cpp:343] Persisted promised to 1
I1201 02:34:19.269330 31782 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1201 02:34:19.270778 31781 replica.cpp:389] Replica received explicit promise request from (11284)@172.17.21.217:48328 for position 0 with proposal 2
I1201 02:34:19.271225 31781 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 402319ns
I1201 02:34:19.271302 31781 replica.cpp:713] Persisted action at 0
I1201 02:34:19.272378 31782 replica.cpp:538] Replica received write request for position 0 from (11285)@172.17.21.217:48328
I1201 02:34:19.272438 31782 leveldb.cpp:436] Reading position from leveldb took 28102ns
I1201 02:34:19.272884 31782 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 404732ns
I1201 02:34:19.272909 31782 replica.cpp:713] Persisted action at 0
I1201 02:34:19.273514 31794 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0
I1201 02:34:19.273974 31794 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 429297ns
I1201 02:34:19.273998 31794 replica.cpp:713] Persisted action at 0
I1201 02:34:19.274015 31794 replica.cpp:698] Replica learned NOP action at position 0
I1201 02:34:19.274664 31783 log.cpp:675] Writer started with ending position 0
I1201 02:34:19.276005 31793 leveldb.cpp:436] Reading position from leveldb took 32689ns
I1201 02:34:19.277209 31794 registrar.cpp:340] Successfully fetched the registry (0B) in 12.146944ms
I1201 02:34:19.277345 31794 registrar.cpp:439] Applied 1 operations in 27629ns; attempting to update the 'registry'
I1201 02:34:19.278126 31791 log.cpp:683] Attempting to append 178 bytes to the log
I1201 02:34:19.278381 31794 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1201 02:34:19.279250 31784 replica.cpp:538] Replica received write request for position 1 from (11286)@172.17.21.217:48328
I1201 02:34:19.279685 31784 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 362960ns
I1201 02:34:19.279716 31784 replica.cpp:713] Persisted action at 1
I1201 02:34:19.280517 31783 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0
I1201 02:34:19.280886 31783 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 328419ns
I1201 02:34:19.280915 31783 replica.cpp:713] Persisted action at 1
I1201 02:34:19.280937 31783 replica.cpp:698] Replica learned APPEND action at position 1
I1201 02:34:19.282039 31785 registrar.cpp:484] Successfully updated the 'registry' in 4.626176ms
I1201 02:34:19.282217 31785 registrar.cpp:370] Successfully recovered registrar
I1201 02:34:19.282318 31789 log.cpp:702] Attempting to truncate the log to 1
I1201 02:34:19.282459 31783 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1201 02:34:19.282727 31784 master.cpp:1447] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1201 02:34:19.282786 31788 hierarchical.cpp:174] Allocator recovery is not supported yet
I1201 02:34:19.283432 31781 replica.cpp:538] Replica received write request for position 2 from (11287)@172.17.21.217:48328
I1201 02:34:19.283809 31781 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 331619ns
I1201 02:34:19.283840 31781 replica.cpp:713] Persisted action at 2
I1201 02:34:19.284519 31779 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0
I1201 02:34:19.284941 31779 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 377829ns
I1201 02:34:19.285006 31779 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33814ns
I1201 02:34:19.285037 31779 replica.cpp:713] Persisted action at 2
I1201 02:34:19.285074 31779 replica.cpp:698] Replica learned TRUNCATE action at position 2
I1201 02:34:19.293673 31760 scheduler.cpp:154] Version: 0.27.0
I1201 02:34:19.294483 31779 scheduler.cpp:236] New master detected at master@172.17.21.217:48328
I1201 02:34:19.295903 31793 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.21.217:48328
I1201 02:34:19.298012 31787 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1201 02:34:19.298130 31787 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.21.217:54786
I1201 02:34:19.298360 31787 master.cpp:1899] Received subscription request for HTTP framework 'default'
I1201 02:34:19.298437 31787 master.cpp:1676] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1201 02:34:19.298838 31787 master.cpp:1991] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1201 02:34:19.299357 31792 hierarchical.cpp:220] Added framework af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
I1201 02:34:19.299427 31792 hierarchical.cpp:1064] No resources available to allocate!
I1201 02:34:19.299474 31779 master.hpp:1542] Sending heartbeat to af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
I1201 02:34:19.299482 31792 hierarchical.cpp:1157] No inverse offers to send out!
I1201 02:34:19.299523 31792 hierarchical.cpp:959] Performed allocation for 0 slaves in 130665ns
2015-12-01 02:34:19,299:31760(0x2b94b0200700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:41913] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
I1201 02:34:19.300420 31785 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.21.217:48328
I1201 02:34:19.300967 31785 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.21.217:48328
I1201 02:34:19.301753 31781 master_maintenance_tests.cpp:172] Ignoring HEARTBEAT event
I1201 02:34:19.301847 31785 scheduler.cpp:298] Sending REQUEST call to master@172.17.21.217:48328
I1201 02:34:19.303249 31792 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1201 02:34:19.303339 31792 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.21.217:54788
I1201 02:34:19.303442 31792 master.cpp:2646] Processing REQUEST call for framework af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000 (default)
I1201 02:34:19.303758 31790 hierarchical.cpp:494] Received resource request from framework af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
I1201 02:34:19.304096 31794 master.cpp:938] Master terminating
I1201 02:34:19.304285 31779 hierarchical.cpp:260] Removed framework af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
E1201 02:34:19.305374 31786 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (59 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I1201 02:34:19.315563 31760 leveldb.cpp:174] Opened db in 3.25947ms
I1201 02:34:19.316541 31760 leveldb.cpp:181] Compacted db in 936697ns
I1201 02:34:19.316591 31760 leveldb.cpp:196] Created db iterator in 15937ns
I1201 02:34:19.316607 31760 leveldb.cpp:202] Seeked to beginning of db in 1890ns
I1201 02:34:19.316619 31760 leveldb.cpp:271] Iterated through 0 keys in the db in 310ns
I1201 02:34:19.316655 31760 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1201 02:34:19.317059 31787 recover.cpp:447] Starting replica recovery
I1201 02:34:19.317514 31787 recover.cpp:473] Replica is in EMPTY status
I1201 02:34:19.318452 31779 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (11292)@172.17.21.217:48328
I1201 02:34:19.318943 31780 recover.cpp:193] Received a recover response from a replica in EMPTY status
I1201 02:34:19.319628 31792 recover.cpp:564] Updating replica status to STARTING
I1201 02:34:19.320474 31782 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 481351ns
I1201 02:34:19.320509 31782 replica.cpp:321] Persisted replica status to STARTING
I1201 02:34:19.320735 31787 master.cpp:365] Master 900492e1-d049-40ea-93f1-21f3cf14daed (62ca2bb3ac6c) started on 172.17.21.217:48328
I1201 02:34:19.320797 31789 recover.cpp:473] Replica is in STARTING status
I1201 02:34:19.320765 31787 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/pQko3w/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/pQko3w/master" --zk_session_timeout="10secs"
I1201 02:34:19.321107 31787 master.cpp:414] Master allowing unauthenticated frameworks to register
I1201 02:34:19.321123 31787 master.cpp:417] Master only allowing authenticated slaves to register
I1201 02:34:19.321132 31787 credentials.hpp:35] Loading credentials for authentication from '/tmp/pQko3w/credentials'
I1201 02:34:19.321450 31787 master.cpp:456] Using default 'crammd5' authenticator
I1201 02:34:19.321575 31787 master.cpp:493] Authorization enabled
I1201 02:34:19.321815 31794 whitelist_watcher.cpp:77] No whitelist given
I1201 02:34:19.321910 31792 hierarchical.cpp:162] Initialized hierarchical allocator process
I1201 02:34:19.321982 31793 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (11293)@172.17.21.217:48328
I1201 02:34:19.322332 31791 recover.cpp:193] Received a recover response from a replica in STARTING status
I1201 02:34:19.322816 31789 recover.cpp:564] Updating replica status to VOTING
I1201 02:34:19.323389 31780 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 351601ns
I1201 02:34:19.323415 31780 replica.cpp:321] Persisted replica status to VOTING
I1201 02:34:19.323585 31780 recover.cpp:578] Successfully joined the Paxos group
I1201 02:34:19.323947 31780 recover.cpp:462] Recover process terminated
I1201 02:34:19.324056 31781 master.cpp:1637] The newly elected leader is master@172.17.21.217:48328 with id 900492e1-d049-40ea-93f1-21f3cf14daed
I1201 02:34:19.324229 31781 master.cpp:1650] Elected as the leading master!
I1201 02:34:19.324365 31781 master.cpp:1395] Recovering from registrar
I1201 02:34:19.324537 31791 registrar.cpp:307] Recovering registrar
I1201 02:34:19.325148 31783 log.cpp:659] Attempting to start the writer
I1201 02:34:19.326383 31787 replica.cpp:494] Replica received implicit promise request from (11294)@172.17.21.217:48328 with proposal 1
I1201 02:34:19.326813 31787 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 393604ns
I1201 02:34:19.326844 31787 replica.cpp:343] Persisted promised to 1
I1201 02:34:19.327396 31779 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1201 02:34:19.328500 31785 replica.cpp:389] Replica received explicit promise request from (11295)@172.17.21.217:48328 for position 0 with proposal 2
I1201 02:34:19.328877 31785 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 334232ns
I1201 02:34:19.328902 31785 replica.cpp:713] Persisted action at 0
I1201 02:34:19.329780 31787 replica.cpp:538] Replica received write request for position 0 from (11296)@172.17.21.217:48328
I1201 02:34:19.329834 31787 leveldb.cpp:436] Reading position from leveldb took 23961ns
I1201 02:34:19.330243 31787 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 370452ns
I1201 02:34:19.330281 31787 replica.cpp:713] Persisted action at 0
I1201 02:34:19.330826 31793 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0
I1201 02:34:19.331305 31793 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 445703ns
I1201 02:34:19.331331 31793 replica.cpp:713] Persisted action at 0
I1201 02:34:19.331353 31793 replica.cpp:698] Replica learned NOP action at position 0
I1201 02:34:19.331894 31790 log.cpp:675] Writer started with ending position 0
I1201 02:34:19.332876 31794 leveldb.cpp:436] Reading position from leveldb took 41043ns
I1201 02:34:19.333824 31789 registrar.cpp:340] Successfully fetched the registry (0B) in 9.236224ms
I1201 02:34:19.333935 31789 registrar.cpp:439] Applied 1 operations in 23397ns; attempting to update the 'registry'
I1201 02:34:19.334709 31789 log.cpp:683] Attempting to append 178 bytes to the log
I1201 02:34:19.334849 31793 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1201 02:34:19.335700 31785 replica.cpp:538] Replica received write request for position 1 from (11297)@172.17.21.217:48328
I1201 02:34:19.336088 31785 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 339998ns
I1201 02:34:19.336117 31785 replica.cpp:713] Persisted action at 1
I1201 02:34:19.336877 31781 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0
I1201 02:34:19.337270 31781 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 339541ns
I1201 02:34:19.337301 31781 replica.cpp:713] Persisted action at 1
I1201 02:34:19.337321 31781 replica.cpp:698] Replica learned APPEND action at position 1
I1201 02:34:19.338389 31788 registrar.cpp:484] Successfully updated the 'registry' in 4.385024ms
I1201 02:34:19.338567 31788 registrar.cpp:370] Successfully recovered registrar
I1201 02:34:19.338676 31793 log.cpp:702] Attempting to truncate the log to 1
I1201 02:34:19.338866 31791 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1201 02:34:19.339190 31779 master.cpp:1447] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
I1201 02:34:19.339221 31789 hierarchical.cpp:174] Allocator recovery is not supported yet
I1201 02:34:19.339902 31792 replica.cpp:538] Replica received write request for position 2 from (11298)@172.17.21.217:48328
I1201 02:34:19.340292 31792 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 342933ns
I1201 02:34:19.340322 31792 replica.cpp:713] Persisted action at 2
I1201 02:34:19.340957 31793 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0
I1201 02:34:19.341444 31793 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 449325ns
I1201 02:34:19.341531 31793 leveldb.cpp:399] Deleting ~1 keys from leveldb took 52495ns
I1201 02:34:19.341563 31793 replica.cpp:713] Persisted action at 2
I1201 02:34:19.341601 31793 replica.cpp:698] Replica learned TRUNCATE action at position 2
I1201 02:34:19.350018 31760 scheduler.cpp:154] Version: 0.27.0
I1201 02:34:19.350697 31793 scheduler.cpp:236] New master detected at master@172.17.21.217:48328
I1201 02:34:19.351855 31785 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.21.217:48328
I1201 02:34:19.353670 31788 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1201 02:34:19.353770 31788 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.21.217:54789
I1201 02:34:19.354106 31788 master.cpp:1899] Received subscription request for HTTP framework 'default'
I1201 02:34:19.354172 31788 master.cpp:1676] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1201 02:34:19.354468 31788 master.cpp:1991] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1201 02:34:19.354849 31791 hierarchical.cpp:220] Added framework 900492e1-d049-40ea-93f1-21f3cf14daed-0000
I1201 02:34:19.354899 31791 hierarchical.cpp:1064] No resources available to allocate!
I1201 02:34:19.354928 31791 hierarchical.cpp:1157] No inverse offers to send out!
I1201 02:34:19.354945 31791 hierarchical.cpp:959] Performed allocation for 0 slaves in 70874ns
I1201 02:34:19.355178 31786 master.hpp:1542] Sending heartbeat to 900492e1-d049-40ea-93f1-21f3cf14daed-0000
I1201 02:34:19.356003 31791 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.21.217:48328
I1201 02:34:19.356551 31791 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.21.217:48328
I1201 02:34:19.357480 31790 master_maintenance_tests.cpp:172] Ignoring HEARTBEAT event
I1201 02:34:19.357565 31787 scheduler.cpp:298] Sending REQUEST call to master@172.17.21.217:48328
I1201 02:34:19.359061 31782 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1201 02:34:19.359122 31782 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.21.217:54790
I1201 02:34:19.359432 31782 master.cpp:2646] Processing REQUEST call for framework 900492e1-d049-40ea-93f1-21f3cf14daed-0000 (default)
I1201 02:34:19.359596 31794 hierarchical.cpp:494] Received resource request from framework 900492e1-d049-40ea-93f1-21f3cf14daed-0000
I1201 02:34:19.360024 31794 master.cpp:938] Master terminating
I1201 02:34:19.360440 31783 hierarchical.cpp:260] Removed framework 900492e1-d049-40ea-93f1-21f3cf14daed-0000
E1201 02:34:19.361205 31787 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (56 ms)
[----------] 22 tests from ContentType/SchedulerTest (4172 ms total)
[----------] Global test environment tear-down
[==========] 867 tests from 116 test cases ran. (336518 ms total)
[ PASSED ] 866 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.27.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1448935419-29488
Untagged: mesos-1448935419-29488:latest
Deleted: 5111c09d08dff461e549e9b09ca23c6fb9e9e9ac8b0914c142b4c650f11c479e
Deleted: a892f31dee1ab1c17ba413344faa2cc4fd5f94185e7ce3c50d3641bef02f9364
Deleted: c05080ab164b6bbdfa8997bbcd84dda660cb607e96d0f88fc6e41f47afb66145
Deleted: dd31d40272d4465c36c379a65afdbde9bc54fd5746dae2e5d2ab79a8517f711e
Deleted: a5c1fafc69f3f401a455fbd5d1c909befcaf1ca4e9b34533e4549f8c2a371b5c
Deleted: 9586e9b81641e66b1aa14c61661c62d2d81975c5e06a59f155cdbca082a85a8e
Deleted: d80af199489b5bad0452c02fbe873431c829bd9b25bcdf0bd7dbb07168caf1c6
Deleted: 58a273741249aa06e9be0d52ae68dccbbe32dd5b91242991325070c006bce703
Deleted: 870a4a6ce8f6b319df51120697474fad2eba202cd9e436d07a1ec0dfd260b780
Deleted: eec94d7588b97209882c83884b1a32bbbd331ac0b235b7f625ae058dd29218ab
Deleted: 736a295c5a68298819f423d6c1a078fe92e0b13af3081a3207d202ef50151b9f
Deleted: f6c3272afd58f83c4136de54b8343bad750102351ab89e26ed4dde6b62ea02bf
Deleted: bb671429b346a7a98a49bd0b6e85502ef1fd2c765b9d59f92a0d4e75733e1262
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 #1296
Posted by Jojy Varghese <jo...@mesosphere.io>.
I have couple of patches (https://reviews.apache.org/r/40873/ <https://reviews.apache.org/r/40873/>) waiting to be reviewed that is not a solution but some improvements to the tests.
-Jojy
> On Dec 3, 2015, at 7:38 PM, Benjamin Mahler <be...@gmail.com> wrote:
>
> +jojy
>
> What is the status of this flaky test? Do we need to disable it?
>
> On Mon, Nov 30, 2015 at 6:40 PM, 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/1296/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/1296/changes>>
>
> Changes:
>
> [benjamin.mahler] Fixed a segmentation fault in the cgroups::freeze.
>
> ------------------------------------------
> [...truncated 147166 lines...]
> I1201 02:34:19.247105 31780 slave.cpp:3773] Cleaning up framework 1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000
> I1201 02:34:19.247177 31791 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_J2f4ap/slaves/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-S0/frameworks/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000/executors/default' for gc 6.99999714068148days in the future
> I1201 02:34:19.247334 31784 status_update_manager.cpp:282] Closing status update streams for framework 1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000
> I1201 02:34:19.247409 31791 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_J2f4ap/slaves/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-S0/frameworks/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000' for gc 6.99999713849482days in the future
> I1201 02:34:19.247490 31784 status_update_manager.cpp:528] Cleaning up status update stream for task f3e62156-97fd-493a-a3e5-9284571d98ab of framework 1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000
> [ OK ] ContentType/SchedulerTest.Message/1 (118 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> I1201 02:34:19.255559 31760 leveldb.cpp:174] Opened db in 3.050594ms
> I1201 02:34:19.256408 31760 leveldb.cpp:181] Compacted db in 808375ns
> I1201 02:34:19.256456 31760 leveldb.cpp:196] Created db iterator in 17455ns
> I1201 02:34:19.256474 31760 leveldb.cpp:202] Seeked to beginning of db in 1827ns
> I1201 02:34:19.256484 31760 leveldb.cpp:271] Iterated through 0 keys in the db in 315ns
> I1201 02:34:19.256526 31760 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I1201 02:34:19.257169 31792 recover.cpp:447] Starting replica recovery
> I1201 02:34:19.258023 31789 recover.cpp:473] Replica is in EMPTY status
> I1201 02:34:19.259486 31787 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (11281)@172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.260138 31781 recover.cpp:193] Received a recover response from a replica in EMPTY status
> I1201 02:34:19.260823 31793 recover.cpp:564] Updating replica status to STARTING
> I1201 02:34:19.261028 31786 master.cpp:365] Master af781e59-a3b4-4c7b-9b12-3c148a5999ae (62ca2bb3ac6c) started on 172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.261060 31786 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/nGa4SZ/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/nGa4SZ/master" --zk_session_timeout="10secs"
> I1201 02:34:19.261584 31786 master.cpp:414] Master allowing unauthenticated frameworks to register
> I1201 02:34:19.261719 31786 master.cpp:417] Master only allowing authenticated slaves to register
> I1201 02:34:19.261735 31786 credentials.hpp:35] Loading credentials for authentication from '/tmp/nGa4SZ/credentials'
> I1201 02:34:19.261963 31782 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 658792ns
> I1201 02:34:19.261996 31782 replica.cpp:321] Persisted replica status to STARTING
> I1201 02:34:19.262101 31786 master.cpp:456] Using default 'crammd5' authenticator
> I1201 02:34:19.262249 31786 master.cpp:493] Authorization enabled
> I1201 02:34:19.262272 31787 recover.cpp:473] Replica is in STARTING status
> I1201 02:34:19.262626 31781 hierarchical.cpp:162] Initialized hierarchical allocator process
> I1201 02:34:19.262665 31789 whitelist_watcher.cpp:77] No whitelist given
> I1201 02:34:19.263484 31785 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (11282)@172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.264495 31786 recover.cpp:193] Received a recover response from a replica in STARTING status
> I1201 02:34:19.264688 31788 master.cpp:1637] The newly elected leader is master@172.17.21.217:48328 <http://master@172.17.21.217:48328/> with id af781e59-a3b4-4c7b-9b12-3c148a5999ae
> I1201 02:34:19.264734 31788 master.cpp:1650] Elected as the leading master!
> I1201 02:34:19.264768 31788 master.cpp:1395] Recovering from registrar
> I1201 02:34:19.265009 31782 registrar.cpp:307] Recovering registrar
> I1201 02:34:19.265298 31788 recover.cpp:564] Updating replica status to VOTING
> I1201 02:34:19.265972 31783 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 394581ns
> I1201 02:34:19.266001 31783 replica.cpp:321] Persisted replica status to VOTING
> I1201 02:34:19.266125 31787 recover.cpp:578] Successfully joined the Paxos group
> I1201 02:34:19.266379 31787 recover.cpp:462] Recover process terminated
> I1201 02:34:19.266872 31786 log.cpp:659] Attempting to start the writer
> I1201 02:34:19.268193 31789 replica.cpp:494] Replica received implicit promise request from (11283)@172.17.21.217:48328 <http://172.17.21.217:48328/> with proposal 1
> I1201 02:34:19.268609 31789 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 374122ns
> I1201 02:34:19.268636 31789 replica.cpp:343] Persisted promised to 1
> I1201 02:34:19.269330 31782 coordinator.cpp:238] Coordinator attempting to fill missing positions
> I1201 02:34:19.270778 31781 replica.cpp:389] Replica received explicit promise request from (11284)@172.17.21.217:48328 <http://172.17.21.217:48328/> for position 0 with proposal 2
> I1201 02:34:19.271225 31781 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 402319ns
> I1201 02:34:19.271302 31781 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.272378 31782 replica.cpp:538] Replica received write request for position 0 from (11285)@172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.272438 31782 leveldb.cpp:436] Reading position from leveldb took 28102ns
> I1201 02:34:19.272884 31782 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 404732ns
> I1201 02:34:19.272909 31782 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.273514 31794 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1201 02:34:19.273974 31794 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 429297ns
> I1201 02:34:19.273998 31794 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.274015 31794 replica.cpp:698] Replica learned NOP action at position 0
> I1201 02:34:19.274664 31783 log.cpp:675] Writer started with ending position 0
> I1201 02:34:19.276005 31793 leveldb.cpp:436] Reading position from leveldb took 32689ns
> I1201 02:34:19.277209 31794 registrar.cpp:340] Successfully fetched the registry (0B) in 12.146944ms
> I1201 02:34:19.277345 31794 registrar.cpp:439] Applied 1 operations in 27629ns; attempting to update the 'registry'
> I1201 02:34:19.278126 31791 log.cpp:683] Attempting to append 178 bytes to the log
> I1201 02:34:19.278381 31794 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
> I1201 02:34:19.279250 31784 replica.cpp:538] Replica received write request for position 1 from (11286)@172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.279685 31784 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 362960ns
> I1201 02:34:19.279716 31784 replica.cpp:713] Persisted action at 1
> I1201 02:34:19.280517 31783 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1201 02:34:19.280886 31783 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 328419ns
> I1201 02:34:19.280915 31783 replica.cpp:713] Persisted action at 1
> I1201 02:34:19.280937 31783 replica.cpp:698] Replica learned APPEND action at position 1
> I1201 02:34:19.282039 31785 registrar.cpp:484] Successfully updated the 'registry' in 4.626176ms
> I1201 02:34:19.282217 31785 registrar.cpp:370] Successfully recovered registrar
> I1201 02:34:19.282318 31789 log.cpp:702] Attempting to truncate the log to 1
> I1201 02:34:19.282459 31783 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
> I1201 02:34:19.282727 31784 master.cpp:1447] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
> I1201 02:34:19.282786 31788 hierarchical.cpp:174] Allocator recovery is not supported yet
> I1201 02:34:19.283432 31781 replica.cpp:538] Replica received write request for position 2 from (11287)@172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.283809 31781 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 331619ns
> I1201 02:34:19.283840 31781 replica.cpp:713] Persisted action at 2
> I1201 02:34:19.284519 31779 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1201 02:34:19.284941 31779 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 377829ns
> I1201 02:34:19.285006 31779 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33814ns
> I1201 02:34:19.285037 31779 replica.cpp:713] Persisted action at 2
> I1201 02:34:19.285074 31779 replica.cpp:698] Replica learned TRUNCATE action at position 2
> I1201 02:34:19.293673 31760 scheduler.cpp:154] Version: 0.27.0
> I1201 02:34:19.294483 31779 scheduler.cpp:236] New master detected at master@172.17.21.217:48328 <http://master@172.17.21.217:48328/>
> I1201 02:34:19.295903 31793 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.21.217:48328 <http://master@172.17.21.217:48328/>
> I1201 02:34:19.298012 31787 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1201 02:34:19.298130 31787 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.21.217:54786 <http://172.17.21.217:54786/>
> I1201 02:34:19.298360 31787 master.cpp:1899] Received subscription request for HTTP framework 'default'
> I1201 02:34:19.298437 31787 master.cpp:1676] Authorizing framework principal 'test-principal' to receive offers for role '*'
> I1201 02:34:19.298838 31787 master.cpp:1991] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
> I1201 02:34:19.299357 31792 hierarchical.cpp:220] Added framework af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
> I1201 02:34:19.299427 31792 hierarchical.cpp:1064] No resources available to allocate!
> I1201 02:34:19.299474 31779 master.hpp:1542] Sending heartbeat to af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
> I1201 02:34:19.299482 31792 hierarchical.cpp:1157] No inverse offers to send out!
> I1201 02:34:19.299523 31792 hierarchical.cpp:959] Performed allocation for 0 slaves in 130665ns
> 2015-12-01 02:34:19,299:31760(0x2b94b0200700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:41913 <http://127.0.0.1:41913/>] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
> I1201 02:34:19.300420 31785 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.21.217:48328 <http://master@172.17.21.217:48328/>
> I1201 02:34:19.300967 31785 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.21.217:48328 <http://master@172.17.21.217:48328/>
> I1201 02:34:19.301753 31781 master_maintenance_tests.cpp:172] Ignoring HEARTBEAT event
> I1201 02:34:19.301847 31785 scheduler.cpp:298] Sending REQUEST call to master@172.17.21.217:48328 <http://master@172.17.21.217:48328/>
> I1201 02:34:19.303249 31792 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1201 02:34:19.303339 31792 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.21.217:54788 <http://172.17.21.217:54788/>
> I1201 02:34:19.303442 31792 master.cpp:2646] Processing REQUEST call for framework af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000 (default)
> I1201 02:34:19.303758 31790 hierarchical.cpp:494] Received resource request from framework af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
> I1201 02:34:19.304096 31794 master.cpp:938] Master terminating
> I1201 02:34:19.304285 31779 hierarchical.cpp:260] Removed framework af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
> E1201 02:34:19.305374 31786 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (59 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I1201 02:34:19.315563 31760 leveldb.cpp:174] Opened db in 3.25947ms
> I1201 02:34:19.316541 31760 leveldb.cpp:181] Compacted db in 936697ns
> I1201 02:34:19.316591 31760 leveldb.cpp:196] Created db iterator in 15937ns
> I1201 02:34:19.316607 31760 leveldb.cpp:202] Seeked to beginning of db in 1890ns
> I1201 02:34:19.316619 31760 leveldb.cpp:271] Iterated through 0 keys in the db in 310ns
> I1201 02:34:19.316655 31760 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I1201 02:34:19.317059 31787 recover.cpp:447] Starting replica recovery
> I1201 02:34:19.317514 31787 recover.cpp:473] Replica is in EMPTY status
> I1201 02:34:19.318452 31779 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (11292)@172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.318943 31780 recover.cpp:193] Received a recover response from a replica in EMPTY status
> I1201 02:34:19.319628 31792 recover.cpp:564] Updating replica status to STARTING
> I1201 02:34:19.320474 31782 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 481351ns
> I1201 02:34:19.320509 31782 replica.cpp:321] Persisted replica status to STARTING
> I1201 02:34:19.320735 31787 master.cpp:365] Master 900492e1-d049-40ea-93f1-21f3cf14daed (62ca2bb3ac6c) started on 172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.320797 31789 recover.cpp:473] Replica is in STARTING status
> I1201 02:34:19.320765 31787 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/pQko3w/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.27.0/_inst/share/mesos/webui" --work_dir="/tmp/pQko3w/master" --zk_session_timeout="10secs"
> I1201 02:34:19.321107 31787 master.cpp:414] Master allowing unauthenticated frameworks to register
> I1201 02:34:19.321123 31787 master.cpp:417] Master only allowing authenticated slaves to register
> I1201 02:34:19.321132 31787 credentials.hpp:35] Loading credentials for authentication from '/tmp/pQko3w/credentials'
> I1201 02:34:19.321450 31787 master.cpp:456] Using default 'crammd5' authenticator
> I1201 02:34:19.321575 31787 master.cpp:493] Authorization enabled
> I1201 02:34:19.321815 31794 whitelist_watcher.cpp:77] No whitelist given
> I1201 02:34:19.321910 31792 hierarchical.cpp:162] Initialized hierarchical allocator process
> I1201 02:34:19.321982 31793 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (11293)@172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.322332 31791 recover.cpp:193] Received a recover response from a replica in STARTING status
> I1201 02:34:19.322816 31789 recover.cpp:564] Updating replica status to VOTING
> I1201 02:34:19.323389 31780 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 351601ns
> I1201 02:34:19.323415 31780 replica.cpp:321] Persisted replica status to VOTING
> I1201 02:34:19.323585 31780 recover.cpp:578] Successfully joined the Paxos group
> I1201 02:34:19.323947 31780 recover.cpp:462] Recover process terminated
> I1201 02:34:19.324056 31781 master.cpp:1637] The newly elected leader is master@172.17.21.217:48328 <http://master@172.17.21.217:48328/> with id 900492e1-d049-40ea-93f1-21f3cf14daed
> I1201 02:34:19.324229 31781 master.cpp:1650] Elected as the leading master!
> I1201 02:34:19.324365 31781 master.cpp:1395] Recovering from registrar
> I1201 02:34:19.324537 31791 registrar.cpp:307] Recovering registrar
> I1201 02:34:19.325148 31783 log.cpp:659] Attempting to start the writer
> I1201 02:34:19.326383 31787 replica.cpp:494] Replica received implicit promise request from (11294)@172.17.21.217:48328 <http://172.17.21.217:48328/> with proposal 1
> I1201 02:34:19.326813 31787 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 393604ns
> I1201 02:34:19.326844 31787 replica.cpp:343] Persisted promised to 1
> I1201 02:34:19.327396 31779 coordinator.cpp:238] Coordinator attempting to fill missing positions
> I1201 02:34:19.328500 31785 replica.cpp:389] Replica received explicit promise request from (11295)@172.17.21.217:48328 <http://172.17.21.217:48328/> for position 0 with proposal 2
> I1201 02:34:19.328877 31785 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 334232ns
> I1201 02:34:19.328902 31785 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.329780 31787 replica.cpp:538] Replica received write request for position 0 from (11296)@172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.329834 31787 leveldb.cpp:436] Reading position from leveldb took 23961ns
> I1201 02:34:19.330243 31787 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 370452ns
> I1201 02:34:19.330281 31787 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.330826 31793 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1201 02:34:19.331305 31793 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 445703ns
> I1201 02:34:19.331331 31793 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.331353 31793 replica.cpp:698] Replica learned NOP action at position 0
> I1201 02:34:19.331894 31790 log.cpp:675] Writer started with ending position 0
> I1201 02:34:19.332876 31794 leveldb.cpp:436] Reading position from leveldb took 41043ns
> I1201 02:34:19.333824 31789 registrar.cpp:340] Successfully fetched the registry (0B) in 9.236224ms
> I1201 02:34:19.333935 31789 registrar.cpp:439] Applied 1 operations in 23397ns; attempting to update the 'registry'
> I1201 02:34:19.334709 31789 log.cpp:683] Attempting to append 178 bytes to the log
> I1201 02:34:19.334849 31793 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
> I1201 02:34:19.335700 31785 replica.cpp:538] Replica received write request for position 1 from (11297)@172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.336088 31785 leveldb.cpp:341] Persisting action (197 bytes) to leveldb took 339998ns
> I1201 02:34:19.336117 31785 replica.cpp:713] Persisted action at 1
> I1201 02:34:19.336877 31781 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1201 02:34:19.337270 31781 leveldb.cpp:341] Persisting action (199 bytes) to leveldb took 339541ns
> I1201 02:34:19.337301 31781 replica.cpp:713] Persisted action at 1
> I1201 02:34:19.337321 31781 replica.cpp:698] Replica learned APPEND action at position 1
> I1201 02:34:19.338389 31788 registrar.cpp:484] Successfully updated the 'registry' in 4.385024ms
> I1201 02:34:19.338567 31788 registrar.cpp:370] Successfully recovered registrar
> I1201 02:34:19.338676 31793 log.cpp:702] Attempting to truncate the log to 1
> I1201 02:34:19.338866 31791 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
> I1201 02:34:19.339190 31779 master.cpp:1447] Recovered 0 slaves from the Registry (139B) ; allowing 10mins for slaves to re-register
> I1201 02:34:19.339221 31789 hierarchical.cpp:174] Allocator recovery is not supported yet
> I1201 02:34:19.339902 31792 replica.cpp:538] Replica received write request for position 2 from (11298)@172.17.21.217:48328 <http://172.17.21.217:48328/>
> I1201 02:34:19.340292 31792 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 342933ns
> I1201 02:34:19.340322 31792 replica.cpp:713] Persisted action at 2
> I1201 02:34:19.340957 31793 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0 <http://0.0.0.0:0/>
> I1201 02:34:19.341444 31793 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 449325ns
> I1201 02:34:19.341531 31793 leveldb.cpp:399] Deleting ~1 keys from leveldb took 52495ns
> I1201 02:34:19.341563 31793 replica.cpp:713] Persisted action at 2
> I1201 02:34:19.341601 31793 replica.cpp:698] Replica learned TRUNCATE action at position 2
> I1201 02:34:19.350018 31760 scheduler.cpp:154] Version: 0.27.0
> I1201 02:34:19.350697 31793 scheduler.cpp:236] New master detected at master@172.17.21.217:48328 <http://master@172.17.21.217:48328/>
> I1201 02:34:19.351855 31785 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.21.217:48328 <http://master@172.17.21.217:48328/>
> I1201 02:34:19.353670 31788 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1201 02:34:19.353770 31788 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.21.217:54789 <http://172.17.21.217:54789/>
> I1201 02:34:19.354106 31788 master.cpp:1899] Received subscription request for HTTP framework 'default'
> I1201 02:34:19.354172 31788 master.cpp:1676] Authorizing framework principal 'test-principal' to receive offers for role '*'
> I1201 02:34:19.354468 31788 master.cpp:1991] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
> I1201 02:34:19.354849 31791 hierarchical.cpp:220] Added framework 900492e1-d049-40ea-93f1-21f3cf14daed-0000
> I1201 02:34:19.354899 31791 hierarchical.cpp:1064] No resources available to allocate!
> I1201 02:34:19.354928 31791 hierarchical.cpp:1157] No inverse offers to send out!
> I1201 02:34:19.354945 31791 hierarchical.cpp:959] Performed allocation for 0 slaves in 70874ns
> I1201 02:34:19.355178 31786 master.hpp:1542] Sending heartbeat to 900492e1-d049-40ea-93f1-21f3cf14daed-0000
> I1201 02:34:19.356003 31791 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.21.217:48328 <http://master@172.17.21.217:48328/>
> I1201 02:34:19.356551 31791 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.21.217:48328 <http://master@172.17.21.217:48328/>
> I1201 02:34:19.357480 31790 master_maintenance_tests.cpp:172] Ignoring HEARTBEAT event
> I1201 02:34:19.357565 31787 scheduler.cpp:298] Sending REQUEST call to master@172.17.21.217:48328 <http://master@172.17.21.217:48328/>
> I1201 02:34:19.359061 31782 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1201 02:34:19.359122 31782 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.21.217:54790 <http://172.17.21.217:54790/>
> I1201 02:34:19.359432 31782 master.cpp:2646] Processing REQUEST call for framework 900492e1-d049-40ea-93f1-21f3cf14daed-0000 (default)
> I1201 02:34:19.359596 31794 hierarchical.cpp:494] Received resource request from framework 900492e1-d049-40ea-93f1-21f3cf14daed-0000
> I1201 02:34:19.360024 31794 master.cpp:938] Master terminating
> I1201 02:34:19.360440 31783 hierarchical.cpp:260] Removed framework 900492e1-d049-40ea-93f1-21f3cf14daed-0000
> E1201 02:34:19.361205 31787 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (56 ms)
> [----------] 22 tests from ContentType/SchedulerTest (4172 ms total)
>
> [----------] Global test environment tear-down
> [==========] 867 tests from 116 test cases ran. (336518 ms total)
> [ PASSED ] 866 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.27.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1448935419-29488
> Untagged: mesos-1448935419-29488:latest
> Deleted: 5111c09d08dff461e549e9b09ca23c6fb9e9e9ac8b0914c142b4c650f11c479e
> Deleted: a892f31dee1ab1c17ba413344faa2cc4fd5f94185e7ce3c50d3641bef02f9364
> Deleted: c05080ab164b6bbdfa8997bbcd84dda660cb607e96d0f88fc6e41f47afb66145
> Deleted: dd31d40272d4465c36c379a65afdbde9bc54fd5746dae2e5d2ab79a8517f711e
> Deleted: a5c1fafc69f3f401a455fbd5d1c909befcaf1ca4e9b34533e4549f8c2a371b5c
> Deleted: 9586e9b81641e66b1aa14c61661c62d2d81975c5e06a59f155cdbca082a85a8e
> Deleted: d80af199489b5bad0452c02fbe873431c829bd9b25bcdf0bd7dbb07168caf1c6
> Deleted: 58a273741249aa06e9be0d52ae68dccbbe32dd5b91242991325070c006bce703
> Deleted: 870a4a6ce8f6b319df51120697474fad2eba202cd9e436d07a1ec0dfd260b780
> Deleted: eec94d7588b97209882c83884b1a32bbbd331ac0b235b7f625ae058dd29218ab
> Deleted: 736a295c5a68298819f423d6c1a078fe92e0b13af3081a3207d202ef50151b9f
> Deleted: f6c3272afd58f83c4136de54b8343bad750102351ab89e26ed4dde6b62ea02bf
> Deleted: bb671429b346a7a98a49bd0b6e85502ef1fd2c765b9d59f92a0d4e75733e1262
> 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 #1296
Posted by Benjamin Mahler <be...@gmail.com>.
+jojy
What is the status of this flaky test? Do we need to disable it?
On Mon, Nov 30, 2015 at 6:40 PM, 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/1296/changes
> >
>
> Changes:
>
> [benjamin.mahler] Fixed a segmentation fault in the cgroups::freeze.
>
> ------------------------------------------
> [...truncated 147166 lines...]
> I1201 02:34:19.247105 31780 slave.cpp:3773] Cleaning up framework
> 1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000
> I1201 02:34:19.247177 31791 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_J2f4ap/slaves/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-S0/frameworks/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000/executors/default'
> for gc 6.99999714068148days in the future
> I1201 02:34:19.247334 31784 status_update_manager.cpp:282] Closing status
> update streams for framework 1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000
> I1201 02:34:19.247409 31791 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_J2f4ap/slaves/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-S0/frameworks/1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000'
> for gc 6.99999713849482days in the future
> I1201 02:34:19.247490 31784 status_update_manager.cpp:528] Cleaning up
> status update stream for task f3e62156-97fd-493a-a3e5-9284571d98ab of
> framework 1ca712bc-e13c-4cfb-974e-96b3eafe76cb-0000
> [ OK ] ContentType/SchedulerTest.Message/1 (118 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> I1201 02:34:19.255559 31760 leveldb.cpp:174] Opened db in 3.050594ms
> I1201 02:34:19.256408 31760 leveldb.cpp:181] Compacted db in 808375ns
> I1201 02:34:19.256456 31760 leveldb.cpp:196] Created db iterator in 17455ns
> I1201 02:34:19.256474 31760 leveldb.cpp:202] Seeked to beginning of db in
> 1827ns
> I1201 02:34:19.256484 31760 leveldb.cpp:271] Iterated through 0 keys in
> the db in 315ns
> I1201 02:34:19.256526 31760 replica.cpp:778] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I1201 02:34:19.257169 31792 recover.cpp:447] Starting replica recovery
> I1201 02:34:19.258023 31789 recover.cpp:473] Replica is in EMPTY status
> I1201 02:34:19.259486 31787 replica.cpp:674] Replica in EMPTY status
> received a broadcasted recover request from (11281)@172.17.21.217:48328
> I1201 02:34:19.260138 31781 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I1201 02:34:19.260823 31793 recover.cpp:564] Updating replica status to
> STARTING
> I1201 02:34:19.261028 31786 master.cpp:365] Master
> af781e59-a3b4-4c7b-9b12-3c148a5999ae (62ca2bb3ac6c) started on
> 172.17.21.217:48328
> I1201 02:34:19.261060 31786 master.cpp:367] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/nGa4SZ/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.27.0/_inst/share/mesos/webui"
> --work_dir="/tmp/nGa4SZ/master" --zk_session_timeout="10secs"
> I1201 02:34:19.261584 31786 master.cpp:414] Master allowing
> unauthenticated frameworks to register
> I1201 02:34:19.261719 31786 master.cpp:417] Master only allowing
> authenticated slaves to register
> I1201 02:34:19.261735 31786 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/nGa4SZ/credentials'
> I1201 02:34:19.261963 31782 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 658792ns
> I1201 02:34:19.261996 31782 replica.cpp:321] Persisted replica status to
> STARTING
> I1201 02:34:19.262101 31786 master.cpp:456] Using default 'crammd5'
> authenticator
> I1201 02:34:19.262249 31786 master.cpp:493] Authorization enabled
> I1201 02:34:19.262272 31787 recover.cpp:473] Replica is in STARTING status
> I1201 02:34:19.262626 31781 hierarchical.cpp:162] Initialized hierarchical
> allocator process
> I1201 02:34:19.262665 31789 whitelist_watcher.cpp:77] No whitelist given
> I1201 02:34:19.263484 31785 replica.cpp:674] Replica in STARTING status
> received a broadcasted recover request from (11282)@172.17.21.217:48328
> I1201 02:34:19.264495 31786 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I1201 02:34:19.264688 31788 master.cpp:1637] The newly elected leader is
> master@172.17.21.217:48328 with id af781e59-a3b4-4c7b-9b12-3c148a5999ae
> I1201 02:34:19.264734 31788 master.cpp:1650] Elected as the leading master!
> I1201 02:34:19.264768 31788 master.cpp:1395] Recovering from registrar
> I1201 02:34:19.265009 31782 registrar.cpp:307] Recovering registrar
> I1201 02:34:19.265298 31788 recover.cpp:564] Updating replica status to
> VOTING
> I1201 02:34:19.265972 31783 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 394581ns
> I1201 02:34:19.266001 31783 replica.cpp:321] Persisted replica status to
> VOTING
> I1201 02:34:19.266125 31787 recover.cpp:578] Successfully joined the Paxos
> group
> I1201 02:34:19.266379 31787 recover.cpp:462] Recover process terminated
> I1201 02:34:19.266872 31786 log.cpp:659] Attempting to start the writer
> I1201 02:34:19.268193 31789 replica.cpp:494] Replica received implicit
> promise request from (11283)@172.17.21.217:48328 with proposal 1
> I1201 02:34:19.268609 31789 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 374122ns
> I1201 02:34:19.268636 31789 replica.cpp:343] Persisted promised to 1
> I1201 02:34:19.269330 31782 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I1201 02:34:19.270778 31781 replica.cpp:389] Replica received explicit
> promise request from (11284)@172.17.21.217:48328 for position 0 with
> proposal 2
> I1201 02:34:19.271225 31781 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 402319ns
> I1201 02:34:19.271302 31781 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.272378 31782 replica.cpp:538] Replica received write
> request for position 0 from (11285)@172.17.21.217:48328
> I1201 02:34:19.272438 31782 leveldb.cpp:436] Reading position from leveldb
> took 28102ns
> I1201 02:34:19.272884 31782 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 404732ns
> I1201 02:34:19.272909 31782 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.273514 31794 replica.cpp:692] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I1201 02:34:19.273974 31794 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 429297ns
> I1201 02:34:19.273998 31794 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.274015 31794 replica.cpp:698] Replica learned NOP action at
> position 0
> I1201 02:34:19.274664 31783 log.cpp:675] Writer started with ending
> position 0
> I1201 02:34:19.276005 31793 leveldb.cpp:436] Reading position from leveldb
> took 32689ns
> I1201 02:34:19.277209 31794 registrar.cpp:340] Successfully fetched the
> registry (0B) in 12.146944ms
> I1201 02:34:19.277345 31794 registrar.cpp:439] Applied 1 operations in
> 27629ns; attempting to update the 'registry'
> I1201 02:34:19.278126 31791 log.cpp:683] Attempting to append 178 bytes to
> the log
> I1201 02:34:19.278381 31794 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I1201 02:34:19.279250 31784 replica.cpp:538] Replica received write
> request for position 1 from (11286)@172.17.21.217:48328
> I1201 02:34:19.279685 31784 leveldb.cpp:341] Persisting action (197 bytes)
> to leveldb took 362960ns
> I1201 02:34:19.279716 31784 replica.cpp:713] Persisted action at 1
> I1201 02:34:19.280517 31783 replica.cpp:692] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I1201 02:34:19.280886 31783 leveldb.cpp:341] Persisting action (199 bytes)
> to leveldb took 328419ns
> I1201 02:34:19.280915 31783 replica.cpp:713] Persisted action at 1
> I1201 02:34:19.280937 31783 replica.cpp:698] Replica learned APPEND action
> at position 1
> I1201 02:34:19.282039 31785 registrar.cpp:484] Successfully updated the
> 'registry' in 4.626176ms
> I1201 02:34:19.282217 31785 registrar.cpp:370] Successfully recovered
> registrar
> I1201 02:34:19.282318 31789 log.cpp:702] Attempting to truncate the log to
> 1
> I1201 02:34:19.282459 31783 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I1201 02:34:19.282727 31784 master.cpp:1447] Recovered 0 slaves from the
> Registry (139B) ; allowing 10mins for slaves to re-register
> I1201 02:34:19.282786 31788 hierarchical.cpp:174] Allocator recovery is
> not supported yet
> I1201 02:34:19.283432 31781 replica.cpp:538] Replica received write
> request for position 2 from (11287)@172.17.21.217:48328
> I1201 02:34:19.283809 31781 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 331619ns
> I1201 02:34:19.283840 31781 replica.cpp:713] Persisted action at 2
> I1201 02:34:19.284519 31779 replica.cpp:692] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I1201 02:34:19.284941 31779 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 377829ns
> I1201 02:34:19.285006 31779 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 33814ns
> I1201 02:34:19.285037 31779 replica.cpp:713] Persisted action at 2
> I1201 02:34:19.285074 31779 replica.cpp:698] Replica learned TRUNCATE
> action at position 2
> I1201 02:34:19.293673 31760 scheduler.cpp:154] Version: 0.27.0
> I1201 02:34:19.294483 31779 scheduler.cpp:236] New master detected at
> master@172.17.21.217:48328
> I1201 02:34:19.295903 31793 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.21.217:48328
> I1201 02:34:19.298012 31787 process.cpp:3067] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1201 02:34:19.298130 31787 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.21.217:54786
> I1201 02:34:19.298360 31787 master.cpp:1899] Received subscription request
> for HTTP framework 'default'
> I1201 02:34:19.298437 31787 master.cpp:1676] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I1201 02:34:19.298838 31787 master.cpp:1991] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I1201 02:34:19.299357 31792 hierarchical.cpp:220] Added framework
> af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
> I1201 02:34:19.299427 31792 hierarchical.cpp:1064] No resources available
> to allocate!
> I1201 02:34:19.299474 31779 master.hpp:1542] Sending heartbeat to
> af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
> I1201 02:34:19.299482 31792 hierarchical.cpp:1157] No inverse offers to
> send out!
> I1201 02:34:19.299523 31792 hierarchical.cpp:959] Performed allocation for
> 0 slaves in 130665ns
> 2015-12-01
> 02:34:19,299:31760(0x2b94b0200700):ZOO_ERROR@handle_socket_error_msg@1697:
> Socket [127.0.0.1:41913] zk retcode=-4, errno=111(Connection refused):
> server refused to accept the client
> I1201 02:34:19.300420 31785 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.21.217:48328
> I1201 02:34:19.300967 31785 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.21.217:48328
> I1201 02:34:19.301753 31781 master_maintenance_tests.cpp:172] Ignoring
> HEARTBEAT event
> I1201 02:34:19.301847 31785 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.21.217:48328
> I1201 02:34:19.303249 31792 process.cpp:3067] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1201 02:34:19.303339 31792 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.21.217:54788
> I1201 02:34:19.303442 31792 master.cpp:2646] Processing REQUEST call for
> framework af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000 (default)
> I1201 02:34:19.303758 31790 hierarchical.cpp:494] Received resource
> request from framework af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
> I1201 02:34:19.304096 31794 master.cpp:938] Master terminating
> I1201 02:34:19.304285 31779 hierarchical.cpp:260] Removed framework
> af781e59-a3b4-4c7b-9b12-3c148a5999ae-0000
> E1201 02:34:19.305374 31786 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (59 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I1201 02:34:19.315563 31760 leveldb.cpp:174] Opened db in 3.25947ms
> I1201 02:34:19.316541 31760 leveldb.cpp:181] Compacted db in 936697ns
> I1201 02:34:19.316591 31760 leveldb.cpp:196] Created db iterator in 15937ns
> I1201 02:34:19.316607 31760 leveldb.cpp:202] Seeked to beginning of db in
> 1890ns
> I1201 02:34:19.316619 31760 leveldb.cpp:271] Iterated through 0 keys in
> the db in 310ns
> I1201 02:34:19.316655 31760 replica.cpp:778] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I1201 02:34:19.317059 31787 recover.cpp:447] Starting replica recovery
> I1201 02:34:19.317514 31787 recover.cpp:473] Replica is in EMPTY status
> I1201 02:34:19.318452 31779 replica.cpp:674] Replica in EMPTY status
> received a broadcasted recover request from (11292)@172.17.21.217:48328
> I1201 02:34:19.318943 31780 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I1201 02:34:19.319628 31792 recover.cpp:564] Updating replica status to
> STARTING
> I1201 02:34:19.320474 31782 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 481351ns
> I1201 02:34:19.320509 31782 replica.cpp:321] Persisted replica status to
> STARTING
> I1201 02:34:19.320735 31787 master.cpp:365] Master
> 900492e1-d049-40ea-93f1-21f3cf14daed (62ca2bb3ac6c) started on
> 172.17.21.217:48328
> I1201 02:34:19.320797 31789 recover.cpp:473] Replica is in STARTING status
> I1201 02:34:19.320765 31787 master.cpp:367] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_slaves="true"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/pQko3w/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.27.0/_inst/share/mesos/webui"
> --work_dir="/tmp/pQko3w/master" --zk_session_timeout="10secs"
> I1201 02:34:19.321107 31787 master.cpp:414] Master allowing
> unauthenticated frameworks to register
> I1201 02:34:19.321123 31787 master.cpp:417] Master only allowing
> authenticated slaves to register
> I1201 02:34:19.321132 31787 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/pQko3w/credentials'
> I1201 02:34:19.321450 31787 master.cpp:456] Using default 'crammd5'
> authenticator
> I1201 02:34:19.321575 31787 master.cpp:493] Authorization enabled
> I1201 02:34:19.321815 31794 whitelist_watcher.cpp:77] No whitelist given
> I1201 02:34:19.321910 31792 hierarchical.cpp:162] Initialized hierarchical
> allocator process
> I1201 02:34:19.321982 31793 replica.cpp:674] Replica in STARTING status
> received a broadcasted recover request from (11293)@172.17.21.217:48328
> I1201 02:34:19.322332 31791 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I1201 02:34:19.322816 31789 recover.cpp:564] Updating replica status to
> VOTING
> I1201 02:34:19.323389 31780 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 351601ns
> I1201 02:34:19.323415 31780 replica.cpp:321] Persisted replica status to
> VOTING
> I1201 02:34:19.323585 31780 recover.cpp:578] Successfully joined the Paxos
> group
> I1201 02:34:19.323947 31780 recover.cpp:462] Recover process terminated
> I1201 02:34:19.324056 31781 master.cpp:1637] The newly elected leader is
> master@172.17.21.217:48328 with id 900492e1-d049-40ea-93f1-21f3cf14daed
> I1201 02:34:19.324229 31781 master.cpp:1650] Elected as the leading master!
> I1201 02:34:19.324365 31781 master.cpp:1395] Recovering from registrar
> I1201 02:34:19.324537 31791 registrar.cpp:307] Recovering registrar
> I1201 02:34:19.325148 31783 log.cpp:659] Attempting to start the writer
> I1201 02:34:19.326383 31787 replica.cpp:494] Replica received implicit
> promise request from (11294)@172.17.21.217:48328 with proposal 1
> I1201 02:34:19.326813 31787 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 393604ns
> I1201 02:34:19.326844 31787 replica.cpp:343] Persisted promised to 1
> I1201 02:34:19.327396 31779 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I1201 02:34:19.328500 31785 replica.cpp:389] Replica received explicit
> promise request from (11295)@172.17.21.217:48328 for position 0 with
> proposal 2
> I1201 02:34:19.328877 31785 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 334232ns
> I1201 02:34:19.328902 31785 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.329780 31787 replica.cpp:538] Replica received write
> request for position 0 from (11296)@172.17.21.217:48328
> I1201 02:34:19.329834 31787 leveldb.cpp:436] Reading position from leveldb
> took 23961ns
> I1201 02:34:19.330243 31787 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 370452ns
> I1201 02:34:19.330281 31787 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.330826 31793 replica.cpp:692] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I1201 02:34:19.331305 31793 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 445703ns
> I1201 02:34:19.331331 31793 replica.cpp:713] Persisted action at 0
> I1201 02:34:19.331353 31793 replica.cpp:698] Replica learned NOP action at
> position 0
> I1201 02:34:19.331894 31790 log.cpp:675] Writer started with ending
> position 0
> I1201 02:34:19.332876 31794 leveldb.cpp:436] Reading position from leveldb
> took 41043ns
> I1201 02:34:19.333824 31789 registrar.cpp:340] Successfully fetched the
> registry (0B) in 9.236224ms
> I1201 02:34:19.333935 31789 registrar.cpp:439] Applied 1 operations in
> 23397ns; attempting to update the 'registry'
> I1201 02:34:19.334709 31789 log.cpp:683] Attempting to append 178 bytes to
> the log
> I1201 02:34:19.334849 31793 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I1201 02:34:19.335700 31785 replica.cpp:538] Replica received write
> request for position 1 from (11297)@172.17.21.217:48328
> I1201 02:34:19.336088 31785 leveldb.cpp:341] Persisting action (197 bytes)
> to leveldb took 339998ns
> I1201 02:34:19.336117 31785 replica.cpp:713] Persisted action at 1
> I1201 02:34:19.336877 31781 replica.cpp:692] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I1201 02:34:19.337270 31781 leveldb.cpp:341] Persisting action (199 bytes)
> to leveldb took 339541ns
> I1201 02:34:19.337301 31781 replica.cpp:713] Persisted action at 1
> I1201 02:34:19.337321 31781 replica.cpp:698] Replica learned APPEND action
> at position 1
> I1201 02:34:19.338389 31788 registrar.cpp:484] Successfully updated the
> 'registry' in 4.385024ms
> I1201 02:34:19.338567 31788 registrar.cpp:370] Successfully recovered
> registrar
> I1201 02:34:19.338676 31793 log.cpp:702] Attempting to truncate the log to
> 1
> I1201 02:34:19.338866 31791 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I1201 02:34:19.339190 31779 master.cpp:1447] Recovered 0 slaves from the
> Registry (139B) ; allowing 10mins for slaves to re-register
> I1201 02:34:19.339221 31789 hierarchical.cpp:174] Allocator recovery is
> not supported yet
> I1201 02:34:19.339902 31792 replica.cpp:538] Replica received write
> request for position 2 from (11298)@172.17.21.217:48328
> I1201 02:34:19.340292 31792 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 342933ns
> I1201 02:34:19.340322 31792 replica.cpp:713] Persisted action at 2
> I1201 02:34:19.340957 31793 replica.cpp:692] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I1201 02:34:19.341444 31793 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 449325ns
> I1201 02:34:19.341531 31793 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 52495ns
> I1201 02:34:19.341563 31793 replica.cpp:713] Persisted action at 2
> I1201 02:34:19.341601 31793 replica.cpp:698] Replica learned TRUNCATE
> action at position 2
> I1201 02:34:19.350018 31760 scheduler.cpp:154] Version: 0.27.0
> I1201 02:34:19.350697 31793 scheduler.cpp:236] New master detected at
> master@172.17.21.217:48328
> I1201 02:34:19.351855 31785 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.21.217:48328
> I1201 02:34:19.353670 31788 process.cpp:3067] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1201 02:34:19.353770 31788 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.21.217:54789
> I1201 02:34:19.354106 31788 master.cpp:1899] Received subscription request
> for HTTP framework 'default'
> I1201 02:34:19.354172 31788 master.cpp:1676] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I1201 02:34:19.354468 31788 master.cpp:1991] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I1201 02:34:19.354849 31791 hierarchical.cpp:220] Added framework
> 900492e1-d049-40ea-93f1-21f3cf14daed-0000
> I1201 02:34:19.354899 31791 hierarchical.cpp:1064] No resources available
> to allocate!
> I1201 02:34:19.354928 31791 hierarchical.cpp:1157] No inverse offers to
> send out!
> I1201 02:34:19.354945 31791 hierarchical.cpp:959] Performed allocation for
> 0 slaves in 70874ns
> I1201 02:34:19.355178 31786 master.hpp:1542] Sending heartbeat to
> 900492e1-d049-40ea-93f1-21f3cf14daed-0000
> I1201 02:34:19.356003 31791 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.21.217:48328
> I1201 02:34:19.356551 31791 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.21.217:48328
> I1201 02:34:19.357480 31790 master_maintenance_tests.cpp:172] Ignoring
> HEARTBEAT event
> I1201 02:34:19.357565 31787 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.21.217:48328
> I1201 02:34:19.359061 31782 process.cpp:3067] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I1201 02:34:19.359122 31782 http.cpp:336] HTTP POST for
> /master/api/v1/scheduler from 172.17.21.217:54790
> I1201 02:34:19.359432 31782 master.cpp:2646] Processing REQUEST call for
> framework 900492e1-d049-40ea-93f1-21f3cf14daed-0000 (default)
> I1201 02:34:19.359596 31794 hierarchical.cpp:494] Received resource
> request from framework 900492e1-d049-40ea-93f1-21f3cf14daed-0000
> I1201 02:34:19.360024 31794 master.cpp:938] Master terminating
> I1201 02:34:19.360440 31783 hierarchical.cpp:260] Removed framework
> 900492e1-d049-40ea-93f1-21f3cf14daed-0000
> E1201 02:34:19.361205 31787 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/1 (56 ms)
> [----------] 22 tests from ContentType/SchedulerTest (4172 ms total)
>
> [----------] Global test environment tear-down
> [==========] 867 tests from 116 test cases ran. (336518 ms total)
> [ PASSED ] 866 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.27.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.27.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1448935419-29488
> Untagged: mesos-1448935419-29488:latest
> Deleted: 5111c09d08dff461e549e9b09ca23c6fb9e9e9ac8b0914c142b4c650f11c479e
> Deleted: a892f31dee1ab1c17ba413344faa2cc4fd5f94185e7ce3c50d3641bef02f9364
> Deleted: c05080ab164b6bbdfa8997bbcd84dda660cb607e96d0f88fc6e41f47afb66145
> Deleted: dd31d40272d4465c36c379a65afdbde9bc54fd5746dae2e5d2ab79a8517f711e
> Deleted: a5c1fafc69f3f401a455fbd5d1c909befcaf1ca4e9b34533e4549f8c2a371b5c
> Deleted: 9586e9b81641e66b1aa14c61661c62d2d81975c5e06a59f155cdbca082a85a8e
> Deleted: d80af199489b5bad0452c02fbe873431c829bd9b25bcdf0bd7dbb07168caf1c6
> Deleted: 58a273741249aa06e9be0d52ae68dccbbe32dd5b91242991325070c006bce703
> Deleted: 870a4a6ce8f6b319df51120697474fad2eba202cd9e436d07a1ec0dfd260b780
> Deleted: eec94d7588b97209882c83884b1a32bbbd331ac0b235b7f625ae058dd29218ab
> Deleted: 736a295c5a68298819f423d6c1a078fe92e0b13af3081a3207d202ef50151b9f
> Deleted: f6c3272afd58f83c4136de54b8343bad750102351ab89e26ed4dde6b62ea02bf
> Deleted: bb671429b346a7a98a49bd0b6e85502ef1fd2c765b9d59f92a0d4e75733e1262
> 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 #1297
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/1297/changes>