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 2016/01/19 00:03:13 UTC

Build failed in Jenkins: Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #1506

See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1506/>

------------------------------------------
[...truncated 155770 lines...]
I0118 23:03:19.844106 29929 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_7OegKY/slaves/05552c6c-3b19-4d76-9402-ef9299661a04-S0/frameworks/05552c6c-3b19-4d76-9402-ef9299661a04-0000' for gc 6.99999023125037days in the future
I0118 23:03:19.844135 29928 status_update_manager.cpp:528] Cleaning up status update stream for task a7ef87eb-1120-4799-98e0-6c12cb4fae8a of framework 05552c6c-3b19-4d76-9402-ef9299661a04-0000
[       OK ] ContentType/SchedulerTest.Message/1 (133 ms)
[ RUN      ] ContentType/SchedulerTest.Request/0
I0118 23:03:19.851078 29898 leveldb.cpp:174] Opened db in 2.742478ms
I0118 23:03:19.852309 29898 leveldb.cpp:181] Compacted db in 1.218396ms
I0118 23:03:19.852401 29898 leveldb.cpp:196] Created db iterator in 33639ns
I0118 23:03:19.852421 29898 leveldb.cpp:202] Seeked to beginning of db in 7363ns
I0118 23:03:19.852429 29898 leveldb.cpp:271] Iterated through 0 keys in the db in 5034ns
I0118 23:03:19.852474 29898 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0118 23:03:19.853023 29930 recover.cpp:447] Starting replica recovery
I0118 23:03:19.854782 29930 recover.cpp:473] Replica is in EMPTY status
I0118 23:03:19.855705 29925 master.cpp:374] Master 624efc91-f4ce-4a4a-a449-00ce1f03b7b9 (3ade37c447fa) started on 172.17.0.4:45683
I0118 23:03:19.855744 29925 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/jzBYpt/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --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/jzBYpt/master" --zk_session_timeout="10secs"
I0118 23:03:19.856138 29925 master.cpp:423] Master allowing unauthenticated frameworks to register
I0118 23:03:19.856154 29925 master.cpp:426] Master only allowing authenticated slaves to register
I0118 23:03:19.856164 29925 credentials.hpp:35] Loading credentials for authentication from '/tmp/jzBYpt/credentials'
I0118 23:03:19.856315 29916 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13683)@172.17.0.4:45683
I0118 23:03:19.856478 29925 master.cpp:466] Using default 'crammd5' authenticator
I0118 23:03:19.856631 29925 master.cpp:535] Using default 'basic' HTTP authenticator
I0118 23:03:19.856799 29925 master.cpp:569] Authorization enabled
I0118 23:03:19.857043 29931 hierarchical.cpp:145] Initialized hierarchical allocator process
I0118 23:03:19.857069 29918 whitelist_watcher.cpp:77] No whitelist given
I0118 23:03:19.857074 29917 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0118 23:03:19.857702 29924 recover.cpp:564] Updating replica status to STARTING
I0118 23:03:19.858502 29917 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 678031ns
I0118 23:03:19.858530 29917 replica.cpp:320] Persisted replica status to STARTING
I0118 23:03:19.858784 29924 recover.cpp:473] Replica is in STARTING status
I0118 23:03:19.859259 29921 master.cpp:1710] The newly elected leader is master@172.17.0.4:45683 with id 624efc91-f4ce-4a4a-a449-00ce1f03b7b9
I0118 23:03:19.859293 29921 master.cpp:1723] Elected as the leading master!
I0118 23:03:19.859303 29921 master.cpp:1468] Recovering from registrar
I0118 23:03:19.859535 29919 registrar.cpp:307] Recovering registrar
I0118 23:03:19.860204 29927 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13685)@172.17.0.4:45683
I0118 23:03:19.860457 29917 recover.cpp:193] Received a recover response from a replica in STARTING status
I0118 23:03:19.860914 29920 recover.cpp:564] Updating replica status to VOTING
I0118 23:03:19.861577 29916 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 382605ns
I0118 23:03:19.861603 29916 replica.cpp:320] Persisted replica status to VOTING
I0118 23:03:19.861704 29925 recover.cpp:578] Successfully joined the Paxos group
I0118 23:03:19.862017 29925 recover.cpp:462] Recover process terminated
I0118 23:03:19.862398 29916 log.cpp:659] Attempting to start the writer
I0118 23:03:19.863638 29916 replica.cpp:493] Replica received implicit promise request from (13686)@172.17.0.4:45683 with proposal 1
I0118 23:03:19.864112 29916 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 460382ns
I0118 23:03:19.864147 29916 replica.cpp:342] Persisted promised to 1
I0118 23:03:19.864703 29928 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0118 23:03:19.865829 29919 replica.cpp:388] Replica received explicit promise request from (13687)@172.17.0.4:45683 for position 0 with proposal 2
I0118 23:03:19.866309 29919 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 454771ns
I0118 23:03:19.866358 29919 replica.cpp:712] Persisted action at 0
I0118 23:03:19.867517 29926 replica.cpp:537] Replica received write request for position 0 from (13688)@172.17.0.4:45683
I0118 23:03:19.867594 29926 leveldb.cpp:436] Reading position from leveldb took 46227ns
I0118 23:03:19.868098 29926 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 464570ns
I0118 23:03:19.868140 29926 replica.cpp:712] Persisted action at 0
I0118 23:03:19.868870 29928 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0118 23:03:19.869282 29928 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 387624ns
I0118 23:03:19.869314 29928 replica.cpp:712] Persisted action at 0
I0118 23:03:19.869335 29928 replica.cpp:697] Replica learned NOP action at position 0
I0118 23:03:19.869954 29929 log.cpp:675] Writer started with ending position 0
I0118 23:03:19.871016 29916 leveldb.cpp:436] Reading position from leveldb took 48216ns
I0118 23:03:19.872004 29919 registrar.cpp:340] Successfully fetched the registry (0B) in 12.32384ms
I0118 23:03:19.872190 29919 registrar.cpp:439] Applied 1 operations in 47911ns; attempting to update the 'registry'
I0118 23:03:19.872951 29916 log.cpp:683] Attempting to append 170 bytes to the log
I0118 23:03:19.873107 29930 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0118 23:03:19.873965 29925 replica.cpp:537] Replica received write request for position 1 from (13689)@172.17.0.4:45683
I0118 23:03:19.874435 29925 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 439239ns
I0118 23:03:19.874466 29925 replica.cpp:712] Persisted action at 1
I0118 23:03:19.875128 29925 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0118 23:03:19.875562 29925 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 416833ns
I0118 23:03:19.875594 29925 replica.cpp:712] Persisted action at 1
I0118 23:03:19.875615 29925 replica.cpp:697] Replica learned APPEND action at position 1
I0118 23:03:19.876617 29930 registrar.cpp:484] Successfully updated the 'registry' in 4.356096ms
I0118 23:03:19.876798 29930 registrar.cpp:370] Successfully recovered registrar
I0118 23:03:19.876873 29922 log.cpp:702] Attempting to truncate the log to 1
I0118 23:03:19.877005 29928 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0118 23:03:19.877459 29929 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0118 23:03:19.877564 29921 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0118 23:03:19.878180 29926 replica.cpp:537] Replica received write request for position 2 from (13690)@172.17.0.4:45683
I0118 23:03:19.878589 29926 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 375269ns
I0118 23:03:19.878620 29926 replica.cpp:712] Persisted action at 2
I0118 23:03:19.879320 29924 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0118 23:03:19.879819 29924 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 477489ns
I0118 23:03:19.879892 29924 leveldb.cpp:399] Deleting ~1 keys from leveldb took 55996ns
I0118 23:03:19.879923 29924 replica.cpp:712] Persisted action at 2
I0118 23:03:19.879952 29924 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0118 23:03:19.888377 29898 scheduler.cpp:154] Version: 0.27.0
I0118 23:03:19.889097 29927 scheduler.cpp:236] New master detected at master@172.17.0.4:45683
I0118 23:03:19.890256 29920 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:45683
I0118 23:03:19.892216 29924 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0118 23:03:19.892801 29922 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:33007
I0118 23:03:19.893009 29922 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0118 23:03:19.893036 29922 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0118 23:03:19.893424 29922 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I0118 23:03:19.893842 29923 hierarchical.cpp:266] Added framework 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
I0118 23:03:19.893908 29923 hierarchical.cpp:1338] No resources available to allocate!
I0118 23:03:19.893946 29917 master.hpp:1658] Sending heartbeat to 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
I0118 23:03:19.893956 29923 hierarchical.cpp:1432] No inverse offers to send out!
I0118 23:03:19.893993 29923 hierarchical.cpp:1086] Performed allocation for 0 slaves in 135870ns
I0118 23:03:19.894763 29919 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:45683
I0118 23:03:19.895226 29919 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:45683
I0118 23:03:19.895767 29919 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0118 23:03:19.896193 29928 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:45683
I0118 23:03:19.897620 29928 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0118 23:03:19.898008 29931 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:33008
I0118 23:03:19.898143 29931 master.cpp:2717] Processing REQUEST call for framework 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000 (default)
I0118 23:03:19.898334 29928 hierarchical.cpp:586] Received resource request from framework 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
I0118 23:03:19.898638 29927 master.cpp:1025] Master terminating
I0118 23:03:19.898875 29919 hierarchical.cpp:327] Removed framework 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
E0118 23:03:19.899845 29926 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[       OK ] ContentType/SchedulerTest.Request/0 (57 ms)
[ RUN      ] ContentType/SchedulerTest.Request/1
I0118 23:03:19.908234 29898 leveldb.cpp:174] Opened db in 2.583835ms
I0118 23:03:19.909324 29898 leveldb.cpp:181] Compacted db in 1.063576ms
I0118 23:03:19.909378 29898 leveldb.cpp:196] Created db iterator in 34454ns
I0118 23:03:19.909404 29898 leveldb.cpp:202] Seeked to beginning of db in 12025ns
I0118 23:03:19.909446 29898 leveldb.cpp:271] Iterated through 0 keys in the db in 18830ns
I0118 23:03:19.909502 29898 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0118 23:03:19.910025 29917 recover.cpp:447] Starting replica recovery
I0118 23:03:19.910282 29917 recover.cpp:473] Replica is in EMPTY status
I0118 23:03:19.911519 29919 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13698)@172.17.0.4:45683
I0118 23:03:19.911931 29925 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0118 23:03:19.912528 29931 recover.cpp:564] Updating replica status to STARTING
I0118 23:03:19.913187 29926 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 590877ns
I0118 23:03:19.913228 29926 replica.cpp:320] Persisted replica status to STARTING
I0118 23:03:19.913403 29920 master.cpp:374] Master ad32f568-972d-46b2-881f-44f7d39ddbdc (3ade37c447fa) started on 172.17.0.4:45683
I0118 23:03:19.913511 29930 recover.cpp:473] Replica is in STARTING status
I0118 23:03:19.913445 29920 master.cpp:376] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/TRUygj/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --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/TRUygj/master" --zk_session_timeout="10secs"
I0118 23:03:19.913852 29920 master.cpp:423] Master allowing unauthenticated frameworks to register
I0118 23:03:19.913866 29920 master.cpp:426] Master only allowing authenticated slaves to register
I0118 23:03:19.913875 29920 credentials.hpp:35] Loading credentials for authentication from '/tmp/TRUygj/credentials'
I0118 23:03:19.914234 29920 master.cpp:466] Using default 'crammd5' authenticator
I0118 23:03:19.914397 29920 master.cpp:535] Using default 'basic' HTTP authenticator
I0118 23:03:19.914485 29921 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13699)@172.17.0.4:45683
I0118 23:03:19.914608 29920 master.cpp:569] Authorization enabled
I0118 23:03:19.914779 29921 hierarchical.cpp:145] Initialized hierarchical allocator process
I0118 23:03:19.914826 29916 whitelist_watcher.cpp:77] No whitelist given
I0118 23:03:19.914924 29927 recover.cpp:193] Received a recover response from a replica in STARTING status
I0118 23:03:19.915542 29919 recover.cpp:564] Updating replica status to VOTING
I0118 23:03:19.916193 29929 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 455878ns
I0118 23:03:19.916219 29929 replica.cpp:320] Persisted replica status to VOTING
I0118 23:03:19.916369 29926 recover.cpp:578] Successfully joined the Paxos group
I0118 23:03:19.916704 29926 recover.cpp:462] Recover process terminated
I0118 23:03:19.917016 29922 master.cpp:1710] The newly elected leader is master@172.17.0.4:45683 with id ad32f568-972d-46b2-881f-44f7d39ddbdc
I0118 23:03:19.917050 29922 master.cpp:1723] Elected as the leading master!
I0118 23:03:19.917282 29922 master.cpp:1468] Recovering from registrar
I0118 23:03:19.917474 29929 registrar.cpp:307] Recovering registrar
I0118 23:03:19.917917 29922 log.cpp:659] Attempting to start the writer
I0118 23:03:19.918970 29924 replica.cpp:493] Replica received implicit promise request from (13701)@172.17.0.4:45683 with proposal 1
I0118 23:03:19.919471 29924 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 434673ns
I0118 23:03:19.919495 29924 replica.cpp:342] Persisted promised to 1
I0118 23:03:19.920037 29925 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0118 23:03:19.921254 29926 replica.cpp:388] Replica received explicit promise request from (13702)@172.17.0.4:45683 for position 0 with proposal 2
I0118 23:03:19.921569 29926 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 290584ns
I0118 23:03:19.921592 29926 replica.cpp:712] Persisted action at 0
I0118 23:03:19.922453 29925 replica.cpp:537] Replica received write request for position 0 from (13703)@172.17.0.4:45683
I0118 23:03:19.922511 29925 leveldb.cpp:436] Reading position from leveldb took 40477ns
I0118 23:03:19.922900 29925 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 356778ns
I0118 23:03:19.922924 29925 replica.cpp:712] Persisted action at 0
I0118 23:03:19.923511 29917 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0118 23:03:19.923873 29917 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 347877ns
I0118 23:03:19.923897 29917 replica.cpp:712] Persisted action at 0
I0118 23:03:19.923913 29917 replica.cpp:697] Replica learned NOP action at position 0
I0118 23:03:19.924587 29927 log.cpp:675] Writer started with ending position 0
I0118 23:03:19.925745 29929 leveldb.cpp:436] Reading position from leveldb took 53389ns
I0118 23:03:19.926780 29924 registrar.cpp:340] Successfully fetched the registry (0B) in 9.268224ms
I0118 23:03:19.926913 29924 registrar.cpp:439] Applied 1 operations in 48411ns; attempting to update the 'registry'
I0118 23:03:19.927549 29926 log.cpp:683] Attempting to append 170 bytes to the log
I0118 23:03:19.927760 29920 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0118 23:03:19.928527 29917 replica.cpp:537] Replica received write request for position 1 from (13704)@172.17.0.4:45683
I0118 23:03:19.928932 29917 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 372405ns
I0118 23:03:19.928956 29917 replica.cpp:712] Persisted action at 1
I0118 23:03:19.929538 29917 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0118 23:03:19.929882 29917 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 326483ns
I0118 23:03:19.929904 29917 replica.cpp:712] Persisted action at 1
I0118 23:03:19.929925 29917 replica.cpp:697] Replica learned APPEND action at position 1
I0118 23:03:19.930896 29930 registrar.cpp:484] Successfully updated the 'registry' in 3.912192ms
I0118 23:03:19.931013 29930 registrar.cpp:370] Successfully recovered registrar
I0118 23:03:19.931152 29931 log.cpp:702] Attempting to truncate the log to 1
I0118 23:03:19.931429 29917 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0118 23:03:19.931476 29929 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0118 23:03:19.931581 29921 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0118 23:03:19.932384 29918 replica.cpp:537] Replica received write request for position 2 from (13705)@172.17.0.4:45683
I0118 23:03:19.932812 29918 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 401469ns
I0118 23:03:19.932837 29918 replica.cpp:712] Persisted action at 2
I0118 23:03:19.933440 29920 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0118 23:03:19.933825 29920 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 368093ns
I0118 23:03:19.933872 29920 leveldb.cpp:399] Deleting ~1 keys from leveldb took 33161ns
I0118 23:03:19.933889 29920 replica.cpp:712] Persisted action at 2
I0118 23:03:19.933905 29920 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0118 23:03:19.942512 29898 scheduler.cpp:154] Version: 0.27.0
I0118 23:03:19.943182 29918 scheduler.cpp:236] New master detected at master@172.17.0.4:45683
I0118 23:03:19.944362 29924 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.4:45683
I0118 23:03:19.946282 29918 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0118 23:03:19.946789 29920 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:33009
I0118 23:03:19.947180 29920 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0118 23:03:19.947206 29920 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0118 23:03:19.947540 29920 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I0118 23:03:19.947973 29918 hierarchical.cpp:266] Added framework ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
I0118 23:03:19.948040 29918 hierarchical.cpp:1338] No resources available to allocate!
I0118 23:03:19.948107 29918 hierarchical.cpp:1432] No inverse offers to send out!
I0118 23:03:19.948130 29918 hierarchical.cpp:1086] Performed allocation for 0 slaves in 138145ns
I0118 23:03:19.948165 29923 master.hpp:1658] Sending heartbeat to ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
I0118 23:03:19.949169 29922 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.4:45683
I0118 23:03:19.949666 29922 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.4:45683
I0118 23:03:19.950438 29918 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0118 23:03:19.950459 29922 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.4:45683
I0118 23:03:19.952298 29927 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0118 23:03:19.952775 29920 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:33010
I0118 23:03:19.953030 29920 master.cpp:2717] Processing REQUEST call for framework ad32f568-972d-46b2-881f-44f7d39ddbdc-0000 (default)
I0118 23:03:19.953277 29922 hierarchical.cpp:586] Received resource request from framework ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
I0118 23:03:19.953598 29925 master.cpp:1025] Master terminating
I0118 23:03:19.954211 29926 hierarchical.cpp:327] Removed framework ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
E0118 23:03:19.955265 29931 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 (4164 ms total)

