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 04:54:15 UTC
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1510
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1510/>
------------------------------------------
[...truncated 155782 lines...]
I0119 03:54:15.963275 614 gc.cpp:54] Scheduling '/tmp/ContentType_SchedulerTest_Message_1_AGI2a2/slaves/7678655f-e955-41df-ba26-195e14c409bf-S0/frameworks/7678655f-e955-41df-ba26-195e14c409bf-0000' for gc 6.99998885171259days in the future
I0119 03:54:15.963289 605 status_update_manager.cpp:282] Closing status update streams for framework 7678655f-e955-41df-ba26-195e14c409bf-0000
I0119 03:54:15.963346 605 status_update_manager.cpp:528] Cleaning up status update stream for task 37f85f3d-0085-4547-96d1-7b80a4ffeae1 of framework 7678655f-e955-41df-ba26-195e14c409bf-0000
[ OK ] ContentType/SchedulerTest.Message/1 (105 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0119 03:54:15.970432 584 leveldb.cpp:174] Opened db in 2.995285ms
I0119 03:54:15.971763 584 leveldb.cpp:181] Compacted db in 1.299841ms
I0119 03:54:15.971832 584 leveldb.cpp:196] Created db iterator in 22214ns
I0119 03:54:15.971858 584 leveldb.cpp:202] Seeked to beginning of db in 2495ns
I0119 03:54:15.971874 584 leveldb.cpp:271] Iterated through 0 keys in the db in 270ns
I0119 03:54:15.971920 584 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0119 03:54:15.972707 611 recover.cpp:447] Starting replica recovery
I0119 03:54:15.973039 611 recover.cpp:473] Replica is in EMPTY status
I0119 03:54:15.974478 607 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13728)@172.17.0.2:58576
I0119 03:54:15.974839 609 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0119 03:54:15.975256 614 recover.cpp:564] Updating replica status to STARTING
I0119 03:54:15.975889 607 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 494397ns
I0119 03:54:15.975913 607 replica.cpp:320] Persisted replica status to STARTING
I0119 03:54:15.976132 606 recover.cpp:473] Replica is in STARTING status
I0119 03:54:15.977077 615 master.cpp:374] Master fb59cb4c-b913-4538-bd64-a91e957268c0 (e9534b118fc1) started on 172.17.0.2:58576
I0119 03:54:15.977341 609 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13729)@172.17.0.2:58576
I0119 03:54:15.977115 615 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/6IvkuW/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/6IvkuW/master" --zk_session_timeout="10secs"
I0119 03:54:15.977536 615 master.cpp:423] Master allowing unauthenticated frameworks to register
I0119 03:54:15.977555 615 master.cpp:426] Master only allowing authenticated slaves to register
I0119 03:54:15.977565 615 credentials.hpp:35] Loading credentials for authentication from '/tmp/6IvkuW/credentials'
I0119 03:54:15.977572 606 recover.cpp:193] Received a recover response from a replica in STARTING status
I0119 03:54:15.978005 616 recover.cpp:564] Updating replica status to VOTING
I0119 03:54:15.978106 615 master.cpp:466] Using default 'crammd5' authenticator
I0119 03:54:15.978309 615 master.cpp:535] Using default 'basic' HTTP authenticator
I0119 03:54:15.978550 615 master.cpp:569] Authorization enabled
I0119 03:54:15.978716 612 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 506700ns
I0119 03:54:15.978742 612 replica.cpp:320] Persisted replica status to VOTING
I0119 03:54:15.978790 617 hierarchical.cpp:145] Initialized hierarchical allocator process
I0119 03:54:15.978837 611 recover.cpp:578] Successfully joined the Paxos group
I0119 03:54:15.978793 603 whitelist_watcher.cpp:77] No whitelist given
I0119 03:54:15.979058 611 recover.cpp:462] Recover process terminated
I0119 03:54:15.980917 615 master.cpp:1710] The newly elected leader is master@172.17.0.2:58576 with id fb59cb4c-b913-4538-bd64-a91e957268c0
I0119 03:54:15.980955 615 master.cpp:1723] Elected as the leading master!
I0119 03:54:15.980976 615 master.cpp:1468] Recovering from registrar
I0119 03:54:15.981158 613 registrar.cpp:307] Recovering registrar
I0119 03:54:15.981987 610 log.cpp:659] Attempting to start the writer
I0119 03:54:15.983471 615 replica.cpp:493] Replica received implicit promise request from (13731)@172.17.0.2:58576 with proposal 1
I0119 03:54:15.984071 615 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 510103ns
I0119 03:54:15.984098 615 replica.cpp:342] Persisted promised to 1
I0119 03:54:15.984797 611 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0119 03:54:15.986280 608 replica.cpp:388] Replica received explicit promise request from (13732)@172.17.0.2:58576 for position 0 with proposal 2
I0119 03:54:15.986778 608 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 452788ns
I0119 03:54:15.986812 608 replica.cpp:712] Persisted action at 0
I0119 03:54:15.987834 604 replica.cpp:537] Replica received write request for position 0 from (13733)@172.17.0.2:58576
I0119 03:54:15.987902 604 leveldb.cpp:436] Reading position from leveldb took 29732ns
I0119 03:54:15.988339 604 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 393079ns
I0119 03:54:15.988363 604 replica.cpp:712] Persisted action at 0
I0119 03:54:15.988880 616 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0119 03:54:15.989300 616 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 388826ns
I0119 03:54:15.989343 616 replica.cpp:712] Persisted action at 0
I0119 03:54:15.989370 616 replica.cpp:697] Replica learned NOP action at position 0
I0119 03:54:15.989960 615 log.cpp:675] Writer started with ending position 0
I0119 03:54:15.990893 604 leveldb.cpp:436] Reading position from leveldb took 24925ns
I0119 03:54:15.991757 615 registrar.cpp:340] Successfully fetched the registry (0B) in 10.560768ms
I0119 03:54:15.991860 615 registrar.cpp:439] Applied 1 operations in 25294ns; attempting to update the 'registry'
I0119 03:54:15.992504 608 log.cpp:683] Attempting to append 170 bytes to the log
I0119 03:54:15.992607 611 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0119 03:54:15.993290 611 replica.cpp:537] Replica received write request for position 1 from (13734)@172.17.0.2:58576
I0119 03:54:15.993960 611 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 635696ns
I0119 03:54:15.993986 611 replica.cpp:712] Persisted action at 1
I0119 03:54:15.994570 603 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0119 03:54:15.995105 603 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 502805ns
I0119 03:54:15.995131 603 replica.cpp:712] Persisted action at 1
I0119 03:54:15.995154 603 replica.cpp:697] Replica learned APPEND action at position 1
I0119 03:54:15.996042 616 registrar.cpp:484] Successfully updated the 'registry' in 4.10496ms
I0119 03:54:15.996191 605 log.cpp:702] Attempting to truncate the log to 1
I0119 03:54:15.996227 616 registrar.cpp:370] Successfully recovered registrar
I0119 03:54:15.996340 608 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0119 03:54:15.996835 611 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0119 03:54:15.996891 610 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0119 03:54:15.997540 616 replica.cpp:537] Replica received write request for position 2 from (13735)@172.17.0.2:58576
I0119 03:54:15.998004 616 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 415111ns
I0119 03:54:15.998036 616 replica.cpp:712] Persisted action at 2
I0119 03:54:15.998867 603 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0119 03:54:15.999300 603 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 394969ns
I0119 03:54:15.999369 603 leveldb.cpp:399] Deleting ~1 keys from leveldb took 37402ns
I0119 03:54:15.999420 603 replica.cpp:712] Persisted action at 2
I0119 03:54:15.999450 603 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0119 03:54:16.007637 584 scheduler.cpp:154] Version: 0.27.0
I0119 03:54:16.008211 615 scheduler.cpp:236] New master detected at master@172.17.0.2:58576
I0119 03:54:16.009395 604 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:58576
I0119 03:54:16.010859 609 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 03:54:16.011354 603 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:47437
I0119 03:54:16.011570 603 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0119 03:54:16.011659 603 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0119 03:54:16.012076 618 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0119 03:54:16.012480 605 hierarchical.cpp:266] Added framework fb59cb4c-b913-4538-bd64-a91e957268c0-0000
I0119 03:54:16.012588 606 master.hpp:1658] Sending heartbeat to fb59cb4c-b913-4538-bd64-a91e957268c0-0000
I0119 03:54:16.012811 605 hierarchical.cpp:1338] No resources available to allocate!
I0119 03:54:16.012934 605 hierarchical.cpp:1432] No inverse offers to send out!
I0119 03:54:16.012974 605 hierarchical.cpp:1086] Performed allocation for 0 slaves in 466306ns
I0119 03:54:16.013468 605 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:58576
I0119 03:54:16.014047 605 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:58576
I0119 03:54:16.014601 617 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0119 03:54:16.014767 611 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:58576
I0119 03:54:16.016019 607 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 03:54:16.016351 613 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:47438
I0119 03:54:16.016479 613 master.cpp:2717] Processing REQUEST call for framework fb59cb4c-b913-4538-bd64-a91e957268c0-0000 (default)
I0119 03:54:16.016676 605 hierarchical.cpp:586] Received resource request from framework fb59cb4c-b913-4538-bd64-a91e957268c0-0000
I0119 03:54:16.017801 616 master.cpp:1025] Master terminating
I0119 03:54:16.018154 612 hierarchical.cpp:327] Removed framework fb59cb4c-b913-4538-bd64-a91e957268c0-0000
E0119 03:54:16.018663 606 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (56 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0119 03:54:16.027212 584 leveldb.cpp:174] Opened db in 2.849992ms
I0119 03:54:16.028408 584 leveldb.cpp:181] Compacted db in 1.160916ms
I0119 03:54:16.028460 584 leveldb.cpp:196] Created db iterator in 20127ns
I0119 03:54:16.028476 584 leveldb.cpp:202] Seeked to beginning of db in 2454ns
I0119 03:54:16.028484 584 leveldb.cpp:271] Iterated through 0 keys in the db in 233ns
I0119 03:54:16.028522 584 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0119 03:54:16.028892 605 recover.cpp:447] Starting replica recovery
I0119 03:54:16.029139 603 recover.cpp:473] Replica is in EMPTY status
I0119 03:54:16.030165 607 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13743)@172.17.0.2:58576
I0119 03:54:16.030355 611 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0119 03:54:16.030779 616 recover.cpp:564] Updating replica status to STARTING
I0119 03:54:16.031474 603 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 565191ns
I0119 03:54:16.031500 603 replica.cpp:320] Persisted replica status to STARTING
I0119 03:54:16.031533 611 master.cpp:374] Master 9e4cae84-cd80-417e-9023-17c0df61c980 (e9534b118fc1) started on 172.17.0.2:58576
I0119 03:54:16.031836 604 recover.cpp:473] Replica is in STARTING status
I0119 03:54:16.031551 611 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/k7UaaA/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/k7UaaA/master" --zk_session_timeout="10secs"
I0119 03:54:16.032344 611 master.cpp:423] Master allowing unauthenticated frameworks to register
I0119 03:54:16.032359 611 master.cpp:426] Master only allowing authenticated slaves to register
I0119 03:54:16.032366 611 credentials.hpp:35] Loading credentials for authentication from '/tmp/k7UaaA/credentials'
I0119 03:54:16.032655 611 master.cpp:466] Using default 'crammd5' authenticator
I0119 03:54:16.032790 611 master.cpp:535] Using default 'basic' HTTP authenticator
I0119 03:54:16.032995 610 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13744)@172.17.0.2:58576
I0119 03:54:16.033190 611 master.cpp:569] Authorization enabled
I0119 03:54:16.033342 605 whitelist_watcher.cpp:77] No whitelist given
I0119 03:54:16.033428 609 recover.cpp:193] Received a recover response from a replica in STARTING status
I0119 03:54:16.033359 612 hierarchical.cpp:145] Initialized hierarchical allocator process
I0119 03:54:16.033902 605 recover.cpp:564] Updating replica status to VOTING
I0119 03:54:16.034526 615 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 403733ns
I0119 03:54:16.034551 615 replica.cpp:320] Persisted replica status to VOTING
I0119 03:54:16.034700 615 recover.cpp:578] Successfully joined the Paxos group
I0119 03:54:16.035019 615 recover.cpp:462] Recover process terminated
I0119 03:54:16.035284 613 master.cpp:1710] The newly elected leader is master@172.17.0.2:58576 with id 9e4cae84-cd80-417e-9023-17c0df61c980
I0119 03:54:16.035312 613 master.cpp:1723] Elected as the leading master!
I0119 03:54:16.035329 613 master.cpp:1468] Recovering from registrar
I0119 03:54:16.035615 613 registrar.cpp:307] Recovering registrar
I0119 03:54:16.036142 614 log.cpp:659] Attempting to start the writer
I0119 03:54:16.037210 612 replica.cpp:493] Replica received implicit promise request from (13746)@172.17.0.2:58576 with proposal 1
I0119 03:54:16.037678 612 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 438216ns
I0119 03:54:16.037699 612 replica.cpp:342] Persisted promised to 1
I0119 03:54:16.038236 617 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0119 03:54:16.039268 608 replica.cpp:388] Replica received explicit promise request from (13747)@172.17.0.2:58576 for position 0 with proposal 2
I0119 03:54:16.039765 608 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 460710ns
I0119 03:54:16.039789 608 replica.cpp:712] Persisted action at 0
I0119 03:54:16.040910 605 replica.cpp:537] Replica received write request for position 0 from (13748)@172.17.0.2:58576
I0119 03:54:16.040966 605 leveldb.cpp:436] Reading position from leveldb took 24855ns
I0119 03:54:16.041483 605 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 475810ns
I0119 03:54:16.041506 605 replica.cpp:712] Persisted action at 0
I0119 03:54:16.042132 613 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0119 03:54:16.042567 613 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 364219ns
I0119 03:54:16.042592 613 replica.cpp:712] Persisted action at 0
I0119 03:54:16.042615 613 replica.cpp:697] Replica learned NOP action at position 0
I0119 03:54:16.043148 604 log.cpp:675] Writer started with ending position 0
I0119 03:54:16.044085 612 leveldb.cpp:436] Reading position from leveldb took 25111ns
I0119 03:54:16.044944 606 registrar.cpp:340] Successfully fetched the registry (0B) in 9.238016ms
I0119 03:54:16.045040 606 registrar.cpp:439] Applied 1 operations in 22407ns; attempting to update the 'registry'
I0119 03:54:16.045660 603 log.cpp:683] Attempting to append 170 bytes to the log
I0119 03:54:16.045758 612 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0119 03:54:16.046370 610 replica.cpp:537] Replica received write request for position 1 from (13749)@172.17.0.2:58576
I0119 03:54:16.046901 610 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 494178ns
I0119 03:54:16.046928 610 replica.cpp:712] Persisted action at 1
I0119 03:54:16.047449 617 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0119 03:54:16.047951 617 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 471111ns
I0119 03:54:16.047976 617 replica.cpp:712] Persisted action at 1
I0119 03:54:16.047992 617 replica.cpp:697] Replica learned APPEND action at position 1
I0119 03:54:16.048874 608 registrar.cpp:484] Successfully updated the 'registry' in 3.77984ms
I0119 03:54:16.049008 608 registrar.cpp:370] Successfully recovered registrar
I0119 03:54:16.049068 604 log.cpp:702] Attempting to truncate the log to 1
I0119 03:54:16.049304 613 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0119 03:54:16.049466 617 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0119 03:54:16.049484 608 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0119 03:54:16.050098 608 replica.cpp:537] Replica received write request for position 2 from (13750)@172.17.0.2:58576
I0119 03:54:16.050616 608 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 485697ns
I0119 03:54:16.050655 608 replica.cpp:712] Persisted action at 2
I0119 03:54:16.051172 603 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0119 03:54:16.051677 603 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 476640ns
I0119 03:54:16.051730 603 leveldb.cpp:399] Deleting ~1 keys from leveldb took 29233ns
I0119 03:54:16.051749 603 replica.cpp:712] Persisted action at 2
I0119 03:54:16.051765 603 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0119 03:54:16.060142 584 scheduler.cpp:154] Version: 0.27.0
I0119 03:54:16.060633 616 scheduler.cpp:236] New master detected at master@172.17.0.2:58576
I0119 03:54:16.061568 618 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.2:58576
I0119 03:54:16.063071 613 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 03:54:16.063769 617 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:47439
I0119 03:54:16.064332 617 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0119 03:54:16.064409 617 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0119 03:54:16.064921 617 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0119 03:54:16.065423 616 hierarchical.cpp:266] Added framework 9e4cae84-cd80-417e-9023-17c0df61c980-0000
I0119 03:54:16.065512 616 hierarchical.cpp:1338] No resources available to allocate!
I0119 03:54:16.065706 616 hierarchical.cpp:1432] No inverse offers to send out!
I0119 03:54:16.065752 616 hierarchical.cpp:1086] Performed allocation for 0 slaves in 291452ns
I0119 03:54:16.065575 617 master.hpp:1658] Sending heartbeat to 9e4cae84-cd80-417e-9023-17c0df61c980-0000
I0119 03:54:16.066784 605 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.2:58576
I0119 03:54:16.067443 605 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.2:58576
I0119 03:54:16.068357 608 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0119 03:54:16.068429 605 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.2:58576
I0119 03:54:16.070456 611 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 03:54:16.070973 618 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:47440
I0119 03:54:16.071233 618 master.cpp:2717] Processing REQUEST call for framework 9e4cae84-cd80-417e-9023-17c0df61c980-0000 (default)
I0119 03:54:16.071413 616 hierarchical.cpp:586] Received resource request from framework 9e4cae84-cd80-417e-9023-17c0df61c980-0000
I0119 03:54:16.071815 615 master.cpp:1025] Master terminating
I0119 03:54:16.072069 614 hierarchical.cpp:327] Removed framework 9e4cae84-cd80-417e-9023-17c0df61c980-0000
E0119 03:54:16.072808 611 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 (4230 ms total)
[----------] Global test environment tear-down
[==========] 936 tests from 124 test cases ran. (365291 ms total)
[ PASSED ] 935 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RegistryClientTest.BadTokenServerAddress
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-1453173700-14139
Untagged: mesos-1453173700-14139:latest
Deleted: 0a51ee31d2c9d2162ebdb2b4edfdf121b0609f23b7c0e058af2ebdeded159df3
Deleted: 159902fd3cd813d739921248878ff6112c3db5f6982b6bc327fd3d216755fe4f
Deleted: 6e75a3f470b092cefe1f2bdea3237ebedf334bb9a796e33ea0b7b9b19ed3509e
Deleted: 5069f32cf1e5e9fdc37b26b8cdcbc4cbd9401030791223f185858f01b3222ffa
Deleted: 8292d1ddfe903ad931c818421041f0d438e5d8a73531da2730e403919d088966
Deleted: d908aaece37dcb54b82194fc0564e45de9c770be2a7ee8fdf30389ff34bb37e1
Deleted: 63b16639a71aa49c15189c44db06691fda94058ebeb6109f37df691c59c46d87
Deleted: 1f5f93042fcbd496ae98584ffb5438844c406d5e156b58ccf6ce1e15ac1c8d0a
Deleted: 6e4f96cc81026dd197d3d95695982d12f76bd0e1f307679c63d0e8f994393ba6
Deleted: 46b4b9411ddfac92fe3fd6e2b24b4acf5e13575bde9e6f6a5fbc9292b4cd1c6c
Deleted: af347bb96b8f75ddc9fb0324669c42dae1d5fb19620eeda449fcd17fbf13c2a8
Deleted: 39b6adce48404bb2c3014fb6b503b5564bede054489bdb3dbdb0285598ecbbf9
Deleted: 9cca66c8060958bdb9a551a7e67763bc9459004697f7348a5ab7e6609145dd91
Deleted: 8805a1d47dc4ea3416b0fa1ebfa0ce98f71021236d2e757b41b5be176992228c
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1513
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1513/changes>
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1512
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1512/>
------------------------------------------
Started by upstream project "Mesos" build number 1512
originally caused by:
Started by an SCM change
[EnvInject] - Loading node environment variables.
Building remotely on ubuntu-4 (docker Ubuntu ubuntu4 ubuntu) in workspace <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/ws/>
Cloning the remote Git repository
Using shallow clone
Cloning repository https://git-wip-us.apache.org/repos/asf/mesos.git
> git init <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/ws/> # timeout=10
Fetching upstream changes from https://git-wip-us.apache.org/repos/asf/mesos.git
> git --version # timeout=10
> git -c core.askpass=true fetch --tags --progress https://git-wip-us.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/* --depth=1 # timeout=60
> git config remote.origin.url https://git-wip-us.apache.org/repos/asf/mesos.git # timeout=10
> git config --add remote.origin.fetch +refs/heads/*:refs/remotes/origin/* # timeout=10
> git config remote.origin.url https://git-wip-us.apache.org/repos/asf/mesos.git # timeout=10
Fetching upstream changes from https://git-wip-us.apache.org/repos/asf/mesos.git
> git -c core.askpass=true fetch --tags --progress https://git-wip-us.apache.org/repos/asf/mesos.git +refs/heads/*:refs/remotes/origin/* # timeout=60
Checking out Revision f5e1bee6b1b8b5518062b76c2246adf5849c936a (origin/master)
> git config core.sparsecheckout # timeout=10
> git checkout -f f5e1bee6b1b8b5518062b76c2246adf5849c936a
FATAL: Could not checkout f5e1bee6b1b8b5518062b76c2246adf5849c936a
hudson.plugins.git.GitException: Could not checkout f5e1bee6b1b8b5518062b76c2246adf5849c936a
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl$9.execute(CliGitAPIImpl.java:1964)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:152)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:145)
at hudson.remoting.UserRequest.perform(UserRequest.java:121)
at hudson.remoting.UserRequest.perform(UserRequest.java:49)
at hudson.remoting.Request$2.run(Request.java:326)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:68)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
at ......remote call to ubuntu-4(Native Method)
at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1413)
at hudson.remoting.UserResponse.retrieve(UserRequest.java:221)
at hudson.remoting.Channel.call(Channel.java:778)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler.execute(RemoteGitImpl.java:145)
at sun.reflect.GeneratedMethodAccessor533.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler.invoke(RemoteGitImpl.java:131)
at com.sun.proxy.$Proxy75.execute(Unknown Source)
at hudson.plugins.git.GitSCM.checkout(GitSCM.java:1081)
at hudson.scm.SCM.checkout(SCM.java:484)
at hudson.model.AbstractProject.checkout(AbstractProject.java:1274)
at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:609)
at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:531)
at hudson.model.Run.execute(Run.java:1738)
at hudson.matrix.MatrixRun.run(MatrixRun.java:146)
at hudson.model.ResourceController.execute(ResourceController.java:98)
at hudson.model.Executor.run(Executor.java:381)
Caused by: hudson.plugins.git.GitException: Command "git checkout -f f5e1bee6b1b8b5518062b76c2246adf5849c936a" returned status code 128:
stdout:
stderr: fatal: reference is not a tree: f5e1bee6b1b8b5518062b76c2246adf5849c936a
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl.launchCommandIn(CliGitAPIImpl.java:1693)
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl.access$500(CliGitAPIImpl.java:62)
at org.jenkinsci.plugins.gitclient.CliGitAPIImpl$9.execute(CliGitAPIImpl.java:1956)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:152)
at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:145)
at hudson.remoting.UserRequest.perform(UserRequest.java:121)
at hudson.remoting.UserRequest.perform(UserRequest.java:49)
at hudson.remoting.Request$2.run(Request.java:326)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:68)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1511
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1511/changes>
Changes:
[nik] Made hook execution order deterministic.
[benjamin.hindman] Added guide to writing highly available Mesos frameworks.
[vinodkone] Corrected a typo in test case DeactivateAndReactivateFramework.
------------------------------------------
[...truncated 156186 lines...]
I0119 22:35:39.293481 586 slave.cpp:2007] Asked to shut down framework 517c65b2-7901-41df-b297-f34672ce98a5-0000 by @0.0.0.0:0
I0119 22:35:39.293526 586 slave.cpp:2032] Shutting down framework 517c65b2-7901-41df-b297-f34672ce98a5-0000
I0119 22:35:39.293618 586 slave.cpp:4059] Shutting down executor 'default' of framework 517c65b2-7901-41df-b297-f34672ce98a5-0000 at executor(139)@172.17.0.3:43530
[ OK ] ContentType/SchedulerTest.Message/1 (112 ms)
[ RUN ] ContentType/SchedulerTest.Request/0
I0119 22:35:39.304060 586 leveldb.cpp:174] Opened db in 2.531018ms
I0119 22:35:39.304883 586 leveldb.cpp:181] Compacted db in 780012ns
I0119 22:35:39.304931 586 leveldb.cpp:196] Created db iterator in 22430ns
I0119 22:35:39.304955 586 leveldb.cpp:202] Seeked to beginning of db in 1780ns
I0119 22:35:39.304971 586 leveldb.cpp:271] Iterated through 0 keys in the db in 525ns
I0119 22:35:39.305029 586 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0119 22:35:39.305737 617 recover.cpp:447] Starting replica recovery
I0119 22:35:39.306205 617 recover.cpp:473] Replica is in EMPTY status
I0119 22:35:39.307513 608 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13720)@172.17.0.3:43530
I0119 22:35:39.308075 608 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0119 22:35:39.308308 616 master.cpp:374] Master 75d82746-7469-4d69-a0b1-dd0594974d47 (f25d5ed18666) started on 172.17.0.3:43530
I0119 22:35:39.308333 616 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/hvoJ6c/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/hvoJ6c/master" --zk_session_timeout="10secs"
I0119 22:35:39.308745 616 master.cpp:423] Master allowing unauthenticated frameworks to register
I0119 22:35:39.308761 616 master.cpp:426] Master only allowing authenticated slaves to register
I0119 22:35:39.308773 616 credentials.hpp:35] Loading credentials for authentication from '/tmp/hvoJ6c/credentials'
I0119 22:35:39.309360 616 master.cpp:466] Using default 'crammd5' authenticator
I0119 22:35:39.309451 613 recover.cpp:564] Updating replica status to STARTING
I0119 22:35:39.309504 616 master.cpp:535] Using default 'basic' HTTP authenticator
I0119 22:35:39.309698 616 master.cpp:569] Authorization enabled
I0119 22:35:39.309897 619 hierarchical.cpp:145] Initialized hierarchical allocator process
I0119 22:35:39.309928 613 whitelist_watcher.cpp:77] No whitelist given
I0119 22:35:39.310283 612 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 576590ns
I0119 22:35:39.310312 612 replica.cpp:320] Persisted replica status to STARTING
I0119 22:35:39.310609 612 recover.cpp:473] Replica is in STARTING status
I0119 22:35:39.313573 605 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13722)@172.17.0.3:43530
I0119 22:35:39.313977 616 master.cpp:1710] The newly elected leader is master@172.17.0.3:43530 with id 75d82746-7469-4d69-a0b1-dd0594974d47
I0119 22:35:39.314008 616 master.cpp:1723] Elected as the leading master!
I0119 22:35:39.314033 616 master.cpp:1468] Recovering from registrar
I0119 22:35:39.314167 613 registrar.cpp:307] Recovering registrar
I0119 22:35:39.314302 617 recover.cpp:193] Received a recover response from a replica in STARTING status
I0119 22:35:39.315029 608 recover.cpp:564] Updating replica status to VOTING
I0119 22:35:39.315687 613 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 371410ns
I0119 22:35:39.315721 613 replica.cpp:320] Persisted replica status to VOTING
I0119 22:35:39.315918 614 recover.cpp:578] Successfully joined the Paxos group
I0119 22:35:39.316187 614 recover.cpp:462] Recover process terminated
I0119 22:35:39.316686 610 log.cpp:659] Attempting to start the writer
I0119 22:35:39.318338 613 replica.cpp:493] Replica received implicit promise request from (13723)@172.17.0.3:43530 with proposal 1
I0119 22:35:39.319665 613 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 1.004696ms
I0119 22:35:39.319712 613 replica.cpp:342] Persisted promised to 1
I0119 22:35:39.320695 613 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0119 22:35:39.322850 606 replica.cpp:388] Replica received explicit promise request from (13724)@172.17.0.3:43530 for position 0 with proposal 2
I0119 22:35:39.323424 606 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 421249ns
I0119 22:35:39.323523 606 replica.cpp:712] Persisted action at 0
I0119 22:35:39.325345 605 replica.cpp:537] Replica received write request for position 0 from (13725)@172.17.0.3:43530
I0119 22:35:39.325428 605 leveldb.cpp:436] Reading position from leveldb took 38927ns
I0119 22:35:39.325867 605 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 382131ns
I0119 22:35:39.325965 605 replica.cpp:712] Persisted action at 0
I0119 22:35:39.326782 612 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0119 22:35:39.327692 612 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 480252ns
I0119 22:35:39.327792 612 replica.cpp:712] Persisted action at 0
I0119 22:35:39.327922 612 replica.cpp:697] Replica learned NOP action at position 0
I0119 22:35:39.328917 613 log.cpp:675] Writer started with ending position 0
I0119 22:35:39.330260 617 leveldb.cpp:436] Reading position from leveldb took 52961ns
I0119 22:35:39.331459 614 registrar.cpp:340] Successfully fetched the registry (0B) in 17.174016ms
I0119 22:35:39.331725 614 registrar.cpp:439] Applied 1 operations in 42685ns; attempting to update the 'registry'
I0119 22:35:39.332669 614 log.cpp:683] Attempting to append 170 bytes to the log
I0119 22:35:39.332877 606 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0119 22:35:39.333817 620 replica.cpp:537] Replica received write request for position 1 from (13726)@172.17.0.3:43530
I0119 22:35:39.334554 620 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 594131ns
I0119 22:35:39.334599 620 replica.cpp:712] Persisted action at 1
I0119 22:35:39.335511 617 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0119 22:35:39.335901 617 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 354258ns
I0119 22:35:39.335932 617 replica.cpp:712] Persisted action at 1
I0119 22:35:39.335959 617 replica.cpp:697] Replica learned APPEND action at position 1
I0119 22:35:39.337738 613 log.cpp:702] Attempting to truncate the log to 1
I0119 22:35:39.337970 610 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0119 22:35:39.337759 605 registrar.cpp:484] Successfully updated the 'registry' in 5.885184ms
I0119 22:35:39.338261 605 registrar.cpp:370] Successfully recovered registrar
I0119 22:35:39.338800 610 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0119 22:35:39.338826 608 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0119 22:35:39.339308 608 replica.cpp:537] Replica received write request for position 2 from (13727)@172.17.0.3:43530
I0119 22:35:39.339776 608 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 419151ns
I0119 22:35:39.339807 608 replica.cpp:712] Persisted action at 2
I0119 22:35:39.340694 617 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0119 22:35:39.341224 617 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 399542ns
I0119 22:35:39.341387 617 leveldb.cpp:399] Deleting ~1 keys from leveldb took 52624ns
I0119 22:35:39.341513 617 replica.cpp:712] Persisted action at 2
I0119 22:35:39.341671 617 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0119 22:35:39.350184 586 scheduler.cpp:154] Version: 0.27.0
I0119 22:35:39.351160 617 scheduler.cpp:236] New master detected at master@172.17.0.3:43530
I0119 22:35:39.352577 619 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:43530
I0119 22:35:39.354753 612 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 22:35:39.355413 605 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:47031
I0119 22:35:39.355669 605 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0119 22:35:39.355743 605 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0119 22:35:39.356127 608 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0119 22:35:39.356698 613 hierarchical.cpp:266] Added framework 75d82746-7469-4d69-a0b1-dd0594974d47-0000
I0119 22:35:39.356787 613 hierarchical.cpp:1338] No resources available to allocate!
I0119 22:35:39.356844 613 hierarchical.cpp:1432] No inverse offers to send out!
I0119 22:35:39.356878 613 hierarchical.cpp:1086] Performed allocation for 0 slaves in 153206ns
I0119 22:35:39.357126 607 master.hpp:1658] Sending heartbeat to 75d82746-7469-4d69-a0b1-dd0594974d47-0000
I0119 22:35:39.357709 612 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:43530
I0119 22:35:39.358705 618 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:43530
I0119 22:35:39.359436 618 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:43530
I0119 22:35:39.360244 610 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0119 22:35:39.360877 610 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 22:35:39.361392 605 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:47032
I0119 22:35:39.361558 605 master.cpp:2717] Processing REQUEST call for framework 75d82746-7469-4d69-a0b1-dd0594974d47-0000 (default)
I0119 22:35:39.361747 617 hierarchical.cpp:586] Received resource request from framework 75d82746-7469-4d69-a0b1-dd0594974d47-0000
I0119 22:35:39.362764 615 master.cpp:1025] Master terminating
I0119 22:35:39.363080 619 hierarchical.cpp:327] Removed framework 75d82746-7469-4d69-a0b1-dd0594974d47-0000
E0119 22:35:39.363845 614 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/0 (69 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0119 22:35:39.372483 586 leveldb.cpp:174] Opened db in 2.362202ms
I0119 22:35:39.373539 586 leveldb.cpp:181] Compacted db in 999655ns
I0119 22:35:39.373600 586 leveldb.cpp:196] Created db iterator in 21778ns
I0119 22:35:39.373634 586 leveldb.cpp:202] Seeked to beginning of db in 2101ns
I0119 22:35:39.373653 586 leveldb.cpp:271] Iterated through 0 keys in the db in 304ns
I0119 22:35:39.373708 586 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0119 22:35:39.374245 613 recover.cpp:447] Starting replica recovery
I0119 22:35:39.374471 613 recover.cpp:473] Replica is in EMPTY status
I0119 22:35:39.375864 620 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (13735)@172.17.0.3:43530
I0119 22:35:39.376405 616 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0119 22:35:39.376801 614 master.cpp:374] Master e75e9b1f-47e0-49b3-afe4-c2b7d8a1d12d (f25d5ed18666) started on 172.17.0.3:43530
I0119 22:35:39.377089 605 recover.cpp:564] Updating replica status to STARTING
I0119 22:35:39.376819 614 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/4JXasS/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/4JXasS/master" --zk_session_timeout="10secs"
I0119 22:35:39.377153 614 master.cpp:423] Master allowing unauthenticated frameworks to register
I0119 22:35:39.377169 614 master.cpp:426] Master only allowing authenticated slaves to register
I0119 22:35:39.377179 614 credentials.hpp:35] Loading credentials for authentication from '/tmp/4JXasS/credentials'
I0119 22:35:39.377477 614 master.cpp:466] Using default 'crammd5' authenticator
I0119 22:35:39.377614 614 master.cpp:535] Using default 'basic' HTTP authenticator
I0119 22:35:39.377779 614 master.cpp:569] Authorization enabled
I0119 22:35:39.377912 613 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 594051ns
I0119 22:35:39.377943 613 replica.cpp:320] Persisted replica status to STARTING
I0119 22:35:39.377974 611 hierarchical.cpp:145] Initialized hierarchical allocator process
I0119 22:35:39.378052 611 whitelist_watcher.cpp:77] No whitelist given
I0119 22:35:39.378201 613 recover.cpp:473] Replica is in STARTING status
I0119 22:35:39.379209 612 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (13737)@172.17.0.3:43530
I0119 22:35:39.379883 607 recover.cpp:193] Received a recover response from a replica in STARTING status
I0119 22:35:39.380059 610 master.cpp:1710] The newly elected leader is master@172.17.0.3:43530 with id e75e9b1f-47e0-49b3-afe4-c2b7d8a1d12d
I0119 22:35:39.380095 610 master.cpp:1723] Elected as the leading master!
I0119 22:35:39.380120 610 master.cpp:1468] Recovering from registrar
I0119 22:35:39.380306 613 registrar.cpp:307] Recovering registrar
I0119 22:35:39.380411 615 recover.cpp:564] Updating replica status to VOTING
I0119 22:35:39.380915 607 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 359583ns
I0119 22:35:39.380944 607 replica.cpp:320] Persisted replica status to VOTING
I0119 22:35:39.381048 613 recover.cpp:578] Successfully joined the Paxos group
I0119 22:35:39.381336 613 recover.cpp:462] Recover process terminated
I0119 22:35:39.381789 607 log.cpp:659] Attempting to start the writer
I0119 22:35:39.382902 614 replica.cpp:493] Replica received implicit promise request from (13738)@172.17.0.3:43530 with proposal 1
I0119 22:35:39.383239 614 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 308213ns
I0119 22:35:39.383263 614 replica.cpp:342] Persisted promised to 1
I0119 22:35:39.383889 616 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0119 22:35:39.385004 614 replica.cpp:388] Replica received explicit promise request from (13739)@172.17.0.3:43530 for position 0 with proposal 2
I0119 22:35:39.385356 614 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 312931ns
I0119 22:35:39.385380 614 replica.cpp:712] Persisted action at 0
I0119 22:35:39.386318 615 replica.cpp:537] Replica received write request for position 0 from (13740)@172.17.0.3:43530
I0119 22:35:39.386375 615 leveldb.cpp:436] Reading position from leveldb took 26582ns
I0119 22:35:39.386720 615 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 294804ns
I0119 22:35:39.386746 615 replica.cpp:712] Persisted action at 0
I0119 22:35:39.387290 605 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0119 22:35:39.387733 605 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 412653ns
I0119 22:35:39.387758 605 replica.cpp:712] Persisted action at 0
I0119 22:35:39.387780 605 replica.cpp:697] Replica learned NOP action at position 0
I0119 22:35:39.388327 612 log.cpp:675] Writer started with ending position 0
I0119 22:35:39.389329 620 leveldb.cpp:436] Reading position from leveldb took 22396ns
I0119 22:35:39.390233 607 registrar.cpp:340] Successfully fetched the registry (0B) in 9.808128ms
I0119 22:35:39.390364 607 registrar.cpp:439] Applied 1 operations in 38135ns; attempting to update the 'registry'
I0119 22:35:39.391124 610 log.cpp:683] Attempting to append 170 bytes to the log
I0119 22:35:39.391358 618 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0119 22:35:39.392176 611 replica.cpp:537] Replica received write request for position 1 from (13741)@172.17.0.3:43530
I0119 22:35:39.392643 611 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 429026ns
I0119 22:35:39.392669 611 replica.cpp:712] Persisted action at 1
I0119 22:35:39.393327 611 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0119 22:35:39.393759 611 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 403290ns
I0119 22:35:39.393784 611 replica.cpp:712] Persisted action at 1
I0119 22:35:39.393882 611 replica.cpp:697] Replica learned APPEND action at position 1
I0119 22:35:39.395011 611 registrar.cpp:484] Successfully updated the 'registry' in 4.59008ms
I0119 22:35:39.395241 611 registrar.cpp:370] Successfully recovered registrar
I0119 22:35:39.395655 620 log.cpp:702] Attempting to truncate the log to 1
I0119 22:35:39.395655 615 master.cpp:1520] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0119 22:35:39.395684 617 hierarchical.cpp:172] Skipping recovery of hierarchical allocator: nothing to recover
I0119 22:35:39.395781 607 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0119 22:35:39.397169 607 replica.cpp:537] Replica received write request for position 2 from (13742)@172.17.0.3:43530
I0119 22:35:39.397691 607 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 477646ns
I0119 22:35:39.397724 607 replica.cpp:712] Persisted action at 2
I0119 22:35:39.398834 614 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0119 22:35:39.399417 614 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 384956ns
I0119 22:35:39.399524 614 leveldb.cpp:399] Deleting ~1 keys from leveldb took 76634ns
I0119 22:35:39.399658 614 replica.cpp:712] Persisted action at 2
I0119 22:35:39.399780 614 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0119 22:35:39.406685 586 scheduler.cpp:154] Version: 0.27.0
I0119 22:35:39.407718 617 scheduler.cpp:236] New master detected at master@172.17.0.3:43530
I0119 22:35:39.409116 607 scheduler.cpp:298] Sending SUBSCRIBE call to master@172.17.0.3:43530
I0119 22:35:39.411584 612 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 22:35:39.412108 617 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:47033
I0119 22:35:39.412546 617 master.cpp:1972] Received subscription request for HTTP framework 'default'
I0119 22:35:39.412642 617 master.cpp:1749] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0119 22:35:39.412974 617 master.cpp:2063] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0119 22:35:39.413525 611 hierarchical.cpp:266] Added framework e75e9b1f-47e0-49b3-afe4-c2b7d8a1d12d-0000
I0119 22:35:39.413919 610 master.hpp:1658] Sending heartbeat to e75e9b1f-47e0-49b3-afe4-c2b7d8a1d12d-0000
I0119 22:35:39.414496 616 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from master@172.17.0.3:43530
I0119 22:35:39.414726 611 hierarchical.cpp:1338] No resources available to allocate!
I0119 22:35:39.414773 611 hierarchical.cpp:1432] No inverse offers to send out!
I0119 22:35:39.414822 611 hierarchical.cpp:1086] Performed allocation for 0 slaves in 1.266717ms
I0119 22:35:39.415247 616 scheduler.cpp:457] Enqueuing event HEARTBEAT received from master@172.17.0.3:43530
I0119 22:35:39.415899 620 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0119 22:35:39.416230 611 scheduler.cpp:298] Sending REQUEST call to master@172.17.0.3:43530
I0119 22:35:39.417670 616 process.cpp:3141] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0119 22:35:39.418174 609 http.cpp:504] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:47034
I0119 22:35:39.418442 609 master.cpp:2717] Processing REQUEST call for framework e75e9b1f-47e0-49b3-afe4-c2b7d8a1d12d-0000 (default)
I0119 22:35:39.418719 616 hierarchical.cpp:586] Received resource request from framework e75e9b1f-47e0-49b3-afe4-c2b7d8a1d12d-0000
I0119 22:35:39.419114 617 master.cpp:1025] Master terminating
I0119 22:35:39.419425 609 hierarchical.cpp:327] Removed framework e75e9b1f-47e0-49b3-afe4-c2b7d8a1d12d-0000
E0119 22:35:39.421670 616 scheduler.cpp:431] End-Of-File received from master. The master closed the event stream
[ OK ] ContentType/SchedulerTest.Request/1 (57 ms)
[----------] 22 tests from ContentType/SchedulerTest (4350 ms total)
[----------] Global test environment tear-down
[==========] 936 tests from 124 test cases ran. (379182 ms total)
[ PASSED ] 935 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RegistryClientTest.BadTokenServerAddress
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-1453241107-22721
Untagged: mesos-1453241107-22721:latest
Deleted: 70990b33c1788a5d46fa5f529cebb2e69b949c60de9c7dfe7991ed4c6cfa0221
Deleted: 7579d991c1db13ff6ce32ff4310b7157667c64e16075c106cb4344080f1ab6fe
Deleted: 743899ba3a98f82a11cf7b814839259cd4adeca86fa6cdf475b1b9f27ba8aa48
Deleted: 2a5e327a110229777df65d4ada5dcba771b5cbd756786a2585be1da40737a220
Deleted: caed3e999d039c507ca0dae7f91c8b993413d2786148ffaac968f3ce88efa843
Deleted: 9b964c2c1f1ff1465e07e628732fac8426f502a5007fbd9f0457e505bd95f69b
Deleted: 162292dae9174997e9a8e179ae5e0d19a966be6d687ceda1fa85f469f45c53ad
Deleted: e513f2a8303fbf08bd5bfac99f8b0c4df1a83c165fb518bc37a679bb8fa497a0
Deleted: 0a2ebb2f8b141b15a359af3004893ff417447f0076ed406f52a2b639f5d5e7fd
Deleted: 80970cae3259f89bcd279858d1b79370d5f1faf43e47b589505b3f2c28f04b7d
Deleted: a8037f99517ebdb5fa17d15cf6ec651d679da6ffea1cf9eb4b0ce2ace7127ced
Deleted: ec344934b3bf498f4baa100979a6349ee49084d6f265d47c5488dca1e1366026
Deleted: 0ac55b32df9d5c660d6dd8a227eae544b88224c10d0009ac0b99dc3e03196aa2
Deleted: cb969c1a2491148c1becf41dd05198f10408eb9b82abe711d1151ff287f3f24b
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1510
Posted by Jojy Varghese <jo...@mesosphere.io>.
Yes there are plans to retire registry client in favor of shelling out “curl” as “libevent” dependency is not acceptable.
We can disable this test for now. Filed https://issues.apache.org/jira/browse/MESOS-4437 <https://issues.apache.org/jira/browse/MESOS-4437>.
-jojy
> On Jan 19, 2016, at 4:16 PM, Anand Mazumdar <an...@mesosphere.io> wrote:
>
> There were plans on retiring <https://issues.apache.org/jira/browse/MESOS-3807?focusedCommentId=15102780&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-15102780> the RegistryClient. Tim/Jojy might know more.
>
> -anand
>
>> On Jan 19, 2016, at 4:07 PM, Vinod Kone <vinodkone@apache.org <ma...@apache.org>> wrote:
>>
>> Triaged?
>>
>> On Mon, Jan 18, 2016 at 7:54 PM, Apache Jenkins Server <
>> jenkins@builds.apache.org <ma...@builds.apache.org>> wrote:
>>
>>> See <
>>> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1510/ <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1510/>
>>>>
>>>
>>> ------------------------------------------
>>> [...truncated 155782 lines...]
>>> I0119 03:54:15.963275 614 gc.cpp:54] Scheduling
>>> '/tmp/ContentType_SchedulerTest_Message_1_AGI2a2/slaves/7678655f-e955-41df-ba26-195e14c409bf-S0/frameworks/7678655f-e955-41df-ba26-195e14c409bf-0000'
>>> for gc 6.99998885171259days in the future
>>> I0119 03:54:15.963289 605 status_update_manager.cpp:282] Closing status
>>> update streams for framework 7678655f-e955-41df-ba26-195e14c409bf-0000
>>> I0119 03:54:15.963346 605 status_update_manager.cpp:528] Cleaning up
>>> status update stream for task 37f85f3d-0085-4547-96d1-7b80a4ffeae1 of
>>> framework 7678655f-e955-41df-ba26-195e14c409bf-0000
>>> [ OK ] ContentType/SchedulerTest.Message/1 (105 ms)
>>> [ RUN ] ContentType/SchedulerTest.Request/0
>>> I0119 03:54:15.970432 584 leveldb.cpp:174] Opened db in 2.995285ms
>>> I0119 03:54:15.971763 584 leveldb.cpp:181] Compacted db in 1.299841ms
>>> I0119 03:54:15.971832 584 leveldb.cpp:196] Created db iterator in 22214ns
>>> I0119 03:54:15.971858 584 leveldb.cpp:202] Seeked to beginning of db in
>>> 2495ns
>>> I0119 03:54:15.971874 584 leveldb.cpp:271] Iterated through 0 keys in
>>> the db in 270ns
>>> I0119 03:54:15.971920 584 replica.cpp:779] Replica recovered with log
>>> positions 0 -> 0 with 1 holes and 0 unlearned
>>> I0119 03:54:15.972707 611 recover.cpp:447] Starting replica recovery
>>> I0119 03:54:15.973039 611 recover.cpp:473] Replica is in EMPTY status
>>> I0119 03:54:15.974478 607 replica.cpp:673] Replica in EMPTY status
>>> received a broadcasted recover request from (13728)@172.17.0.2:58576
>>> I0119 03:54:15.974839 609 recover.cpp:193] Received a recover response
>>> from a replica in EMPTY status
>>> I0119 03:54:15.975256 614 recover.cpp:564] Updating replica status to
>>> STARTING
>>> I0119 03:54:15.975889 607 leveldb.cpp:304] Persisting metadata (8 bytes)
>>> to leveldb took 494397ns
>>> I0119 03:54:15.975913 607 replica.cpp:320] Persisted replica status to
>>> STARTING
>>> I0119 03:54:15.976132 606 recover.cpp:473] Replica is in STARTING status
>>> I0119 03:54:15.977077 615 master.cpp:374] Master
>>> fb59cb4c-b913-4538-bd64-a91e957268c0 (e9534b118fc1) started on
>>> 172.17.0.2:58576
>>> I0119 03:54:15.977341 609 replica.cpp:673] Replica in STARTING status
>>> received a broadcasted recover request from (13729)@172.17.0.2:58576
>>> I0119 03:54:15.977115 615 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/6IvkuW/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/6IvkuW/master" --zk_session_timeout="10secs"
>>> I0119 03:54:15.977536 615 master.cpp:423] Master allowing
>>> unauthenticated frameworks to register
>>> I0119 03:54:15.977555 615 master.cpp:426] Master only allowing
>>> authenticated slaves to register
>>> I0119 03:54:15.977565 615 credentials.hpp:35] Loading credentials for
>>> authentication from '/tmp/6IvkuW/credentials'
>>> I0119 03:54:15.977572 606 recover.cpp:193] Received a recover response
>>> from a replica in STARTING status
>>> I0119 03:54:15.978005 616 recover.cpp:564] Updating replica status to
>>> VOTING
>>> I0119 03:54:15.978106 615 master.cpp:466] Using default 'crammd5'
>>> authenticator
>>> I0119 03:54:15.978309 615 master.cpp:535] Using default 'basic' HTTP
>>> authenticator
>>> I0119 03:54:15.978550 615 master.cpp:569] Authorization enabled
>>> I0119 03:54:15.978716 612 leveldb.cpp:304] Persisting metadata (8 bytes)
>>> to leveldb took 506700ns
>>> I0119 03:54:15.978742 612 replica.cpp:320] Persisted replica status to
>>> VOTING
>>> I0119 03:54:15.978790 617 hierarchical.cpp:145] Initialized hierarchical
>>> allocator process
>>> I0119 03:54:15.978837 611 recover.cpp:578] Successfully joined the Paxos
>>> group
>>> I0119 03:54:15.978793 603 whitelist_watcher.cpp:77] No whitelist given
>>> I0119 03:54:15.979058 611 recover.cpp:462] Recover process terminated
>>> I0119 03:54:15.980917 615 master.cpp:1710] The newly elected leader is
>>> master@172.17.0.2:58576 with id fb59cb4c-b913-4538-bd64-a91e957268c0
>>> I0119 03:54:15.980955 615 master.cpp:1723] Elected as the leading master!
>>> I0119 03:54:15.980976 615 master.cpp:1468] Recovering from registrar
>>> I0119 03:54:15.981158 613 registrar.cpp:307] Recovering registrar
>>> I0119 03:54:15.981987 610 log.cpp:659] Attempting to start the writer
>>> I0119 03:54:15.983471 615 replica.cpp:493] Replica received implicit
>>> promise request from (13731)@172.17.0.2:58576 with proposal 1
>>> I0119 03:54:15.984071 615 leveldb.cpp:304] Persisting metadata (8 bytes)
>>> to leveldb took 510103ns
>>> I0119 03:54:15.984098 615 replica.cpp:342] Persisted promised to 1
>>> I0119 03:54:15.984797 611 coordinator.cpp:238] Coordinator attempting to
>>> fill missing positions
>>> I0119 03:54:15.986280 608 replica.cpp:388] Replica received explicit
>>> promise request from (13732)@172.17.0.2:58576 for position 0 with
>>> proposal 2
>>> I0119 03:54:15.986778 608 leveldb.cpp:341] Persisting action (8 bytes)
>>> to leveldb took 452788ns
>>> I0119 03:54:15.986812 608 replica.cpp:712] Persisted action at 0
>>> I0119 03:54:15.987834 604 replica.cpp:537] Replica received write
>>> request for position 0 from (13733)@172.17.0.2:58576
>>> I0119 03:54:15.987902 604 leveldb.cpp:436] Reading position from leveldb
>>> took 29732ns
>>> I0119 03:54:15.988339 604 leveldb.cpp:341] Persisting action (14 bytes)
>>> to leveldb took 393079ns
>>> I0119 03:54:15.988363 604 replica.cpp:712] Persisted action at 0
>>> I0119 03:54:15.988880 616 replica.cpp:691] Replica received learned
>>> notice for position 0 from @0.0.0.0:0
>>> I0119 03:54:15.989300 616 leveldb.cpp:341] Persisting action (16 bytes)
>>> to leveldb took 388826ns
>>> I0119 03:54:15.989343 616 replica.cpp:712] Persisted action at 0
>>> I0119 03:54:15.989370 616 replica.cpp:697] Replica learned NOP action at
>>> position 0
>>> I0119 03:54:15.989960 615 log.cpp:675] Writer started with ending
>>> position 0
>>> I0119 03:54:15.990893 604 leveldb.cpp:436] Reading position from leveldb
>>> took 24925ns
>>> I0119 03:54:15.991757 615 registrar.cpp:340] Successfully fetched the
>>> registry (0B) in 10.560768ms
>>> I0119 03:54:15.991860 615 registrar.cpp:439] Applied 1 operations in
>>> 25294ns; attempting to update the 'registry'
>>> I0119 03:54:15.992504 608 log.cpp:683] Attempting to append 170 bytes to
>>> the log
>>> I0119 03:54:15.992607 611 coordinator.cpp:348] Coordinator attempting to
>>> write APPEND action at position 1
>>> I0119 03:54:15.993290 611 replica.cpp:537] Replica received write
>>> request for position 1 from (13734)@172.17.0.2:58576
>>> I0119 03:54:15.993960 611 leveldb.cpp:341] Persisting action (189 bytes)
>>> to leveldb took 635696ns
>>> I0119 03:54:15.993986 611 replica.cpp:712] Persisted action at 1
>>> I0119 03:54:15.994570 603 replica.cpp:691] Replica received learned
>>> notice for position 1 from @0.0.0.0:0
>>> I0119 03:54:15.995105 603 leveldb.cpp:341] Persisting action (191 bytes)
>>> to leveldb took 502805ns
>>> I0119 03:54:15.995131 603 replica.cpp:712] Persisted action at 1
>>> I0119 03:54:15.995154 603 replica.cpp:697] Replica learned APPEND action
>>> at position 1
>>> I0119 03:54:15.996042 616 registrar.cpp:484] Successfully updated the
>>> 'registry' in 4.10496ms
>>> I0119 03:54:15.996191 605 log.cpp:702] Attempting to truncate the log to
>>> 1
>>> I0119 03:54:15.996227 616 registrar.cpp:370] Successfully recovered
>>> registrar
>>> I0119 03:54:15.996340 608 coordinator.cpp:348] Coordinator attempting to
>>> write TRUNCATE action at position 2
>>> I0119 03:54:15.996835 611 master.cpp:1520] Recovered 0 slaves from the
>>> Registry (131B) ; allowing 10mins for slaves to re-register
>>> I0119 03:54:15.996891 610 hierarchical.cpp:172] Skipping recovery of
>>> hierarchical allocator: nothing to recover
>>> I0119 03:54:15.997540 616 replica.cpp:537] Replica received write
>>> request for position 2 from (13735)@172.17.0.2:58576
>>> I0119 03:54:15.998004 616 leveldb.cpp:341] Persisting action (16 bytes)
>>> to leveldb took 415111ns
>>> I0119 03:54:15.998036 616 replica.cpp:712] Persisted action at 2
>>> I0119 03:54:15.998867 603 replica.cpp:691] Replica received learned
>>> notice for position 2 from @0.0.0.0:0
>>> I0119 03:54:15.999300 603 leveldb.cpp:341] Persisting action (18 bytes)
>>> to leveldb took 394969ns
>>> I0119 03:54:15.999369 603 leveldb.cpp:399] Deleting ~1 keys from leveldb
>>> took 37402ns
>>> I0119 03:54:15.999420 603 replica.cpp:712] Persisted action at 2
>>> I0119 03:54:15.999450 603 replica.cpp:697] Replica learned TRUNCATE
>>> action at position 2
>>> I0119 03:54:16.007637 584 scheduler.cpp:154] Version: 0.27.0
>>> I0119 03:54:16.008211 615 scheduler.cpp:236] New master detected at
>>> master@172.17.0.2:58576
>>> I0119 03:54:16.009395 604 scheduler.cpp:298] Sending SUBSCRIBE call to
>>> master@172.17.0.2:58576
>>> I0119 03:54:16.010859 609 process.cpp:3141] Handling HTTP event for
>>> process 'master' with path: '/master/api/v1/scheduler'
>>> I0119 03:54:16.011354 603 http.cpp:504] HTTP POST for
>>> /master/api/v1/scheduler from 172.17.0.2:47437
>>> I0119 03:54:16.011570 603 master.cpp:1972] Received subscription request
>>> for HTTP framework 'default'
>>> I0119 03:54:16.011659 603 master.cpp:1749] Authorizing framework
>>> principal 'test-principal' to receive offers for role '*'
>>> I0119 03:54:16.012076 618 master.cpp:2063] Subscribing framework
>>> 'default' with checkpointing disabled and capabilities [ ]
>>> I0119 03:54:16.012480 605 hierarchical.cpp:266] Added framework
>>> fb59cb4c-b913-4538-bd64-a91e957268c0-0000
>>> I0119 03:54:16.012588 606 master.hpp:1658] Sending heartbeat to
>>> fb59cb4c-b913-4538-bd64-a91e957268c0-0000
>>> I0119 03:54:16.012811 605 hierarchical.cpp:1338] No resources available
>>> to allocate!
>>> I0119 03:54:16.012934 605 hierarchical.cpp:1432] No inverse offers to
>>> send out!
>>> I0119 03:54:16.012974 605 hierarchical.cpp:1086] Performed allocation
>>> for 0 slaves in 466306ns
>>> I0119 03:54:16.013468 605 scheduler.cpp:457] Enqueuing event SUBSCRIBED
>>> received from master@172.17.0.2:58576
>>> I0119 03:54:16.014047 605 scheduler.cpp:457] Enqueuing event HEARTBEAT
>>> received from master@172.17.0.2:58576
>>> I0119 03:54:16.014601 617 master_maintenance_tests.cpp:177] Ignoring
>>> HEARTBEAT event
>>> I0119 03:54:16.014767 611 scheduler.cpp:298] Sending REQUEST call to
>>> master@172.17.0.2:58576
>>> I0119 03:54:16.016019 607 process.cpp:3141] Handling HTTP event for
>>> process 'master' with path: '/master/api/v1/scheduler'
>>> I0119 03:54:16.016351 613 http.cpp:504] HTTP POST for
>>> /master/api/v1/scheduler from 172.17.0.2:47438
>>> I0119 03:54:16.016479 613 master.cpp:2717] Processing REQUEST call for
>>> framework fb59cb4c-b913-4538-bd64-a91e957268c0-0000 (default)
>>> I0119 03:54:16.016676 605 hierarchical.cpp:586] Received resource
>>> request from framework fb59cb4c-b913-4538-bd64-a91e957268c0-0000
>>> I0119 03:54:16.017801 616 master.cpp:1025] Master terminating
>>> I0119 03:54:16.018154 612 hierarchical.cpp:327] Removed framework
>>> fb59cb4c-b913-4538-bd64-a91e957268c0-0000
>>> E0119 03:54:16.018663 606 scheduler.cpp:431] End-Of-File received from
>>> master. The master closed the event stream
>>> [ OK ] ContentType/SchedulerTest.Request/0 (56 ms)
>>> [ RUN ] ContentType/SchedulerTest.Request/1
>>> I0119 03:54:16.027212 584 leveldb.cpp:174] Opened db in 2.849992ms
>>> I0119 03:54:16.028408 584 leveldb.cpp:181] Compacted db in 1.160916ms
>>> I0119 03:54:16.028460 584 leveldb.cpp:196] Created db iterator in 20127ns
>>> I0119 03:54:16.028476 584 leveldb.cpp:202] Seeked to beginning of db in
>>> 2454ns
>>> I0119 03:54:16.028484 584 leveldb.cpp:271] Iterated through 0 keys in
>>> the db in 233ns
>>> I0119 03:54:16.028522 584 replica.cpp:779] Replica recovered with log
>>> positions 0 -> 0 with 1 holes and 0 unlearned
>>> I0119 03:54:16.028892 605 recover.cpp:447] Starting replica recovery
>>> I0119 03:54:16.029139 603 recover.cpp:473] Replica is in EMPTY status
>>> I0119 03:54:16.030165 607 replica.cpp:673] Replica in EMPTY status
>>> received a broadcasted recover request from (13743)@172.17.0.2:58576
>>> I0119 03:54:16.030355 611 recover.cpp:193] Received a recover response
>>> from a replica in EMPTY status
>>> I0119 03:54:16.030779 616 recover.cpp:564] Updating replica status to
>>> STARTING
>>> I0119 03:54:16.031474 603 leveldb.cpp:304] Persisting metadata (8 bytes)
>>> to leveldb took 565191ns
>>> I0119 03:54:16.031500 603 replica.cpp:320] Persisted replica status to
>>> STARTING
>>> I0119 03:54:16.031533 611 master.cpp:374] Master
>>> 9e4cae84-cd80-417e-9023-17c0df61c980 (e9534b118fc1) started on
>>> 172.17.0.2:58576
>>> I0119 03:54:16.031836 604 recover.cpp:473] Replica is in STARTING status
>>> I0119 03:54:16.031551 611 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/k7UaaA/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/k7UaaA/master" --zk_session_timeout="10secs"
>>> I0119 03:54:16.032344 611 master.cpp:423] Master allowing
>>> unauthenticated frameworks to register
>>> I0119 03:54:16.032359 611 master.cpp:426] Master only allowing
>>> authenticated slaves to register
>>> I0119 03:54:16.032366 611 credentials.hpp:35] Loading credentials for
>>> authentication from '/tmp/k7UaaA/credentials'
>>> I0119 03:54:16.032655 611 master.cpp:466] Using default 'crammd5'
>>> authenticator
>>> I0119 03:54:16.032790 611 master.cpp:535] Using default 'basic' HTTP
>>> authenticator
>>> I0119 03:54:16.032995 610 replica.cpp:673] Replica in STARTING status
>>> received a broadcasted recover request from (13744)@172.17.0.2:58576
>>> I0119 03:54:16.033190 611 master.cpp:569] Authorization enabled
>>> I0119 03:54:16.033342 605 whitelist_watcher.cpp:77] No whitelist given
>>> I0119 03:54:16.033428 609 recover.cpp:193] Received a recover response
>>> from a replica in STARTING status
>>> I0119 03:54:16.033359 612 hierarchical.cpp:145] Initialized hierarchical
>>> allocator process
>>> I0119 03:54:16.033902 605 recover.cpp:564] Updating replica status to
>>> VOTING
>>> I0119 03:54:16.034526 615 leveldb.cpp:304] Persisting metadata (8 bytes)
>>> to leveldb took 403733ns
>>> I0119 03:54:16.034551 615 replica.cpp:320] Persisted replica status to
>>> VOTING
>>> I0119 03:54:16.034700 615 recover.cpp:578] Successfully joined the Paxos
>>> group
>>> I0119 03:54:16.035019 615 recover.cpp:462] Recover process terminated
>>> I0119 03:54:16.035284 613 master.cpp:1710] The newly elected leader is
>>> master@172.17.0.2:58576 with id 9e4cae84-cd80-417e-9023-17c0df61c980
>>> I0119 03:54:16.035312 613 master.cpp:1723] Elected as the leading master!
>>> I0119 03:54:16.035329 613 master.cpp:1468] Recovering from registrar
>>> I0119 03:54:16.035615 613 registrar.cpp:307] Recovering registrar
>>> I0119 03:54:16.036142 614 log.cpp:659] Attempting to start the writer
>>> I0119 03:54:16.037210 612 replica.cpp:493] Replica received implicit
>>> promise request from (13746)@172.17.0.2:58576 with proposal 1
>>> I0119 03:54:16.037678 612 leveldb.cpp:304] Persisting metadata (8 bytes)
>>> to leveldb took 438216ns
>>> I0119 03:54:16.037699 612 replica.cpp:342] Persisted promised to 1
>>> I0119 03:54:16.038236 617 coordinator.cpp:238] Coordinator attempting to
>>> fill missing positions
>>> I0119 03:54:16.039268 608 replica.cpp:388] Replica received explicit
>>> promise request from (13747)@172.17.0.2:58576 for position 0 with
>>> proposal 2
>>> I0119 03:54:16.039765 608 leveldb.cpp:341] Persisting action (8 bytes) to
>>> leveldb took 460710ns
>>> I0119 03:54:16.039789 608 replica.cpp:712] Persisted action at 0
>>> I0119 03:54:16.040910 605 replica.cpp:537] Replica received write
>>> request for position 0 from (13748)@172.17.0.2:58576
>>> I0119 03:54:16.040966 605 leveldb.cpp:436] Reading position from leveldb
>>> took 24855ns
>>> I0119 03:54:16.041483 605 leveldb.cpp:341] Persisting action (14 bytes)
>>> to leveldb took 475810ns
>>> I0119 03:54:16.041506 605 replica.cpp:712] Persisted action at 0
>>> I0119 03:54:16.042132 613 replica.cpp:691] Replica received learned
>>> notice for position 0 from @0.0.0.0:0
>>> I0119 03:54:16.042567 613 leveldb.cpp:341] Persisting action (16 bytes)
>>> to leveldb took 364219ns
>>> I0119 03:54:16.042592 613 replica.cpp:712] Persisted action at 0
>>> I0119 03:54:16.042615 613 replica.cpp:697] Replica learned NOP action at
>>> position 0
>>> I0119 03:54:16.043148 604 log.cpp:675] Writer started with ending
>>> position 0
>>> I0119 03:54:16.044085 612 leveldb.cpp:436] Reading position from leveldb
>>> took 25111ns
>>> I0119 03:54:16.044944 606 registrar.cpp:340] Successfully fetched the
>>> registry (0B) in 9.238016ms
>>> I0119 03:54:16.045040 606 registrar.cpp:439] Applied 1 operations in
>>> 22407ns; attempting to update the 'registry'
>>> I0119 03:54:16.045660 603 log.cpp:683] Attempting to append 170 bytes to
>>> the log
>>> I0119 03:54:16.045758 612 coordinator.cpp:348] Coordinator attempting to
>>> write APPEND action at position 1
>>> I0119 03:54:16.046370 610 replica.cpp:537] Replica received write
>>> request for position 1 from (13749)@172.17.0.2:58576
>>> I0119 03:54:16.046901 610 leveldb.cpp:341] Persisting action (189 bytes)
>>> to leveldb took 494178ns
>>> I0119 03:54:16.046928 610 replica.cpp:712] Persisted action at 1
>>> I0119 03:54:16.047449 617 replica.cpp:691] Replica received learned
>>> notice for position 1 from @0.0.0.0:0
>>> I0119 03:54:16.047951 617 leveldb.cpp:341] Persisting action (191 bytes)
>>> to leveldb took 471111ns
>>> I0119 03:54:16.047976 617 replica.cpp:712] Persisted action at 1
>>> I0119 03:54:16.047992 617 replica.cpp:697] Replica learned APPEND action
>>> at position 1
>>> I0119 03:54:16.048874 608 registrar.cpp:484] Successfully updated the
>>> 'registry' in 3.77984ms
>>> I0119 03:54:16.049008 608 registrar.cpp:370] Successfully recovered
>>> registrar
>>> I0119 03:54:16.049068 604 log.cpp:702] Attempting to truncate the log to
>>> 1
>>> I0119 03:54:16.049304 613 coordinator.cpp:348] Coordinator attempting to
>>> write TRUNCATE action at position 2
>>> I0119 03:54:16.049466 617 master.cpp:1520] Recovered 0 slaves from the
>>> Registry (131B) ; allowing 10mins for slaves to re-register
>>> I0119 03:54:16.049484 608 hierarchical.cpp:172] Skipping recovery of
>>> hierarchical allocator: nothing to recover
>>> I0119 03:54:16.050098 608 replica.cpp:537] Replica received write
>>> request for position 2 from (13750)@172.17.0.2:58576
>>> I0119 03:54:16.050616 608 leveldb.cpp:341] Persisting action (16 bytes)
>>> to leveldb took 485697ns
>>> I0119 03:54:16.050655 608 replica.cpp:712] Persisted action at 2
>>> I0119 03:54:16.051172 603 replica.cpp:691] Replica received learned
>>> notice for position 2 from @0.0.0.0:0
>>> I0119 03:54:16.051677 603 leveldb.cpp:341] Persisting action (18 bytes)
>>> to leveldb took 476640ns
>>> I0119 03:54:16.051730 603 leveldb.cpp:399] Deleting ~1 keys from leveldb
>>> took 29233ns
>>> I0119 03:54:16.051749 603 replica.cpp:712] Persisted action at 2
>>> I0119 03:54:16.051765 603 replica.cpp:697] Replica learned TRUNCATE
>>> action at position 2
>>> I0119 03:54:16.060142 584 scheduler.cpp:154] Version: 0.27.0
>>> I0119 03:54:16.060633 616 scheduler.cpp:236] New master detected at
>>> master@172.17.0.2:58576
>>> I0119 03:54:16.061568 618 scheduler.cpp:298] Sending SUBSCRIBE call to
>>> master@172.17.0.2:58576
>>> I0119 03:54:16.063071 613 process.cpp:3141] Handling HTTP event for
>>> process 'master' with path: '/master/api/v1/scheduler'
>>> I0119 03:54:16.063769 617 http.cpp:504] HTTP POST for
>>> /master/api/v1/scheduler from 172.17.0.2:47439
>>> I0119 03:54:16.064332 617 master.cpp:1972] Received subscription request
>>> for HTTP framework 'default'
>>> I0119 03:54:16.064409 617 master.cpp:1749] Authorizing framework
>>> principal 'test-principal' to receive offers for role '*'
>>> I0119 03:54:16.064921 617 master.cpp:2063] Subscribing framework
>>> 'default' with checkpointing disabled and capabilities [ ]
>>> I0119 03:54:16.065423 616 hierarchical.cpp:266] Added framework
>>> 9e4cae84-cd80-417e-9023-17c0df61c980-0000
>>> I0119 03:54:16.065512 616 hierarchical.cpp:1338] No resources available
>>> to allocate!
>>> I0119 03:54:16.065706 616 hierarchical.cpp:1432] No inverse offers to
>>> send out!
>>> I0119 03:54:16.065752 616 hierarchical.cpp:1086] Performed allocation
>>> for 0 slaves in 291452ns
>>> I0119 03:54:16.065575 617 master.hpp:1658] Sending heartbeat to
>>> 9e4cae84-cd80-417e-9023-17c0df61c980-0000
>>> I0119 03:54:16.066784 605 scheduler.cpp:457] Enqueuing event SUBSCRIBED
>>> received from master@172.17.0.2:58576
>>> I0119 03:54:16.067443 605 scheduler.cpp:457] Enqueuing event HEARTBEAT
>>> received from master@172.17.0.2:58576
>>> I0119 03:54:16.068357 608 master_maintenance_tests.cpp:177] Ignoring
>>> HEARTBEAT event
>>> I0119 03:54:16.068429 605 scheduler.cpp:298] Sending REQUEST call to
>>> master@172.17.0.2:58576
>>> I0119 03:54:16.070456 611 process.cpp:3141] Handling HTTP event for
>>> process 'master' with path: '/master/api/v1/scheduler'
>>> I0119 03:54:16.070973 618 http.cpp:504] HTTP POST for
>>> /master/api/v1/scheduler from 172.17.0.2:47440
>>> I0119 03:54:16.071233 618 master.cpp:2717] Processing REQUEST call for
>>> framework 9e4cae84-cd80-417e-9023-17c0df61c980-0000 (default)
>>> I0119 03:54:16.071413 616 hierarchical.cpp:586] Received resource
>>> request from framework 9e4cae84-cd80-417e-9023-17c0df61c980-0000
>>> I0119 03:54:16.071815 615 master.cpp:1025] Master terminating
>>> I0119 03:54:16.072069 614 hierarchical.cpp:327] Removed framework
>>> 9e4cae84-cd80-417e-9023-17c0df61c980-0000
>>> E0119 03:54:16.072808 611 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 (4230 ms total)
>>>
>>> [----------] Global test environment tear-down
>>> [==========] 936 tests from 124 test cases ran. (365291 ms total)
>>> [ PASSED ] 935 tests.
>>> [ FAILED ] 1 test, listed below:
>>> [ FAILED ] RegistryClientTest.BadTokenServerAddress
>>>
>>> 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-1453173700-14139
>>> Untagged: mesos-1453173700-14139:latest
>>> Deleted: 0a51ee31d2c9d2162ebdb2b4edfdf121b0609f23b7c0e058af2ebdeded159df3
>>> Deleted: 159902fd3cd813d739921248878ff6112c3db5f6982b6bc327fd3d216755fe4f
>>> Deleted: 6e75a3f470b092cefe1f2bdea3237ebedf334bb9a796e33ea0b7b9b19ed3509e
>>> Deleted: 5069f32cf1e5e9fdc37b26b8cdcbc4cbd9401030791223f185858f01b3222ffa
>>> Deleted: 8292d1ddfe903ad931c818421041f0d438e5d8a73531da2730e403919d088966
>>> Deleted: d908aaece37dcb54b82194fc0564e45de9c770be2a7ee8fdf30389ff34bb37e1
>>> Deleted: 63b16639a71aa49c15189c44db06691fda94058ebeb6109f37df691c59c46d87
>>> Deleted: 1f5f93042fcbd496ae98584ffb5438844c406d5e156b58ccf6ce1e15ac1c8d0a
>>> Deleted: 6e4f96cc81026dd197d3d95695982d12f76bd0e1f307679c63d0e8f994393ba6
>>> Deleted: 46b4b9411ddfac92fe3fd6e2b24b4acf5e13575bde9e6f6a5fbc9292b4cd1c6c
>>> Deleted: af347bb96b8f75ddc9fb0324669c42dae1d5fb19620eeda449fcd17fbf13c2a8
>>> Deleted: 39b6adce48404bb2c3014fb6b503b5564bede054489bdb3dbdb0285598ecbbf9
>>> Deleted: 9cca66c8060958bdb9a551a7e67763bc9459004697f7348a5ab7e6609145dd91
>>> Deleted: 8805a1d47dc4ea3416b0fa1ebfa0ce98f71021236d2e757b41b5be176992228c
>>> Build step 'Execute shell' marked build as failure
>>>
>
Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1510
Posted by Anand Mazumdar <an...@mesosphere.io>.
There were plans on retiring <https://issues.apache.org/jira/browse/MESOS-3807?focusedCommentId=15102780&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-15102780> the RegistryClient. Tim/Jojy might know more.
-anand
> On Jan 19, 2016, at 4:07 PM, Vinod Kone <vi...@apache.org> wrote:
>
> Triaged?
>
> On Mon, Jan 18, 2016 at 7:54 PM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
>> See <
>> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1510/
>>>
>>
>> ------------------------------------------
>> [...truncated 155782 lines...]
>> I0119 03:54:15.963275 614 gc.cpp:54] Scheduling
>> '/tmp/ContentType_SchedulerTest_Message_1_AGI2a2/slaves/7678655f-e955-41df-ba26-195e14c409bf-S0/frameworks/7678655f-e955-41df-ba26-195e14c409bf-0000'
>> for gc 6.99998885171259days in the future
>> I0119 03:54:15.963289 605 status_update_manager.cpp:282] Closing status
>> update streams for framework 7678655f-e955-41df-ba26-195e14c409bf-0000
>> I0119 03:54:15.963346 605 status_update_manager.cpp:528] Cleaning up
>> status update stream for task 37f85f3d-0085-4547-96d1-7b80a4ffeae1 of
>> framework 7678655f-e955-41df-ba26-195e14c409bf-0000
>> [ OK ] ContentType/SchedulerTest.Message/1 (105 ms)
>> [ RUN ] ContentType/SchedulerTest.Request/0
>> I0119 03:54:15.970432 584 leveldb.cpp:174] Opened db in 2.995285ms
>> I0119 03:54:15.971763 584 leveldb.cpp:181] Compacted db in 1.299841ms
>> I0119 03:54:15.971832 584 leveldb.cpp:196] Created db iterator in 22214ns
>> I0119 03:54:15.971858 584 leveldb.cpp:202] Seeked to beginning of db in
>> 2495ns
>> I0119 03:54:15.971874 584 leveldb.cpp:271] Iterated through 0 keys in
>> the db in 270ns
>> I0119 03:54:15.971920 584 replica.cpp:779] Replica recovered with log
>> positions 0 -> 0 with 1 holes and 0 unlearned
>> I0119 03:54:15.972707 611 recover.cpp:447] Starting replica recovery
>> I0119 03:54:15.973039 611 recover.cpp:473] Replica is in EMPTY status
>> I0119 03:54:15.974478 607 replica.cpp:673] Replica in EMPTY status
>> received a broadcasted recover request from (13728)@172.17.0.2:58576
>> I0119 03:54:15.974839 609 recover.cpp:193] Received a recover response
>> from a replica in EMPTY status
>> I0119 03:54:15.975256 614 recover.cpp:564] Updating replica status to
>> STARTING
>> I0119 03:54:15.975889 607 leveldb.cpp:304] Persisting metadata (8 bytes)
>> to leveldb took 494397ns
>> I0119 03:54:15.975913 607 replica.cpp:320] Persisted replica status to
>> STARTING
>> I0119 03:54:15.976132 606 recover.cpp:473] Replica is in STARTING status
>> I0119 03:54:15.977077 615 master.cpp:374] Master
>> fb59cb4c-b913-4538-bd64-a91e957268c0 (e9534b118fc1) started on
>> 172.17.0.2:58576
>> I0119 03:54:15.977341 609 replica.cpp:673] Replica in STARTING status
>> received a broadcasted recover request from (13729)@172.17.0.2:58576
>> I0119 03:54:15.977115 615 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/6IvkuW/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/6IvkuW/master" --zk_session_timeout="10secs"
>> I0119 03:54:15.977536 615 master.cpp:423] Master allowing
>> unauthenticated frameworks to register
>> I0119 03:54:15.977555 615 master.cpp:426] Master only allowing
>> authenticated slaves to register
>> I0119 03:54:15.977565 615 credentials.hpp:35] Loading credentials for
>> authentication from '/tmp/6IvkuW/credentials'
>> I0119 03:54:15.977572 606 recover.cpp:193] Received a recover response
>> from a replica in STARTING status
>> I0119 03:54:15.978005 616 recover.cpp:564] Updating replica status to
>> VOTING
>> I0119 03:54:15.978106 615 master.cpp:466] Using default 'crammd5'
>> authenticator
>> I0119 03:54:15.978309 615 master.cpp:535] Using default 'basic' HTTP
>> authenticator
>> I0119 03:54:15.978550 615 master.cpp:569] Authorization enabled
>> I0119 03:54:15.978716 612 leveldb.cpp:304] Persisting metadata (8 bytes)
>> to leveldb took 506700ns
>> I0119 03:54:15.978742 612 replica.cpp:320] Persisted replica status to
>> VOTING
>> I0119 03:54:15.978790 617 hierarchical.cpp:145] Initialized hierarchical
>> allocator process
>> I0119 03:54:15.978837 611 recover.cpp:578] Successfully joined the Paxos
>> group
>> I0119 03:54:15.978793 603 whitelist_watcher.cpp:77] No whitelist given
>> I0119 03:54:15.979058 611 recover.cpp:462] Recover process terminated
>> I0119 03:54:15.980917 615 master.cpp:1710] The newly elected leader is
>> master@172.17.0.2:58576 with id fb59cb4c-b913-4538-bd64-a91e957268c0
>> I0119 03:54:15.980955 615 master.cpp:1723] Elected as the leading master!
>> I0119 03:54:15.980976 615 master.cpp:1468] Recovering from registrar
>> I0119 03:54:15.981158 613 registrar.cpp:307] Recovering registrar
>> I0119 03:54:15.981987 610 log.cpp:659] Attempting to start the writer
>> I0119 03:54:15.983471 615 replica.cpp:493] Replica received implicit
>> promise request from (13731)@172.17.0.2:58576 with proposal 1
>> I0119 03:54:15.984071 615 leveldb.cpp:304] Persisting metadata (8 bytes)
>> to leveldb took 510103ns
>> I0119 03:54:15.984098 615 replica.cpp:342] Persisted promised to 1
>> I0119 03:54:15.984797 611 coordinator.cpp:238] Coordinator attempting to
>> fill missing positions
>> I0119 03:54:15.986280 608 replica.cpp:388] Replica received explicit
>> promise request from (13732)@172.17.0.2:58576 for position 0 with
>> proposal 2
>> I0119 03:54:15.986778 608 leveldb.cpp:341] Persisting action (8 bytes)
>> to leveldb took 452788ns
>> I0119 03:54:15.986812 608 replica.cpp:712] Persisted action at 0
>> I0119 03:54:15.987834 604 replica.cpp:537] Replica received write
>> request for position 0 from (13733)@172.17.0.2:58576
>> I0119 03:54:15.987902 604 leveldb.cpp:436] Reading position from leveldb
>> took 29732ns
>> I0119 03:54:15.988339 604 leveldb.cpp:341] Persisting action (14 bytes)
>> to leveldb took 393079ns
>> I0119 03:54:15.988363 604 replica.cpp:712] Persisted action at 0
>> I0119 03:54:15.988880 616 replica.cpp:691] Replica received learned
>> notice for position 0 from @0.0.0.0:0
>> I0119 03:54:15.989300 616 leveldb.cpp:341] Persisting action (16 bytes)
>> to leveldb took 388826ns
>> I0119 03:54:15.989343 616 replica.cpp:712] Persisted action at 0
>> I0119 03:54:15.989370 616 replica.cpp:697] Replica learned NOP action at
>> position 0
>> I0119 03:54:15.989960 615 log.cpp:675] Writer started with ending
>> position 0
>> I0119 03:54:15.990893 604 leveldb.cpp:436] Reading position from leveldb
>> took 24925ns
>> I0119 03:54:15.991757 615 registrar.cpp:340] Successfully fetched the
>> registry (0B) in 10.560768ms
>> I0119 03:54:15.991860 615 registrar.cpp:439] Applied 1 operations in
>> 25294ns; attempting to update the 'registry'
>> I0119 03:54:15.992504 608 log.cpp:683] Attempting to append 170 bytes to
>> the log
>> I0119 03:54:15.992607 611 coordinator.cpp:348] Coordinator attempting to
>> write APPEND action at position 1
>> I0119 03:54:15.993290 611 replica.cpp:537] Replica received write
>> request for position 1 from (13734)@172.17.0.2:58576
>> I0119 03:54:15.993960 611 leveldb.cpp:341] Persisting action (189 bytes)
>> to leveldb took 635696ns
>> I0119 03:54:15.993986 611 replica.cpp:712] Persisted action at 1
>> I0119 03:54:15.994570 603 replica.cpp:691] Replica received learned
>> notice for position 1 from @0.0.0.0:0
>> I0119 03:54:15.995105 603 leveldb.cpp:341] Persisting action (191 bytes)
>> to leveldb took 502805ns
>> I0119 03:54:15.995131 603 replica.cpp:712] Persisted action at 1
>> I0119 03:54:15.995154 603 replica.cpp:697] Replica learned APPEND action
>> at position 1
>> I0119 03:54:15.996042 616 registrar.cpp:484] Successfully updated the
>> 'registry' in 4.10496ms
>> I0119 03:54:15.996191 605 log.cpp:702] Attempting to truncate the log to
>> 1
>> I0119 03:54:15.996227 616 registrar.cpp:370] Successfully recovered
>> registrar
>> I0119 03:54:15.996340 608 coordinator.cpp:348] Coordinator attempting to
>> write TRUNCATE action at position 2
>> I0119 03:54:15.996835 611 master.cpp:1520] Recovered 0 slaves from the
>> Registry (131B) ; allowing 10mins for slaves to re-register
>> I0119 03:54:15.996891 610 hierarchical.cpp:172] Skipping recovery of
>> hierarchical allocator: nothing to recover
>> I0119 03:54:15.997540 616 replica.cpp:537] Replica received write
>> request for position 2 from (13735)@172.17.0.2:58576
>> I0119 03:54:15.998004 616 leveldb.cpp:341] Persisting action (16 bytes)
>> to leveldb took 415111ns
>> I0119 03:54:15.998036 616 replica.cpp:712] Persisted action at 2
>> I0119 03:54:15.998867 603 replica.cpp:691] Replica received learned
>> notice for position 2 from @0.0.0.0:0
>> I0119 03:54:15.999300 603 leveldb.cpp:341] Persisting action (18 bytes)
>> to leveldb took 394969ns
>> I0119 03:54:15.999369 603 leveldb.cpp:399] Deleting ~1 keys from leveldb
>> took 37402ns
>> I0119 03:54:15.999420 603 replica.cpp:712] Persisted action at 2
>> I0119 03:54:15.999450 603 replica.cpp:697] Replica learned TRUNCATE
>> action at position 2
>> I0119 03:54:16.007637 584 scheduler.cpp:154] Version: 0.27.0
>> I0119 03:54:16.008211 615 scheduler.cpp:236] New master detected at
>> master@172.17.0.2:58576
>> I0119 03:54:16.009395 604 scheduler.cpp:298] Sending SUBSCRIBE call to
>> master@172.17.0.2:58576
>> I0119 03:54:16.010859 609 process.cpp:3141] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I0119 03:54:16.011354 603 http.cpp:504] HTTP POST for
>> /master/api/v1/scheduler from 172.17.0.2:47437
>> I0119 03:54:16.011570 603 master.cpp:1972] Received subscription request
>> for HTTP framework 'default'
>> I0119 03:54:16.011659 603 master.cpp:1749] Authorizing framework
>> principal 'test-principal' to receive offers for role '*'
>> I0119 03:54:16.012076 618 master.cpp:2063] Subscribing framework
>> 'default' with checkpointing disabled and capabilities [ ]
>> I0119 03:54:16.012480 605 hierarchical.cpp:266] Added framework
>> fb59cb4c-b913-4538-bd64-a91e957268c0-0000
>> I0119 03:54:16.012588 606 master.hpp:1658] Sending heartbeat to
>> fb59cb4c-b913-4538-bd64-a91e957268c0-0000
>> I0119 03:54:16.012811 605 hierarchical.cpp:1338] No resources available
>> to allocate!
>> I0119 03:54:16.012934 605 hierarchical.cpp:1432] No inverse offers to
>> send out!
>> I0119 03:54:16.012974 605 hierarchical.cpp:1086] Performed allocation
>> for 0 slaves in 466306ns
>> I0119 03:54:16.013468 605 scheduler.cpp:457] Enqueuing event SUBSCRIBED
>> received from master@172.17.0.2:58576
>> I0119 03:54:16.014047 605 scheduler.cpp:457] Enqueuing event HEARTBEAT
>> received from master@172.17.0.2:58576
>> I0119 03:54:16.014601 617 master_maintenance_tests.cpp:177] Ignoring
>> HEARTBEAT event
>> I0119 03:54:16.014767 611 scheduler.cpp:298] Sending REQUEST call to
>> master@172.17.0.2:58576
>> I0119 03:54:16.016019 607 process.cpp:3141] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I0119 03:54:16.016351 613 http.cpp:504] HTTP POST for
>> /master/api/v1/scheduler from 172.17.0.2:47438
>> I0119 03:54:16.016479 613 master.cpp:2717] Processing REQUEST call for
>> framework fb59cb4c-b913-4538-bd64-a91e957268c0-0000 (default)
>> I0119 03:54:16.016676 605 hierarchical.cpp:586] Received resource
>> request from framework fb59cb4c-b913-4538-bd64-a91e957268c0-0000
>> I0119 03:54:16.017801 616 master.cpp:1025] Master terminating
>> I0119 03:54:16.018154 612 hierarchical.cpp:327] Removed framework
>> fb59cb4c-b913-4538-bd64-a91e957268c0-0000
>> E0119 03:54:16.018663 606 scheduler.cpp:431] End-Of-File received from
>> master. The master closed the event stream
>> [ OK ] ContentType/SchedulerTest.Request/0 (56 ms)
>> [ RUN ] ContentType/SchedulerTest.Request/1
>> I0119 03:54:16.027212 584 leveldb.cpp:174] Opened db in 2.849992ms
>> I0119 03:54:16.028408 584 leveldb.cpp:181] Compacted db in 1.160916ms
>> I0119 03:54:16.028460 584 leveldb.cpp:196] Created db iterator in 20127ns
>> I0119 03:54:16.028476 584 leveldb.cpp:202] Seeked to beginning of db in
>> 2454ns
>> I0119 03:54:16.028484 584 leveldb.cpp:271] Iterated through 0 keys in
>> the db in 233ns
>> I0119 03:54:16.028522 584 replica.cpp:779] Replica recovered with log
>> positions 0 -> 0 with 1 holes and 0 unlearned
>> I0119 03:54:16.028892 605 recover.cpp:447] Starting replica recovery
>> I0119 03:54:16.029139 603 recover.cpp:473] Replica is in EMPTY status
>> I0119 03:54:16.030165 607 replica.cpp:673] Replica in EMPTY status
>> received a broadcasted recover request from (13743)@172.17.0.2:58576
>> I0119 03:54:16.030355 611 recover.cpp:193] Received a recover response
>> from a replica in EMPTY status
>> I0119 03:54:16.030779 616 recover.cpp:564] Updating replica status to
>> STARTING
>> I0119 03:54:16.031474 603 leveldb.cpp:304] Persisting metadata (8 bytes)
>> to leveldb took 565191ns
>> I0119 03:54:16.031500 603 replica.cpp:320] Persisted replica status to
>> STARTING
>> I0119 03:54:16.031533 611 master.cpp:374] Master
>> 9e4cae84-cd80-417e-9023-17c0df61c980 (e9534b118fc1) started on
>> 172.17.0.2:58576
>> I0119 03:54:16.031836 604 recover.cpp:473] Replica is in STARTING status
>> I0119 03:54:16.031551 611 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/k7UaaA/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/k7UaaA/master" --zk_session_timeout="10secs"
>> I0119 03:54:16.032344 611 master.cpp:423] Master allowing
>> unauthenticated frameworks to register
>> I0119 03:54:16.032359 611 master.cpp:426] Master only allowing
>> authenticated slaves to register
>> I0119 03:54:16.032366 611 credentials.hpp:35] Loading credentials for
>> authentication from '/tmp/k7UaaA/credentials'
>> I0119 03:54:16.032655 611 master.cpp:466] Using default 'crammd5'
>> authenticator
>> I0119 03:54:16.032790 611 master.cpp:535] Using default 'basic' HTTP
>> authenticator
>> I0119 03:54:16.032995 610 replica.cpp:673] Replica in STARTING status
>> received a broadcasted recover request from (13744)@172.17.0.2:58576
>> I0119 03:54:16.033190 611 master.cpp:569] Authorization enabled
>> I0119 03:54:16.033342 605 whitelist_watcher.cpp:77] No whitelist given
>> I0119 03:54:16.033428 609 recover.cpp:193] Received a recover response
>> from a replica in STARTING status
>> I0119 03:54:16.033359 612 hierarchical.cpp:145] Initialized hierarchical
>> allocator process
>> I0119 03:54:16.033902 605 recover.cpp:564] Updating replica status to
>> VOTING
>> I0119 03:54:16.034526 615 leveldb.cpp:304] Persisting metadata (8 bytes)
>> to leveldb took 403733ns
>> I0119 03:54:16.034551 615 replica.cpp:320] Persisted replica status to
>> VOTING
>> I0119 03:54:16.034700 615 recover.cpp:578] Successfully joined the Paxos
>> group
>> I0119 03:54:16.035019 615 recover.cpp:462] Recover process terminated
>> I0119 03:54:16.035284 613 master.cpp:1710] The newly elected leader is
>> master@172.17.0.2:58576 with id 9e4cae84-cd80-417e-9023-17c0df61c980
>> I0119 03:54:16.035312 613 master.cpp:1723] Elected as the leading master!
>> I0119 03:54:16.035329 613 master.cpp:1468] Recovering from registrar
>> I0119 03:54:16.035615 613 registrar.cpp:307] Recovering registrar
>> I0119 03:54:16.036142 614 log.cpp:659] Attempting to start the writer
>> I0119 03:54:16.037210 612 replica.cpp:493] Replica received implicit
>> promise request from (13746)@172.17.0.2:58576 with proposal 1
>> I0119 03:54:16.037678 612 leveldb.cpp:304] Persisting metadata (8 bytes)
>> to leveldb took 438216ns
>> I0119 03:54:16.037699 612 replica.cpp:342] Persisted promised to 1
>> I0119 03:54:16.038236 617 coordinator.cpp:238] Coordinator attempting to
>> fill missing positions
>> I0119 03:54:16.039268 608 replica.cpp:388] Replica received explicit
>> promise request from (13747)@172.17.0.2:58576 for position 0 with
>> proposal 2
>> I0119 03:54:16.039765 608 leveldb.cpp:341] Persisting action (8 bytes) to
>> leveldb took 460710ns
>> I0119 03:54:16.039789 608 replica.cpp:712] Persisted action at 0
>> I0119 03:54:16.040910 605 replica.cpp:537] Replica received write
>> request for position 0 from (13748)@172.17.0.2:58576
>> I0119 03:54:16.040966 605 leveldb.cpp:436] Reading position from leveldb
>> took 24855ns
>> I0119 03:54:16.041483 605 leveldb.cpp:341] Persisting action (14 bytes)
>> to leveldb took 475810ns
>> I0119 03:54:16.041506 605 replica.cpp:712] Persisted action at 0
>> I0119 03:54:16.042132 613 replica.cpp:691] Replica received learned
>> notice for position 0 from @0.0.0.0:0
>> I0119 03:54:16.042567 613 leveldb.cpp:341] Persisting action (16 bytes)
>> to leveldb took 364219ns
>> I0119 03:54:16.042592 613 replica.cpp:712] Persisted action at 0
>> I0119 03:54:16.042615 613 replica.cpp:697] Replica learned NOP action at
>> position 0
>> I0119 03:54:16.043148 604 log.cpp:675] Writer started with ending
>> position 0
>> I0119 03:54:16.044085 612 leveldb.cpp:436] Reading position from leveldb
>> took 25111ns
>> I0119 03:54:16.044944 606 registrar.cpp:340] Successfully fetched the
>> registry (0B) in 9.238016ms
>> I0119 03:54:16.045040 606 registrar.cpp:439] Applied 1 operations in
>> 22407ns; attempting to update the 'registry'
>> I0119 03:54:16.045660 603 log.cpp:683] Attempting to append 170 bytes to
>> the log
>> I0119 03:54:16.045758 612 coordinator.cpp:348] Coordinator attempting to
>> write APPEND action at position 1
>> I0119 03:54:16.046370 610 replica.cpp:537] Replica received write
>> request for position 1 from (13749)@172.17.0.2:58576
>> I0119 03:54:16.046901 610 leveldb.cpp:341] Persisting action (189 bytes)
>> to leveldb took 494178ns
>> I0119 03:54:16.046928 610 replica.cpp:712] Persisted action at 1
>> I0119 03:54:16.047449 617 replica.cpp:691] Replica received learned
>> notice for position 1 from @0.0.0.0:0
>> I0119 03:54:16.047951 617 leveldb.cpp:341] Persisting action (191 bytes)
>> to leveldb took 471111ns
>> I0119 03:54:16.047976 617 replica.cpp:712] Persisted action at 1
>> I0119 03:54:16.047992 617 replica.cpp:697] Replica learned APPEND action
>> at position 1
>> I0119 03:54:16.048874 608 registrar.cpp:484] Successfully updated the
>> 'registry' in 3.77984ms
>> I0119 03:54:16.049008 608 registrar.cpp:370] Successfully recovered
>> registrar
>> I0119 03:54:16.049068 604 log.cpp:702] Attempting to truncate the log to
>> 1
>> I0119 03:54:16.049304 613 coordinator.cpp:348] Coordinator attempting to
>> write TRUNCATE action at position 2
>> I0119 03:54:16.049466 617 master.cpp:1520] Recovered 0 slaves from the
>> Registry (131B) ; allowing 10mins for slaves to re-register
>> I0119 03:54:16.049484 608 hierarchical.cpp:172] Skipping recovery of
>> hierarchical allocator: nothing to recover
>> I0119 03:54:16.050098 608 replica.cpp:537] Replica received write
>> request for position 2 from (13750)@172.17.0.2:58576
>> I0119 03:54:16.050616 608 leveldb.cpp:341] Persisting action (16 bytes)
>> to leveldb took 485697ns
>> I0119 03:54:16.050655 608 replica.cpp:712] Persisted action at 2
>> I0119 03:54:16.051172 603 replica.cpp:691] Replica received learned
>> notice for position 2 from @0.0.0.0:0
>> I0119 03:54:16.051677 603 leveldb.cpp:341] Persisting action (18 bytes)
>> to leveldb took 476640ns
>> I0119 03:54:16.051730 603 leveldb.cpp:399] Deleting ~1 keys from leveldb
>> took 29233ns
>> I0119 03:54:16.051749 603 replica.cpp:712] Persisted action at 2
>> I0119 03:54:16.051765 603 replica.cpp:697] Replica learned TRUNCATE
>> action at position 2
>> I0119 03:54:16.060142 584 scheduler.cpp:154] Version: 0.27.0
>> I0119 03:54:16.060633 616 scheduler.cpp:236] New master detected at
>> master@172.17.0.2:58576
>> I0119 03:54:16.061568 618 scheduler.cpp:298] Sending SUBSCRIBE call to
>> master@172.17.0.2:58576
>> I0119 03:54:16.063071 613 process.cpp:3141] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I0119 03:54:16.063769 617 http.cpp:504] HTTP POST for
>> /master/api/v1/scheduler from 172.17.0.2:47439
>> I0119 03:54:16.064332 617 master.cpp:1972] Received subscription request
>> for HTTP framework 'default'
>> I0119 03:54:16.064409 617 master.cpp:1749] Authorizing framework
>> principal 'test-principal' to receive offers for role '*'
>> I0119 03:54:16.064921 617 master.cpp:2063] Subscribing framework
>> 'default' with checkpointing disabled and capabilities [ ]
>> I0119 03:54:16.065423 616 hierarchical.cpp:266] Added framework
>> 9e4cae84-cd80-417e-9023-17c0df61c980-0000
>> I0119 03:54:16.065512 616 hierarchical.cpp:1338] No resources available
>> to allocate!
>> I0119 03:54:16.065706 616 hierarchical.cpp:1432] No inverse offers to
>> send out!
>> I0119 03:54:16.065752 616 hierarchical.cpp:1086] Performed allocation
>> for 0 slaves in 291452ns
>> I0119 03:54:16.065575 617 master.hpp:1658] Sending heartbeat to
>> 9e4cae84-cd80-417e-9023-17c0df61c980-0000
>> I0119 03:54:16.066784 605 scheduler.cpp:457] Enqueuing event SUBSCRIBED
>> received from master@172.17.0.2:58576
>> I0119 03:54:16.067443 605 scheduler.cpp:457] Enqueuing event HEARTBEAT
>> received from master@172.17.0.2:58576
>> I0119 03:54:16.068357 608 master_maintenance_tests.cpp:177] Ignoring
>> HEARTBEAT event
>> I0119 03:54:16.068429 605 scheduler.cpp:298] Sending REQUEST call to
>> master@172.17.0.2:58576
>> I0119 03:54:16.070456 611 process.cpp:3141] Handling HTTP event for
>> process 'master' with path: '/master/api/v1/scheduler'
>> I0119 03:54:16.070973 618 http.cpp:504] HTTP POST for
>> /master/api/v1/scheduler from 172.17.0.2:47440
>> I0119 03:54:16.071233 618 master.cpp:2717] Processing REQUEST call for
>> framework 9e4cae84-cd80-417e-9023-17c0df61c980-0000 (default)
>> I0119 03:54:16.071413 616 hierarchical.cpp:586] Received resource
>> request from framework 9e4cae84-cd80-417e-9023-17c0df61c980-0000
>> I0119 03:54:16.071815 615 master.cpp:1025] Master terminating
>> I0119 03:54:16.072069 614 hierarchical.cpp:327] Removed framework
>> 9e4cae84-cd80-417e-9023-17c0df61c980-0000
>> E0119 03:54:16.072808 611 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 (4230 ms total)
>>
>> [----------] Global test environment tear-down
>> [==========] 936 tests from 124 test cases ran. (365291 ms total)
>> [ PASSED ] 935 tests.
>> [ FAILED ] 1 test, listed below:
>> [ FAILED ] RegistryClientTest.BadTokenServerAddress
>>
>> 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-1453173700-14139
>> Untagged: mesos-1453173700-14139:latest
>> Deleted: 0a51ee31d2c9d2162ebdb2b4edfdf121b0609f23b7c0e058af2ebdeded159df3
>> Deleted: 159902fd3cd813d739921248878ff6112c3db5f6982b6bc327fd3d216755fe4f
>> Deleted: 6e75a3f470b092cefe1f2bdea3237ebedf334bb9a796e33ea0b7b9b19ed3509e
>> Deleted: 5069f32cf1e5e9fdc37b26b8cdcbc4cbd9401030791223f185858f01b3222ffa
>> Deleted: 8292d1ddfe903ad931c818421041f0d438e5d8a73531da2730e403919d088966
>> Deleted: d908aaece37dcb54b82194fc0564e45de9c770be2a7ee8fdf30389ff34bb37e1
>> Deleted: 63b16639a71aa49c15189c44db06691fda94058ebeb6109f37df691c59c46d87
>> Deleted: 1f5f93042fcbd496ae98584ffb5438844c406d5e156b58ccf6ce1e15ac1c8d0a
>> Deleted: 6e4f96cc81026dd197d3d95695982d12f76bd0e1f307679c63d0e8f994393ba6
>> Deleted: 46b4b9411ddfac92fe3fd6e2b24b4acf5e13575bde9e6f6a5fbc9292b4cd1c6c
>> Deleted: af347bb96b8f75ddc9fb0324669c42dae1d5fb19620eeda449fcd17fbf13c2a8
>> Deleted: 39b6adce48404bb2c3014fb6b503b5564bede054489bdb3dbdb0285598ecbbf9
>> Deleted: 9cca66c8060958bdb9a551a7e67763bc9459004697f7348a5ab7e6609145dd91
>> Deleted: 8805a1d47dc4ea3416b0fa1ebfa0ce98f71021236d2e757b41b5be176992228c
>> Build step 'Execute shell' marked build as failure
>>
Re: Build failed in Jenkins: Mesos » gcc,--verbose --enable-libevent --enable-ssl,ubuntu:14.04,docker||Hadoop #1510
Posted by Vinod Kone <vi...@apache.org>.
Triaged?
On Mon, Jan 18, 2016 at 7:54 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=ubuntu%3A14.04,label_exp=docker%7C%7CHadoop/1510/
> >
>
> ------------------------------------------
> [...truncated 155782 lines...]
> I0119 03:54:15.963275 614 gc.cpp:54] Scheduling
> '/tmp/ContentType_SchedulerTest_Message_1_AGI2a2/slaves/7678655f-e955-41df-ba26-195e14c409bf-S0/frameworks/7678655f-e955-41df-ba26-195e14c409bf-0000'
> for gc 6.99998885171259days in the future
> I0119 03:54:15.963289 605 status_update_manager.cpp:282] Closing status
> update streams for framework 7678655f-e955-41df-ba26-195e14c409bf-0000
> I0119 03:54:15.963346 605 status_update_manager.cpp:528] Cleaning up
> status update stream for task 37f85f3d-0085-4547-96d1-7b80a4ffeae1 of
> framework 7678655f-e955-41df-ba26-195e14c409bf-0000
> [ OK ] ContentType/SchedulerTest.Message/1 (105 ms)
> [ RUN ] ContentType/SchedulerTest.Request/0
> I0119 03:54:15.970432 584 leveldb.cpp:174] Opened db in 2.995285ms
> I0119 03:54:15.971763 584 leveldb.cpp:181] Compacted db in 1.299841ms
> I0119 03:54:15.971832 584 leveldb.cpp:196] Created db iterator in 22214ns
> I0119 03:54:15.971858 584 leveldb.cpp:202] Seeked to beginning of db in
> 2495ns
> I0119 03:54:15.971874 584 leveldb.cpp:271] Iterated through 0 keys in
> the db in 270ns
> I0119 03:54:15.971920 584 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0119 03:54:15.972707 611 recover.cpp:447] Starting replica recovery
> I0119 03:54:15.973039 611 recover.cpp:473] Replica is in EMPTY status
> I0119 03:54:15.974478 607 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13728)@172.17.0.2:58576
> I0119 03:54:15.974839 609 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0119 03:54:15.975256 614 recover.cpp:564] Updating replica status to
> STARTING
> I0119 03:54:15.975889 607 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 494397ns
> I0119 03:54:15.975913 607 replica.cpp:320] Persisted replica status to
> STARTING
> I0119 03:54:15.976132 606 recover.cpp:473] Replica is in STARTING status
> I0119 03:54:15.977077 615 master.cpp:374] Master
> fb59cb4c-b913-4538-bd64-a91e957268c0 (e9534b118fc1) started on
> 172.17.0.2:58576
> I0119 03:54:15.977341 609 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13729)@172.17.0.2:58576
> I0119 03:54:15.977115 615 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/6IvkuW/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/6IvkuW/master" --zk_session_timeout="10secs"
> I0119 03:54:15.977536 615 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0119 03:54:15.977555 615 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0119 03:54:15.977565 615 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/6IvkuW/credentials'
> I0119 03:54:15.977572 606 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0119 03:54:15.978005 616 recover.cpp:564] Updating replica status to
> VOTING
> I0119 03:54:15.978106 615 master.cpp:466] Using default 'crammd5'
> authenticator
> I0119 03:54:15.978309 615 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0119 03:54:15.978550 615 master.cpp:569] Authorization enabled
> I0119 03:54:15.978716 612 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 506700ns
> I0119 03:54:15.978742 612 replica.cpp:320] Persisted replica status to
> VOTING
> I0119 03:54:15.978790 617 hierarchical.cpp:145] Initialized hierarchical
> allocator process
> I0119 03:54:15.978837 611 recover.cpp:578] Successfully joined the Paxos
> group
> I0119 03:54:15.978793 603 whitelist_watcher.cpp:77] No whitelist given
> I0119 03:54:15.979058 611 recover.cpp:462] Recover process terminated
> I0119 03:54:15.980917 615 master.cpp:1710] The newly elected leader is
> master@172.17.0.2:58576 with id fb59cb4c-b913-4538-bd64-a91e957268c0
> I0119 03:54:15.980955 615 master.cpp:1723] Elected as the leading master!
> I0119 03:54:15.980976 615 master.cpp:1468] Recovering from registrar
> I0119 03:54:15.981158 613 registrar.cpp:307] Recovering registrar
> I0119 03:54:15.981987 610 log.cpp:659] Attempting to start the writer
> I0119 03:54:15.983471 615 replica.cpp:493] Replica received implicit
> promise request from (13731)@172.17.0.2:58576 with proposal 1
> I0119 03:54:15.984071 615 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 510103ns
> I0119 03:54:15.984098 615 replica.cpp:342] Persisted promised to 1
> I0119 03:54:15.984797 611 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0119 03:54:15.986280 608 replica.cpp:388] Replica received explicit
> promise request from (13732)@172.17.0.2:58576 for position 0 with
> proposal 2
> I0119 03:54:15.986778 608 leveldb.cpp:341] Persisting action (8 bytes)
> to leveldb took 452788ns
> I0119 03:54:15.986812 608 replica.cpp:712] Persisted action at 0
> I0119 03:54:15.987834 604 replica.cpp:537] Replica received write
> request for position 0 from (13733)@172.17.0.2:58576
> I0119 03:54:15.987902 604 leveldb.cpp:436] Reading position from leveldb
> took 29732ns
> I0119 03:54:15.988339 604 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 393079ns
> I0119 03:54:15.988363 604 replica.cpp:712] Persisted action at 0
> I0119 03:54:15.988880 616 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0119 03:54:15.989300 616 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 388826ns
> I0119 03:54:15.989343 616 replica.cpp:712] Persisted action at 0
> I0119 03:54:15.989370 616 replica.cpp:697] Replica learned NOP action at
> position 0
> I0119 03:54:15.989960 615 log.cpp:675] Writer started with ending
> position 0
> I0119 03:54:15.990893 604 leveldb.cpp:436] Reading position from leveldb
> took 24925ns
> I0119 03:54:15.991757 615 registrar.cpp:340] Successfully fetched the
> registry (0B) in 10.560768ms
> I0119 03:54:15.991860 615 registrar.cpp:439] Applied 1 operations in
> 25294ns; attempting to update the 'registry'
> I0119 03:54:15.992504 608 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0119 03:54:15.992607 611 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0119 03:54:15.993290 611 replica.cpp:537] Replica received write
> request for position 1 from (13734)@172.17.0.2:58576
> I0119 03:54:15.993960 611 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 635696ns
> I0119 03:54:15.993986 611 replica.cpp:712] Persisted action at 1
> I0119 03:54:15.994570 603 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0119 03:54:15.995105 603 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 502805ns
> I0119 03:54:15.995131 603 replica.cpp:712] Persisted action at 1
> I0119 03:54:15.995154 603 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0119 03:54:15.996042 616 registrar.cpp:484] Successfully updated the
> 'registry' in 4.10496ms
> I0119 03:54:15.996191 605 log.cpp:702] Attempting to truncate the log to
> 1
> I0119 03:54:15.996227 616 registrar.cpp:370] Successfully recovered
> registrar
> I0119 03:54:15.996340 608 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0119 03:54:15.996835 611 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0119 03:54:15.996891 610 hierarchical.cpp:172] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0119 03:54:15.997540 616 replica.cpp:537] Replica received write
> request for position 2 from (13735)@172.17.0.2:58576
> I0119 03:54:15.998004 616 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 415111ns
> I0119 03:54:15.998036 616 replica.cpp:712] Persisted action at 2
> I0119 03:54:15.998867 603 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0119 03:54:15.999300 603 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 394969ns
> I0119 03:54:15.999369 603 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 37402ns
> I0119 03:54:15.999420 603 replica.cpp:712] Persisted action at 2
> I0119 03:54:15.999450 603 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0119 03:54:16.007637 584 scheduler.cpp:154] Version: 0.27.0
> I0119 03:54:16.008211 615 scheduler.cpp:236] New master detected at
> master@172.17.0.2:58576
> I0119 03:54:16.009395 604 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.2:58576
> I0119 03:54:16.010859 609 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0119 03:54:16.011354 603 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:47437
> I0119 03:54:16.011570 603 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0119 03:54:16.011659 603 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0119 03:54:16.012076 618 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0119 03:54:16.012480 605 hierarchical.cpp:266] Added framework
> fb59cb4c-b913-4538-bd64-a91e957268c0-0000
> I0119 03:54:16.012588 606 master.hpp:1658] Sending heartbeat to
> fb59cb4c-b913-4538-bd64-a91e957268c0-0000
> I0119 03:54:16.012811 605 hierarchical.cpp:1338] No resources available
> to allocate!
> I0119 03:54:16.012934 605 hierarchical.cpp:1432] No inverse offers to
> send out!
> I0119 03:54:16.012974 605 hierarchical.cpp:1086] Performed allocation
> for 0 slaves in 466306ns
> I0119 03:54:16.013468 605 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.2:58576
> I0119 03:54:16.014047 605 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.2:58576
> I0119 03:54:16.014601 617 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0119 03:54:16.014767 611 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.2:58576
> I0119 03:54:16.016019 607 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0119 03:54:16.016351 613 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:47438
> I0119 03:54:16.016479 613 master.cpp:2717] Processing REQUEST call for
> framework fb59cb4c-b913-4538-bd64-a91e957268c0-0000 (default)
> I0119 03:54:16.016676 605 hierarchical.cpp:586] Received resource
> request from framework fb59cb4c-b913-4538-bd64-a91e957268c0-0000
> I0119 03:54:16.017801 616 master.cpp:1025] Master terminating
> I0119 03:54:16.018154 612 hierarchical.cpp:327] Removed framework
> fb59cb4c-b913-4538-bd64-a91e957268c0-0000
> E0119 03:54:16.018663 606 scheduler.cpp:431] End-Of-File received from
> master. The master closed the event stream
> [ OK ] ContentType/SchedulerTest.Request/0 (56 ms)
> [ RUN ] ContentType/SchedulerTest.Request/1
> I0119 03:54:16.027212 584 leveldb.cpp:174] Opened db in 2.849992ms
> I0119 03:54:16.028408 584 leveldb.cpp:181] Compacted db in 1.160916ms
> I0119 03:54:16.028460 584 leveldb.cpp:196] Created db iterator in 20127ns
> I0119 03:54:16.028476 584 leveldb.cpp:202] Seeked to beginning of db in
> 2454ns
> I0119 03:54:16.028484 584 leveldb.cpp:271] Iterated through 0 keys in
> the db in 233ns
> I0119 03:54:16.028522 584 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0119 03:54:16.028892 605 recover.cpp:447] Starting replica recovery
> I0119 03:54:16.029139 603 recover.cpp:473] Replica is in EMPTY status
> I0119 03:54:16.030165 607 replica.cpp:673] Replica in EMPTY status
> received a broadcasted recover request from (13743)@172.17.0.2:58576
> I0119 03:54:16.030355 611 recover.cpp:193] Received a recover response
> from a replica in EMPTY status
> I0119 03:54:16.030779 616 recover.cpp:564] Updating replica status to
> STARTING
> I0119 03:54:16.031474 603 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 565191ns
> I0119 03:54:16.031500 603 replica.cpp:320] Persisted replica status to
> STARTING
> I0119 03:54:16.031533 611 master.cpp:374] Master
> 9e4cae84-cd80-417e-9023-17c0df61c980 (e9534b118fc1) started on
> 172.17.0.2:58576
> I0119 03:54:16.031836 604 recover.cpp:473] Replica is in STARTING status
> I0119 03:54:16.031551 611 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/k7UaaA/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/k7UaaA/master" --zk_session_timeout="10secs"
> I0119 03:54:16.032344 611 master.cpp:423] Master allowing
> unauthenticated frameworks to register
> I0119 03:54:16.032359 611 master.cpp:426] Master only allowing
> authenticated slaves to register
> I0119 03:54:16.032366 611 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/k7UaaA/credentials'
> I0119 03:54:16.032655 611 master.cpp:466] Using default 'crammd5'
> authenticator
> I0119 03:54:16.032790 611 master.cpp:535] Using default 'basic' HTTP
> authenticator
> I0119 03:54:16.032995 610 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (13744)@172.17.0.2:58576
> I0119 03:54:16.033190 611 master.cpp:569] Authorization enabled
> I0119 03:54:16.033342 605 whitelist_watcher.cpp:77] No whitelist given
> I0119 03:54:16.033428 609 recover.cpp:193] Received a recover response
> from a replica in STARTING status
> I0119 03:54:16.033359 612 hierarchical.cpp:145] Initialized hierarchical
> allocator process
> I0119 03:54:16.033902 605 recover.cpp:564] Updating replica status to
> VOTING
> I0119 03:54:16.034526 615 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 403733ns
> I0119 03:54:16.034551 615 replica.cpp:320] Persisted replica status to
> VOTING
> I0119 03:54:16.034700 615 recover.cpp:578] Successfully joined the Paxos
> group
> I0119 03:54:16.035019 615 recover.cpp:462] Recover process terminated
> I0119 03:54:16.035284 613 master.cpp:1710] The newly elected leader is
> master@172.17.0.2:58576 with id 9e4cae84-cd80-417e-9023-17c0df61c980
> I0119 03:54:16.035312 613 master.cpp:1723] Elected as the leading master!
> I0119 03:54:16.035329 613 master.cpp:1468] Recovering from registrar
> I0119 03:54:16.035615 613 registrar.cpp:307] Recovering registrar
> I0119 03:54:16.036142 614 log.cpp:659] Attempting to start the writer
> I0119 03:54:16.037210 612 replica.cpp:493] Replica received implicit
> promise request from (13746)@172.17.0.2:58576 with proposal 1
> I0119 03:54:16.037678 612 leveldb.cpp:304] Persisting metadata (8 bytes)
> to leveldb took 438216ns
> I0119 03:54:16.037699 612 replica.cpp:342] Persisted promised to 1
> I0119 03:54:16.038236 617 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0119 03:54:16.039268 608 replica.cpp:388] Replica received explicit
> promise request from (13747)@172.17.0.2:58576 for position 0 with
> proposal 2
> I0119 03:54:16.039765 608 leveldb.cpp:341] Persisting action (8 bytes) to
> leveldb took 460710ns
> I0119 03:54:16.039789 608 replica.cpp:712] Persisted action at 0
> I0119 03:54:16.040910 605 replica.cpp:537] Replica received write
> request for position 0 from (13748)@172.17.0.2:58576
> I0119 03:54:16.040966 605 leveldb.cpp:436] Reading position from leveldb
> took 24855ns
> I0119 03:54:16.041483 605 leveldb.cpp:341] Persisting action (14 bytes)
> to leveldb took 475810ns
> I0119 03:54:16.041506 605 replica.cpp:712] Persisted action at 0
> I0119 03:54:16.042132 613 replica.cpp:691] Replica received learned
> notice for position 0 from @0.0.0.0:0
> I0119 03:54:16.042567 613 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 364219ns
> I0119 03:54:16.042592 613 replica.cpp:712] Persisted action at 0
> I0119 03:54:16.042615 613 replica.cpp:697] Replica learned NOP action at
> position 0
> I0119 03:54:16.043148 604 log.cpp:675] Writer started with ending
> position 0
> I0119 03:54:16.044085 612 leveldb.cpp:436] Reading position from leveldb
> took 25111ns
> I0119 03:54:16.044944 606 registrar.cpp:340] Successfully fetched the
> registry (0B) in 9.238016ms
> I0119 03:54:16.045040 606 registrar.cpp:439] Applied 1 operations in
> 22407ns; attempting to update the 'registry'
> I0119 03:54:16.045660 603 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0119 03:54:16.045758 612 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0119 03:54:16.046370 610 replica.cpp:537] Replica received write
> request for position 1 from (13749)@172.17.0.2:58576
> I0119 03:54:16.046901 610 leveldb.cpp:341] Persisting action (189 bytes)
> to leveldb took 494178ns
> I0119 03:54:16.046928 610 replica.cpp:712] Persisted action at 1
> I0119 03:54:16.047449 617 replica.cpp:691] Replica received learned
> notice for position 1 from @0.0.0.0:0
> I0119 03:54:16.047951 617 leveldb.cpp:341] Persisting action (191 bytes)
> to leveldb took 471111ns
> I0119 03:54:16.047976 617 replica.cpp:712] Persisted action at 1
> I0119 03:54:16.047992 617 replica.cpp:697] Replica learned APPEND action
> at position 1
> I0119 03:54:16.048874 608 registrar.cpp:484] Successfully updated the
> 'registry' in 3.77984ms
> I0119 03:54:16.049008 608 registrar.cpp:370] Successfully recovered
> registrar
> I0119 03:54:16.049068 604 log.cpp:702] Attempting to truncate the log to
> 1
> I0119 03:54:16.049304 613 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0119 03:54:16.049466 617 master.cpp:1520] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0119 03:54:16.049484 608 hierarchical.cpp:172] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0119 03:54:16.050098 608 replica.cpp:537] Replica received write
> request for position 2 from (13750)@172.17.0.2:58576
> I0119 03:54:16.050616 608 leveldb.cpp:341] Persisting action (16 bytes)
> to leveldb took 485697ns
> I0119 03:54:16.050655 608 replica.cpp:712] Persisted action at 2
> I0119 03:54:16.051172 603 replica.cpp:691] Replica received learned
> notice for position 2 from @0.0.0.0:0
> I0119 03:54:16.051677 603 leveldb.cpp:341] Persisting action (18 bytes)
> to leveldb took 476640ns
> I0119 03:54:16.051730 603 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 29233ns
> I0119 03:54:16.051749 603 replica.cpp:712] Persisted action at 2
> I0119 03:54:16.051765 603 replica.cpp:697] Replica learned TRUNCATE
> action at position 2
> I0119 03:54:16.060142 584 scheduler.cpp:154] Version: 0.27.0
> I0119 03:54:16.060633 616 scheduler.cpp:236] New master detected at
> master@172.17.0.2:58576
> I0119 03:54:16.061568 618 scheduler.cpp:298] Sending SUBSCRIBE call to
> master@172.17.0.2:58576
> I0119 03:54:16.063071 613 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0119 03:54:16.063769 617 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:47439
> I0119 03:54:16.064332 617 master.cpp:1972] Received subscription request
> for HTTP framework 'default'
> I0119 03:54:16.064409 617 master.cpp:1749] Authorizing framework
> principal 'test-principal' to receive offers for role '*'
> I0119 03:54:16.064921 617 master.cpp:2063] Subscribing framework
> 'default' with checkpointing disabled and capabilities [ ]
> I0119 03:54:16.065423 616 hierarchical.cpp:266] Added framework
> 9e4cae84-cd80-417e-9023-17c0df61c980-0000
> I0119 03:54:16.065512 616 hierarchical.cpp:1338] No resources available
> to allocate!
> I0119 03:54:16.065706 616 hierarchical.cpp:1432] No inverse offers to
> send out!
> I0119 03:54:16.065752 616 hierarchical.cpp:1086] Performed allocation
> for 0 slaves in 291452ns
> I0119 03:54:16.065575 617 master.hpp:1658] Sending heartbeat to
> 9e4cae84-cd80-417e-9023-17c0df61c980-0000
> I0119 03:54:16.066784 605 scheduler.cpp:457] Enqueuing event SUBSCRIBED
> received from master@172.17.0.2:58576
> I0119 03:54:16.067443 605 scheduler.cpp:457] Enqueuing event HEARTBEAT
> received from master@172.17.0.2:58576
> I0119 03:54:16.068357 608 master_maintenance_tests.cpp:177] Ignoring
> HEARTBEAT event
> I0119 03:54:16.068429 605 scheduler.cpp:298] Sending REQUEST call to
> master@172.17.0.2:58576
> I0119 03:54:16.070456 611 process.cpp:3141] Handling HTTP event for
> process 'master' with path: '/master/api/v1/scheduler'
> I0119 03:54:16.070973 618 http.cpp:504] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.2:47440
> I0119 03:54:16.071233 618 master.cpp:2717] Processing REQUEST call for
> framework 9e4cae84-cd80-417e-9023-17c0df61c980-0000 (default)
> I0119 03:54:16.071413 616 hierarchical.cpp:586] Received resource
> request from framework 9e4cae84-cd80-417e-9023-17c0df61c980-0000
> I0119 03:54:16.071815 615 master.cpp:1025] Master terminating
> I0119 03:54:16.072069 614 hierarchical.cpp:327] Removed framework
> 9e4cae84-cd80-417e-9023-17c0df61c980-0000
> E0119 03:54:16.072808 611 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 (4230 ms total)
>
> [----------] Global test environment tear-down
> [==========] 936 tests from 124 test cases ran. (365291 ms total)
> [ PASSED ] 935 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] RegistryClientTest.BadTokenServerAddress
>
> 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-1453173700-14139
> Untagged: mesos-1453173700-14139:latest
> Deleted: 0a51ee31d2c9d2162ebdb2b4edfdf121b0609f23b7c0e058af2ebdeded159df3
> Deleted: 159902fd3cd813d739921248878ff6112c3db5f6982b6bc327fd3d216755fe4f
> Deleted: 6e75a3f470b092cefe1f2bdea3237ebedf334bb9a796e33ea0b7b9b19ed3509e
> Deleted: 5069f32cf1e5e9fdc37b26b8cdcbc4cbd9401030791223f185858f01b3222ffa
> Deleted: 8292d1ddfe903ad931c818421041f0d438e5d8a73531da2730e403919d088966
> Deleted: d908aaece37dcb54b82194fc0564e45de9c770be2a7ee8fdf30389ff34bb37e1
> Deleted: 63b16639a71aa49c15189c44db06691fda94058ebeb6109f37df691c59c46d87
> Deleted: 1f5f93042fcbd496ae98584ffb5438844c406d5e156b58ccf6ce1e15ac1c8d0a
> Deleted: 6e4f96cc81026dd197d3d95695982d12f76bd0e1f307679c63d0e8f994393ba6
> Deleted: 46b4b9411ddfac92fe3fd6e2b24b4acf5e13575bde9e6f6a5fbc9292b4cd1c6c
> Deleted: af347bb96b8f75ddc9fb0324669c42dae1d5fb19620eeda449fcd17fbf13c2a8
> Deleted: 39b6adce48404bb2c3014fb6b503b5564bede054489bdb3dbdb0285598ecbbf9
> Deleted: 9cca66c8060958bdb9a551a7e67763bc9459004697f7348a5ab7e6609145dd91
> Deleted: 8805a1d47dc4ea3416b0fa1ebfa0ce98f71021236d2e757b41b5be176992228c
> Build step 'Execute shell' marked build as failure
>