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/03/03 07:03:26 UTC
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1764
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1764/changes>
Changes:
[bmahler] Updated /metrics/snapshot rate limiting to be configurable.
[bmahler] Documented LIBPROCESS_METRICS_SNAPSHOT_ENDPOINT_RATE_LIMIT.
[bmahler] Disabled rate limiting of /metrics/snapshot in the mesos tests.
[bmahler] Updated tests now that /metrics/snapshot is not rate limited.
------------------------------------------
[...truncated 166488 lines...]
I0303 06:03:26.328289 770 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 06:03:26.328299 770 master.cpp:427] Master only allowing authenticated slaves to register
I0303 06:03:26.328305 770 credentials.hpp:35] Loading credentials for authentication from '/tmp/Fj4rVM/credentials'
I0303 06:03:26.328543 767 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0303 06:03:26.328591 770 master.cpp:467] Using default 'crammd5' authenticator
I0303 06:03:26.328769 770 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 06:03:26.329032 770 master.cpp:570] Authorization enabled
I0303 06:03:26.329109 761 recover.cpp:564] Updating replica status to STARTING
I0303 06:03:26.329426 757 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 06:03:26.329455 761 whitelist_watcher.cpp:77] No whitelist given
I0303 06:03:26.329906 763 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 529886ns
I0303 06:03:26.329931 763 replica.cpp:320] Persisted replica status to STARTING
I0303 06:03:26.330229 765 recover.cpp:473] Replica is in STARTING status
I0303 06:03:26.331281 757 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15010)@172.17.0.2:58861
I0303 06:03:26.331785 758 master.cpp:1711] The newly elected leader is master@172.17.0.2:58861 with id acecccda-5bca-48d2-9823-e0cca2c13fa4
I0303 06:03:26.331899 758 master.cpp:1724] Elected as the leading master!
I0303 06:03:26.332051 758 master.cpp:1469] Recovering from registrar
I0303 06:03:26.332124 771 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 06:03:26.332571 758 registrar.cpp:307] Recovering registrar
I0303 06:03:26.333076 766 recover.cpp:564] Updating replica status to VOTING
I0303 06:03:26.333663 759 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 402142ns
I0303 06:03:26.333696 759 replica.cpp:320] Persisted replica status to VOTING
I0303 06:03:26.333830 769 recover.cpp:578] Successfully joined the Paxos group
I0303 06:03:26.334105 769 recover.cpp:462] Recover process terminated
I0303 06:03:26.334631 767 log.cpp:659] Attempting to start the writer
I0303 06:03:26.336374 768 replica.cpp:493] Replica received implicit promise request from (15011)@172.17.0.2:58861 with proposal 1
I0303 06:03:26.336736 768 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 322516ns
I0303 06:03:26.336767 768 replica.cpp:342] Persisted promised to 1
I0303 06:03:26.337581 767 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 06:03:26.339073 766 replica.cpp:388] Replica received explicit promise request from (15012)@172.17.0.2:58861 for position 0 with proposal 2
I0303 06:03:26.339481 766 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 353993ns
I0303 06:03:26.339511 766 replica.cpp:712] Persisted action at 0
I0303 06:03:26.340832 757 replica.cpp:537] Replica received write request for position 0 from (15013)@172.17.0.2:58861
I0303 06:03:26.340903 757 leveldb.cpp:436] Reading position from leveldb took 32152ns
I0303 06:03:26.341310 757 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 333925ns
I0303 06:03:26.341341 757 replica.cpp:712] Persisted action at 0
I0303 06:03:26.342113 759 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 06:03:26.342633 759 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 365563ns
I0303 06:03:26.342664 759 replica.cpp:712] Persisted action at 0
I0303 06:03:26.342692 759 replica.cpp:697] Replica learned NOP action at position 0
I0303 06:03:26.343372 759 log.cpp:675] Writer started with ending position 0
I0303 06:03:26.344642 769 leveldb.cpp:436] Reading position from leveldb took 33734ns
I0303 06:03:26.345823 765 registrar.cpp:340] Successfully fetched the registry (0B) in 13.121024ms
I0303 06:03:26.346004 765 registrar.cpp:439] Applied 1 operations in 71808ns; attempting to update the 'registry'
I0303 06:03:26.346843 761 log.cpp:683] Attempting to append 170 bytes to the log
I0303 06:03:26.347028 762 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 06:03:26.347988 761 replica.cpp:537] Replica received write request for position 1 from (15014)@172.17.0.2:58861
I0303 06:03:26.348402 761 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 361130ns
I0303 06:03:26.348433 761 replica.cpp:712] Persisted action at 1
I0303 06:03:26.349159 766 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 06:03:26.349535 766 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 334348ns
I0303 06:03:26.349565 766 replica.cpp:712] Persisted action at 1
I0303 06:03:26.349588 766 replica.cpp:697] Replica learned APPEND action at position 1
I0303 06:03:26.350814 763 registrar.cpp:484] Successfully updated the 'registry' in 4.740096ms
I0303 06:03:26.350996 763 registrar.cpp:370] Successfully recovered registrar
I0303 06:03:26.351032 757 log.cpp:702] Attempting to truncate the log to 1
I0303 06:03:26.351212 768 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 06:03:26.351557 757 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 06:03:26.351585 764 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 06:03:26.352318 756 replica.cpp:537] Replica received write request for position 2 from (15015)@172.17.0.2:58861
I0303 06:03:26.352686 756 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 320681ns
I0303 06:03:26.352717 756 replica.cpp:712] Persisted action at 2
I0303 06:03:26.353864 757 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 06:03:26.354399 757 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 480120ns
I0303 06:03:26.354452 757 leveldb.cpp:399] Deleting ~1 keys from leveldb took 30076ns
I0303 06:03:26.354470 757 replica.cpp:712] Persisted action at 2
I0303 06:03:26.354499 757 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 06:03:26.362509 737 scheduler.cpp:172] Version: 0.28.0
I0303 06:03:26.363203 763 scheduler.cpp:432] New master detected at master@172.17.0.2:58861
I0303 06:03:26.364797 762 scheduler.cpp:332] Connected with the master at http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.366225 763 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.367178 757 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:03:26.367730 771 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:35285
I0303 06:03:26.368006 771 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 06:03:26.368077 771 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 06:03:26.368391 771 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 06:03:26.368821 767 hierarchical.cpp:265] Added framework acecccda-5bca-48d2-9823-e0cca2c13fa4-0000
I0303 06:03:26.368909 767 hierarchical.cpp:1453] No resources available to allocate!
I0303 06:03:26.368965 767 hierarchical.cpp:1548] No inverse offers to send out!
I0303 06:03:26.368978 758 master.hpp:1657] Sending heartbeat to acecccda-5bca-48d2-9823-e0cca2c13fa4-0000
I0303 06:03:26.368993 767 hierarchical.cpp:1130] Performed allocation for 0 slaves in 143850ns
I0303 06:03:26.370343 761 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.370832 761 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.371737 757 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 06:03:26.371727 761 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.372835 763 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:03:26.373313 756 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:35286
I0303 06:03:26.373437 756 master.cpp:2670] Processing REQUEST call for framework acecccda-5bca-48d2-9823-e0cca2c13fa4-0000 (default)
I0303 06:03:26.373595 762 hierarchical.cpp:589] Received resource request from framework acecccda-5bca-48d2-9823-e0cca2c13fa4-0000
I0303 06:03:26.374181 760 master.cpp:1026] Master terminating
I0303 06:03:26.374408 762 hierarchical.cpp:326] Removed framework acecccda-5bca-48d2-9823-e0cca2c13fa4-0000
E0303 06:03:26.375155 756 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 06:03:26.376646 760 scheduler.cpp:414] Re-detecting master
I0303 06:03:26.377310 760 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:03:26.377372 760 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:03:26.377570 760 scheduler.cpp:432] New master detected at master@172.17.0.2:58861
I0303 06:03:26.379185 757 scheduler.cpp:332] Connected with the master at http://172.17.0.2:58861/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/0 (64 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0303 06:03:26.388181 737 leveldb.cpp:174] Opened db in 2.732482ms
I0303 06:03:26.389035 737 leveldb.cpp:181] Compacted db in 813558ns
I0303 06:03:26.389093 737 leveldb.cpp:196] Created db iterator in 20742ns
I0303 06:03:26.389116 737 leveldb.cpp:202] Seeked to beginning of db in 2140ns
I0303 06:03:26.389127 737 leveldb.cpp:271] Iterated through 0 keys in the db in 305ns
I0303 06:03:26.389166 737 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0303 06:03:26.390018 767 recover.cpp:447] Starting replica recovery
I0303 06:03:26.390275 767 recover.cpp:473] Replica is in EMPTY status
I0303 06:03:26.391562 760 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (15023)@172.17.0.2:58861
I0303 06:03:26.392118 757 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0303 06:03:26.392572 756 recover.cpp:564] Updating replica status to STARTING
I0303 06:03:26.393383 770 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 487007ns
I0303 06:03:26.393420 770 replica.cpp:320] Persisted replica status to STARTING
I0303 06:03:26.393721 762 recover.cpp:473] Replica is in STARTING status
I0303 06:03:26.393746 766 master.cpp:375] Master 5068a93f-0e7d-4584-81ec-a14d21fa8370 (d35e5f56a77e) started on 172.17.0.2:58861
I0303 06:03:26.393774 766 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/mACY1p/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="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/mACY1p/master" --zk_session_timeout="10secs"
I0303 06:03:26.394181 766 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 06:03:26.394198 766 master.cpp:427] Master only allowing authenticated slaves to register
I0303 06:03:26.394213 766 credentials.hpp:35] Loading credentials for authentication from '/tmp/mACY1p/credentials'
I0303 06:03:26.394596 766 master.cpp:467] Using default 'crammd5' authenticator
I0303 06:03:26.394774 766 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 06:03:26.394901 771 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15024)@172.17.0.2:58861
I0303 06:03:26.394985 766 master.cpp:570] Authorization enabled
I0303 06:03:26.395193 764 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 06:03:26.395195 762 whitelist_watcher.cpp:77] No whitelist given
I0303 06:03:26.395424 763 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 06:03:26.395882 769 recover.cpp:564] Updating replica status to VOTING
I0303 06:03:26.396491 756 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 338295ns
I0303 06:03:26.396519 756 replica.cpp:320] Persisted replica status to VOTING
I0303 06:03:26.396669 768 recover.cpp:578] Successfully joined the Paxos group
I0303 06:03:26.396935 768 recover.cpp:462] Recover process terminated
I0303 06:03:26.397766 758 master.cpp:1711] The newly elected leader is master@172.17.0.2:58861 with id 5068a93f-0e7d-4584-81ec-a14d21fa8370
I0303 06:03:26.397799 758 master.cpp:1724] Elected as the leading master!
I0303 06:03:26.397814 758 master.cpp:1469] Recovering from registrar
I0303 06:03:26.397982 765 registrar.cpp:307] Recovering registrar
I0303 06:03:26.398502 763 log.cpp:659] Attempting to start the writer
I0303 06:03:26.399648 757 replica.cpp:493] Replica received implicit promise request from (15026)@172.17.0.2:58861 with proposal 1
I0303 06:03:26.400009 757 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 327521ns
I0303 06:03:26.400035 757 replica.cpp:342] Persisted promised to 1
I0303 06:03:26.400660 769 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 06:03:26.401792 763 replica.cpp:388] Replica received explicit promise request from (15027)@172.17.0.2:58861 for position 0 with proposal 2
I0303 06:03:26.402127 763 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 290781ns
I0303 06:03:26.402154 763 replica.cpp:712] Persisted action at 0
I0303 06:03:26.403151 769 replica.cpp:537] Replica received write request for position 0 from (15028)@172.17.0.2:58861
I0303 06:03:26.403221 769 leveldb.cpp:436] Reading position from leveldb took 33268ns
I0303 06:03:26.403548 769 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 273838ns
I0303 06:03:26.403573 769 replica.cpp:712] Persisted action at 0
I0303 06:03:26.404157 759 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 06:03:26.404525 759 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 334962ns
I0303 06:03:26.404554 759 replica.cpp:712] Persisted action at 0
I0303 06:03:26.404582 759 replica.cpp:697] Replica learned NOP action at position 0
I0303 06:03:26.405216 765 log.cpp:675] Writer started with ending position 0
I0303 06:03:26.406675 759 leveldb.cpp:436] Reading position from leveldb took 34634ns
I0303 06:03:26.407979 762 registrar.cpp:340] Successfully fetched the registry (0B) in 9.924096ms
I0303 06:03:26.408107 762 registrar.cpp:439] Applied 1 operations in 32472ns; attempting to update the 'registry'
I0303 06:03:26.409001 770 log.cpp:683] Attempting to append 170 bytes to the log
I0303 06:03:26.409153 759 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 06:03:26.409988 765 replica.cpp:537] Replica received write request for position 1 from (15029)@172.17.0.2:58861
I0303 06:03:26.410452 765 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 348301ns
I0303 06:03:26.410485 765 replica.cpp:712] Persisted action at 1
I0303 06:03:26.411231 770 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 06:03:26.411633 770 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 360443ns
I0303 06:03:26.411664 770 replica.cpp:712] Persisted action at 1
I0303 06:03:26.411694 770 replica.cpp:697] Replica learned APPEND action at position 1
I0303 06:03:26.412816 767 registrar.cpp:484] Successfully updated the 'registry' in 4.636928ms
I0303 06:03:26.412997 767 registrar.cpp:370] Successfully recovered registrar
I0303 06:03:26.413162 768 log.cpp:702] Attempting to truncate the log to 1
I0303 06:03:26.413332 760 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 06:03:26.413916 759 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 06:03:26.414250 762 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 06:03:26.414451 764 replica.cpp:537] Replica received write request for position 2 from (15030)@172.17.0.2:58861
I0303 06:03:26.414819 764 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 320799ns
I0303 06:03:26.414850 764 replica.cpp:712] Persisted action at 2
I0303 06:03:26.415727 761 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 06:03:26.416085 761 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 314908ns
I0303 06:03:26.416158 761 leveldb.cpp:399] Deleting ~1 keys from leveldb took 40489ns
I0303 06:03:26.416187 761 replica.cpp:712] Persisted action at 2
I0303 06:03:26.416209 761 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 06:03:26.424468 737 scheduler.cpp:172] Version: 0.28.0
I0303 06:03:26.425623 769 scheduler.cpp:432] New master detected at master@172.17.0.2:58861
I0303 06:03:26.427839 769 scheduler.cpp:332] Connected with the master at http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.429163 769 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.430287 764 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:03:26.430752 763 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:35289
I0303 06:03:26.431074 763 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 06:03:26.431128 763 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 06:03:26.431365 763 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 06:03:26.431682 764 hierarchical.cpp:265] Added framework 5068a93f-0e7d-4584-81ec-a14d21fa8370-0000
I0303 06:03:26.431753 764 hierarchical.cpp:1453] No resources available to allocate!
I0303 06:03:26.431776 756 master.hpp:1657] Sending heartbeat to 5068a93f-0e7d-4584-81ec-a14d21fa8370-0000
I0303 06:03:26.431789 764 hierarchical.cpp:1548] No inverse offers to send out!
I0303 06:03:26.431813 764 hierarchical.cpp:1130] Performed allocation for 0 slaves in 108141ns
I0303 06:03:26.432418 764 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.432832 764 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.433595 760 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.2:58861/master/api/v1/scheduler
I0303 06:03:26.433626 768 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 06:03:26.435045 760 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 06:03:26.435531 756 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:35290
I0303 06:03:26.435864 756 master.cpp:2670] Processing REQUEST call for framework 5068a93f-0e7d-4584-81ec-a14d21fa8370-0000 (default)
I0303 06:03:26.436075 761 hierarchical.cpp:589] Received resource request from framework 5068a93f-0e7d-4584-81ec-a14d21fa8370-0000
I0303 06:03:26.437233 761 master.cpp:1026] Master terminating
I0303 06:03:26.437463 756 hierarchical.cpp:326] Removed framework 5068a93f-0e7d-4584-81ec-a14d21fa8370-0000
E0303 06:03:26.438262 771 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 06:03:26.439854 771 scheduler.cpp:414] Re-detecting master
I0303 06:03:26.440524 771 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:03:26.440681 771 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 06:03:26.440783 771 scheduler.cpp:432] New master detected at master@172.17.0.2:58861
I0303 06:03:26.442837 758 scheduler.cpp:332] Connected with the master at http://172.17.0.2:58861/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/1 (63 ms)
[----------] 26 tests from ContentType/SchedulerTest (4661 ms total)
[----------] Global test environment tear-down
E0303 06:03:26.559387 737 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_WriteRead_ttsyl7': No such file or directory
E0303 06:03:26.559449 737 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_LostZooKeeper_etsrgN': No such file or directory
[==========] 997 tests from 128 test cases ran. (326824 ms total)
[ PASSED ] 996 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] AppcImageFetcherTest.SimpleFetch
1 FAILED TEST
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1456983087-5826
Untagged: mesos-1456983087-5826:latest
Deleted: 3917f89dcb5bc05ec40808db4fa478ce78551d483d4d88fb97eb1fe091b1b0f2
Deleted: 5d7f90357283de3251f8b81399c5355f9df4dd1f26a3b25fab63c4775d3e7995
Deleted: efbbdec049d2f2a69dfcd1813e22490242c9bb59e8e381fa3b5f8e21ca0982f0
Deleted: f402027eb52684b7507490faebef0d70118afe90a19c5c68a532004c36b9db09
Deleted: f0c95fec1c2c2e02771c60c68013dbed7400c9f64fa3b42b640aeeb5d741777e
Deleted: be870f0f19b59d3dd1e3e60b1157c6a3fb40b027cc631f2b5dc52267105814a3
Deleted: 3433893649e26ccb30e8191c40655dd541221acb52e0c05642839a6b3bb342ee
Deleted: fdcd90c7f09a452587c9b63f2e7d828ccd9a1f108a8394e4439261ecb3576c36
Deleted: 9f9667b087b2d6abd4ffeb9cb80e8a85003f8bd141a9c584660ecb2e71f9a424
Deleted: 1c8f7e83f0d77e860629284aabb0049d266d283943ebbbfd283f6fc9a442950d
Deleted: e1bfa794d1ee58184d42a42104ddfee737dd90fdc251c2f77f13aca642eb5983
Deleted: 060db92ac8da736b5050efa17c294e2b3a853694233cdeba8433f16f89801a79
Deleted: c6a4d016e14391592b0263a7625b9e1f61e7b82ab9809100f35f5093bc88ded3
Deleted: a66a00daf3a57e2577b7d9d3de471caf10e3fb37069b1ca0ac7d9ee1a37bba81
Deleted: b6c3a0e9d3a060baf8cde447933bc0ca12d47a486cef52c9bb81001e95e89751
Deleted: 2f836507404116b8af399d6c7a40f404927158112042f3f008085d26b8ea81a8
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1766
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1766/changes>
Build failed in Jenkins: Mesos » gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(docker||Hadoop)&&(!ubuntu-us1) #1765
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)/1765/changes>
Changes:
[joris.van.remoortere] Fixed virtual function shadowing in appc provision test.
------------------------------------------
[...truncated 171264 lines...]
I0303 07:46:27.070379 770 master.cpp:375] Master 6fd214c8-bcc7-4762-b908-21b6c08b6bc9 (e766e26128b8) started on 172.17.0.3:54257
I0303 07:46:27.070555 770 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/481i4s/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="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/481i4s/master" --zk_session_timeout="10secs"
I0303 07:46:27.071296 770 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 07:46:27.071370 770 master.cpp:427] Master only allowing authenticated slaves to register
I0303 07:46:27.071478 770 credentials.hpp:35] Loading credentials for authentication from '/tmp/481i4s/credentials'
I0303 07:46:27.071969 770 master.cpp:467] Using default 'crammd5' authenticator
I0303 07:46:27.072262 770 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 07:46:27.072484 770 master.cpp:570] Authorization enabled
I0303 07:46:27.074409 759 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 07:46:27.074576 759 whitelist_watcher.cpp:77] No whitelist given
I0303 07:46:27.077095 770 master.cpp:1711] The newly elected leader is master@172.17.0.3:54257 with id 6fd214c8-bcc7-4762-b908-21b6c08b6bc9
I0303 07:46:27.077313 770 master.cpp:1724] Elected as the leading master!
I0303 07:46:27.077424 770 master.cpp:1469] Recovering from registrar
I0303 07:46:27.077818 770 registrar.cpp:307] Recovering registrar
I0303 07:46:27.109452 762 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 45.726225ms
I0303 07:46:27.109537 762 replica.cpp:320] Persisted replica status to STARTING
I0303 07:46:27.109920 763 recover.cpp:473] Replica is in STARTING status
I0303 07:46:27.111078 759 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15011)@172.17.0.3:54257
I0303 07:46:27.111961 764 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 07:46:27.118065 764 recover.cpp:564] Updating replica status to VOTING
I0303 07:46:27.168000 762 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 49.389924ms
I0303 07:46:27.168092 762 replica.cpp:320] Persisted replica status to VOTING
I0303 07:46:27.168366 762 recover.cpp:578] Successfully joined the Paxos group
I0303 07:46:27.168576 762 recover.cpp:462] Recover process terminated
I0303 07:46:27.169327 762 log.cpp:659] Attempting to start the writer
I0303 07:46:27.171008 762 replica.cpp:493] Replica received implicit promise request from (15012)@172.17.0.3:54257 with proposal 1
I0303 07:46:27.251467 762 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 80.399424ms
I0303 07:46:27.251554 762 replica.cpp:342] Persisted promised to 1
I0303 07:46:27.252495 763 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 07:46:27.254469 763 replica.cpp:388] Replica received explicit promise request from (15013)@172.17.0.3:54257 for position 0 with proposal 2
I0303 07:46:27.307003 763 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 52.433895ms
I0303 07:46:27.307090 763 replica.cpp:712] Persisted action at 0
I0303 07:46:27.309676 763 replica.cpp:537] Replica received write request for position 0 from (15014)@172.17.0.3:54257
I0303 07:46:27.309854 763 leveldb.cpp:436] Reading position from leveldb took 76249ns
I0303 07:46:27.390465 763 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 80.509691ms
I0303 07:46:27.390552 763 replica.cpp:712] Persisted action at 0
I0303 07:46:27.394549 769 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 07:46:27.465482 769 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 70.844182ms
I0303 07:46:27.465574 769 replica.cpp:712] Persisted action at 0
I0303 07:46:27.465612 769 replica.cpp:697] Replica learned NOP action at position 0
I0303 07:46:27.466975 761 log.cpp:675] Writer started with ending position 0
I0303 07:46:27.468443 761 leveldb.cpp:436] Reading position from leveldb took 57765ns
I0303 07:46:27.469974 761 registrar.cpp:340] Successfully fetched the registry (0B) in 391.85408ms
I0303 07:46:27.470108 761 registrar.cpp:439] Applied 1 operations in 34601ns; attempting to update the 'registry'
I0303 07:46:27.471022 761 log.cpp:683] Attempting to append 170 bytes to the log
I0303 07:46:27.471155 756 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 07:46:27.472246 756 replica.cpp:537] Replica received write request for position 1 from (15015)@172.17.0.3:54257
I0303 07:46:27.498946 756 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 26.636533ms
I0303 07:46:27.499037 756 replica.cpp:712] Persisted action at 1
I0303 07:46:27.500481 756 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 07:46:27.524065 756 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 23.525657ms
I0303 07:46:27.524158 756 replica.cpp:712] Persisted action at 1
I0303 07:46:27.524194 756 replica.cpp:697] Replica learned APPEND action at position 1
I0303 07:46:27.526278 756 registrar.cpp:484] Successfully updated the 'registry' in 56.09984ms
I0303 07:46:27.526432 756 registrar.cpp:370] Successfully recovered registrar
I0303 07:46:27.526681 756 log.cpp:702] Attempting to truncate the log to 1
I0303 07:46:27.527161 756 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 07:46:27.527390 770 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 07:46:27.527866 770 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 07:46:27.528982 766 replica.cpp:537] Replica received write request for position 2 from (15016)@172.17.0.3:54257
I0303 07:46:27.549178 766 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 20.122097ms
I0303 07:46:27.549280 766 replica.cpp:712] Persisted action at 2
I0303 07:46:27.550154 766 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 07:46:27.574327 766 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 24.118031ms
I0303 07:46:27.574493 766 leveldb.cpp:399] Deleting ~1 keys from leveldb took 75375ns
I0303 07:46:27.574522 766 replica.cpp:712] Persisted action at 2
I0303 07:46:27.574559 766 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 07:46:27.579474 736 scheduler.cpp:172] Version: 0.28.0
I0303 07:46:27.580442 763 scheduler.cpp:432] New master detected at master@172.17.0.3:54257
I0303 07:46:27.582197 760 scheduler.cpp:332] Connected with the master at http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:27.583495 755 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:27.584646 755 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:46:27.585207 755 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50405
I0303 07:46:27.585448 755 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 07:46:27.585515 755 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 07:46:27.586231 755 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 07:46:27.587290 767 master.hpp:1657] Sending heartbeat to 6fd214c8-bcc7-4762-b908-21b6c08b6bc9-0000
I0303 07:46:27.587735 755 hierarchical.cpp:265] Added framework 6fd214c8-bcc7-4762-b908-21b6c08b6bc9-0000
I0303 07:46:27.587823 755 hierarchical.cpp:1453] No resources available to allocate!
I0303 07:46:27.587862 755 hierarchical.cpp:1548] No inverse offers to send out!
I0303 07:46:27.587890 755 hierarchical.cpp:1130] Performed allocation for 0 slaves in 132448ns
I0303 07:46:27.588418 762 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:27.588915 762 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:27.590019 765 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 07:46:27.590489 762 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:27.591581 766 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:46:27.592021 766 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50406
I0303 07:46:27.592144 766 master.cpp:2670] Processing REQUEST call for framework 6fd214c8-bcc7-4762-b908-21b6c08b6bc9-0000 (default)
I0303 07:46:27.592320 760 hierarchical.cpp:589] Received resource request from framework 6fd214c8-bcc7-4762-b908-21b6c08b6bc9-0000
I0303 07:46:27.592742 736 master.cpp:1026] Master terminating
I0303 07:46:27.592993 766 hierarchical.cpp:326] Removed framework 6fd214c8-bcc7-4762-b908-21b6c08b6bc9-0000
E0303 07:46:27.593811 757 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 07:46:27.595706 757 scheduler.cpp:414] Re-detecting master
I0303 07:46:27.596019 757 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 07:46:27.596086 757 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 07:46:27.596834 757 scheduler.cpp:432] New master detected at master@172.17.0.3:54257
I0303 07:46:27.612818 760 scheduler.cpp:332] Connected with the master at http://172.17.0.3:54257/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/0 (816 ms)
[ RUN ] ContentType/SchedulerTest.Request/1
I0303 07:46:27.715982 736 leveldb.cpp:174] Opened db in 83.341186ms
I0303 07:46:27.760998 736 leveldb.cpp:181] Compacted db in 44.928402ms
I0303 07:46:27.761090 736 leveldb.cpp:196] Created db iterator in 23149ns
I0303 07:46:27.761107 736 leveldb.cpp:202] Seeked to beginning of db in 2965ns
I0303 07:46:27.761117 736 leveldb.cpp:271] Iterated through 0 keys in the db in 220ns
I0303 07:46:27.761168 736 replica.cpp:779] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0303 07:46:27.761812 763 recover.cpp:447] Starting replica recovery
I0303 07:46:27.762686 763 recover.cpp:473] Replica is in EMPTY status
I0303 07:46:27.765123 757 master.cpp:375] Master e595e34f-e0ee-47ea-9a78-960efec9c3aa (e766e26128b8) started on 172.17.0.3:54257
I0303 07:46:27.765156 757 master.cpp:377] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_http="true" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/I1YRuU/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="100secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.28.0/_inst/share/mesos/webui" --work_dir="/tmp/I1YRuU/master" --zk_session_timeout="10secs"
I0303 07:46:27.765542 757 master.cpp:424] Master allowing unauthenticated frameworks to register
I0303 07:46:27.765554 757 master.cpp:427] Master only allowing authenticated slaves to register
I0303 07:46:27.765563 757 credentials.hpp:35] Loading credentials for authentication from '/tmp/I1YRuU/credentials'
I0303 07:46:27.765945 757 master.cpp:467] Using default 'crammd5' authenticator
I0303 07:46:27.766103 757 master.cpp:536] Using default 'basic' HTTP authenticator
I0303 07:46:27.766261 757 master.cpp:570] Authorization enabled
I0303 07:46:27.766450 768 hierarchical.cpp:144] Initialized hierarchical allocator process
I0303 07:46:27.766472 758 whitelist_watcher.cpp:77] No whitelist given
I0303 07:46:27.768074 759 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from (15025)@172.17.0.3:54257
I0303 07:46:27.768370 758 recover.cpp:193] Received a recover response from a replica in EMPTY status
I0303 07:46:27.769515 759 recover.cpp:564] Updating replica status to STARTING
I0303 07:46:27.769920 769 master.cpp:1711] The newly elected leader is master@172.17.0.3:54257 with id e595e34f-e0ee-47ea-9a78-960efec9c3aa
I0303 07:46:27.769955 769 master.cpp:1724] Elected as the leading master!
I0303 07:46:27.769979 769 master.cpp:1469] Recovering from registrar
I0303 07:46:27.770160 768 registrar.cpp:307] Recovering registrar
I0303 07:46:27.811064 756 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 40.324546ms
I0303 07:46:27.811157 756 replica.cpp:320] Persisted replica status to STARTING
I0303 07:46:27.811555 756 recover.cpp:473] Replica is in STARTING status
I0303 07:46:27.813606 756 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from (15026)@172.17.0.3:54257
I0303 07:46:27.814059 756 recover.cpp:193] Received a recover response from a replica in STARTING status
I0303 07:46:27.814872 756 recover.cpp:564] Updating replica status to VOTING
I0303 07:46:27.861186 756 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 46.033107ms
I0303 07:46:27.861284 756 replica.cpp:320] Persisted replica status to VOTING
I0303 07:46:27.861527 761 recover.cpp:578] Successfully joined the Paxos group
I0303 07:46:27.861816 766 recover.cpp:462] Recover process terminated
I0303 07:46:27.866699 761 log.cpp:659] Attempting to start the writer
I0303 07:46:27.868250 764 replica.cpp:493] Replica received implicit promise request from (15027)@172.17.0.3:54257 with proposal 1
I0303 07:46:27.908170 764 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 39.854935ms
I0303 07:46:27.908270 764 replica.cpp:342] Persisted promised to 1
I0303 07:46:27.909167 764 coordinator.cpp:238] Coordinator attempting to fill missing positions
I0303 07:46:27.910426 764 replica.cpp:388] Replica received explicit promise request from (15028)@172.17.0.3:54257 for position 0 with proposal 2
I0303 07:46:27.953073 764 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 42.577028ms
I0303 07:46:27.953166 764 replica.cpp:712] Persisted action at 0
I0303 07:46:27.954988 764 replica.cpp:537] Replica received write request for position 0 from (15029)@172.17.0.3:54257
I0303 07:46:27.955062 764 leveldb.cpp:436] Reading position from leveldb took 38752ns
I0303 07:46:27.994864 764 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 39.738043ms
I0303 07:46:27.994962 764 replica.cpp:712] Persisted action at 0
I0303 07:46:27.996114 764 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I0303 07:46:28.050781 764 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 54.607529ms
I0303 07:46:28.050874 764 replica.cpp:712] Persisted action at 0
I0303 07:46:28.050911 764 replica.cpp:697] Replica learned NOP action at position 0
I0303 07:46:28.052177 766 log.cpp:675] Writer started with ending position 0
I0303 07:46:28.053673 766 leveldb.cpp:436] Reading position from leveldb took 59908ns
I0303 07:46:28.054991 767 registrar.cpp:340] Successfully fetched the registry (0B) in 284.783872ms
I0303 07:46:28.055136 767 registrar.cpp:439] Applied 1 operations in 36070ns; attempting to update the 'registry'
I0303 07:46:28.055888 767 log.cpp:683] Attempting to append 170 bytes to the log
I0303 07:46:28.056033 761 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I0303 07:46:28.056892 761 replica.cpp:537] Replica received write request for position 1 from (15030)@172.17.0.3:54257
I0303 07:46:28.100971 761 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 44.024824ms
I0303 07:46:28.101052 761 replica.cpp:712] Persisted action at 1
I0303 07:46:28.102404 761 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I0303 07:46:28.125967 761 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 23.504569ms
I0303 07:46:28.126060 761 replica.cpp:712] Persisted action at 1
I0303 07:46:28.126096 761 replica.cpp:697] Replica learned APPEND action at position 1
I0303 07:46:28.128149 761 registrar.cpp:484] Successfully updated the 'registry' in 72.944896ms
I0303 07:46:28.128311 761 registrar.cpp:370] Successfully recovered registrar
I0303 07:46:28.128559 761 log.cpp:702] Attempting to truncate the log to 1
I0303 07:46:28.129017 761 master.cpp:1521] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register
I0303 07:46:28.129107 761 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I0303 07:46:28.129534 757 hierarchical.cpp:171] Skipping recovery of hierarchical allocator: nothing to recover
I0303 07:46:28.131428 761 replica.cpp:537] Replica received write request for position 2 from (15031)@172.17.0.3:54257
I0303 07:46:28.151368 761 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 19.856809ms
I0303 07:46:28.151464 761 replica.cpp:712] Persisted action at 2
I0303 07:46:28.153205 761 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I0303 07:46:28.176636 761 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 23.357042ms
I0303 07:46:28.176803 761 leveldb.cpp:399] Deleting ~1 keys from leveldb took 75960ns
I0303 07:46:28.176833 761 replica.cpp:712] Persisted action at 2
I0303 07:46:28.176873 761 replica.cpp:697] Replica learned TRUNCATE action at position 2
I0303 07:46:28.184624 736 scheduler.cpp:172] Version: 0.28.0
I0303 07:46:28.185606 768 scheduler.cpp:432] New master detected at master@172.17.0.3:54257
I0303 07:46:28.187809 757 scheduler.cpp:332] Connected with the master at http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:28.189692 767 scheduler.cpp:230] Sending SUBSCRIBE call to http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:28.191330 767 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:46:28.191967 767 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50421
I0303 07:46:28.192445 767 master.cpp:1973] Received subscription request for HTTP framework 'default'
I0303 07:46:28.192524 767 master.cpp:1750] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0303 07:46:28.193358 767 master.cpp:2064] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I0303 07:46:28.194545 759 hierarchical.cpp:265] Added framework e595e34f-e0ee-47ea-9a78-960efec9c3aa-0000
I0303 07:46:28.194705 759 hierarchical.cpp:1453] No resources available to allocate!
I0303 07:46:28.194852 759 hierarchical.cpp:1548] No inverse offers to send out!
I0303 07:46:28.194958 759 hierarchical.cpp:1130] Performed allocation for 0 slaves in 330516ns
I0303 07:46:28.195320 759 master.hpp:1657] Sending heartbeat to e595e34f-e0ee-47ea-9a78-960efec9c3aa-0000
I0303 07:46:28.196990 757 scheduler.cpp:602] Enqueuing event SUBSCRIBED received from http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:28.198981 767 scheduler.cpp:230] Sending REQUEST call to http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:28.199602 767 scheduler.cpp:602] Enqueuing event HEARTBEAT received from http://172.17.0.3:54257/master/api/v1/scheduler
I0303 07:46:28.201007 767 master_maintenance_tests.cpp:177] Ignoring HEARTBEAT event
I0303 07:46:28.201305 757 process.cpp:3136] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0303 07:46:28.202173 757 http.cpp:311] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:50423
I0303 07:46:28.202622 757 master.cpp:2670] Processing REQUEST call for framework e595e34f-e0ee-47ea-9a78-960efec9c3aa-0000 (default)
I0303 07:46:28.203480 769 hierarchical.cpp:589] Received resource request from framework e595e34f-e0ee-47ea-9a78-960efec9c3aa-0000
I0303 07:46:28.204419 759 master.cpp:1026] Master terminating
I0303 07:46:28.205340 759 hierarchical.cpp:326] Removed framework e595e34f-e0ee-47ea-9a78-960efec9c3aa-0000
E0303 07:46:28.206203 755 scheduler.cpp:575] End-Of-File received from master. The master closed the event stream
I0303 07:46:28.207478 755 scheduler.cpp:414] Re-detecting master
I0303 07:46:28.207808 755 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 07:46:28.207861 755 scheduler.cpp:365] Ignoring disconnection attempt from stale connection
I0303 07:46:28.207964 755 scheduler.cpp:432] New master detected at master@172.17.0.3:54257
I0303 07:46:28.213348 770 scheduler.cpp:332] Connected with the master at http://172.17.0.3:54257/master/api/v1/scheduler
[ OK ] ContentType/SchedulerTest.Request/1 (587 ms)
[----------] 26 tests from ContentType/SchedulerTest (23509 ms total)
[----------] Global test environment tear-down
E0303 07:46:28.339565 736 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_WriteRead_uXnJpt': No such file or directory
E0303 07:46:28.339653 736 environment.cpp:752] Failed to remove '/tmp/LogZooKeeperTest_LostZooKeeper_UNDfRk': No such file or directory
[==========] 997 tests from 128 test cases ran. (859935 ms total)
[ PASSED ] 996 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] AppcImageFetcherTest.SimpleFetch
1 FAILED TEST
YOU HAVE 6 DISABLED TESTS
make[4]: *** [check-local] Error 1
make[4]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[3]: *** [check-am] Error 2
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.28.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.28.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1456987289-14902
Untagged: mesos-1456987289-14902:latest
Deleted: 0913efe34aa56f8ace67a4529845b8a29d15a290194598f2e5f36632a6c716ad
Deleted: 60c28883ea2f75a626f3d083383887b8f4be0df089a64576556ae26e3a2eb0eb
Deleted: 4e20efeffbb1e86b0b2cfb938094d00eaa2d531726f6fee32d4785591a5a2874
Deleted: f43585fc27f8781dcbba81a7b0e09166f91fa2aa3c30fdeb96acf106ae50b3ea
Deleted: c5d6815738515bd1fc99bce6493e4051fcf022aa45b267515c75de4fc8b58dc4
Deleted: 8d1dff9d23c8799d8eafc554afb48b9c0b003067379906e9ba7ff2ceec364fbc
Deleted: 7d19f999fb8d7f820e0e7ad027d85143a22019cd1da2b8f0b1898e3787905b42
Deleted: fb83b8ec33dade061831b49f5cd84f7a47afe6d415ffbda39f5c4b4f9dd03368
Deleted: 81915dace72c9dde2de55cd3adad49a47d9fdec212597832960ab0ed5a5f43cc
Deleted: 5bc12fcc62a0e2e98d71ba636579e543e69af4d8d1d648a3895359ff30b419bf
Deleted: 6d8711bbe973afe5ca6116742b16132113630d6ecc2cc62a161aef906b532c5f
Deleted: 23e6fecc0ec35f15537ed2a5ac097cbb6a479da4a2c6dbc499492e3bb9b3dd77
Deleted: fdc7e40a37428e2846212b5e16ac71816be601583a7bc8d3146c5222ff70dfb0
Deleted: b8c1e20f02a37de805be0ec81efc83d0d9d48ce87b0cc123c8b907fa188f9677
Deleted: 1b1ab1a60a175c7c3b98b1f047f1bebe5c0bf92deb146ff9c4930c7865741a2c
Deleted: b345f26fe143c59599b716787042f918555ad7e5dd6c6e0cafb261faf72f5fd9
Build step 'Execute shell' marked build as failure