[----------] Global test environment tear-down
2016-01-18 23:03:20,258:29898(0x2ac46780c700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:39162] zk retcode=-4, errno=111(Connection refused): server refused to accept the client
[==========] 928 tests from 123 test cases ran. (331537 ms total)
[  PASSED  ] 927 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] MasterTest.MaxCompletedTasksPerFrameworkFlag

 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-1453156296-5368
Untagged: mesos-1453156296-5368:latest
Deleted: 777e17b94a7fe7b758f183d0b1a56358a99a0a909b3aa663b2601c26a1da04cf
Deleted: 993b895d8a13121bdc79d16466b88816a50d376351d1dfb76bd12e9473ab1f6c
Deleted: bd18ccd42876654f92330a6bca63c16d56c580ad106fc1a2d7c4102c757477b4
Deleted: 8afec7c08a7fa37bd4c0ac02cdb99220292a2b7e4cc9f632510c66a6594793d9
Deleted: 8b25c2d8746431e3dca92de5763e8c7bb381d721c950d75aec6cb42c07afe8b0
Deleted: 70a463f67f40a22afe151ac66a9b0b303ebb22e812f9244d34d89606328e291c
Deleted: 6350c6abe5f933c63c932bf6e8ace0d7327ed71a2ed119af69935d91ebdfc9a1
Deleted: 0a9bdbd9750c7033aeb02816ec7dd581b15088198a2edad03a249530ddc88685
Deleted: faac0508488d9dd6093ffbfa5919755ba6a99ccb19c25a349174cc68cdbea2bc
Deleted: 8f2d7d308ce6b45dda6417457c6dcf89f073a69225ee92ca534ba0a9f8200fb7
Deleted: 7b29adc92f4eef68d50d293a2f550f2b8b332d71cc7c1646abd90c62d581f2a3
Deleted: c1839eb2495d1e24b9745c59d922117208dae9e024d9dff8d383214969cf0400
Deleted: 523f472d6ba67e69aedf9c76aeb6d1757cffb2562c3a6623a67310bfcbc7b47e
Deleted: 74d595bedbfcd4d38a9b5f6e4b64f5cc86236ce07f67f40debbf8d277d1c38a4
Build step 'Execute shell' marked build as failure

Jenkins build is back to normal : Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #1507

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1507/changes>


Re: Build failed in Jenkins: Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #1506

Posted by Benjamin Mahler <bm...@apache.org>.
It will be fixed soon.

On Tue, Jan 19, 2016 at 4:34 PM, Greg Mann <gr...@mesosphere.io> wrote:

> Looks like it could be caused by the same issue as
> https://issues.apache.org/jira/browse/MESOS-4409
>
> On Tue, Jan 19, 2016 at 4:07 PM, Vinod Kone <vi...@apache.org> wrote:
>
> > Is this being looked at?
> >
> > On Mon, Jan 18, 2016 at 3:03 PM, Apache Jenkins Server <
> > jenkins@builds.apache.org> wrote:
> >
> > > See <
> > >
> >
> https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1506/
> > > >
> > >
> > > ------------------------------------------
> > > [...truncated 155770 lines...]
> > > I0118 23:03:19.844106 29929 gc.cpp:54] Scheduling
> > >
> >
> '/tmp/ContentType_SchedulerTest_Message_1_7OegKY/slaves/05552c6c-3b19-4d76-9402-ef9299661a04-S0/frameworks/05552c6c-3b19-4d76-9402-ef9299661a04-0000'
> > > for gc 6.99999023125037days in the future
> > > I0118 23:03:19.844135 29928 status_update_manager.cpp:528] Cleaning up
> > > status update stream for task a7ef87eb-1120-4799-98e0-6c12cb4fae8a of
> > > framework 05552c6c-3b19-4d76-9402-ef9299661a04-0000
> > > [       OK ] ContentType/SchedulerTest.Message/1 (133 ms)
> > > [ RUN      ] ContentType/SchedulerTest.Request/0
> > > I0118 23:03:19.851078 29898 leveldb.cpp:174] Opened db in 2.742478ms
> > > I0118 23:03:19.852309 29898 leveldb.cpp:181] Compacted db in 1.218396ms
> > > I0118 23:03:19.852401 29898 leveldb.cpp:196] Created db iterator in
> > 33639ns
> > > I0118 23:03:19.852421 29898 leveldb.cpp:202] Seeked to beginning of db
> in
> > > 7363ns
> > > I0118 23:03:19.852429 29898 leveldb.cpp:271] Iterated through 0 keys in
> > > the db in 5034ns
> > > I0118 23:03:19.852474 29898 replica.cpp:779] Replica recovered with log
> > > positions 0 -> 0 with 1 holes and 0 unlearned
> > > I0118 23:03:19.853023 29930 recover.cpp:447] Starting replica recovery
> > > I0118 23:03:19.854782 29930 recover.cpp:473] Replica is in EMPTY status
> > > I0118 23:03:19.855705 29925 master.cpp:374] Master
> > > 624efc91-f4ce-4a4a-a449-00ce1f03b7b9 (3ade37c447fa) started on
> > > 172.17.0.4:45683
> > > I0118 23:03:19.855744 29925 master.cpp:376] Flags at startup: --acls=""
> > > --allocation_interval="1secs" --allocator="HierarchicalDRF"
> > > --authenticate="false" --authenticate_http="true"
> > > --authenticate_slaves="true" --authenticators="crammd5"
> > > --authorizers="local" --credentials="/tmp/jzBYpt/credentials"
> > > --framework_sorter="drf" --help="false" --hostname_lookup="true"
> > > --http_authenticators="basic" --initialize_driver_logging="true"
> > > --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> > > --max_completed_frameworks="50"
> > --max_completed_tasks_per_framework="1000"
> > > --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/jzBYpt/master" --zk_session_timeout="10secs"
> > > I0118 23:03:19.856138 29925 master.cpp:423] Master allowing
> > > unauthenticated frameworks to register
> > > I0118 23:03:19.856154 29925 master.cpp:426] Master only allowing
> > > authenticated slaves to register
> > > I0118 23:03:19.856164 29925 credentials.hpp:35] Loading credentials for
> > > authentication from '/tmp/jzBYpt/credentials'
> > > I0118 23:03:19.856315 29916 replica.cpp:673] Replica in EMPTY status
> > > received a broadcasted recover request from (13683)@172.17.0.4:45683
> > > I0118 23:03:19.856478 29925 master.cpp:466] Using default 'crammd5'
> > > authenticator
> > > I0118 23:03:19.856631 29925 master.cpp:535] Using default 'basic' HTTP
> > > authenticator
> > > I0118 23:03:19.856799 29925 master.cpp:569] Authorization enabled
> > > I0118 23:03:19.857043 29931 hierarchical.cpp:145] Initialized
> > hierarchical
> > > allocator process
> > > I0118 23:03:19.857069 29918 whitelist_watcher.cpp:77] No whitelist
> given
> > > I0118 23:03:19.857074 29917 recover.cpp:193] Received a recover
> response
> > > from a replica in EMPTY status
> > > I0118 23:03:19.857702 29924 recover.cpp:564] Updating replica status to
> > > STARTING
> > > I0118 23:03:19.858502 29917 leveldb.cpp:304] Persisting metadata (8
> > bytes)
> > > to leveldb took 678031ns
> > > I0118 23:03:19.858530 29917 replica.cpp:320] Persisted replica status
> to
> > > STARTING
> > > I0118 23:03:19.858784 29924 recover.cpp:473] Replica is in STARTING
> > status
> > > I0118 23:03:19.859259 29921 master.cpp:1710] The newly elected leader
> is
> > > master@172.17.0.4:45683 with id 624efc91-f4ce-4a4a-a449-00ce1f03b7b9
> > > I0118 23:03:19.859293 29921 master.cpp:1723] Elected as the leading
> > master!
> > > I0118 23:03:19.859303 29921 master.cpp:1468] Recovering from registrar
> > > I0118 23:03:19.859535 29919 registrar.cpp:307] Recovering registrar
> > > I0118 23:03:19.860204 29927 replica.cpp:673] Replica in STARTING status
> > > received a broadcasted recover request from (13685)@172.17.0.4:45683
> > > I0118 23:03:19.860457 29917 recover.cpp:193] Received a recover
> response
> > > from a replica in STARTING status
> > > I0118 23:03:19.860914 29920 recover.cpp:564] Updating replica status to
> > > VOTING
> > > I0118 23:03:19.861577 29916 leveldb.cpp:304] Persisting metadata (8
> > bytes)
> > > to leveldb took 382605ns
> > > I0118 23:03:19.861603 29916 replica.cpp:320] Persisted replica status
> to
> > > VOTING
> > > I0118 23:03:19.861704 29925 recover.cpp:578] Successfully joined the
> > Paxos
> > > group
> > > I0118 23:03:19.862017 29925 recover.cpp:462] Recover process terminated
> > > I0118 23:03:19.862398 29916 log.cpp:659] Attempting to start the writer
> > > I0118 23:03:19.863638 29916 replica.cpp:493] Replica received implicit
> > > promise request from (13686)@172.17.0.4:45683 with proposal 1
> > > I0118 23:03:19.864112 29916 leveldb.cpp:304] Persisting metadata (8
> > bytes)
> > > to leveldb took 460382ns
> > > I0118 23:03:19.864147 29916 replica.cpp:342] Persisted promised to 1
> > > I0118 23:03:19.864703 29928 coordinator.cpp:238] Coordinator attempting
> > to
> > > fill missing positions
> > > I0118 23:03:19.865829 29919 replica.cpp:388] Replica received explicit
> > > promise request from (13687)@172.17.0.4:45683 for position 0 with
> > > proposal 2
> > > I0118 23:03:19.866309 29919 leveldb.cpp:341] Persisting action (8
> bytes)
> > > to leveldb took 454771ns
> > > I0118 23:03:19.866358 29919 replica.cpp:712] Persisted action at 0
> > > I0118 23:03:19.867517 29926 replica.cpp:537] Replica received write
> > > request for position 0 from (13688)@172.17.0.4:45683
> > > I0118 23:03:19.867594 29926 leveldb.cpp:436] Reading position from
> > leveldb
> > > took 46227ns
> > > I0118 23:03:19.868098 29926 leveldb.cpp:341] Persisting action (14
> bytes)
> > > to leveldb took 464570ns
> > > I0118 23:03:19.868140 29926 replica.cpp:712] Persisted action at 0
> > > I0118 23:03:19.868870 29928 replica.cpp:691] Replica received learned
> > > notice for position 0 from @0.0.0.0:0
> > > I0118 23:03:19.869282 29928 leveldb.cpp:341] Persisting action (16
> bytes)
> > > to leveldb took 387624ns
> > > I0118 23:03:19.869314 29928 replica.cpp:712] Persisted action at 0
> > > I0118 23:03:19.869335 29928 replica.cpp:697] Replica learned NOP action
> > at
> > > position 0
> > > I0118 23:03:19.869954 29929 log.cpp:675] Writer started with ending
> > > position 0
> > > I0118 23:03:19.871016 29916 leveldb.cpp:436] Reading position from
> > leveldb
> > > took 48216ns
> > > I0118 23:03:19.872004 29919 registrar.cpp:340] Successfully fetched the
> > > registry (0B) in 12.32384ms
> > > I0118 23:03:19.872190 29919 registrar.cpp:439] Applied 1 operations in
> > > 47911ns; attempting to update the 'registry'
> > > I0118 23:03:19.872951 29916 log.cpp:683] Attempting to append 170 bytes
> > to
> > > the log
> > > I0118 23:03:19.873107 29930 coordinator.cpp:348] Coordinator attempting
> > to
> > > write APPEND action at position 1
> > > I0118 23:03:19.873965 29925 replica.cpp:537] Replica received write
> > > request for position 1 from (13689)@172.17.0.4:45683
> > > I0118 23:03:19.874435 29925 leveldb.cpp:341] Persisting action (189
> > bytes)
> > > to leveldb took 439239ns
> > > I0118 23:03:19.874466 29925 replica.cpp:712] Persisted action at 1
> > > I0118 23:03:19.875128 29925 replica.cpp:691] Replica received learned
> > > notice for position 1 from @0.0.0.0:0
> > > I0118 23:03:19.875562 29925 leveldb.cpp:341] Persisting action (191
> > bytes)
> > > to leveldb took 416833ns
> > > I0118 23:03:19.875594 29925 replica.cpp:712] Persisted action at 1
> > > I0118 23:03:19.875615 29925 replica.cpp:697] Replica learned APPEND
> > action
> > > at position 1
> > > I0118 23:03:19.876617 29930 registrar.cpp:484] Successfully updated the
> > > 'registry' in 4.356096ms
> > > I0118 23:03:19.876798 29930 registrar.cpp:370] Successfully recovered
> > > registrar
> > > I0118 23:03:19.876873 29922 log.cpp:702] Attempting to truncate the log
> > to
> > > 1
> > > I0118 23:03:19.877005 29928 coordinator.cpp:348] Coordinator attempting
> > to
> > > write TRUNCATE action at position 2
> > > I0118 23:03:19.877459 29929 master.cpp:1520] Recovered 0 slaves from
> the
> > > Registry (131B) ; allowing 10mins for slaves to re-register
> > > I0118 23:03:19.877564 29921 hierarchical.cpp:172] Skipping recovery of
> > > hierarchical allocator: nothing to recover
> > > I0118 23:03:19.878180 29926 replica.cpp:537] Replica received write
> > > request for position 2 from (13690)@172.17.0.4:45683
> > > I0118 23:03:19.878589 29926 leveldb.cpp:341] Persisting action (16
> bytes)
> > > to leveldb took 375269ns
> > > I0118 23:03:19.878620 29926 replica.cpp:712] Persisted action at 2
> > > I0118 23:03:19.879320 29924 replica.cpp:691] Replica received learned
> > > notice for position 2 from @0.0.0.0:0
> > > I0118 23:03:19.879819 29924 leveldb.cpp:341] Persisting action (18
> bytes)
> > > to leveldb took 477489ns
> > > I0118 23:03:19.879892 29924 leveldb.cpp:399] Deleting ~1 keys from
> > leveldb
> > > took 55996ns
> > > I0118 23:03:19.879923 29924 replica.cpp:712] Persisted action at 2
> > > I0118 23:03:19.879952 29924 replica.cpp:697] Replica learned TRUNCATE
> > > action at position 2
> > > I0118 23:03:19.888377 29898 scheduler.cpp:154] Version: 0.27.0
> > > I0118 23:03:19.889097 29927 scheduler.cpp:236] New master detected at
> > > master@172.17.0.4:45683
> > > I0118 23:03:19.890256 29920 scheduler.cpp:298] Sending SUBSCRIBE call
> to
> > > master@172.17.0.4:45683
> > > I0118 23:03:19.892216 29924 process.cpp:3141] Handling HTTP event for
> > > process 'master' with path: '/master/api/v1/scheduler'
> > > I0118 23:03:19.892801 29922 http.cpp:504] HTTP POST for
> > > /master/api/v1/scheduler from 172.17.0.4:33007
> > > I0118 23:03:19.893009 29922 master.cpp:1972] Received subscription
> > request
> > > for HTTP framework 'default'
> > > I0118 23:03:19.893036 29922 master.cpp:1749] Authorizing framework
> > > principal 'test-principal' to receive offers for role '*'
> > > I0118 23:03:19.893424 29922 master.cpp:2063] Subscribing framework
> > > 'default' with checkpointing disabled and capabilities [  ]
> > > I0118 23:03:19.893842 29923 hierarchical.cpp:266] Added framework
> > > 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> > > I0118 23:03:19.893908 29923 hierarchical.cpp:1338] No resources
> available
> > > to allocate!
> > > I0118 23:03:19.893946 29917 master.hpp:1658] Sending heartbeat to
> > > 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> > > I0118 23:03:19.893956 29923 hierarchical.cpp:1432] No inverse offers to
> > > send out!
> > > I0118 23:03:19.893993 29923 hierarchical.cpp:1086] Performed allocation
> > > for 0 slaves in 135870ns
> > > I0118 23:03:19.894763 29919 scheduler.cpp:457] Enqueuing event
> SUBSCRIBED
> > > received from master@172.17.0.4:45683
> > > I0118 23:03:19.895226 29919 scheduler.cpp:457] Enqueuing event
> HEARTBEAT
> > > received from master@172.17.0.4:45683
> > > I0118 23:03:19.895767 29919 master_maintenance_tests.cpp:177] Ignoring
> > > HEARTBEAT event
> > > I0118 23:03:19.896193 29928 scheduler.cpp:298] Sending REQUEST call to
> > > master@172.17.0.4:45683
> > > I0118 23:03:19.897620 29928 process.cpp:3141] Handling HTTP event for
> > > process 'master' with path: '/master/api/v1/scheduler'
> > > I0118 23:03:19.898008 29931 http.cpp:504] HTTP POST for
> > > /master/api/v1/scheduler from 172.17.0.4:33008
> > > I0118 23:03:19.898143 29931 master.cpp:2717] Processing REQUEST call
> for
> > > framework 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000 (default)
> > > I0118 23:03:19.898334 29928 hierarchical.cpp:586] Received resource
> > > request from framework 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> > > I0118 23:03:19.898638 29927 master.cpp:1025] Master terminating
> > > I0118 23:03:19.898875 29919 hierarchical.cpp:327] Removed framework
> > > 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> > > E0118 23:03:19.899845 29926 scheduler.cpp:431] End-Of-File received
> from
> > > master. The master closed the event stream
> > > [       OK ] ContentType/SchedulerTest.Request/0 (57 ms)
> > > [ RUN      ] ContentType/SchedulerTest.Request/1
> > > I0118 23:03:19.908234 29898 leveldb.cpp:174] Opened db in 2.583835ms
> > > I0118 23:03:19.909324 29898 leveldb.cpp:181] Compacted db in 1.063576ms
> > > I0118 23:03:19.909378 29898 leveldb.cpp:196] Created db iterator in
> > 34454ns
> > > I0118 23:03:19.909404 29898 leveldb.cpp:202] Seeked to beginning of db
> in
> > > 12025ns
> > > I0118 23:03:19.909446 29898 leveldb.cpp:271] Iterated through 0 keys in
> > > the db in 18830ns
> > > I0118 23:03:19.909502 29898 replica.cpp:779] Replica recovered with log
> > > positions 0 -> 0 with 1 holes and 0 unlearned
> > > I0118 23:03:19.910025 29917 recover.cpp:447] Starting replica recovery
> > > I0118 23:03:19.910282 29917 recover.cpp:473] Replica is in EMPTY status
> > > I0118 23:03:19.911519 29919 replica.cpp:673] Replica in EMPTY status
> > > received a broadcasted recover request from (13698)@172.17.0.4:45683
> > > I0118 23:03:19.911931 29925 recover.cpp:193] Received a recover
> response
> > > from a replica in EMPTY status
> > > I0118 23:03:19.912528 29931 recover.cpp:564] Updating replica status to
> > > STARTING
> > > I0118 23:03:19.913187 29926 leveldb.cpp:304] Persisting metadata (8
> > bytes)
> > > to leveldb took 590877ns
> > > I0118 23:03:19.913228 29926 replica.cpp:320] Persisted replica status
> to
> > > STARTING
> > > I0118 23:03:19.913403 29920 master.cpp:374] Master
> > > ad32f568-972d-46b2-881f-44f7d39ddbdc (3ade37c447fa) started on
> > > 172.17.0.4:45683
> > > I0118 23:03:19.913511 29930 recover.cpp:473] Replica is in STARTING
> > status
> > > I0118 23:03:19.913445 29920 master.cpp:376] Flags at startup: --acls=""
> > > --allocation_interval="1secs" --allocator="HierarchicalDRF"
> > > --authenticate="false" --authenticate_http="true"
> > > --authenticate_slaves="true" --authenticators="crammd5"
> > > --authorizers="local" --credentials="/tmp/TRUygj/credentials"
> > > --framework_sorter="drf" --help="false" --hostname_lookup="true"
> > > --http_authenticators="basic" --initialize_driver_logging="true"
> > > --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> > > --max_completed_frameworks="50"
> > --max_completed_tasks_per_framework="1000"
> > > --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/TRUygj/master" --zk_session_timeout="10secs"
> > > I0118 23:03:19.913852 29920 master.cpp:423] Master allowing
> > > unauthenticated frameworks to register
> > > I0118 23:03:19.913866 29920 master.cpp:426] Master only allowing
> > > authenticated slaves to register
> > > I0118 23:03:19.913875 29920 credentials.hpp:35] Loading credentials for
> > > authentication from '/tmp/TRUygj/credentials'
> > > I0118 23:03:19.914234 29920 master.cpp:466] Using default 'crammd5'
> > > authenticator
> > > I0118 23:03:19.914397 29920 master.cpp:535] Using default 'basic' HTTP
> > > authenticator
> > > I0118 23:03:19.914485 29921 replica.cpp:673] Replica in STARTING status
> > > received a broadcasted recover request from (13699)@172.17.0.4:45683
> > > I0118 23:03:19.914608 29920 master.cpp:569] Authorization enabled
> > > I0118 23:03:19.914779 29921 hierarchical.cpp:145] Initialized
> > hierarchical
> > > allocator process
> > > I0118 23:03:19.914826 29916 whitelist_watcher.cpp:77] No whitelist
> given
> > > I0118 23:03:19.914924 29927 recover.cpp:193] Received a recover
> response
> > > from a replica in STARTING status
> > > I0118 23:03:19.915542 29919 recover.cpp:564] Updating replica status to
> > > VOTING
> > > I0118 23:03:19.916193 29929 leveldb.cpp:304] Persisting metadata (8
> > bytes)
> > > to leveldb took 455878ns
> > > I0118 23:03:19.916219 29929 replica.cpp:320] Persisted replica status
> to
> > > VOTING
> > > I0118 23:03:19.916369 29926 recover.cpp:578] Successfully joined the
> > Paxos
> > > group
> > > I0118 23:03:19.916704 29926 recover.cpp:462] Recover process terminated
> > > I0118 23:03:19.917016 29922 master.cpp:1710] The newly elected leader
> is
> > > master@172.17.0.4:45683 with id ad32f568-972d-46b2-881f-44f7d39ddbdc
> > > I0118 23:03:19.917050 29922 master.cpp:1723] Elected as the leading
> > master!
> > > I0118 23:03:19.917282 29922 master.cpp:1468] Recovering from registrar
> > > I0118 23:03:19.917474 29929 registrar.cpp:307] Recovering registrar
> > > I0118 23:03:19.917917 29922 log.cpp:659] Attempting to start the writer
> > > I0118 23:03:19.918970 29924 replica.cpp:493] Replica received implicit
> > > promise request from (13701)@172.17.0.4:45683 with proposal 1
> > > I0118 23:03:19.919471 29924 leveldb.cpp:304] Persisting metadata (8
> > bytes)
> > > to leveldb took 434673ns
> > > I0118 23:03:19.919495 29924 replica.cpp:342] Persisted promised to 1
> > > I0118 23:03:19.920037 29925 coordinator.cpp:238] Coordinator attempting
> > to
> > > fill missing positions
> > > I0118 23:03:19.921254 29926 replica.cpp:388] Replica received explicit
> > > promise request from (13702)@172.17.0.4:45683 for position 0 with
> > > proposal 2
> > > I0118 23:03:19.921569 29926 leveldb.cpp:341] Persisting action (8
> bytes)
> > > to leveldb took 290584ns
> > > I0118 23:03:19.921592 29926 replica.cpp:712] Persisted action at 0
> > > I0118 23:03:19.922453 29925 replica.cpp:537] Replica received write
> > > request for position 0 from (13703)@172.17.0.4:45683
> > > I0118 23:03:19.922511 29925 leveldb.cpp:436] Reading position from
> > leveldb
> > > took 40477ns
> > > I0118 23:03:19.922900 29925 leveldb.cpp:341] Persisting action (14
> bytes)
> > > to leveldb took 356778ns
> > > I0118 23:03:19.922924 29925 replica.cpp:712] Persisted action at 0
> > > I0118 23:03:19.923511 29917 replica.cpp:691] Replica received learned
> > > notice for position 0 from @0.0.0.0:0
> > > I0118 23:03:19.923873 29917 leveldb.cpp:341] Persisting action (16
> bytes)
> > > to leveldb took 347877ns
> > > I0118 23:03:19.923897 29917 replica.cpp:712] Persisted action at 0
> > > I0118 23:03:19.923913 29917 replica.cpp:697] Replica learned NOP action
> > at
> > > position 0
> > > I0118 23:03:19.924587 29927 log.cpp:675] Writer started with ending
> > > position 0
> > > I0118 23:03:19.925745 29929 leveldb.cpp:436] Reading position from
> > leveldb
> > > took 53389ns
> > > I0118 23:03:19.926780 29924 registrar.cpp:340] Successfully fetched the
> > > registry (0B) in 9.268224ms
> > > I0118 23:03:19.926913 29924 registrar.cpp:439] Applied 1 operations in
> > > 48411ns; attempting to update the 'registry'
> > > I0118 23:03:19.927549 29926 log.cpp:683] Attempting to append 170 bytes
> > to
> > > the log
> > > I0118 23:03:19.927760 29920 coordinator.cpp:348] Coordinator attempting
> > to
> > > write APPEND action at position 1
> > > I0118 23:03:19.928527 29917 replica.cpp:537] Replica received write
> > > request for position 1 from (13704)@172.17.0.4:45683
> > > I0118 23:03:19.928932 29917 leveldb.cpp:341] Persisting action (189
> > bytes)
> > > to leveldb took 372405ns
> > > I0118 23:03:19.928956 29917 replica.cpp:712] Persisted action at 1
> > > I0118 23:03:19.929538 29917 replica.cpp:691] Replica received learned
> > > notice for position 1 from @0.0.0.0:0
> > > I0118 23:03:19.929882 29917 leveldb.cpp:341] Persisting action (191
> > bytes)
> > > to leveldb took 326483ns
> > > I0118 23:03:19.929904 29917 replica.cpp:712] Persisted action at 1
> > > I0118 23:03:19.929925 29917 replica.cpp:697] Replica learned APPEND
> > action
> > > at position 1
> > > I0118 23:03:19.930896 29930 registrar.cpp:484] Successfully updated the
> > > 'registry' in 3.912192ms
> > > I0118 23:03:19.931013 29930 registrar.cpp:370] Successfully recovered
> > > registrar
> > > I0118 23:03:19.931152 29931 log.cpp:702] Attempting to truncate the log
> > to
> > > 1
> > > I0118 23:03:19.931429 29917 master.cpp:1520] Recovered 0 slaves from
> the
> > > Registry (131B) ; allowing 10mins for slaves to re-register
> > > I0118 23:03:19.931476 29929 hierarchical.cpp:172] Skipping recovery of
> > > hierarchical allocator: nothing to recover
> > > I0118 23:03:19.931581 29921 coordinator.cpp:348] Coordinator attempting
> > to
> > > write TRUNCATE action at position 2
> > > I0118 23:03:19.932384 29918 replica.cpp:537] Replica received write
> > > request for position 2 from (13705)@172.17.0.4:45683
> > > I0118 23:03:19.932812 29918 leveldb.cpp:341] Persisting action (16
> bytes)
> > > to leveldb took 401469ns
> > > I0118 23:03:19.932837 29918 replica.cpp:712] Persisted action at 2
> > > I0118 23:03:19.933440 29920 replica.cpp:691] Replica received learned
> > > notice for position 2 from @0.0.0.0:0
> > > I0118 23:03:19.933825 29920 leveldb.cpp:341] Persisting action (18
> bytes)
> > > to leveldb took 368093ns
> > > I0118 23:03:19.933872 29920 leveldb.cpp:399] Deleting ~1 keys from
> > leveldb
> > > took 33161ns
> > > I0118 23:03:19.933889 29920 replica.cpp:712] Persisted action at 2
> > > I0118 23:03:19.933905 29920 replica.cpp:697] Replica learned TRUNCATE
> > > action at position 2
> > > I0118 23:03:19.942512 29898 scheduler.cpp:154] Version: 0.27.0
> > > I0118 23:03:19.943182 29918 scheduler.cpp:236] New master detected at
> > > master@172.17.0.4:45683
> > > I0118 23:03:19.944362 29924 scheduler.cpp:298] Sending SUBSCRIBE call
> to
> > > master@172.17.0.4:45683
> > > I0118 23:03:19.946282 29918 process.cpp:3141] Handling HTTP event for
> > > process 'master' with path: '/master/api/v1/scheduler'
> > > I0118 23:03:19.946789 29920 http.cpp:504] HTTP POST for
> > > /master/api/v1/scheduler from 172.17.0.4:33009
> > > I0118 23:03:19.947180 29920 master.cpp:1972] Received subscription
> > request
> > > for HTTP framework 'default'
> > > I0118 23:03:19.947206 29920 master.cpp:1749] Authorizing framework
> > > principal 'test-principal' to receive offers for role '*'
> > > I0118 23:03:19.947540 29920 master.cpp:2063] Subscribing framework
> > > 'default' with checkpointing disabled and capabilities [  ]
> > > I0118 23:03:19.947973 29918 hierarchical.cpp:266] Added framework
> > > ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> > > I0118 23:03:19.948040 29918 hierarchical.cpp:1338] No resources
> available
> > > to allocate!
> > > I0118 23:03:19.948107 29918 hierarchical.cpp:1432] No inverse offers to
> > > send out!
> > > I0118 23:03:19.948130 29918 hierarchical.cpp:1086] Performed allocation
> > > for 0 slaves in 138145ns
> > > I0118 23:03:19.948165 29923 master.hpp:1658] Sending heartbeat to
> > > ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> > > I0118 23:03:19.949169 29922 scheduler.cpp:457] Enqueuing event
> SUBSCRIBED
> > > received from master@172.17.0.4:45683
> > > I0118 23:03:19.949666 29922 scheduler.cpp:457] Enqueuing event
> HEARTBEAT
> > > received from master@172.17.0.4:45683
> > > I0118 23:03:19.950438 29918 master_maintenance_tests.cpp:177] Ignoring
> > > HEARTBEAT event
> > > I0118 23:03:19.950459 29922 scheduler.cpp:298] Sending REQUEST call to
> > > master@172.17.0.4:45683
> > > I0118 23:03:19.952298 29927 process.cpp:3141] Handling HTTP event for
> > > process 'master' with path: '/master/api/v1/scheduler'
> > > I0118 23:03:19.952775 29920 http.cpp:504] HTTP POST for
> > > /master/api/v1/scheduler from 172.17.0.4:33010
> > > I0118 23:03:19.953030 29920 master.cpp:2717] Processing REQUEST call
> for
> > > framework ad32f568-972d-46b2-881f-44f7d39ddbdc-0000 (default)
> > > I0118 23:03:19.953277 29922 hierarchical.cpp:586] Received resource
> > > request from framework ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> > > I0118 23:03:19.953598 29925 master.cpp:1025] Master terminating
> > > I0118 23:03:19.954211 29926 hierarchical.cpp:327] Removed framework
> > > ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> > > E0118 23:03:19.955265 29931 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 (4164 ms total)
> > >
> > > [----------] Global test environment tear-down
> > > 2016-01-18
> > > 23:03:20,258:29898(0x2ac46780c700):ZOO_ERROR@handle_socket_error_msg
> > @1697:
> > > Socket [127.0.0.1:39162] zk retcode=-4, errno=111(Connection refused):
> > > server refused to accept the client
> > > [==========] 928 tests from 123 test cases ran. (331537 ms total)
> > > [  PASSED  ] 927 tests.
> > > [  FAILED  ] 1 test, listed below:
> > > [  FAILED  ] MasterTest.MaxCompletedTasksPerFrameworkFlag
> > >
> > >  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-1453156296-5368
> > > Untagged: mesos-1453156296-5368:latest
> > > Deleted:
> 777e17b94a7fe7b758f183d0b1a56358a99a0a909b3aa663b2601c26a1da04cf
> > > Deleted:
> 993b895d8a13121bdc79d16466b88816a50d376351d1dfb76bd12e9473ab1f6c
> > > Deleted:
> bd18ccd42876654f92330a6bca63c16d56c580ad106fc1a2d7c4102c757477b4
> > > Deleted:
> 8afec7c08a7fa37bd4c0ac02cdb99220292a2b7e4cc9f632510c66a6594793d9
> > > Deleted:
> 8b25c2d8746431e3dca92de5763e8c7bb381d721c950d75aec6cb42c07afe8b0
> > > Deleted:
> 70a463f67f40a22afe151ac66a9b0b303ebb22e812f9244d34d89606328e291c
> > > Deleted:
> 6350c6abe5f933c63c932bf6e8ace0d7327ed71a2ed119af69935d91ebdfc9a1
> > > Deleted:
> 0a9bdbd9750c7033aeb02816ec7dd581b15088198a2edad03a249530ddc88685
> > > Deleted:
> faac0508488d9dd6093ffbfa5919755ba6a99ccb19c25a349174cc68cdbea2bc
> > > Deleted:
> 8f2d7d308ce6b45dda6417457c6dcf89f073a69225ee92ca534ba0a9f8200fb7
> > > Deleted:
> 7b29adc92f4eef68d50d293a2f550f2b8b332d71cc7c1646abd90c62d581f2a3
> > > Deleted:
> c1839eb2495d1e24b9745c59d922117208dae9e024d9dff8d383214969cf0400
> > > Deleted:
> 523f472d6ba67e69aedf9c76aeb6d1757cffb2562c3a6623a67310bfcbc7b47e
> > > Deleted:
> 74d595bedbfcd4d38a9b5f6e4b64f5cc86236ce07f67f40debbf8d277d1c38a4
> > > Build step 'Execute shell' marked build as failure
> > >
> >
>

Re: Build failed in Jenkins: Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #1506

Posted by Greg Mann <gr...@mesosphere.io>.
Looks like it could be caused by the same issue as
https://issues.apache.org/jira/browse/MESOS-4409

On Tue, Jan 19, 2016 at 4:07 PM, Vinod Kone <vi...@apache.org> wrote:

> Is this being looked at?
>
> On Mon, Jan 18, 2016 at 3:03 PM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
> > See <
> >
> https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1506/
> > >
> >
> > ------------------------------------------
> > [...truncated 155770 lines...]
> > I0118 23:03:19.844106 29929 gc.cpp:54] Scheduling
> >
> '/tmp/ContentType_SchedulerTest_Message_1_7OegKY/slaves/05552c6c-3b19-4d76-9402-ef9299661a04-S0/frameworks/05552c6c-3b19-4d76-9402-ef9299661a04-0000'
> > for gc 6.99999023125037days in the future
> > I0118 23:03:19.844135 29928 status_update_manager.cpp:528] Cleaning up
> > status update stream for task a7ef87eb-1120-4799-98e0-6c12cb4fae8a of
> > framework 05552c6c-3b19-4d76-9402-ef9299661a04-0000
> > [       OK ] ContentType/SchedulerTest.Message/1 (133 ms)
> > [ RUN      ] ContentType/SchedulerTest.Request/0
> > I0118 23:03:19.851078 29898 leveldb.cpp:174] Opened db in 2.742478ms
> > I0118 23:03:19.852309 29898 leveldb.cpp:181] Compacted db in 1.218396ms
> > I0118 23:03:19.852401 29898 leveldb.cpp:196] Created db iterator in
> 33639ns
> > I0118 23:03:19.852421 29898 leveldb.cpp:202] Seeked to beginning of db in
> > 7363ns
> > I0118 23:03:19.852429 29898 leveldb.cpp:271] Iterated through 0 keys in
> > the db in 5034ns
> > I0118 23:03:19.852474 29898 replica.cpp:779] Replica recovered with log
> > positions 0 -> 0 with 1 holes and 0 unlearned
> > I0118 23:03:19.853023 29930 recover.cpp:447] Starting replica recovery
> > I0118 23:03:19.854782 29930 recover.cpp:473] Replica is in EMPTY status
> > I0118 23:03:19.855705 29925 master.cpp:374] Master
> > 624efc91-f4ce-4a4a-a449-00ce1f03b7b9 (3ade37c447fa) started on
> > 172.17.0.4:45683
> > I0118 23:03:19.855744 29925 master.cpp:376] Flags at startup: --acls=""
> > --allocation_interval="1secs" --allocator="HierarchicalDRF"
> > --authenticate="false" --authenticate_http="true"
> > --authenticate_slaves="true" --authenticators="crammd5"
> > --authorizers="local" --credentials="/tmp/jzBYpt/credentials"
> > --framework_sorter="drf" --help="false" --hostname_lookup="true"
> > --http_authenticators="basic" --initialize_driver_logging="true"
> > --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> > --max_completed_frameworks="50"
> --max_completed_tasks_per_framework="1000"
> > --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/jzBYpt/master" --zk_session_timeout="10secs"
> > I0118 23:03:19.856138 29925 master.cpp:423] Master allowing
> > unauthenticated frameworks to register
> > I0118 23:03:19.856154 29925 master.cpp:426] Master only allowing
> > authenticated slaves to register
> > I0118 23:03:19.856164 29925 credentials.hpp:35] Loading credentials for
> > authentication from '/tmp/jzBYpt/credentials'
> > I0118 23:03:19.856315 29916 replica.cpp:673] Replica in EMPTY status
> > received a broadcasted recover request from (13683)@172.17.0.4:45683
> > I0118 23:03:19.856478 29925 master.cpp:466] Using default 'crammd5'
> > authenticator
> > I0118 23:03:19.856631 29925 master.cpp:535] Using default 'basic' HTTP
> > authenticator
> > I0118 23:03:19.856799 29925 master.cpp:569] Authorization enabled
> > I0118 23:03:19.857043 29931 hierarchical.cpp:145] Initialized
> hierarchical
> > allocator process
> > I0118 23:03:19.857069 29918 whitelist_watcher.cpp:77] No whitelist given
> > I0118 23:03:19.857074 29917 recover.cpp:193] Received a recover response
> > from a replica in EMPTY status
> > I0118 23:03:19.857702 29924 recover.cpp:564] Updating replica status to
> > STARTING
> > I0118 23:03:19.858502 29917 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 678031ns
> > I0118 23:03:19.858530 29917 replica.cpp:320] Persisted replica status to
> > STARTING
> > I0118 23:03:19.858784 29924 recover.cpp:473] Replica is in STARTING
> status
> > I0118 23:03:19.859259 29921 master.cpp:1710] The newly elected leader is
> > master@172.17.0.4:45683 with id 624efc91-f4ce-4a4a-a449-00ce1f03b7b9
> > I0118 23:03:19.859293 29921 master.cpp:1723] Elected as the leading
> master!
> > I0118 23:03:19.859303 29921 master.cpp:1468] Recovering from registrar
> > I0118 23:03:19.859535 29919 registrar.cpp:307] Recovering registrar
> > I0118 23:03:19.860204 29927 replica.cpp:673] Replica in STARTING status
> > received a broadcasted recover request from (13685)@172.17.0.4:45683
> > I0118 23:03:19.860457 29917 recover.cpp:193] Received a recover response
> > from a replica in STARTING status
> > I0118 23:03:19.860914 29920 recover.cpp:564] Updating replica status to
> > VOTING
> > I0118 23:03:19.861577 29916 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 382605ns
> > I0118 23:03:19.861603 29916 replica.cpp:320] Persisted replica status to
> > VOTING
> > I0118 23:03:19.861704 29925 recover.cpp:578] Successfully joined the
> Paxos
> > group
> > I0118 23:03:19.862017 29925 recover.cpp:462] Recover process terminated
> > I0118 23:03:19.862398 29916 log.cpp:659] Attempting to start the writer
> > I0118 23:03:19.863638 29916 replica.cpp:493] Replica received implicit
> > promise request from (13686)@172.17.0.4:45683 with proposal 1
> > I0118 23:03:19.864112 29916 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 460382ns
> > I0118 23:03:19.864147 29916 replica.cpp:342] Persisted promised to 1
> > I0118 23:03:19.864703 29928 coordinator.cpp:238] Coordinator attempting
> to
> > fill missing positions
> > I0118 23:03:19.865829 29919 replica.cpp:388] Replica received explicit
> > promise request from (13687)@172.17.0.4:45683 for position 0 with
> > proposal 2
> > I0118 23:03:19.866309 29919 leveldb.cpp:341] Persisting action (8 bytes)
> > to leveldb took 454771ns
> > I0118 23:03:19.866358 29919 replica.cpp:712] Persisted action at 0
> > I0118 23:03:19.867517 29926 replica.cpp:537] Replica received write
> > request for position 0 from (13688)@172.17.0.4:45683
> > I0118 23:03:19.867594 29926 leveldb.cpp:436] Reading position from
> leveldb
> > took 46227ns
> > I0118 23:03:19.868098 29926 leveldb.cpp:341] Persisting action (14 bytes)
> > to leveldb took 464570ns
> > I0118 23:03:19.868140 29926 replica.cpp:712] Persisted action at 0
> > I0118 23:03:19.868870 29928 replica.cpp:691] Replica received learned
> > notice for position 0 from @0.0.0.0:0
> > I0118 23:03:19.869282 29928 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 387624ns
> > I0118 23:03:19.869314 29928 replica.cpp:712] Persisted action at 0
> > I0118 23:03:19.869335 29928 replica.cpp:697] Replica learned NOP action
> at
> > position 0
> > I0118 23:03:19.869954 29929 log.cpp:675] Writer started with ending
> > position 0
> > I0118 23:03:19.871016 29916 leveldb.cpp:436] Reading position from
> leveldb
> > took 48216ns
> > I0118 23:03:19.872004 29919 registrar.cpp:340] Successfully fetched the
> > registry (0B) in 12.32384ms
> > I0118 23:03:19.872190 29919 registrar.cpp:439] Applied 1 operations in
> > 47911ns; attempting to update the 'registry'
> > I0118 23:03:19.872951 29916 log.cpp:683] Attempting to append 170 bytes
> to
> > the log
> > I0118 23:03:19.873107 29930 coordinator.cpp:348] Coordinator attempting
> to
> > write APPEND action at position 1
> > I0118 23:03:19.873965 29925 replica.cpp:537] Replica received write
> > request for position 1 from (13689)@172.17.0.4:45683
> > I0118 23:03:19.874435 29925 leveldb.cpp:341] Persisting action (189
> bytes)
> > to leveldb took 439239ns
> > I0118 23:03:19.874466 29925 replica.cpp:712] Persisted action at 1
> > I0118 23:03:19.875128 29925 replica.cpp:691] Replica received learned
> > notice for position 1 from @0.0.0.0:0
> > I0118 23:03:19.875562 29925 leveldb.cpp:341] Persisting action (191
> bytes)
> > to leveldb took 416833ns
> > I0118 23:03:19.875594 29925 replica.cpp:712] Persisted action at 1
> > I0118 23:03:19.875615 29925 replica.cpp:697] Replica learned APPEND
> action
> > at position 1
> > I0118 23:03:19.876617 29930 registrar.cpp:484] Successfully updated the
> > 'registry' in 4.356096ms
> > I0118 23:03:19.876798 29930 registrar.cpp:370] Successfully recovered
> > registrar
> > I0118 23:03:19.876873 29922 log.cpp:702] Attempting to truncate the log
> to
> > 1
> > I0118 23:03:19.877005 29928 coordinator.cpp:348] Coordinator attempting
> to
> > write TRUNCATE action at position 2
> > I0118 23:03:19.877459 29929 master.cpp:1520] Recovered 0 slaves from the
> > Registry (131B) ; allowing 10mins for slaves to re-register
> > I0118 23:03:19.877564 29921 hierarchical.cpp:172] Skipping recovery of
> > hierarchical allocator: nothing to recover
> > I0118 23:03:19.878180 29926 replica.cpp:537] Replica received write
> > request for position 2 from (13690)@172.17.0.4:45683
> > I0118 23:03:19.878589 29926 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 375269ns
> > I0118 23:03:19.878620 29926 replica.cpp:712] Persisted action at 2
> > I0118 23:03:19.879320 29924 replica.cpp:691] Replica received learned
> > notice for position 2 from @0.0.0.0:0
> > I0118 23:03:19.879819 29924 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 477489ns
> > I0118 23:03:19.879892 29924 leveldb.cpp:399] Deleting ~1 keys from
> leveldb
> > took 55996ns
> > I0118 23:03:19.879923 29924 replica.cpp:712] Persisted action at 2
> > I0118 23:03:19.879952 29924 replica.cpp:697] Replica learned TRUNCATE
> > action at position 2
> > I0118 23:03:19.888377 29898 scheduler.cpp:154] Version: 0.27.0
> > I0118 23:03:19.889097 29927 scheduler.cpp:236] New master detected at
> > master@172.17.0.4:45683
> > I0118 23:03:19.890256 29920 scheduler.cpp:298] Sending SUBSCRIBE call to
> > master@172.17.0.4:45683
> > I0118 23:03:19.892216 29924 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0118 23:03:19.892801 29922 http.cpp:504] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.4:33007
> > I0118 23:03:19.893009 29922 master.cpp:1972] Received subscription
> request
> > for HTTP framework 'default'
> > I0118 23:03:19.893036 29922 master.cpp:1749] Authorizing framework
> > principal 'test-principal' to receive offers for role '*'
> > I0118 23:03:19.893424 29922 master.cpp:2063] Subscribing framework
> > 'default' with checkpointing disabled and capabilities [  ]
> > I0118 23:03:19.893842 29923 hierarchical.cpp:266] Added framework
> > 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> > I0118 23:03:19.893908 29923 hierarchical.cpp:1338] No resources available
> > to allocate!
> > I0118 23:03:19.893946 29917 master.hpp:1658] Sending heartbeat to
> > 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> > I0118 23:03:19.893956 29923 hierarchical.cpp:1432] No inverse offers to
> > send out!
> > I0118 23:03:19.893993 29923 hierarchical.cpp:1086] Performed allocation
> > for 0 slaves in 135870ns
> > I0118 23:03:19.894763 29919 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> > received from master@172.17.0.4:45683
> > I0118 23:03:19.895226 29919 scheduler.cpp:457] Enqueuing event HEARTBEAT
> > received from master@172.17.0.4:45683
> > I0118 23:03:19.895767 29919 master_maintenance_tests.cpp:177] Ignoring
> > HEARTBEAT event
> > I0118 23:03:19.896193 29928 scheduler.cpp:298] Sending REQUEST call to
> > master@172.17.0.4:45683
> > I0118 23:03:19.897620 29928 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0118 23:03:19.898008 29931 http.cpp:504] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.4:33008
> > I0118 23:03:19.898143 29931 master.cpp:2717] Processing REQUEST call for
> > framework 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000 (default)
> > I0118 23:03:19.898334 29928 hierarchical.cpp:586] Received resource
> > request from framework 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> > I0118 23:03:19.898638 29927 master.cpp:1025] Master terminating
> > I0118 23:03:19.898875 29919 hierarchical.cpp:327] Removed framework
> > 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> > E0118 23:03:19.899845 29926 scheduler.cpp:431] End-Of-File received from
> > master. The master closed the event stream
> > [       OK ] ContentType/SchedulerTest.Request/0 (57 ms)
> > [ RUN      ] ContentType/SchedulerTest.Request/1
> > I0118 23:03:19.908234 29898 leveldb.cpp:174] Opened db in 2.583835ms
> > I0118 23:03:19.909324 29898 leveldb.cpp:181] Compacted db in 1.063576ms
> > I0118 23:03:19.909378 29898 leveldb.cpp:196] Created db iterator in
> 34454ns
> > I0118 23:03:19.909404 29898 leveldb.cpp:202] Seeked to beginning of db in
> > 12025ns
> > I0118 23:03:19.909446 29898 leveldb.cpp:271] Iterated through 0 keys in
> > the db in 18830ns
> > I0118 23:03:19.909502 29898 replica.cpp:779] Replica recovered with log
> > positions 0 -> 0 with 1 holes and 0 unlearned
> > I0118 23:03:19.910025 29917 recover.cpp:447] Starting replica recovery
> > I0118 23:03:19.910282 29917 recover.cpp:473] Replica is in EMPTY status
> > I0118 23:03:19.911519 29919 replica.cpp:673] Replica in EMPTY status
> > received a broadcasted recover request from (13698)@172.17.0.4:45683
> > I0118 23:03:19.911931 29925 recover.cpp:193] Received a recover response
> > from a replica in EMPTY status
> > I0118 23:03:19.912528 29931 recover.cpp:564] Updating replica status to
> > STARTING
> > I0118 23:03:19.913187 29926 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 590877ns
> > I0118 23:03:19.913228 29926 replica.cpp:320] Persisted replica status to
> > STARTING
> > I0118 23:03:19.913403 29920 master.cpp:374] Master
> > ad32f568-972d-46b2-881f-44f7d39ddbdc (3ade37c447fa) started on
> > 172.17.0.4:45683
> > I0118 23:03:19.913511 29930 recover.cpp:473] Replica is in STARTING
> status
> > I0118 23:03:19.913445 29920 master.cpp:376] Flags at startup: --acls=""
> > --allocation_interval="1secs" --allocator="HierarchicalDRF"
> > --authenticate="false" --authenticate_http="true"
> > --authenticate_slaves="true" --authenticators="crammd5"
> > --authorizers="local" --credentials="/tmp/TRUygj/credentials"
> > --framework_sorter="drf" --help="false" --hostname_lookup="true"
> > --http_authenticators="basic" --initialize_driver_logging="true"
> > --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> > --max_completed_frameworks="50"
> --max_completed_tasks_per_framework="1000"
> > --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/TRUygj/master" --zk_session_timeout="10secs"
> > I0118 23:03:19.913852 29920 master.cpp:423] Master allowing
> > unauthenticated frameworks to register
> > I0118 23:03:19.913866 29920 master.cpp:426] Master only allowing
> > authenticated slaves to register
> > I0118 23:03:19.913875 29920 credentials.hpp:35] Loading credentials for
> > authentication from '/tmp/TRUygj/credentials'
> > I0118 23:03:19.914234 29920 master.cpp:466] Using default 'crammd5'
> > authenticator
> > I0118 23:03:19.914397 29920 master.cpp:535] Using default 'basic' HTTP
> > authenticator
> > I0118 23:03:19.914485 29921 replica.cpp:673] Replica in STARTING status
> > received a broadcasted recover request from (13699)@172.17.0.4:45683
> > I0118 23:03:19.914608 29920 master.cpp:569] Authorization enabled
> > I0118 23:03:19.914779 29921 hierarchical.cpp:145] Initialized
> hierarchical
> > allocator process
> > I0118 23:03:19.914826 29916 whitelist_watcher.cpp:77] No whitelist given
> > I0118 23:03:19.914924 29927 recover.cpp:193] Received a recover response
> > from a replica in STARTING status
> > I0118 23:03:19.915542 29919 recover.cpp:564] Updating replica status to
> > VOTING
> > I0118 23:03:19.916193 29929 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 455878ns
> > I0118 23:03:19.916219 29929 replica.cpp:320] Persisted replica status to
> > VOTING
> > I0118 23:03:19.916369 29926 recover.cpp:578] Successfully joined the
> Paxos
> > group
> > I0118 23:03:19.916704 29926 recover.cpp:462] Recover process terminated
> > I0118 23:03:19.917016 29922 master.cpp:1710] The newly elected leader is
> > master@172.17.0.4:45683 with id ad32f568-972d-46b2-881f-44f7d39ddbdc
> > I0118 23:03:19.917050 29922 master.cpp:1723] Elected as the leading
> master!
> > I0118 23:03:19.917282 29922 master.cpp:1468] Recovering from registrar
> > I0118 23:03:19.917474 29929 registrar.cpp:307] Recovering registrar
> > I0118 23:03:19.917917 29922 log.cpp:659] Attempting to start the writer
> > I0118 23:03:19.918970 29924 replica.cpp:493] Replica received implicit
> > promise request from (13701)@172.17.0.4:45683 with proposal 1
> > I0118 23:03:19.919471 29924 leveldb.cpp:304] Persisting metadata (8
> bytes)
> > to leveldb took 434673ns
> > I0118 23:03:19.919495 29924 replica.cpp:342] Persisted promised to 1
> > I0118 23:03:19.920037 29925 coordinator.cpp:238] Coordinator attempting
> to
> > fill missing positions
> > I0118 23:03:19.921254 29926 replica.cpp:388] Replica received explicit
> > promise request from (13702)@172.17.0.4:45683 for position 0 with
> > proposal 2
> > I0118 23:03:19.921569 29926 leveldb.cpp:341] Persisting action (8 bytes)
> > to leveldb took 290584ns
> > I0118 23:03:19.921592 29926 replica.cpp:712] Persisted action at 0
> > I0118 23:03:19.922453 29925 replica.cpp:537] Replica received write
> > request for position 0 from (13703)@172.17.0.4:45683
> > I0118 23:03:19.922511 29925 leveldb.cpp:436] Reading position from
> leveldb
> > took 40477ns
> > I0118 23:03:19.922900 29925 leveldb.cpp:341] Persisting action (14 bytes)
> > to leveldb took 356778ns
> > I0118 23:03:19.922924 29925 replica.cpp:712] Persisted action at 0
> > I0118 23:03:19.923511 29917 replica.cpp:691] Replica received learned
> > notice for position 0 from @0.0.0.0:0
> > I0118 23:03:19.923873 29917 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 347877ns
> > I0118 23:03:19.923897 29917 replica.cpp:712] Persisted action at 0
> > I0118 23:03:19.923913 29917 replica.cpp:697] Replica learned NOP action
> at
> > position 0
> > I0118 23:03:19.924587 29927 log.cpp:675] Writer started with ending
> > position 0
> > I0118 23:03:19.925745 29929 leveldb.cpp:436] Reading position from
> leveldb
> > took 53389ns
> > I0118 23:03:19.926780 29924 registrar.cpp:340] Successfully fetched the
> > registry (0B) in 9.268224ms
> > I0118 23:03:19.926913 29924 registrar.cpp:439] Applied 1 operations in
> > 48411ns; attempting to update the 'registry'
> > I0118 23:03:19.927549 29926 log.cpp:683] Attempting to append 170 bytes
> to
> > the log
> > I0118 23:03:19.927760 29920 coordinator.cpp:348] Coordinator attempting
> to
> > write APPEND action at position 1
> > I0118 23:03:19.928527 29917 replica.cpp:537] Replica received write
> > request for position 1 from (13704)@172.17.0.4:45683
> > I0118 23:03:19.928932 29917 leveldb.cpp:341] Persisting action (189
> bytes)
> > to leveldb took 372405ns
> > I0118 23:03:19.928956 29917 replica.cpp:712] Persisted action at 1
> > I0118 23:03:19.929538 29917 replica.cpp:691] Replica received learned
> > notice for position 1 from @0.0.0.0:0
> > I0118 23:03:19.929882 29917 leveldb.cpp:341] Persisting action (191
> bytes)
> > to leveldb took 326483ns
> > I0118 23:03:19.929904 29917 replica.cpp:712] Persisted action at 1
> > I0118 23:03:19.929925 29917 replica.cpp:697] Replica learned APPEND
> action
> > at position 1
> > I0118 23:03:19.930896 29930 registrar.cpp:484] Successfully updated the
> > 'registry' in 3.912192ms
> > I0118 23:03:19.931013 29930 registrar.cpp:370] Successfully recovered
> > registrar
> > I0118 23:03:19.931152 29931 log.cpp:702] Attempting to truncate the log
> to
> > 1
> > I0118 23:03:19.931429 29917 master.cpp:1520] Recovered 0 slaves from the
> > Registry (131B) ; allowing 10mins for slaves to re-register
> > I0118 23:03:19.931476 29929 hierarchical.cpp:172] Skipping recovery of
> > hierarchical allocator: nothing to recover
> > I0118 23:03:19.931581 29921 coordinator.cpp:348] Coordinator attempting
> to
> > write TRUNCATE action at position 2
> > I0118 23:03:19.932384 29918 replica.cpp:537] Replica received write
> > request for position 2 from (13705)@172.17.0.4:45683
> > I0118 23:03:19.932812 29918 leveldb.cpp:341] Persisting action (16 bytes)
> > to leveldb took 401469ns
> > I0118 23:03:19.932837 29918 replica.cpp:712] Persisted action at 2
> > I0118 23:03:19.933440 29920 replica.cpp:691] Replica received learned
> > notice for position 2 from @0.0.0.0:0
> > I0118 23:03:19.933825 29920 leveldb.cpp:341] Persisting action (18 bytes)
> > to leveldb took 368093ns
> > I0118 23:03:19.933872 29920 leveldb.cpp:399] Deleting ~1 keys from
> leveldb
> > took 33161ns
> > I0118 23:03:19.933889 29920 replica.cpp:712] Persisted action at 2
> > I0118 23:03:19.933905 29920 replica.cpp:697] Replica learned TRUNCATE
> > action at position 2
> > I0118 23:03:19.942512 29898 scheduler.cpp:154] Version: 0.27.0
> > I0118 23:03:19.943182 29918 scheduler.cpp:236] New master detected at
> > master@172.17.0.4:45683
> > I0118 23:03:19.944362 29924 scheduler.cpp:298] Sending SUBSCRIBE call to
> > master@172.17.0.4:45683
> > I0118 23:03:19.946282 29918 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0118 23:03:19.946789 29920 http.cpp:504] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.4:33009
> > I0118 23:03:19.947180 29920 master.cpp:1972] Received subscription
> request
> > for HTTP framework 'default'
> > I0118 23:03:19.947206 29920 master.cpp:1749] Authorizing framework
> > principal 'test-principal' to receive offers for role '*'
> > I0118 23:03:19.947540 29920 master.cpp:2063] Subscribing framework
> > 'default' with checkpointing disabled and capabilities [  ]
> > I0118 23:03:19.947973 29918 hierarchical.cpp:266] Added framework
> > ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> > I0118 23:03:19.948040 29918 hierarchical.cpp:1338] No resources available
> > to allocate!
> > I0118 23:03:19.948107 29918 hierarchical.cpp:1432] No inverse offers to
> > send out!
> > I0118 23:03:19.948130 29918 hierarchical.cpp:1086] Performed allocation
> > for 0 slaves in 138145ns
> > I0118 23:03:19.948165 29923 master.hpp:1658] Sending heartbeat to
> > ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> > I0118 23:03:19.949169 29922 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> > received from master@172.17.0.4:45683
> > I0118 23:03:19.949666 29922 scheduler.cpp:457] Enqueuing event HEARTBEAT
> > received from master@172.17.0.4:45683
> > I0118 23:03:19.950438 29918 master_maintenance_tests.cpp:177] Ignoring
> > HEARTBEAT event
> > I0118 23:03:19.950459 29922 scheduler.cpp:298] Sending REQUEST call to
> > master@172.17.0.4:45683
> > I0118 23:03:19.952298 29927 process.cpp:3141] Handling HTTP event for
> > process 'master' with path: '/master/api/v1/scheduler'
> > I0118 23:03:19.952775 29920 http.cpp:504] HTTP POST for
> > /master/api/v1/scheduler from 172.17.0.4:33010
> > I0118 23:03:19.953030 29920 master.cpp:2717] Processing REQUEST call for
> > framework ad32f568-972d-46b2-881f-44f7d39ddbdc-0000 (default)
> > I0118 23:03:19.953277 29922 hierarchical.cpp:586] Received resource
> > request from framework ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> > I0118 23:03:19.953598 29925 master.cpp:1025] Master terminating
> > I0118 23:03:19.954211 29926 hierarchical.cpp:327] Removed framework
> > ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> > E0118 23:03:19.955265 29931 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 (4164 ms total)
> >
> > [----------] Global test environment tear-down
> > 2016-01-18
> > 23:03:20,258:29898(0x2ac46780c700):ZOO_ERROR@handle_socket_error_msg
> @1697:
> > Socket [127.0.0.1:39162] zk retcode=-4, errno=111(Connection refused):
> > server refused to accept the client
> > [==========] 928 tests from 123 test cases ran. (331537 ms total)
> > [  PASSED  ] 927 tests.
> > [  FAILED  ] 1 test, listed below:
> > [  FAILED  ] MasterTest.MaxCompletedTasksPerFrameworkFlag
> >
> >  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-1453156296-5368
> > Untagged: mesos-1453156296-5368:latest
> > Deleted: 777e17b94a7fe7b758f183d0b1a56358a99a0a909b3aa663b2601c26a1da04cf
> > Deleted: 993b895d8a13121bdc79d16466b88816a50d376351d1dfb76bd12e9473ab1f6c
> > Deleted: bd18ccd42876654f92330a6bca63c16d56c580ad106fc1a2d7c4102c757477b4
> > Deleted: 8afec7c08a7fa37bd4c0ac02cdb99220292a2b7e4cc9f632510c66a6594793d9
> > Deleted: 8b25c2d8746431e3dca92de5763e8c7bb381d721c950d75aec6cb42c07afe8b0
> > Deleted: 70a463f67f40a22afe151ac66a9b0b303ebb22e812f9244d34d89606328e291c
> > Deleted: 6350c6abe5f933c63c932bf6e8ace0d7327ed71a2ed119af69935d91ebdfc9a1
> > Deleted: 0a9bdbd9750c7033aeb02816ec7dd581b15088198a2edad03a249530ddc88685
> > Deleted: faac0508488d9dd6093ffbfa5919755ba6a99ccb19c25a349174cc68cdbea2bc
> > Deleted: 8f2d7d308ce6b45dda6417457c6dcf89f073a69225ee92ca534ba0a9f8200fb7
> > Deleted: 7b29adc92f4eef68d50d293a2f550f2b8b332d71cc7c1646abd90c62d581f2a3
> > Deleted: c1839eb2495d1e24b9745c59d922117208dae9e024d9dff8d383214969cf0400
> > Deleted: 523f472d6ba67e69aedf9c76aeb6d1757cffb2562c3a6623a67310bfcbc7b47e
> > Deleted: 74d595bedbfcd4d38a9b5f6e4b64f5cc86236ce07f67f40debbf8d277d1c38a4
> > Build step 'Execute shell' marked build as failure
> >
>

Re: Build failed in Jenkins: Mesos » clang,--verbose,ubuntu:14.04,docker||Hadoop #1506

Posted by Vinod Kone <vi...@apache.org>.
Is this being looked at?

On Mon, Jan 18, 2016 at 3:03 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:

> See <
> https://builds.apache.org/job/Mesos/COMPILER=clang,CONFIGURATION=--verbose,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1506/
> >
>
> ------------------------------------------
> [...truncated 155770 lines...]
> I0118 23:03:19.844106 29929 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_7OegKY/slaves/05552c6c-3b19-4d76-9402-ef9299661a04-S0/frameworks/05552c6c-3b19-4d76-9402-ef9299661a04-0000'
> for gc 6.99999023125037days in the future
> I0118 23:03:19.844135 29928 status_update_manager.cpp:528] Cleaning up
> status update stream for task a7ef87eb-1120-4799-98e0-6c12cb4fae8a of
> framework 05552c6c-3b19-4d76-9402-ef9299661a04-0000
> [       OK ] ContentType/SchedulerTest.Message/1 (133 ms)
> [ RUN      ] ContentType/SchedulerTest.Request/0
> I0118 23:03:19.851078 29898 leveldb.cpp:174] Opened db in 2.742478ms
> I0118 23:03:19.852309 29898 leveldb.cpp:181] Compacted db in 1.218396ms
> I0118 23:03:19.852401 29898 leveldb.cpp:196] Created db iterator in 33639ns
> I0118 23:03:19.852421 29898 leveldb.cpp:202] Seeked to beginning of db in
> 7363ns
> I0118 23:03:19.852429 29898 leveldb.cpp:271] Iterated through 0 keys in
> the db in 5034ns
> I0118 23:03:19.852474 29898 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0118 23:03:19.853023 29930 recover.cpp:447] Starting replica recovery
> I0118 23:03:19.854782 29930 recover.cpp:473] Replica is in EMPTY status
> I0118 23:03:19.855705 29925 master.cpp:374] Master
> 624efc91-f4ce-4a4a-a449-00ce1f03b7b9 (3ade37c447fa) started on
> 172.17.0.4:45683
> I0118 23:03:19.855744 29925 master.cpp:376] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/jzBYpt/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --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/jzBYpt/master" --zk_session_timeout="10secs"
> I0118 23:03:19.856138 29925 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0118 23:03:19.856154 29925 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0118 23:03:19.856164 29925 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/jzBYpt/credentials'
> I0118 23:03:19.856315 29916 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13683)@172.17.0.4:45683
> I0118 23:03:19.856478 29925 master.cpp:466] Using default 'crammd5'
> authenticator
> I0118 23:03:19.856631 29925 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0118 23:03:19.856799 29925 master.cpp:569] Authorization enabled
> I0118 23:03:19.857043 29931 hierarchical.cpp:145] Initialized hierarchical
> allocator process
> I0118 23:03:19.857069 29918 whitelist_watcher.cpp:77] No whitelist given
> I0118 23:03:19.857074 29917 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0118 23:03:19.857702 29924 recover.cpp:564] Updating replica status to
> STARTING
> I0118 23:03:19.858502 29917 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 678031ns
> I0118 23:03:19.858530 29917 replica.cpp:320] Persisted replica status to
> STARTING
> I0118 23:03:19.858784 29924 recover.cpp:473] Replica is in STARTING status
> I0118 23:03:19.859259 29921 master.cpp:1710] The newly elected leader is
> master@172.17.0.4:45683 with id 624efc91-f4ce-4a4a-a449-00ce1f03b7b9
> I0118 23:03:19.859293 29921 master.cpp:1723] Elected as the leading master!
> I0118 23:03:19.859303 29921 master.cpp:1468] Recovering from registrar
> I0118 23:03:19.859535 29919 registrar.cpp:307] Recovering registrar
> I0118 23:03:19.860204 29927 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13685)@172.17.0.4:45683
> I0118 23:03:19.860457 29917 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0118 23:03:19.860914 29920 recover.cpp:564] Updating replica status to
> VOTING
> I0118 23:03:19.861577 29916 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 382605ns
> I0118 23:03:19.861603 29916 replica.cpp:320] Persisted replica status to
> VOTING
> I0118 23:03:19.861704 29925 recover.cpp:578] Successfully joined the Paxos
> group
> I0118 23:03:19.862017 29925 recover.cpp:462] Recover process terminated
> I0118 23:03:19.862398 29916 log.cpp:659] Attempting to start the writer
> I0118 23:03:19.863638 29916 replica.cpp:493] Replica received implicit
> promise request from (13686)@172.17.0.4:45683 with proposal 1
> I0118 23:03:19.864112 29916 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 460382ns
> I0118 23:03:19.864147 29916 replica.cpp:342] Persisted promised to 1
> I0118 23:03:19.864703 29928 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0118 23:03:19.865829 29919 replica.cpp:388] Replica received explicit
> promise request from (13687)@172.17.0.4:45683 for position 0 with
> proposal 2
> I0118 23:03:19.866309 29919 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 454771ns
> I0118 23:03:19.866358 29919 replica.cpp:712] Persisted action at 0
> I0118 23:03:19.867517 29926 replica.cpp:537] Replica received write
> request for position 0 from (13688)@172.17.0.4:45683
> I0118 23:03:19.867594 29926 leveldb.cpp:436] Reading position from leveldb
> took 46227ns
> I0118 23:03:19.868098 29926 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 464570ns
> I0118 23:03:19.868140 29926 replica.cpp:712] Persisted action at 0
> I0118 23:03:19.868870 29928 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0118 23:03:19.869282 29928 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 387624ns
> I0118 23:03:19.869314 29928 replica.cpp:712] Persisted action at 0
> I0118 23:03:19.869335 29928 replica.cpp:697] Replica learned NOP action at
> position 0
> I0118 23:03:19.869954 29929 log.cpp:675] Writer started with ending
> position 0
> I0118 23:03:19.871016 29916 leveldb.cpp:436] Reading position from leveldb
> took 48216ns
> I0118 23:03:19.872004 29919 registrar.cpp:340] Successfully fetched the
> registry (0B) in 12.32384ms
> I0118 23:03:19.872190 29919 registrar.cpp:439] Applied 1 operations in
> 47911ns; attempting to update the 'registry'
> I0118 23:03:19.872951 29916 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0118 23:03:19.873107 29930 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0118 23:03:19.873965 29925 replica.cpp:537] Replica received write
> request for position 1 from (13689)@172.17.0.4:45683
> I0118 23:03:19.874435 29925 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 439239ns
> I0118 23:03:19.874466 29925 replica.cpp:712] Persisted action at 1
> I0118 23:03:19.875128 29925 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0118 23:03:19.875562 29925 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 416833ns
> I0118 23:03:19.875594 29925 replica.cpp:712] Persisted action at 1
> I0118 23:03:19.875615 29925 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0118 23:03:19.876617 29930 registrar.cpp:484] Successfully updated the
> 'registry' in 4.356096ms
> I0118 23:03:19.876798 29930 registrar.cpp:370] Successfully recovered
> registrar
> I0118 23:03:19.876873 29922 log.cpp:702] Attempting to truncate the log to
> 1
> I0118 23:03:19.877005 29928 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0118 23:03:19.877459 29929 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0118 23:03:19.877564 29921 hierarchical.cpp:172] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0118 23:03:19.878180 29926 replica.cpp:537] Replica received write
> request for position 2 from (13690)@172.17.0.4:45683
> I0118 23:03:19.878589 29926 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 375269ns
> I0118 23:03:19.878620 29926 replica.cpp:712] Persisted action at 2
> I0118 23:03:19.879320 29924 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0118 23:03:19.879819 29924 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 477489ns
> I0118 23:03:19.879892 29924 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 55996ns
> I0118 23:03:19.879923 29924 replica.cpp:712] Persisted action at 2
> I0118 23:03:19.879952 29924 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0118 23:03:19.888377 29898 scheduler.cpp:154] Version: 0.27.0
> I0118 23:03:19.889097 29927 scheduler.cpp:236] New master detected at
> master@172.17.0.4:45683
> I0118 23:03:19.890256 29920 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.4:45683
> I0118 23:03:19.892216 29924 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0118 23:03:19.892801 29922 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:33007
> I0118 23:03:19.893009 29922 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0118 23:03:19.893036 29922 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0118 23:03:19.893424 29922 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [  ]
> I0118 23:03:19.893842 29923 hierarchical.cpp:266] Added framework
> 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> I0118 23:03:19.893908 29923 hierarchical.cpp:1338] No resources available
> to allocate!
> I0118 23:03:19.893946 29917 master.hpp:1658] Sending heartbeat to
> 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> I0118 23:03:19.893956 29923 hierarchical.cpp:1432] No inverse offers to
> send out!
> I0118 23:03:19.893993 29923 hierarchical.cpp:1086] Performed allocation
> for 0 slaves in 135870ns
> I0118 23:03:19.894763 29919 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.4:45683
> I0118 23:03:19.895226 29919 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.4:45683
> I0118 23:03:19.895767 29919 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0118 23:03:19.896193 29928 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.4:45683
> I0118 23:03:19.897620 29928 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0118 23:03:19.898008 29931 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:33008
> I0118 23:03:19.898143 29931 master.cpp:2717] Processing REQUEST call for
> framework 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000 (default)
> I0118 23:03:19.898334 29928 hierarchical.cpp:586] Received resource
> request from framework 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> I0118 23:03:19.898638 29927 master.cpp:1025] Master terminating
> I0118 23:03:19.898875 29919 hierarchical.cpp:327] Removed framework
> 624efc91-f4ce-4a4a-a449-00ce1f03b7b9-0000
> E0118 23:03:19.899845 29926 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [       OK ] ContentType/SchedulerTest.Request/0 (57 ms)
> [ RUN      ] ContentType/SchedulerTest.Request/1
> I0118 23:03:19.908234 29898 leveldb.cpp:174] Opened db in 2.583835ms
> I0118 23:03:19.909324 29898 leveldb.cpp:181] Compacted db in 1.063576ms
> I0118 23:03:19.909378 29898 leveldb.cpp:196] Created db iterator in 34454ns
> I0118 23:03:19.909404 29898 leveldb.cpp:202] Seeked to beginning of db in
> 12025ns
> I0118 23:03:19.909446 29898 leveldb.cpp:271] Iterated through 0 keys in
> the db in 18830ns
> I0118 23:03:19.909502 29898 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0118 23:03:19.910025 29917 recover.cpp:447] Starting replica recovery
> I0118 23:03:19.910282 29917 recover.cpp:473] Replica is in EMPTY status
> I0118 23:03:19.911519 29919 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13698)@172.17.0.4:45683
> I0118 23:03:19.911931 29925 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0118 23:03:19.912528 29931 recover.cpp:564] Updating replica status to
> STARTING
> I0118 23:03:19.913187 29926 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 590877ns
> I0118 23:03:19.913228 29926 replica.cpp:320] Persisted replica status to
> STARTING
> I0118 23:03:19.913403 29920 master.cpp:374] Master
> ad32f568-972d-46b2-881f-44f7d39ddbdc (3ade37c447fa) started on
> 172.17.0.4:45683
> I0118 23:03:19.913511 29930 recover.cpp:473] Replica is in STARTING status
> I0118 23:03:19.913445 29920 master.cpp:376] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5"
> --authorizers="local" --credentials="/tmp/TRUygj/credentials"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --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/TRUygj/master" --zk_session_timeout="10secs"
> I0118 23:03:19.913852 29920 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0118 23:03:19.913866 29920 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0118 23:03:19.913875 29920 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/TRUygj/credentials'
> I0118 23:03:19.914234 29920 master.cpp:466] Using default 'crammd5'
> authenticator
> I0118 23:03:19.914397 29920 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0118 23:03:19.914485 29921 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13699)@172.17.0.4:45683
> I0118 23:03:19.914608 29920 master.cpp:569] Authorization enabled
> I0118 23:03:19.914779 29921 hierarchical.cpp:145] Initialized hierarchical
> allocator process
> I0118 23:03:19.914826 29916 whitelist_watcher.cpp:77] No whitelist given
> I0118 23:03:19.914924 29927 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0118 23:03:19.915542 29919 recover.cpp:564] Updating replica status to
> VOTING
> I0118 23:03:19.916193 29929 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 455878ns
> I0118 23:03:19.916219 29929 replica.cpp:320] Persisted replica status to
> VOTING
> I0118 23:03:19.916369 29926 recover.cpp:578] Successfully joined the Paxos
> group
> I0118 23:03:19.916704 29926 recover.cpp:462] Recover process terminated
> I0118 23:03:19.917016 29922 master.cpp:1710] The newly elected leader is
> master@172.17.0.4:45683 with id ad32f568-972d-46b2-881f-44f7d39ddbdc
> I0118 23:03:19.917050 29922 master.cpp:1723] Elected as the leading master!
> I0118 23:03:19.917282 29922 master.cpp:1468] Recovering from registrar
> I0118 23:03:19.917474 29929 registrar.cpp:307] Recovering registrar
> I0118 23:03:19.917917 29922 log.cpp:659] Attempting to start the writer
> I0118 23:03:19.918970 29924 replica.cpp:493] Replica received implicit
> promise request from (13701)@172.17.0.4:45683 with proposal 1
> I0118 23:03:19.919471 29924 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 434673ns
> I0118 23:03:19.919495 29924 replica.cpp:342] Persisted promised to 1
> I0118 23:03:19.920037 29925 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0118 23:03:19.921254 29926 replica.cpp:388] Replica received explicit
> promise request from (13702)@172.17.0.4:45683 for position 0 with
> proposal 2
> I0118 23:03:19.921569 29926 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 290584ns
> I0118 23:03:19.921592 29926 replica.cpp:712] Persisted action at 0
> I0118 23:03:19.922453 29925 replica.cpp:537] Replica received write
> request for position 0 from (13703)@172.17.0.4:45683
> I0118 23:03:19.922511 29925 leveldb.cpp:436] Reading position from leveldb
> took 40477ns
> I0118 23:03:19.922900 29925 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 356778ns
> I0118 23:03:19.922924 29925 replica.cpp:712] Persisted action at 0
> I0118 23:03:19.923511 29917 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0118 23:03:19.923873 29917 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 347877ns
> I0118 23:03:19.923897 29917 replica.cpp:712] Persisted action at 0
> I0118 23:03:19.923913 29917 replica.cpp:697] Replica learned NOP action at
> position 0
> I0118 23:03:19.924587 29927 log.cpp:675] Writer started with ending
> position 0
> I0118 23:03:19.925745 29929 leveldb.cpp:436] Reading position from leveldb
> took 53389ns
> I0118 23:03:19.926780 29924 registrar.cpp:340] Successfully fetched the
> registry (0B) in 9.268224ms
> I0118 23:03:19.926913 29924 registrar.cpp:439] Applied 1 operations in
> 48411ns; attempting to update the 'registry'
> I0118 23:03:19.927549 29926 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0118 23:03:19.927760 29920 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0118 23:03:19.928527 29917 replica.cpp:537] Replica received write
> request for position 1 from (13704)@172.17.0.4:45683
> I0118 23:03:19.928932 29917 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 372405ns
> I0118 23:03:19.928956 29917 replica.cpp:712] Persisted action at 1
> I0118 23:03:19.929538 29917 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0118 23:03:19.929882 29917 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 326483ns
> I0118 23:03:19.929904 29917 replica.cpp:712] Persisted action at 1
> I0118 23:03:19.929925 29917 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0118 23:03:19.930896 29930 registrar.cpp:484] Successfully updated the
> 'registry' in 3.912192ms
> I0118 23:03:19.931013 29930 registrar.cpp:370] Successfully recovered
> registrar
> I0118 23:03:19.931152 29931 log.cpp:702] Attempting to truncate the log to
> 1
> I0118 23:03:19.931429 29917 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0118 23:03:19.931476 29929 hierarchical.cpp:172] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0118 23:03:19.931581 29921 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0118 23:03:19.932384 29918 replica.cpp:537] Replica received write
> request for position 2 from (13705)@172.17.0.4:45683
> I0118 23:03:19.932812 29918 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 401469ns
> I0118 23:03:19.932837 29918 replica.cpp:712] Persisted action at 2
> I0118 23:03:19.933440 29920 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0118 23:03:19.933825 29920 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 368093ns
> I0118 23:03:19.933872 29920 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 33161ns
> I0118 23:03:19.933889 29920 replica.cpp:712] Persisted action at 2
> I0118 23:03:19.933905 29920 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0118 23:03:19.942512 29898 scheduler.cpp:154] Version: 0.27.0
> I0118 23:03:19.943182 29918 scheduler.cpp:236] New master detected at
> master@172.17.0.4:45683
> I0118 23:03:19.944362 29924 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.4:45683
> I0118 23:03:19.946282 29918 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0118 23:03:19.946789 29920 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:33009
> I0118 23:03:19.947180 29920 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0118 23:03:19.947206 29920 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0118 23:03:19.947540 29920 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [  ]
> I0118 23:03:19.947973 29918 hierarchical.cpp:266] Added framework
> ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> I0118 23:03:19.948040 29918 hierarchical.cpp:1338] No resources available
> to allocate!
> I0118 23:03:19.948107 29918 hierarchical.cpp:1432] No inverse offers to
> send out!
> I0118 23:03:19.948130 29918 hierarchical.cpp:1086] Performed allocation
> for 0 slaves in 138145ns
> I0118 23:03:19.948165 29923 master.hpp:1658] Sending heartbeat to
> ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> I0118 23:03:19.949169 29922 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.4:45683
> I0118 23:03:19.949666 29922 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.4:45683
> I0118 23:03:19.950438 29918 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0118 23:03:19.950459 29922 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.4:45683
> I0118 23:03:19.952298 29927 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0118 23:03:19.952775 29920 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:33010
> I0118 23:03:19.953030 29920 master.cpp:2717] Processing REQUEST call for
> framework ad32f568-972d-46b2-881f-44f7d39ddbdc-0000 (default)
> I0118 23:03:19.953277 29922 hierarchical.cpp:586] Received resource
> request from framework ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> I0118 23:03:19.953598 29925 master.cpp:1025] Master terminating
> I0118 23:03:19.954211 29926 hierarchical.cpp:327] Removed framework
> ad32f568-972d-46b2-881f-44f7d39ddbdc-0000
> E0118 23:03:19.955265 29931 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 (4164 ms total)
>
> [----------] Global test environment tear-down
> 2016-01-18
> 23:03:20,258:29898(0x2ac46780c700):ZOO_ERROR@handle_socket_error_msg@1697:
> Socket [127.0.0.1:39162] zk retcode=-4, errno=111(Connection refused):
> server refused to accept the client
> [==========] 928 tests from 123 test cases ran. (331537 ms total)
> [  PASSED  ] 927 tests.
> [  FAILED  ] 1 test, listed below:
> [  FAILED  ] MasterTest.MaxCompletedTasksPerFrameworkFlag
>
>  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-1453156296-5368
> Untagged: mesos-1453156296-5368:latest
> Deleted: 777e17b94a7fe7b758f183d0b1a56358a99a0a909b3aa663b2601c26a1da04cf
> Deleted: 993b895d8a13121bdc79d16466b88816a50d376351d1dfb76bd12e9473ab1f6c
> Deleted: bd18ccd42876654f92330a6bca63c16d56c580ad106fc1a2d7c4102c757477b4
> Deleted: 8afec7c08a7fa37bd4c0ac02cdb99220292a2b7e4cc9f632510c66a6594793d9
> Deleted: 8b25c2d8746431e3dca92de5763e8c7bb381d721c950d75aec6cb42c07afe8b0
> Deleted: 70a463f67f40a22afe151ac66a9b0b303ebb22e812f9244d34d89606328e291c
> Deleted: 6350c6abe5f933c63c932bf6e8ace0d7327ed71a2ed119af69935d91ebdfc9a1
> Deleted: 0a9bdbd9750c7033aeb02816ec7dd581b15088198a2edad03a249530ddc88685
> Deleted: faac0508488d9dd6093ffbfa5919755ba6a99ccb19c25a349174cc68cdbea2bc
> Deleted: 8f2d7d308ce6b45dda6417457c6dcf89f073a69225ee92ca534ba0a9f8200fb7
> Deleted: 7b29adc92f4eef68d50d293a2f550f2b8b332d71cc7c1646abd90c62d581f2a3
> Deleted: c1839eb2495d1e24b9745c59d922117208dae9e024d9dff8d383214969cf0400
> Deleted: 523f472d6ba67e69aedf9c76aeb6d1757cffb2562c3a6623a67310bfcbc7b47e
> Deleted: 74d595bedbfcd4d38a9b5f6e4b64f5cc86236ce07f67f40debbf8d277d1c38a4
> Build step 'Execute shell' marked build as failure
>