[
https://issues.apache.org/jira/browse/MESOS-4948?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Anand Mazumdar updated MESOS-4948:
----------------------------------
Description:
We need to move the existing maintenance tests to use the new scheduler
interface. We have already moved 1 test
{{MasterMaintenanceTest.PendingUnavailabilityTest}} to use the new interface.
It would be good to move the other 2 remaining tests to the new interface since
it can lead to failures around the stack object being referenced after has been
already destroyed. Detailed log from an ASF CI build failure.
{code}
[ RUN ] MasterMaintenanceTest.InverseOffers
I0315 04:16:50.786032 2681 leveldb.cpp:174] Opened db in 125.361171ms
I0315 04:16:50.836374 2681 leveldb.cpp:181] Compacted db in 50.254411ms
I0315 04:16:50.836470 2681 leveldb.cpp:196] Created db iterator in 25917ns
I0315 04:16:50.836488 2681 leveldb.cpp:202] Seeked to beginning of db in 3291ns
I0315 04:16:50.836498 2681 leveldb.cpp:271] Iterated through 0 keys in the db
in 253ns
I0315 04:16:50.836549 2681 replica.cpp:779] Replica recovered with log
positions 0 -> 0 with 1 holes and 0 unlearned
I0315 04:16:50.837474 2702 recover.cpp:447] Starting replica recovery
I0315 04:16:50.837565 2681 cluster.cpp:183] Creating default 'local' authorizer
I0315 04:16:50.838191 2702 recover.cpp:473] Replica is in EMPTY status
I0315 04:16:50.839532 2704 replica.cpp:673] Replica in EMPTY status received a
broadcasted recover request from (4784)@172.17.0.4:39845
I0315 04:16:50.839754 2705 recover.cpp:193] Received a recover response from a
replica in EMPTY status
I0315 04:16:50.841893 2704 recover.cpp:564] Updating replica status to STARTING
I0315 04:16:50.842566 2703 master.cpp:376] Master
c326bc68-2581-48d4-9dc4-0d6f270bdda1 (01fcd642f65f) started on 172.17.0.4:39845
I0315 04:16:50.842644 2703 master.cpp:378] Flags at startup: --acls=""
--allocation_interval="1secs" --allocator="HierarchicalDRF"
--authenticate="false" --authenticate_http="true" --authenticate_slaves="true"
--authenticators="crammd5" --authorizers="local"
--credentials="/tmp/DE2Uaw/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.29.0/_inst/share/mesos/webui"
--work_dir="/tmp/DE2Uaw/master" --zk_session_timeout="10secs"
I0315 04:16:50.843168 2703 master.cpp:425] Master allowing unauthenticated
frameworks to register
I0315 04:16:50.843227 2703 master.cpp:428] Master only allowing authenticated
slaves to register
I0315 04:16:50.843302 2703 credentials.hpp:35] Loading credentials for
authentication from '/tmp/DE2Uaw/credentials'
I0315 04:16:50.843737 2703 master.cpp:468] Using default 'crammd5'
authenticator
I0315 04:16:50.843969 2703 master.cpp:537] Using default 'basic' HTTP
authenticator
I0315 04:16:50.844177 2703 master.cpp:571] Authorization enabled
I0315 04:16:50.844360 2708 hierarchical.cpp:144] Initialized hierarchical
allocator process
I0315 04:16:50.844430 2708 whitelist_watcher.cpp:77] No whitelist given
I0315 04:16:50.848227 2703 master.cpp:1806] The newly elected leader is
[email protected]:39845 with id c326bc68-2581-48d4-9dc4-0d6f270bdda1
I0315 04:16:50.848269 2703 master.cpp:1819] Elected as the leading master!
I0315 04:16:50.848292 2703 master.cpp:1508] Recovering from registrar
I0315 04:16:50.848563 2703 registrar.cpp:307] Recovering registrar
I0315 04:16:50.876277 2711 leveldb.cpp:304] Persisting metadata (8 bytes) to
leveldb took 34.178445ms
I0315 04:16:50.876365 2711 replica.cpp:320] Persisted replica status to
STARTING
I0315 04:16:50.876776 2711 recover.cpp:473] Replica is in STARTING status
I0315 04:16:50.878779 2706 replica.cpp:673] Replica in STARTING status
received a broadcasted recover request from (4786)@172.17.0.4:39845
I0315 04:16:50.879240 2706 recover.cpp:193] Received a recover response from a
replica in STARTING status
I0315 04:16:50.880100 2701 recover.cpp:564] Updating replica status to VOTING
I0315 04:16:50.915776 2701 leveldb.cpp:304] Persisting metadata (8 bytes) to
leveldb took 35.472106ms
I0315 04:16:50.915868 2701 replica.cpp:320] Persisted replica status to VOTING
I0315 04:16:50.916158 2701 recover.cpp:578] Successfully joined the Paxos group
I0315 04:16:50.916363 2701 recover.cpp:462] Recover process terminated
I0315 04:16:50.917192 2701 log.cpp:659] Attempting to start the writer
I0315 04:16:50.919196 2714 replica.cpp:493] Replica received implicit promise
request from (4787)@172.17.0.4:39845 with proposal 1
I0315 04:16:50.957757 2714 leveldb.cpp:304] Persisting metadata (8 bytes) to
leveldb took 38.496305ms
I0315 04:16:50.957844 2714 replica.cpp:342] Persisted promised to 1
I0315 04:16:50.959254 2714 coordinator.cpp:238] Coordinator attempting to fill
missing positions
I0315 04:16:50.960928 2712 replica.cpp:388] Replica received explicit promise
request from (4788)@172.17.0.4:39845 for position 0 with proposal 2
I0315 04:16:51.000308 2712 leveldb.cpp:341] Persisting action (8 bytes) to
leveldb took 39.300546ms
I0315 04:16:51.000401 2712 replica.cpp:712] Persisted action at 0
I0315 04:16:51.002223 2707 replica.cpp:537] Replica received write request for
position 0 from (4789)@172.17.0.4:39845
I0315 04:16:51.002362 2707 leveldb.cpp:436] Reading position from leveldb took
83026ns
I0315 04:16:51.035646 2707 leveldb.cpp:341] Persisting action (14 bytes) to
leveldb took 33.201925ms
I0315 04:16:51.035750 2707 replica.cpp:712] Persisted action at 0
I0315 04:16:51.036618 2707 replica.cpp:691] Replica received learned notice
for position 0 from @0.0.0.0:0
I0315 04:16:51.056340 2707 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 19.66721ms
I0315 04:16:51.056438 2707 replica.cpp:712] Persisted action at 0
I0315 04:16:51.056480 2707 replica.cpp:697] Replica learned NOP action at
position 0
I0315 04:16:51.057850 2715 log.cpp:675] Writer started with ending position 0
I0315 04:16:51.059509 2709 leveldb.cpp:436] Reading position from leveldb took
75281ns
I0315 04:16:51.061115 2709 registrar.cpp:340] Successfully fetched the
registry (0B) in 212.499968ms
I0315 04:16:51.061276 2709 registrar.cpp:439] Applied 1 operations in 44901ns;
attempting to update the 'registry'
I0315 04:16:51.062515 2702 log.cpp:683] Attempting to append 170 bytes to the
log
I0315 04:16:51.062980 2709 coordinator.cpp:348] Coordinator attempting to
write APPEND action at position 1
I0315 04:16:51.064456 2709 replica.cpp:537] Replica received write request for
position 1 from (4790)@172.17.0.4:39845
I0315 04:16:51.098196 2709 leveldb.cpp:341] Persisting action (189 bytes) to
leveldb took 33.666091ms
I0315 04:16:51.098292 2709 replica.cpp:712] Persisted action at 1
I0315 04:16:51.099901 2709 replica.cpp:691] Replica received learned notice
for position 1 from @0.0.0.0:0
I0315 04:16:51.142916 2709 leveldb.cpp:341] Persisting action (191 bytes) to
leveldb took 42.95982ms
I0315 04:16:51.143008 2709 replica.cpp:712] Persisted action at 1
I0315 04:16:51.143048 2709 replica.cpp:697] Replica learned APPEND action at
position 1
I0315 04:16:51.145321 2709 registrar.cpp:484] Successfully updated the
'registry' in 83.969024ms
I0315 04:16:51.145479 2709 registrar.cpp:370] Successfully recovered registrar
I0315 04:16:51.145836 2702 log.cpp:702] Attempting to truncate the log to 1
I0315 04:16:51.146333 2706 master.cpp:1616] Recovered 0 slaves from the
Registry (131B) ; allowing 10mins for slaves to re-register
I0315 04:16:51.146528 2700 hierarchical.cpp:171] Skipping recovery of
hierarchical allocator: nothing to recover
I0315 04:16:51.147137 2700 coordinator.cpp:348] Coordinator attempting to
write TRUNCATE action at position 2
I0315 04:16:51.148613 2700 replica.cpp:537] Replica received write request for
position 2 from (4791)@172.17.0.4:39845
I0315 04:16:51.181690 2700 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 32.919462ms
I0315 04:16:51.181779 2700 replica.cpp:712] Persisted action at 2
I0315 04:16:51.183358 2700 replica.cpp:691] Replica received learned notice
for position 2 from @0.0.0.0:0
I0315 04:16:51.215826 2700 leveldb.cpp:341] Persisting action (18 bytes) to
leveldb took 32.418101ms
I0315 04:16:51.215983 2700 leveldb.cpp:399] Deleting ~1 keys from leveldb took
75363ns
I0315 04:16:51.216012 2700 replica.cpp:712] Persisted action at 2
I0315 04:16:51.216049 2700 replica.cpp:697] Replica learned TRUNCATE action at
position 2
I0315 04:16:51.230171 2700 slave.cpp:193] Slave started on
117)@172.17.0.4:39845
I0315 04:16:51.230217 2700 slave.cpp:194] Flags at startup:
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5"
--cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false"
--cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false"
--cgroups_root="mesos" --container_disk_watch_interval="15secs"
--containerizers="mesos"
--credential="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/credential"
--default_role="*" --disk_watch_interval="1mins" --docker="docker"
--docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io";
--docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock"
--docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker"
--enforce_container_disk_quota="false" --executor_registration_timeout="1mins"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/fetch"
--fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
--gc_disk_headroom="0.1" --hadoop_home="" --help="false"
--hostname="maintenance-host" --hostname_lookup="true"
--image_provisioner_backend="copy" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem"
--launcher_dir="/mesos/mesos-0.29.0/_build/src" --logbufsecs="0"
--logging_level="INFO" --oversubscribed_resources_interval="15secs"
--perf_duration="10secs" --perf_interval="1mins"
--qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect"
--recovery_timeout="15mins" --registration_backoff_factor="10ms"
--resources="cpus:2;mem:1024;disk:1024;ports:[31000-32000]"
--revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox"
--strict="true" --switch_user="true" --systemd_enable_support="true"
--systemd_runtime_directory="/run/systemd/system" --version="false"
--work_dir="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV"
I0315 04:16:51.230711 2700 credentials.hpp:83] Loading credential for
authentication from '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/credential'
I0315 04:16:51.230989 2700 slave.cpp:324] Slave using credential for:
test-principal
I0315 04:16:51.231161 2700 resources.cpp:572] Parsing resources as JSON
failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000]
Trying semicolon-delimited string format instead
I0315 04:16:51.231653 2700 slave.cpp:464] Slave resources: cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0315 04:16:51.232312 2700 slave.cpp:472] Slave attributes: [ ]
I0315 04:16:51.232403 2700 slave.cpp:477] Slave hostname: maintenance-host
I0315 04:16:51.235890 2705 state.cpp:58] Recovering state from
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/meta'
I0315 04:16:51.236862 2705 status_update_manager.cpp:200] Recovering status
update manager
I0315 04:16:51.237467 2705 slave.cpp:4565] Finished recovery
I0315 04:16:51.237757 2715 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/maintenance/schedule'
I0315 04:16:51.238085 2705 slave.cpp:4737] Querying resource estimator for
oversubscribable resources
I0315 04:16:51.239225 2715 http.cpp:312] HTTP POST for
/master/maintenance/schedule from 172.17.0.4:53179
I0315 04:16:51.240380 2715 registrar.cpp:439] Applied 1 operations in
144666ns; attempting to update the 'registry'
I0315 04:16:51.242146 2708 log.cpp:683] Attempting to append 292 bytes to the
log
I0315 04:16:51.242471 2708 coordinator.cpp:348] Coordinator attempting to
write APPEND action at position 3
I0315 04:16:51.243657 2708 replica.cpp:537] Replica received write request for
position 3 from (4798)@172.17.0.4:39845
I0315 04:16:51.244132 2705 slave.cpp:4751] Received oversubscribable resources
from the resource estimator
I0315 04:16:51.244442 2704 status_update_manager.cpp:174] Pausing sending
status updates
I0315 04:16:51.244591 2705 slave.cpp:796] New master detected at
[email protected]:39845
I0315 04:16:51.244786 2705 slave.cpp:859] Authenticating with master
[email protected]:39845
I0315 04:16:51.244886 2705 slave.cpp:864] Using default CRAM-MD5 authenticatee
I0315 04:16:51.245357 2707 authenticatee.cpp:121] Creating new client SASL
connection
I0315 04:16:51.245787 2707 master.cpp:5659] Authenticating
slave(117)@172.17.0.4:39845
I0315 04:16:51.246064 2707 authenticator.cpp:413] Starting authentication
session for crammd5_authenticatee(301)@172.17.0.4:39845
I0315 04:16:51.246462 2707 authenticator.cpp:98] Creating new server SASL
connection
I0315 04:16:51.246776 2707 authenticatee.cpp:212] Received SASL authentication
mechanisms: CRAM-MD5
I0315 04:16:51.246865 2707 authenticatee.cpp:238] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0315 04:16:51.247047 2707 authenticator.cpp:203] Received SASL authentication
start
I0315 04:16:51.247180 2707 authenticator.cpp:325] Authentication requires more
steps
I0315 04:16:51.247341 2707 authenticatee.cpp:258] Received SASL authentication
step
I0315 04:16:51.247489 2707 authenticator.cpp:231] Received SASL authentication
step
I0315 04:16:51.247572 2707 auxprop.cpp:107] Request to lookup properties for
user: 'test-principal' realm: '01fcd642f65f' server FQDN: '01fcd642f65f'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0315 04:16:51.247640 2707 auxprop.cpp:179] Looking up auxiliary property
'*userPassword'
I0315 04:16:51.247807 2707 auxprop.cpp:179] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0315 04:16:51.247920 2707 auxprop.cpp:107] Request to lookup properties for
user: 'test-principal' realm: '01fcd642f65f' server FQDN: '01fcd642f65f'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0315 04:16:51.248013 2707 auxprop.cpp:129] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0315 04:16:51.248100 2707 auxprop.cpp:129] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0315 04:16:51.248196 2707 authenticator.cpp:317] Authentication success
I0315 04:16:51.248461 2707 authenticatee.cpp:298] Authentication success
I0315 04:16:51.248597 2707 master.cpp:5689] Successfully authenticated
principal 'test-principal' at slave(117)@172.17.0.4:39845
I0315 04:16:51.248759 2700 authenticator.cpp:431] Authentication session
cleanup for crammd5_authenticatee(301)@172.17.0.4:39845
I0315 04:16:51.248988 2705 slave.cpp:832] Detecting new master
I0315 04:16:51.249363 2705 slave.cpp:927] Successfully authenticated with
master [email protected]:39845
I0315 04:16:51.249506 2705 slave.cpp:1321] Will retry registration in
9.155413ms if necessary
I0315 04:16:51.249981 2711 master.cpp:4370] Registering slave at
slave(117)@172.17.0.4:39845 (maintenance-host) with id
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
I0315 04:16:51.261998 2711 slave.cpp:1321] Will retry registration in
10.936296ms if necessary
I0315 04:16:51.262398 2711 master.cpp:4358] Ignoring register slave message
from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already in
progress
I0315 04:16:51.275990 2711 slave.cpp:1321] Will retry registration in
3.200397ms if necessary
I0315 04:16:51.276379 2711 master.cpp:4358] Ignoring register slave message
from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already in
progress
I0315 04:16:51.277753 2708 leveldb.cpp:341] Persisting action (311 bytes) to
leveldb took 33.976895ms
I0315 04:16:51.277799 2708 replica.cpp:712] Persisted action at 3
I0315 04:16:51.279341 2708 replica.cpp:691] Replica received learned notice
for position 3 from @0.0.0.0:0
I0315 04:16:51.281918 2711 slave.cpp:1321] Will retry registration in 131597ns
if necessary
I0315 04:16:51.282146 2700 master.cpp:4358] Ignoring register slave message
from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already in
progress
I0315 04:16:51.283844 2711 slave.cpp:1321] Will retry registration in
245.466527ms if necessary
I0315 04:16:51.284080 2711 master.cpp:4358] Ignoring register slave message
from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already in
progress
I0315 04:16:51.318001 2708 leveldb.cpp:341] Persisting action (313 bytes) to
leveldb took 38.528659ms
I0315 04:16:51.318091 2708 replica.cpp:712] Persisted action at 3
I0315 04:16:51.318123 2708 replica.cpp:697] Replica learned APPEND action at
position 3
I0315 04:16:51.320458 2711 registrar.cpp:484] Successfully updated the
'registry' in 79.843072ms
I0315 04:16:51.320747 2714 log.cpp:702] Attempting to truncate the log to 3
I0315 04:16:51.320879 2704 coordinator.cpp:348] Coordinator attempting to
write TRUNCATE action at position 4
I0315 04:16:51.320919 2711 registrar.cpp:439] Applied 1 operations in
118795ns; attempting to update the 'registry'
I0315 04:16:51.322357 2704 replica.cpp:537] Replica received write request for
position 4 from (4799)@172.17.0.4:39845
I0315 04:16:51.324488 2702 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/maintenance/status'
I0315 04:16:51.325279 2702 http.cpp:312] HTTP GET for
/master/maintenance/status from 172.17.0.4:53180
I0315 04:16:51.328512 2681 scheduler.cpp:172] Version: 0.29.0
I0315 04:16:51.329731 2703 scheduler.cpp:437] New master detected at
[email protected]:39845
I0315 04:16:51.332334 2702 scheduler.cpp:337] Connected with the master at
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.333514 2714 scheduler.cpp:230] Sending SUBSCRIBE call to
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.334751 2708 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0315 04:16:51.335245 2702 http.cpp:312] HTTP POST for
/master/api/v1/scheduler from 172.17.0.4:53181
I0315 04:16:51.335464 2702 master.cpp:2068] Received subscription request for
HTTP framework 'default'
I0315 04:16:51.335528 2702 master.cpp:1845] Authorizing framework principal
'test-principal' to receive offers for role '*'
I0315 04:16:51.335896 2713 master.cpp:2159] Subscribing framework 'default'
with checkpointing disabled and capabilities [ ]
I0315 04:16:51.337347 2700 hierarchical.cpp:265] Added framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.337435 2700 hierarchical.cpp:1453] No resources available to
allocate!
I0315 04:16:51.337471 2700 hierarchical.cpp:1548] No inverse offers to send
out!
I0315 04:16:51.337496 2700 hierarchical.cpp:1130] Performed allocation for 0
slaves in 122430ns
I0315 04:16:51.337657 2700 master.hpp:1715] Sending heartbeat to
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.338486 2711 scheduler.cpp:612] Enqueuing event SUBSCRIBED
received from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.339167 2711 scheduler.cpp:612] Enqueuing event HEARTBEAT
received from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.339838 2714 master_maintenance_tests.cpp:179] Ignoring
HEARTBEAT event
I0315 04:16:51.359691 2704 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 37.255846ms
I0315 04:16:51.359787 2704 replica.cpp:712] Persisted action at 4
I0315 04:16:51.361541 2702 replica.cpp:691] Replica received learned notice
for position 4 from @0.0.0.0:0
I0315 04:16:51.393460 2702 leveldb.cpp:341] Persisting action (18 bytes) to
leveldb took 31.826446ms
I0315 04:16:51.393631 2702 leveldb.cpp:399] Deleting ~2 keys from leveldb took
82223ns
I0315 04:16:51.393667 2702 replica.cpp:712] Persisted action at 4
I0315 04:16:51.393718 2702 replica.cpp:697] Replica learned TRUNCATE action at
position 4
I0315 04:16:51.395421 2702 log.cpp:683] Attempting to append 465 bytes to the
log
I0315 04:16:51.395716 2702 coordinator.cpp:348] Coordinator attempting to
write APPEND action at position 5
I0315 04:16:51.397063 2702 replica.cpp:537] Replica received write request for
position 5 from (4803)@172.17.0.4:39845
I0315 04:16:51.430773 2702 leveldb.cpp:341] Persisting action (484 bytes) to
leveldb took 33.553652ms
I0315 04:16:51.430871 2702 replica.cpp:712] Persisted action at 5
I0315 04:16:51.432451 2702 replica.cpp:691] Replica received learned notice
for position 5 from @0.0.0.0:0
I0315 04:16:51.473805 2702 leveldb.cpp:341] Persisting action (486 bytes) to
leveldb took 41.212274ms
I0315 04:16:51.473908 2702 replica.cpp:712] Persisted action at 5
I0315 04:16:51.473949 2702 replica.cpp:697] Replica learned APPEND action at
position 5
I0315 04:16:51.476976 2703 registrar.cpp:484] Successfully updated the
'registry' in 155.968768ms
I0315 04:16:51.477423 2703 log.cpp:702] Attempting to truncate the log to 5
I0315 04:16:51.477689 2703 coordinator.cpp:348] Coordinator attempting to
write TRUNCATE action at position 6
I0315 04:16:51.478329 2702 master.cpp:4438] Registered slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host) with cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
I0315 04:16:51.478806 2713 hierarchical.cpp:473] Added slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host) with cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
I0315 04:16:51.479184 2702 replica.cpp:537] Replica received write request for
position 6 from (4804)@172.17.0.4:39845
I0315 04:16:51.478400 2703 slave.cpp:3482] Received ping from
slave-observer(117)@172.17.0.4:39845
I0315 04:16:51.479872 2703 slave.cpp:971] Registered with master
[email protected]:39845; given slave ID c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
I0315 04:16:51.479902 2703 fetcher.cpp:81] Clearing fetcher cache
I0315 04:16:51.480332 2703 slave.cpp:994] Checkpointing SlaveInfo to
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/meta/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/slave.info'
I0315 04:16:51.480789 2712 status_update_manager.cpp:181] Resuming sending
status updates
I0315 04:16:51.481290 2713 hierarchical.cpp:1150] Performed allocation for
slave c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 in 2.431536ms
I0315 04:16:51.481817 2703 slave.cpp:1030] Forwarding total oversubscribed
resources
I0315 04:16:51.482067 2713 master.cpp:5488] Sending 1 offers to framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
I0315 04:16:51.483192 2713 master.cpp:5578] Sending 1 inverse offers to
framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
I0315 04:16:51.483569 2713 master.cpp:4782] Received update of slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host) with total oversubscribed resources
I0315 04:16:51.484576 2713 hierarchical.cpp:531] Slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host) updated with
oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000])
I0315 04:16:51.484849 2713 hierarchical.cpp:1453] No resources available to
allocate!
I0315 04:16:51.484966 2701 scheduler.cpp:612] Enqueuing event OFFERS received
from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.485061 2713 hierarchical.cpp:1150] Performed allocation for
slave c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 in 414324ns
I0315 04:16:51.485884 2701 scheduler.cpp:612] Enqueuing event OFFERS received
from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.491091 2701 scheduler.cpp:230] Sending ACCEPT call to
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.493937 2712 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0315 04:16:51.494441 2714 http.cpp:312] HTTP POST for
/master/api/v1/scheduler from 172.17.0.4:53182
I0315 04:16:51.495529 2714 master.cpp:3268] Processing ACCEPT call for offers:
[ c326bc68-2581-48d4-9dc4-0d6f270bdda1-O0 ] on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host) for framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
(default)
I0315 04:16:51.495589 2714 master.cpp:2871] Authorizing framework principal
'test-principal' to launch task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 as user
'mesos'
W0315 04:16:51.501534 2714 validation.cpp:404] Executor default for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 uses less CPUs (None) than the minimum
required (0.01). Please update your executor, as this will be mandatory in
future releases.
W0315 04:16:51.501618 2714 validation.cpp:416] Executor default for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 uses less memory (None) than the minimum
required (32MB). Please update your executor, as this will be mandatory in
future releases.
I0315 04:16:51.502182 2714 master.hpp:177] Adding task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host)
I0315 04:16:51.502437 2714 master.cpp:3753] Launching task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) with resources cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host)
I0315 04:16:51.503787 2700 slave.cpp:1361] Got assigned task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 for framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.504485 2700 slave.cpp:1480] Launching task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 for framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.512953 2700 paths.cpp:528] Trying to chown
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
to user 'mesos'
I0315 04:16:51.519822 2702 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 40.48414ms
I0315 04:16:51.519923 2702 replica.cpp:712] Persisted action at 6
I0315 04:16:51.521419 2710 replica.cpp:691] Replica received learned notice
for position 6 from @0.0.0.0:0
I0315 04:16:51.524533 2700 slave.cpp:5367] Launching executor default of
framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 with resources in work
directory
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
I0315 04:16:51.527022 2700 exec.cpp:143] Version: 0.29.0
I0315 04:16:51.527752 2704 exec.cpp:193] Executor started at:
executor(47)@172.17.0.4:39845 with pid 2681
I0315 04:16:51.527802 2700 slave.cpp:1698] Queuing task
'ce9b06cb-9896-4c2e-9fad-ea8538541cf4' for executor 'default' of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.527966 2700 slave.cpp:749] Successfully attached file
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
I0315 04:16:51.528192 2700 slave.cpp:2643] Got registration for executor
'default' of framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from
executor(47)@172.17.0.4:39845
I0315 04:16:51.529881 2706 exec.cpp:217] Executor registered on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
I0315 04:16:51.529955 2706 exec.cpp:229] Executor::registered took 36242ns
I0315 04:16:51.530278 2700 slave.cpp:1863] Sending queued task
'ce9b06cb-9896-4c2e-9fad-ea8538541cf4' to executor 'default' of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 at executor(47)@172.17.0.4:39845
I0315 04:16:51.530894 2708 exec.cpp:304] Executor asked to run task
'ce9b06cb-9896-4c2e-9fad-ea8538541cf4'
I0315 04:16:51.530988 2708 exec.cpp:313] Executor::launchTask took 67937ns
I0315 04:16:51.531083 2708 exec.cpp:526] Executor sending status update
TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.531365 2708 slave.cpp:3002] Handling status update TASK_RUNNING
(UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from executor(47)@172.17.0.4:39845
I0315 04:16:51.532158 2708 status_update_manager.cpp:320] Received status
update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.532274 2708 status_update_manager.cpp:497] Creating
StatusUpdate stream for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.532951 2708 status_update_manager.cpp:374] Forwarding update
TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to the slave
I0315 04:16:51.533524 2708 slave.cpp:3400] Forwarding the update TASK_RUNNING
(UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to [email protected]:39845
I0315 04:16:51.533817 2708 slave.cpp:3294] Status update manager successfully
handled status update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e)
for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.533936 2708 slave.cpp:3310] Sending acknowledgement for status
update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to executor(47)@172.17.0.4:39845
I0315 04:16:51.534340 2708 master.cpp:4927] Status update TASK_RUNNING (UUID:
5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host)
I0315 04:16:51.534457 2708 master.cpp:4975] Forwarding status update
TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.534803 2701 exec.cpp:350] Executor received status update
acknowledgement 5c63475c-af40-417d-9368-b7e3ede4a30e for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.535385 2708 master.cpp:6585] Updating the state of task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
I0315 04:16:51.537346 2704 scheduler.cpp:612] Enqueuing event UPDATE received
from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.541487 2708 scheduler.cpp:230] Sending ACKNOWLEDGE call to
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.542043 2708 scheduler.cpp:230] Sending DECLINE call to
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.543292 2708 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0315 04:16:51.543979 2708 http.cpp:312] HTTP POST for
/master/api/v1/scheduler from 172.17.0.4:53182
I0315 04:16:51.544251 2708 master.cpp:4082] Processing ACKNOWLEDGE call
5c63475c-af40-417d-9368-b7e3ede4a30e for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
I0315 04:16:51.544818 2708 status_update_manager.cpp:392] Received status
update acknowledgement (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.545315 2708 slave.cpp:2412] Status update manager successfully
handled status update acknowledgement (UUID:
5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.546144 2702 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0315 04:16:51.546668 2702 http.cpp:312] HTTP POST for
/master/api/v1/scheduler from 172.17.0.4:53182
I0315 04:16:51.547322 2702 master.cpp:3805] Processing DECLINE call for
offers: [ c326bc68-2581-48d4-9dc4-0d6f270bdda1-O1 ] for framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
I0315 04:16:51.565781 2710 leveldb.cpp:341] Persisting action (18 bytes) to
leveldb took 44.297436ms
I0315 04:16:51.565945 2710 leveldb.cpp:399] Deleting ~2 keys from leveldb took
76582ns
I0315 04:16:51.565978 2710 replica.cpp:712] Persisted action at 6
I0315 04:16:51.566015 2710 replica.cpp:697] Replica learned TRUNCATE action at
position 6
I0315 04:16:51.570482 2707 hierarchical.cpp:1453] No resources available to
allocate!
I0315 04:16:51.570847 2707 hierarchical.cpp:1130] Performed allocation for 1
slaves in 640118ns
I0315 04:16:51.571091 2707 master.cpp:5578] Sending 1 inverse offers to
framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
I0315 04:16:51.573333 2712 scheduler.cpp:612] Enqueuing event OFFERS received
from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.581941 2713 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/maintenance/status'
I0315 04:16:51.582535 2706 http.cpp:312] HTTP GET for
/master/maintenance/status from 172.17.0.4:53183
I0315 04:16:51.587846 2715 scheduler.cpp:230] Sending ACCEPT call to
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.589800 2715 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0315 04:16:51.590328 2715 http.cpp:312] HTTP POST for
/master/api/v1/scheduler from 172.17.0.4:53182
W0315 04:16:51.590833 2715 master.cpp:3231] ACCEPT call used invalid offers '[
c326bc68-2581-48d4-9dc4-0d6f270bdda1-O2 ]': Offer
c326bc68-2581-48d4-9dc4-0d6f270bdda1-O2 is no longer valid
I0315 04:16:51.603070 2706 hierarchical.cpp:1453] No resources available to
allocate!
I0315 04:16:51.603425 2706 hierarchical.cpp:1130] Performed allocation for 1
slaves in 570929ns
I0315 04:16:51.603674 2706 master.cpp:5578] Sending 1 inverse offers to
framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
I0315 04:16:51.605583 2711 scheduler.cpp:612] Enqueuing event OFFERS received
from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.614972 2709 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/maintenance/status'
I0315 04:16:51.616044 2713 http.cpp:312] HTTP GET for
/master/maintenance/status from 172.17.0.4:53184
I0315 04:16:51.620043 2681 master.cpp:1065] Master terminating
W0315 04:16:51.620407 2681 master.cpp:6637] Removing task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host) in non-terminal state TASK_RUNNING
I0315 04:16:51.621245 2712 hierarchical.cpp:505] Removed slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
I0315 04:16:51.621573 2681 master.cpp:6680] Removing executor 'default' with
resources of framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host)
I0315 04:16:51.622886 2704 hierarchical.cpp:326] Removed framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
E0315 04:16:51.624392 2705 scheduler.cpp:585] End-Of-File received from
master. The master closed the event stream
I0315 04:16:51.628783 2703 slave.cpp:3528] [email protected]:39845 exited
W0315 04:16:51.628839 2703 slave.cpp:3531] Master disconnected! Waiting for a
new master to be elected
I0315 04:16:51.632709 2704 slave.cpp:3528] executor(47)@172.17.0.4:39845 exited
I0315 04:16:51.633152 2704 slave.cpp:3886] Executor 'default' of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 exited with status 0
I0315 04:16:51.633311 2704 slave.cpp:3002] Handling status update TASK_FAILED
(UUID: f793d2cc-720c-4d89-91d5-3f45e73ad6ea) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from @0.0.0.0:0
I0315 04:16:51.641787 2704 slave.cpp:668] Slave terminating
I0315 04:16:51.641914 2704 slave.cpp:2079] Asked to shut down framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 by @0.0.0.0:0
I0315 04:16:51.641957 2704 slave.cpp:2104] Shutting down framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.642027 2704 slave.cpp:3990] Cleaning up executor 'default' of
framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 at
executor(47)@172.17.0.4:39845
I0315 04:16:51.642453 2704 slave.cpp:4078] Cleaning up framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.642616 2707 gc.cpp:55] Scheduling
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
for gc 6.99999256701333days in the future
I0315 04:16:51.642633 2710 status_update_manager.cpp:282] Closing status
update streams for framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.642719 2710 status_update_manager.cpp:528] Cleaning up status
update stream for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.643265 2707 gc.cpp:55] Scheduling
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default'
for gc 6.99999256488296days in the future
I0315 04:16:51.643373 2707 gc.cpp:55] Scheduling
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000'
for gc 6.99999256301037days in the future
I0315 04:16:51.646150 2705 scheduler.cpp:419] Re-detecting master
I0315 04:16:51.646462 2705 scheduler.cpp:370] Ignoring disconnection attempt
from stale connection
I0315 04:16:51.646507 2705 scheduler.cpp:370] Ignoring disconnection attempt
from stale connection
[ OK ] MasterMaintenanceTest.InverseOffers (992 ms)
[ RUN ] MasterMaintenanceTest.InverseOffersFilters
*** Aborted at 1458015411 (unix time) try "date -d @1458015411" if you are
using GNU date ***
PC: @ 0x172ca21
testing::internal::UntypedFunctionMockerBase::UntypedInvokeWith()
*** SIGSEGV (@0x0) received by PID 2681 (TID 0x2afe25c47700) from PID 0; stack
trace: ***
@ 0x2afe689dfff7 (unknown)
@ 0x2afe689e4159 (unknown)
@ 0x2afe1b57d340 (unknown)
@ 0x172ca21
testing::internal::UntypedFunctionMockerBase::UntypedInvokeWith()
@ 0xf494ff testing::internal::FunctionMockerBase<>::InvokeWith()
@ 0xf43663 testing::internal::FunctionMocker<>::Invoke()
@ 0xf42920
mesos::internal::tests::MasterMaintenanceTest::Callbacks::disconnected()
@ 0xf5ab55
_ZNKSt7_Mem_fnIMN5mesos8internal5tests21MasterMaintenanceTest9CallbacksEFvvEEclIJEvEEvRS4_DpOT_
@ 0xf57120
_ZNSt5_BindIFSt7_Mem_fnIMN5mesos8internal5tests21MasterMaintenanceTest9CallbacksEFvvEESt17reference_wrapperIS5_EEE6__callIvJEJLm0EEEET_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE
@ 0xf52d84 std::_Bind<>::operator()<>()
@ 0xf4e099 std::_Function_handler<>::_M_invoke()
@ 0x99f3ac std::function<>::operator()()
I0315 04:16:51.810700 2681 leveldb.cpp:174] Opened db in 153.621998ms
@ 0x2afe188c14e9 process::AsyncExecutorProcess::execute<>()
@ 0x2afe188c8d09
_ZZN7process8dispatchI7NothingNS_20AsyncExecutorProcessERKSt8functionIFvvEEPvS5_S8_EENS_6FutureIT_EERKNS_3PIDIT0_EEMSD_FSA_T1_T2_ET3_T4_ENKUlPNS_11ProcessBaseEE_clESO_
@ 0x2afe188d48b1
_ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8dispatchI7NothingNS0_20AsyncExecutorProcessERKSt8functionIFvvEEPvS9_SC_EENS0_6FutureIT_EERKNS0_3PIDIT0_EEMSH_FSE_T1_T2_ET3_T4_EUlS2_E_E9_M_invokeERKSt9_Any_dataS2_
@ 0x2afe197a8c61 std::function<>::operator()()
I0315 04:16:51.855080 2681 leveldb.cpp:181] Compacted db in 44.189206ms
I0315 04:16:51.855180 2681 leveldb.cpp:196] Created db iterator in 27246ns
I0315 04:16:51.855200 2681 leveldb.cpp:202] Seeked to beginning of db in 3314ns
I0315 04:16:51.855211 2681 leveldb.cpp:271] Iterated through 0 keys in the db
in 364ns
I0315 04:16:51.855265 2681 replica.cpp:779] Replica recovered with log
positions 0 -> 0 with 1 holes and 0 unlearned
I0315 04:16:51.856449 2681 cluster.cpp:183] Creating default 'local' authorizer
I0315 04:16:51.859966 2709 master.cpp:376] Master
d429b4cf-027e-46a9-97af-226792924cc4 (01fcd642f65f) started on 172.17.0.4:39845
@ 0x2afe1978ee7f process::ProcessBase::visit()
I0315 04:16:51.860005 2709 master.cpp:378] Flags at startup: --acls=""
--allocation_interval="1secs" --allocator="HierarchicalDRF"
--authenticate="false" --authenticate_http="true" --authenticate_slaves="true"
--authenticators="crammd5" --authorizers="local"
--credentials="/tmp/rHaIvb/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.29.0/_inst/share/mesos/webui"
--work_dir="/tmp/rHaIvb/master" --zk_session_timeout="10secs"
I0315 04:16:51.860431 2709 master.cpp:425] Master allowing unauthenticated
frameworks to register
I0315 04:16:51.860445 2709 master.cpp:428] Master only allowing authenticated
slaves to register
I0315 04:16:51.860453 2709 credentials.hpp:35] Loading credentials for
authentication from '/tmp/rHaIvb/credentials'
I0315 04:16:51.861218 2709 master.cpp:468] Using default 'crammd5'
authenticator
I0315 04:16:51.861392 2709 master.cpp:537] Using default 'basic' HTTP
authenticator
I0315 04:16:51.861528 2709 master.cpp:571] Authorization enabled
I0315 04:16:51.861888 2706 hierarchical.cpp:144] Initialized hierarchical
allocator process
I0315 04:16:51.861968 2706 whitelist_watcher.cpp:77] No whitelist given
I0315 04:16:51.862046 2714 recover.cpp:447] Starting replica recovery
I0315 04:16:51.862376 2714 recover.cpp:473] Replica is in EMPTY status
I0315 04:16:51.867487 2705 replica.cpp:673] Replica in EMPTY status received a
broadcasted recover request from (4813)@172.17.0.4:39845
I0315 04:16:51.868098 2713 recover.cpp:193] Received a recover response from a
replica in EMPTY status
@ 0x2afe19794e0c process::DispatchEvent::visit()
I0315 04:16:51.868788 2715 recover.cpp:564] Updating replica status to STARTING
I0315 04:16:51.871018 2701 master.cpp:1806] The newly elected leader is
[email protected]:39845 with id d429b4cf-027e-46a9-97af-226792924cc4
I0315 04:16:51.871063 2701 master.cpp:1819] Elected as the leading master!
I0315 04:16:51.871083 2701 master.cpp:1508] Recovering from registrar
I0315 04:16:51.871234 2707 registrar.cpp:307] Recovering registrar
@ 0x99d90c process::ProcessBase::serve()
@ 0x2afe1978b078 process::ProcessManager::resume()
@ 0x2afe19788112
_ZZN7process14ProcessManager12init_threadsEvENKUlRKSt11atomic_boolE_clES3_
@ 0x2afe197945ce
_ZNSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS3_EEE6__callIvIEILm0EEEET_OSt5tupleIIDpT0_EESt12_Index_tupleIIXspT1_EEE
@ 0x2afe1979457e
_ZNSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS3_EEEclIIEvEET0_DpOT_
@ 0x2afe19794510
_ZNSt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS4_EEEvEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2afe19794467
_ZNSt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS4_EEEvEEclEv
@ 0x2afe19794400
_ZNSt6thread5_ImplISt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS6_EEEvEEE6_M_runEv
@ 0x2afe1adfea60 (unknown)
@ 0x2afe1b575182 start_thread
@ 0x2afe1b88547d (unknown)
make[4]: *** [check-local] Segmentation fault
make[4]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.29.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1458012352-18905
Untagged: mesos-1458012352-18905:latest
Deleted: 136cfc69a211fc726228e37ee0b50f9d79ef349a6c5e2ac33c569c68057ab614
Deleted: fc91397a445e569ffadf2e537efdd1207bfad4d82534049de6d641ba98daa368
Deleted: b69b88c1e1cd00181d5c9154f3e9619ec8fb3afe892aeb0490f0765aebf780d8
Deleted: 17e1610f1e27666a13f8ca079e9ebb11c24494b8a5ed4ed5df877691ba470435
Deleted: d5fa89bf05553adfc6f954ce4ba7d916e71341915211c817d05975f52f4bc12e
Deleted: 144027a85962f820f57caaf7d2104455214a428b1d0af893c9a8de74edd97e45
Deleted: 848daccb153b7aa6ff4a229278d24d945b6ea23e2ad8b06ecdc0f389c641da1a
Deleted: 38957fcac7db8839ad02f28f40499a2207cc5950800d749ca6039073ffcca741
Deleted: d4c338b5a13fffa3aa27b7883e0eaf819948aa7c44ba88d294f32343fd62eec0
Deleted: 7477643b2cce0c37f0ca58fff6d9faeed377218cd81c26395557c08ca6913c9f
Deleted: f6e006f6d02695a98bec8e3962e21cff0cda0293bc07880a8943cd1c0ec9cb2e
Deleted: 65dc81e742400834c56b316b9ebaa09d8c3812ff8864ba1ccbae2f99badaa425
Deleted: 735b32b15c2d6bf3b1b0796ae49fda0cdc5e85106273bf943d1cf1ad1aa9f204
Deleted: f8c3ca62f0644c95f1499f0cac5da0680dc3d6533ed9bd5050429a27d0a497d3
Deleted: 87d93f820d589b1eb5a106762f6ae63ba67d2e7623783d07df14dd3599b9d3a0
Deleted: 7d6b1a49cb8025d36f0a6b29bfcdec395d23c88a00bad57fb0f4eca8667b9f53
Build step 'Execute shell' marked build as failure
{code}
was:
This seems to be an issue distinct from the other tickets that have been filed
on this test. Failed log is included below; while the core dump appears just
after the start of {{MasterMaintenanceTest.InverseOffersFilters}}, it looks to
me like the segfault is triggered by one of the callbacks called at the end of
{{MasterMaintenanceTest.InverseOffers}}.
{code}
[ RUN ] MasterMaintenanceTest.InverseOffers
I0315 04:16:50.786032 2681 leveldb.cpp:174] Opened db in 125.361171ms
I0315 04:16:50.836374 2681 leveldb.cpp:181] Compacted db in 50.254411ms
I0315 04:16:50.836470 2681 leveldb.cpp:196] Created db iterator in 25917ns
I0315 04:16:50.836488 2681 leveldb.cpp:202] Seeked to beginning of db in 3291ns
I0315 04:16:50.836498 2681 leveldb.cpp:271] Iterated through 0 keys in the db
in 253ns
I0315 04:16:50.836549 2681 replica.cpp:779] Replica recovered with log
positions 0 -> 0 with 1 holes and 0 unlearned
I0315 04:16:50.837474 2702 recover.cpp:447] Starting replica recovery
I0315 04:16:50.837565 2681 cluster.cpp:183] Creating default 'local' authorizer
I0315 04:16:50.838191 2702 recover.cpp:473] Replica is in EMPTY status
I0315 04:16:50.839532 2704 replica.cpp:673] Replica in EMPTY status received a
broadcasted recover request from (4784)@172.17.0.4:39845
I0315 04:16:50.839754 2705 recover.cpp:193] Received a recover response from a
replica in EMPTY status
I0315 04:16:50.841893 2704 recover.cpp:564] Updating replica status to STARTING
I0315 04:16:50.842566 2703 master.cpp:376] Master
c326bc68-2581-48d4-9dc4-0d6f270bdda1 (01fcd642f65f) started on 172.17.0.4:39845
I0315 04:16:50.842644 2703 master.cpp:378] Flags at startup: --acls=""
--allocation_interval="1secs" --allocator="HierarchicalDRF"
--authenticate="false" --authenticate_http="true" --authenticate_slaves="true"
--authenticators="crammd5" --authorizers="local"
--credentials="/tmp/DE2Uaw/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.29.0/_inst/share/mesos/webui"
--work_dir="/tmp/DE2Uaw/master" --zk_session_timeout="10secs"
I0315 04:16:50.843168 2703 master.cpp:425] Master allowing unauthenticated
frameworks to register
I0315 04:16:50.843227 2703 master.cpp:428] Master only allowing authenticated
slaves to register
I0315 04:16:50.843302 2703 credentials.hpp:35] Loading credentials for
authentication from '/tmp/DE2Uaw/credentials'
I0315 04:16:50.843737 2703 master.cpp:468] Using default 'crammd5'
authenticator
I0315 04:16:50.843969 2703 master.cpp:537] Using default 'basic' HTTP
authenticator
I0315 04:16:50.844177 2703 master.cpp:571] Authorization enabled
I0315 04:16:50.844360 2708 hierarchical.cpp:144] Initialized hierarchical
allocator process
I0315 04:16:50.844430 2708 whitelist_watcher.cpp:77] No whitelist given
I0315 04:16:50.848227 2703 master.cpp:1806] The newly elected leader is
[email protected]:39845 with id c326bc68-2581-48d4-9dc4-0d6f270bdda1
I0315 04:16:50.848269 2703 master.cpp:1819] Elected as the leading master!
I0315 04:16:50.848292 2703 master.cpp:1508] Recovering from registrar
I0315 04:16:50.848563 2703 registrar.cpp:307] Recovering registrar
I0315 04:16:50.876277 2711 leveldb.cpp:304] Persisting metadata (8 bytes) to
leveldb took 34.178445ms
I0315 04:16:50.876365 2711 replica.cpp:320] Persisted replica status to
STARTING
I0315 04:16:50.876776 2711 recover.cpp:473] Replica is in STARTING status
I0315 04:16:50.878779 2706 replica.cpp:673] Replica in STARTING status
received a broadcasted recover request from (4786)@172.17.0.4:39845
I0315 04:16:50.879240 2706 recover.cpp:193] Received a recover response from a
replica in STARTING status
I0315 04:16:50.880100 2701 recover.cpp:564] Updating replica status to VOTING
I0315 04:16:50.915776 2701 leveldb.cpp:304] Persisting metadata (8 bytes) to
leveldb took 35.472106ms
I0315 04:16:50.915868 2701 replica.cpp:320] Persisted replica status to VOTING
I0315 04:16:50.916158 2701 recover.cpp:578] Successfully joined the Paxos group
I0315 04:16:50.916363 2701 recover.cpp:462] Recover process terminated
I0315 04:16:50.917192 2701 log.cpp:659] Attempting to start the writer
I0315 04:16:50.919196 2714 replica.cpp:493] Replica received implicit promise
request from (4787)@172.17.0.4:39845 with proposal 1
I0315 04:16:50.957757 2714 leveldb.cpp:304] Persisting metadata (8 bytes) to
leveldb took 38.496305ms
I0315 04:16:50.957844 2714 replica.cpp:342] Persisted promised to 1
I0315 04:16:50.959254 2714 coordinator.cpp:238] Coordinator attempting to fill
missing positions
I0315 04:16:50.960928 2712 replica.cpp:388] Replica received explicit promise
request from (4788)@172.17.0.4:39845 for position 0 with proposal 2
I0315 04:16:51.000308 2712 leveldb.cpp:341] Persisting action (8 bytes) to
leveldb took 39.300546ms
I0315 04:16:51.000401 2712 replica.cpp:712] Persisted action at 0
I0315 04:16:51.002223 2707 replica.cpp:537] Replica received write request for
position 0 from (4789)@172.17.0.4:39845
I0315 04:16:51.002362 2707 leveldb.cpp:436] Reading position from leveldb took
83026ns
I0315 04:16:51.035646 2707 leveldb.cpp:341] Persisting action (14 bytes) to
leveldb took 33.201925ms
I0315 04:16:51.035750 2707 replica.cpp:712] Persisted action at 0
I0315 04:16:51.036618 2707 replica.cpp:691] Replica received learned notice
for position 0 from @0.0.0.0:0
I0315 04:16:51.056340 2707 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 19.66721ms
I0315 04:16:51.056438 2707 replica.cpp:712] Persisted action at 0
I0315 04:16:51.056480 2707 replica.cpp:697] Replica learned NOP action at
position 0
I0315 04:16:51.057850 2715 log.cpp:675] Writer started with ending position 0
I0315 04:16:51.059509 2709 leveldb.cpp:436] Reading position from leveldb took
75281ns
I0315 04:16:51.061115 2709 registrar.cpp:340] Successfully fetched the
registry (0B) in 212.499968ms
I0315 04:16:51.061276 2709 registrar.cpp:439] Applied 1 operations in 44901ns;
attempting to update the 'registry'
I0315 04:16:51.062515 2702 log.cpp:683] Attempting to append 170 bytes to the
log
I0315 04:16:51.062980 2709 coordinator.cpp:348] Coordinator attempting to
write APPEND action at position 1
I0315 04:16:51.064456 2709 replica.cpp:537] Replica received write request for
position 1 from (4790)@172.17.0.4:39845
I0315 04:16:51.098196 2709 leveldb.cpp:341] Persisting action (189 bytes) to
leveldb took 33.666091ms
I0315 04:16:51.098292 2709 replica.cpp:712] Persisted action at 1
I0315 04:16:51.099901 2709 replica.cpp:691] Replica received learned notice
for position 1 from @0.0.0.0:0
I0315 04:16:51.142916 2709 leveldb.cpp:341] Persisting action (191 bytes) to
leveldb took 42.95982ms
I0315 04:16:51.143008 2709 replica.cpp:712] Persisted action at 1
I0315 04:16:51.143048 2709 replica.cpp:697] Replica learned APPEND action at
position 1
I0315 04:16:51.145321 2709 registrar.cpp:484] Successfully updated the
'registry' in 83.969024ms
I0315 04:16:51.145479 2709 registrar.cpp:370] Successfully recovered registrar
I0315 04:16:51.145836 2702 log.cpp:702] Attempting to truncate the log to 1
I0315 04:16:51.146333 2706 master.cpp:1616] Recovered 0 slaves from the
Registry (131B) ; allowing 10mins for slaves to re-register
I0315 04:16:51.146528 2700 hierarchical.cpp:171] Skipping recovery of
hierarchical allocator: nothing to recover
I0315 04:16:51.147137 2700 coordinator.cpp:348] Coordinator attempting to
write TRUNCATE action at position 2
I0315 04:16:51.148613 2700 replica.cpp:537] Replica received write request for
position 2 from (4791)@172.17.0.4:39845
I0315 04:16:51.181690 2700 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 32.919462ms
I0315 04:16:51.181779 2700 replica.cpp:712] Persisted action at 2
I0315 04:16:51.183358 2700 replica.cpp:691] Replica received learned notice
for position 2 from @0.0.0.0:0
I0315 04:16:51.215826 2700 leveldb.cpp:341] Persisting action (18 bytes) to
leveldb took 32.418101ms
I0315 04:16:51.215983 2700 leveldb.cpp:399] Deleting ~1 keys from leveldb took
75363ns
I0315 04:16:51.216012 2700 replica.cpp:712] Persisted action at 2
I0315 04:16:51.216049 2700 replica.cpp:697] Replica learned TRUNCATE action at
position 2
I0315 04:16:51.230171 2700 slave.cpp:193] Slave started on
117)@172.17.0.4:39845
I0315 04:16:51.230217 2700 slave.cpp:194] Flags at startup:
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5"
--cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false"
--cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false"
--cgroups_root="mesos" --container_disk_watch_interval="15secs"
--containerizers="mesos"
--credential="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/credential"
--default_role="*" --disk_watch_interval="1mins" --docker="docker"
--docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io";
--docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock"
--docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker"
--enforce_container_disk_quota="false" --executor_registration_timeout="1mins"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/fetch"
--fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
--gc_disk_headroom="0.1" --hadoop_home="" --help="false"
--hostname="maintenance-host" --hostname_lookup="true"
--image_provisioner_backend="copy" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem"
--launcher_dir="/mesos/mesos-0.29.0/_build/src" --logbufsecs="0"
--logging_level="INFO" --oversubscribed_resources_interval="15secs"
--perf_duration="10secs" --perf_interval="1mins"
--qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect"
--recovery_timeout="15mins" --registration_backoff_factor="10ms"
--resources="cpus:2;mem:1024;disk:1024;ports:[31000-32000]"
--revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox"
--strict="true" --switch_user="true" --systemd_enable_support="true"
--systemd_runtime_directory="/run/systemd/system" --version="false"
--work_dir="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV"
I0315 04:16:51.230711 2700 credentials.hpp:83] Loading credential for
authentication from '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/credential'
I0315 04:16:51.230989 2700 slave.cpp:324] Slave using credential for:
test-principal
I0315 04:16:51.231161 2700 resources.cpp:572] Parsing resources as JSON
failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000]
Trying semicolon-delimited string format instead
I0315 04:16:51.231653 2700 slave.cpp:464] Slave resources: cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0315 04:16:51.232312 2700 slave.cpp:472] Slave attributes: [ ]
I0315 04:16:51.232403 2700 slave.cpp:477] Slave hostname: maintenance-host
I0315 04:16:51.235890 2705 state.cpp:58] Recovering state from
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/meta'
I0315 04:16:51.236862 2705 status_update_manager.cpp:200] Recovering status
update manager
I0315 04:16:51.237467 2705 slave.cpp:4565] Finished recovery
I0315 04:16:51.237757 2715 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/maintenance/schedule'
I0315 04:16:51.238085 2705 slave.cpp:4737] Querying resource estimator for
oversubscribable resources
I0315 04:16:51.239225 2715 http.cpp:312] HTTP POST for
/master/maintenance/schedule from 172.17.0.4:53179
I0315 04:16:51.240380 2715 registrar.cpp:439] Applied 1 operations in
144666ns; attempting to update the 'registry'
I0315 04:16:51.242146 2708 log.cpp:683] Attempting to append 292 bytes to the
log
I0315 04:16:51.242471 2708 coordinator.cpp:348] Coordinator attempting to
write APPEND action at position 3
I0315 04:16:51.243657 2708 replica.cpp:537] Replica received write request for
position 3 from (4798)@172.17.0.4:39845
I0315 04:16:51.244132 2705 slave.cpp:4751] Received oversubscribable resources
from the resource estimator
I0315 04:16:51.244442 2704 status_update_manager.cpp:174] Pausing sending
status updates
I0315 04:16:51.244591 2705 slave.cpp:796] New master detected at
[email protected]:39845
I0315 04:16:51.244786 2705 slave.cpp:859] Authenticating with master
[email protected]:39845
I0315 04:16:51.244886 2705 slave.cpp:864] Using default CRAM-MD5 authenticatee
I0315 04:16:51.245357 2707 authenticatee.cpp:121] Creating new client SASL
connection
I0315 04:16:51.245787 2707 master.cpp:5659] Authenticating
slave(117)@172.17.0.4:39845
I0315 04:16:51.246064 2707 authenticator.cpp:413] Starting authentication
session for crammd5_authenticatee(301)@172.17.0.4:39845
I0315 04:16:51.246462 2707 authenticator.cpp:98] Creating new server SASL
connection
I0315 04:16:51.246776 2707 authenticatee.cpp:212] Received SASL authentication
mechanisms: CRAM-MD5
I0315 04:16:51.246865 2707 authenticatee.cpp:238] Attempting to authenticate
with mechanism 'CRAM-MD5'
I0315 04:16:51.247047 2707 authenticator.cpp:203] Received SASL authentication
start
I0315 04:16:51.247180 2707 authenticator.cpp:325] Authentication requires more
steps
I0315 04:16:51.247341 2707 authenticatee.cpp:258] Received SASL authentication
step
I0315 04:16:51.247489 2707 authenticator.cpp:231] Received SASL authentication
step
I0315 04:16:51.247572 2707 auxprop.cpp:107] Request to lookup properties for
user: 'test-principal' realm: '01fcd642f65f' server FQDN: '01fcd642f65f'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
I0315 04:16:51.247640 2707 auxprop.cpp:179] Looking up auxiliary property
'*userPassword'
I0315 04:16:51.247807 2707 auxprop.cpp:179] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I0315 04:16:51.247920 2707 auxprop.cpp:107] Request to lookup properties for
user: 'test-principal' realm: '01fcd642f65f' server FQDN: '01fcd642f65f'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
I0315 04:16:51.248013 2707 auxprop.cpp:129] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I0315 04:16:51.248100 2707 auxprop.cpp:129] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0315 04:16:51.248196 2707 authenticator.cpp:317] Authentication success
I0315 04:16:51.248461 2707 authenticatee.cpp:298] Authentication success
I0315 04:16:51.248597 2707 master.cpp:5689] Successfully authenticated
principal 'test-principal' at slave(117)@172.17.0.4:39845
I0315 04:16:51.248759 2700 authenticator.cpp:431] Authentication session
cleanup for crammd5_authenticatee(301)@172.17.0.4:39845
I0315 04:16:51.248988 2705 slave.cpp:832] Detecting new master
I0315 04:16:51.249363 2705 slave.cpp:927] Successfully authenticated with
master [email protected]:39845
I0315 04:16:51.249506 2705 slave.cpp:1321] Will retry registration in
9.155413ms if necessary
I0315 04:16:51.249981 2711 master.cpp:4370] Registering slave at
slave(117)@172.17.0.4:39845 (maintenance-host) with id
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
I0315 04:16:51.261998 2711 slave.cpp:1321] Will retry registration in
10.936296ms if necessary
I0315 04:16:51.262398 2711 master.cpp:4358] Ignoring register slave message
from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already in
progress
I0315 04:16:51.275990 2711 slave.cpp:1321] Will retry registration in
3.200397ms if necessary
I0315 04:16:51.276379 2711 master.cpp:4358] Ignoring register slave message
from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already in
progress
I0315 04:16:51.277753 2708 leveldb.cpp:341] Persisting action (311 bytes) to
leveldb took 33.976895ms
I0315 04:16:51.277799 2708 replica.cpp:712] Persisted action at 3
I0315 04:16:51.279341 2708 replica.cpp:691] Replica received learned notice
for position 3 from @0.0.0.0:0
I0315 04:16:51.281918 2711 slave.cpp:1321] Will retry registration in 131597ns
if necessary
I0315 04:16:51.282146 2700 master.cpp:4358] Ignoring register slave message
from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already in
progress
I0315 04:16:51.283844 2711 slave.cpp:1321] Will retry registration in
245.466527ms if necessary
I0315 04:16:51.284080 2711 master.cpp:4358] Ignoring register slave message
from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already in
progress
I0315 04:16:51.318001 2708 leveldb.cpp:341] Persisting action (313 bytes) to
leveldb took 38.528659ms
I0315 04:16:51.318091 2708 replica.cpp:712] Persisted action at 3
I0315 04:16:51.318123 2708 replica.cpp:697] Replica learned APPEND action at
position 3
I0315 04:16:51.320458 2711 registrar.cpp:484] Successfully updated the
'registry' in 79.843072ms
I0315 04:16:51.320747 2714 log.cpp:702] Attempting to truncate the log to 3
I0315 04:16:51.320879 2704 coordinator.cpp:348] Coordinator attempting to
write TRUNCATE action at position 4
I0315 04:16:51.320919 2711 registrar.cpp:439] Applied 1 operations in
118795ns; attempting to update the 'registry'
I0315 04:16:51.322357 2704 replica.cpp:537] Replica received write request for
position 4 from (4799)@172.17.0.4:39845
I0315 04:16:51.324488 2702 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/maintenance/status'
I0315 04:16:51.325279 2702 http.cpp:312] HTTP GET for
/master/maintenance/status from 172.17.0.4:53180
I0315 04:16:51.328512 2681 scheduler.cpp:172] Version: 0.29.0
I0315 04:16:51.329731 2703 scheduler.cpp:437] New master detected at
[email protected]:39845
I0315 04:16:51.332334 2702 scheduler.cpp:337] Connected with the master at
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.333514 2714 scheduler.cpp:230] Sending SUBSCRIBE call to
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.334751 2708 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0315 04:16:51.335245 2702 http.cpp:312] HTTP POST for
/master/api/v1/scheduler from 172.17.0.4:53181
I0315 04:16:51.335464 2702 master.cpp:2068] Received subscription request for
HTTP framework 'default'
I0315 04:16:51.335528 2702 master.cpp:1845] Authorizing framework principal
'test-principal' to receive offers for role '*'
I0315 04:16:51.335896 2713 master.cpp:2159] Subscribing framework 'default'
with checkpointing disabled and capabilities [ ]
I0315 04:16:51.337347 2700 hierarchical.cpp:265] Added framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.337435 2700 hierarchical.cpp:1453] No resources available to
allocate!
I0315 04:16:51.337471 2700 hierarchical.cpp:1548] No inverse offers to send
out!
I0315 04:16:51.337496 2700 hierarchical.cpp:1130] Performed allocation for 0
slaves in 122430ns
I0315 04:16:51.337657 2700 master.hpp:1715] Sending heartbeat to
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.338486 2711 scheduler.cpp:612] Enqueuing event SUBSCRIBED
received from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.339167 2711 scheduler.cpp:612] Enqueuing event HEARTBEAT
received from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.339838 2714 master_maintenance_tests.cpp:179] Ignoring
HEARTBEAT event
I0315 04:16:51.359691 2704 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 37.255846ms
I0315 04:16:51.359787 2704 replica.cpp:712] Persisted action at 4
I0315 04:16:51.361541 2702 replica.cpp:691] Replica received learned notice
for position 4 from @0.0.0.0:0
I0315 04:16:51.393460 2702 leveldb.cpp:341] Persisting action (18 bytes) to
leveldb took 31.826446ms
I0315 04:16:51.393631 2702 leveldb.cpp:399] Deleting ~2 keys from leveldb took
82223ns
I0315 04:16:51.393667 2702 replica.cpp:712] Persisted action at 4
I0315 04:16:51.393718 2702 replica.cpp:697] Replica learned TRUNCATE action at
position 4
I0315 04:16:51.395421 2702 log.cpp:683] Attempting to append 465 bytes to the
log
I0315 04:16:51.395716 2702 coordinator.cpp:348] Coordinator attempting to
write APPEND action at position 5
I0315 04:16:51.397063 2702 replica.cpp:537] Replica received write request for
position 5 from (4803)@172.17.0.4:39845
I0315 04:16:51.430773 2702 leveldb.cpp:341] Persisting action (484 bytes) to
leveldb took 33.553652ms
I0315 04:16:51.430871 2702 replica.cpp:712] Persisted action at 5
I0315 04:16:51.432451 2702 replica.cpp:691] Replica received learned notice
for position 5 from @0.0.0.0:0
I0315 04:16:51.473805 2702 leveldb.cpp:341] Persisting action (486 bytes) to
leveldb took 41.212274ms
I0315 04:16:51.473908 2702 replica.cpp:712] Persisted action at 5
I0315 04:16:51.473949 2702 replica.cpp:697] Replica learned APPEND action at
position 5
I0315 04:16:51.476976 2703 registrar.cpp:484] Successfully updated the
'registry' in 155.968768ms
I0315 04:16:51.477423 2703 log.cpp:702] Attempting to truncate the log to 5
I0315 04:16:51.477689 2703 coordinator.cpp:348] Coordinator attempting to
write TRUNCATE action at position 6
I0315 04:16:51.478329 2702 master.cpp:4438] Registered slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host) with cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
I0315 04:16:51.478806 2713 hierarchical.cpp:473] Added slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host) with cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
I0315 04:16:51.479184 2702 replica.cpp:537] Replica received write request for
position 6 from (4804)@172.17.0.4:39845
I0315 04:16:51.478400 2703 slave.cpp:3482] Received ping from
slave-observer(117)@172.17.0.4:39845
I0315 04:16:51.479872 2703 slave.cpp:971] Registered with master
[email protected]:39845; given slave ID c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
I0315 04:16:51.479902 2703 fetcher.cpp:81] Clearing fetcher cache
I0315 04:16:51.480332 2703 slave.cpp:994] Checkpointing SlaveInfo to
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/meta/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/slave.info'
I0315 04:16:51.480789 2712 status_update_manager.cpp:181] Resuming sending
status updates
I0315 04:16:51.481290 2713 hierarchical.cpp:1150] Performed allocation for
slave c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 in 2.431536ms
I0315 04:16:51.481817 2703 slave.cpp:1030] Forwarding total oversubscribed
resources
I0315 04:16:51.482067 2713 master.cpp:5488] Sending 1 offers to framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
I0315 04:16:51.483192 2713 master.cpp:5578] Sending 1 inverse offers to
framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
I0315 04:16:51.483569 2713 master.cpp:4782] Received update of slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host) with total oversubscribed resources
I0315 04:16:51.484576 2713 hierarchical.cpp:531] Slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host) updated with
oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000])
I0315 04:16:51.484849 2713 hierarchical.cpp:1453] No resources available to
allocate!
I0315 04:16:51.484966 2701 scheduler.cpp:612] Enqueuing event OFFERS received
from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.485061 2713 hierarchical.cpp:1150] Performed allocation for
slave c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 in 414324ns
I0315 04:16:51.485884 2701 scheduler.cpp:612] Enqueuing event OFFERS received
from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.491091 2701 scheduler.cpp:230] Sending ACCEPT call to
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.493937 2712 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0315 04:16:51.494441 2714 http.cpp:312] HTTP POST for
/master/api/v1/scheduler from 172.17.0.4:53182
I0315 04:16:51.495529 2714 master.cpp:3268] Processing ACCEPT call for offers:
[ c326bc68-2581-48d4-9dc4-0d6f270bdda1-O0 ] on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host) for framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
(default)
I0315 04:16:51.495589 2714 master.cpp:2871] Authorizing framework principal
'test-principal' to launch task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 as user
'mesos'
W0315 04:16:51.501534 2714 validation.cpp:404] Executor default for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 uses less CPUs (None) than the minimum
required (0.01). Please update your executor, as this will be mandatory in
future releases.
W0315 04:16:51.501618 2714 validation.cpp:416] Executor default for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 uses less memory (None) than the minimum
required (32MB). Please update your executor, as this will be mandatory in
future releases.
I0315 04:16:51.502182 2714 master.hpp:177] Adding task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host)
I0315 04:16:51.502437 2714 master.cpp:3753] Launching task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) with resources cpus(*):2;
mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host)
I0315 04:16:51.503787 2700 slave.cpp:1361] Got assigned task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 for framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.504485 2700 slave.cpp:1480] Launching task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 for framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.512953 2700 paths.cpp:528] Trying to chown
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
to user 'mesos'
I0315 04:16:51.519822 2702 leveldb.cpp:341] Persisting action (16 bytes) to
leveldb took 40.48414ms
I0315 04:16:51.519923 2702 replica.cpp:712] Persisted action at 6
I0315 04:16:51.521419 2710 replica.cpp:691] Replica received learned notice
for position 6 from @0.0.0.0:0
I0315 04:16:51.524533 2700 slave.cpp:5367] Launching executor default of
framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 with resources in work
directory
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
I0315 04:16:51.527022 2700 exec.cpp:143] Version: 0.29.0
I0315 04:16:51.527752 2704 exec.cpp:193] Executor started at:
executor(47)@172.17.0.4:39845 with pid 2681
I0315 04:16:51.527802 2700 slave.cpp:1698] Queuing task
'ce9b06cb-9896-4c2e-9fad-ea8538541cf4' for executor 'default' of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.527966 2700 slave.cpp:749] Successfully attached file
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
I0315 04:16:51.528192 2700 slave.cpp:2643] Got registration for executor
'default' of framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from
executor(47)@172.17.0.4:39845
I0315 04:16:51.529881 2706 exec.cpp:217] Executor registered on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
I0315 04:16:51.529955 2706 exec.cpp:229] Executor::registered took 36242ns
I0315 04:16:51.530278 2700 slave.cpp:1863] Sending queued task
'ce9b06cb-9896-4c2e-9fad-ea8538541cf4' to executor 'default' of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 at executor(47)@172.17.0.4:39845
I0315 04:16:51.530894 2708 exec.cpp:304] Executor asked to run task
'ce9b06cb-9896-4c2e-9fad-ea8538541cf4'
I0315 04:16:51.530988 2708 exec.cpp:313] Executor::launchTask took 67937ns
I0315 04:16:51.531083 2708 exec.cpp:526] Executor sending status update
TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.531365 2708 slave.cpp:3002] Handling status update TASK_RUNNING
(UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from executor(47)@172.17.0.4:39845
I0315 04:16:51.532158 2708 status_update_manager.cpp:320] Received status
update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.532274 2708 status_update_manager.cpp:497] Creating
StatusUpdate stream for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.532951 2708 status_update_manager.cpp:374] Forwarding update
TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to the slave
I0315 04:16:51.533524 2708 slave.cpp:3400] Forwarding the update TASK_RUNNING
(UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to [email protected]:39845
I0315 04:16:51.533817 2708 slave.cpp:3294] Status update manager successfully
handled status update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e)
for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.533936 2708 slave.cpp:3310] Sending acknowledgement for status
update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to executor(47)@172.17.0.4:39845
I0315 04:16:51.534340 2708 master.cpp:4927] Status update TASK_RUNNING (UUID:
5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host)
I0315 04:16:51.534457 2708 master.cpp:4975] Forwarding status update
TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.534803 2701 exec.cpp:350] Executor received status update
acknowledgement 5c63475c-af40-417d-9368-b7e3ede4a30e for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.535385 2708 master.cpp:6585] Updating the state of task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
I0315 04:16:51.537346 2704 scheduler.cpp:612] Enqueuing event UPDATE received
from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.541487 2708 scheduler.cpp:230] Sending ACKNOWLEDGE call to
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.542043 2708 scheduler.cpp:230] Sending DECLINE call to
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.543292 2708 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0315 04:16:51.543979 2708 http.cpp:312] HTTP POST for
/master/api/v1/scheduler from 172.17.0.4:53182
I0315 04:16:51.544251 2708 master.cpp:4082] Processing ACKNOWLEDGE call
5c63475c-af40-417d-9368-b7e3ede4a30e for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
I0315 04:16:51.544818 2708 status_update_manager.cpp:392] Received status
update acknowledgement (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.545315 2708 slave.cpp:2412] Status update manager successfully
handled status update acknowledgement (UUID:
5c63475c-af40-417d-9368-b7e3ede4a30e) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.546144 2702 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0315 04:16:51.546668 2702 http.cpp:312] HTTP POST for
/master/api/v1/scheduler from 172.17.0.4:53182
I0315 04:16:51.547322 2702 master.cpp:3805] Processing DECLINE call for
offers: [ c326bc68-2581-48d4-9dc4-0d6f270bdda1-O1 ] for framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
I0315 04:16:51.565781 2710 leveldb.cpp:341] Persisting action (18 bytes) to
leveldb took 44.297436ms
I0315 04:16:51.565945 2710 leveldb.cpp:399] Deleting ~2 keys from leveldb took
76582ns
I0315 04:16:51.565978 2710 replica.cpp:712] Persisted action at 6
I0315 04:16:51.566015 2710 replica.cpp:697] Replica learned TRUNCATE action at
position 6
I0315 04:16:51.570482 2707 hierarchical.cpp:1453] No resources available to
allocate!
I0315 04:16:51.570847 2707 hierarchical.cpp:1130] Performed allocation for 1
slaves in 640118ns
I0315 04:16:51.571091 2707 master.cpp:5578] Sending 1 inverse offers to
framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
I0315 04:16:51.573333 2712 scheduler.cpp:612] Enqueuing event OFFERS received
from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.581941 2713 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/maintenance/status'
I0315 04:16:51.582535 2706 http.cpp:312] HTTP GET for
/master/maintenance/status from 172.17.0.4:53183
I0315 04:16:51.587846 2715 scheduler.cpp:230] Sending ACCEPT call to
http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.589800 2715 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/api/v1/scheduler'
I0315 04:16:51.590328 2715 http.cpp:312] HTTP POST for
/master/api/v1/scheduler from 172.17.0.4:53182
W0315 04:16:51.590833 2715 master.cpp:3231] ACCEPT call used invalid offers '[
c326bc68-2581-48d4-9dc4-0d6f270bdda1-O2 ]': Offer
c326bc68-2581-48d4-9dc4-0d6f270bdda1-O2 is no longer valid
I0315 04:16:51.603070 2706 hierarchical.cpp:1453] No resources available to
allocate!
I0315 04:16:51.603425 2706 hierarchical.cpp:1130] Performed allocation for 1
slaves in 570929ns
I0315 04:16:51.603674 2706 master.cpp:5578] Sending 1 inverse offers to
framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
I0315 04:16:51.605583 2711 scheduler.cpp:612] Enqueuing event OFFERS received
from http://172.17.0.4:39845/master/api/v1/scheduler
I0315 04:16:51.614972 2709 process.cpp:3136] Handling HTTP event for process
'master' with path: '/master/maintenance/status'
I0315 04:16:51.616044 2713 http.cpp:312] HTTP GET for
/master/maintenance/status from 172.17.0.4:53184
I0315 04:16:51.620043 2681 master.cpp:1065] Master terminating
W0315 04:16:51.620407 2681 master.cpp:6637] Removing task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host) in non-terminal state TASK_RUNNING
I0315 04:16:51.621245 2712 hierarchical.cpp:505] Removed slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
I0315 04:16:51.621573 2681 master.cpp:6680] Removing executor 'default' with
resources of framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 on slave
c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
(maintenance-host)
I0315 04:16:51.622886 2704 hierarchical.cpp:326] Removed framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
E0315 04:16:51.624392 2705 scheduler.cpp:585] End-Of-File received from
master. The master closed the event stream
I0315 04:16:51.628783 2703 slave.cpp:3528] [email protected]:39845 exited
W0315 04:16:51.628839 2703 slave.cpp:3531] Master disconnected! Waiting for a
new master to be elected
I0315 04:16:51.632709 2704 slave.cpp:3528] executor(47)@172.17.0.4:39845 exited
I0315 04:16:51.633152 2704 slave.cpp:3886] Executor 'default' of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 exited with status 0
I0315 04:16:51.633311 2704 slave.cpp:3002] Handling status update TASK_FAILED
(UUID: f793d2cc-720c-4d89-91d5-3f45e73ad6ea) for task
ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from @0.0.0.0:0
I0315 04:16:51.641787 2704 slave.cpp:668] Slave terminating
I0315 04:16:51.641914 2704 slave.cpp:2079] Asked to shut down framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 by @0.0.0.0:0
I0315 04:16:51.641957 2704 slave.cpp:2104] Shutting down framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.642027 2704 slave.cpp:3990] Cleaning up executor 'default' of
framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 at
executor(47)@172.17.0.4:39845
I0315 04:16:51.642453 2704 slave.cpp:4078] Cleaning up framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.642616 2707 gc.cpp:55] Scheduling
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
for gc 6.99999256701333days in the future
I0315 04:16:51.642633 2710 status_update_manager.cpp:282] Closing status
update streams for framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.642719 2710 status_update_manager.cpp:528] Cleaning up status
update stream for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
I0315 04:16:51.643265 2707 gc.cpp:55] Scheduling
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default'
for gc 6.99999256488296days in the future
I0315 04:16:51.643373 2707 gc.cpp:55] Scheduling
'/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000'
for gc 6.99999256301037days in the future
I0315 04:16:51.646150 2705 scheduler.cpp:419] Re-detecting master
I0315 04:16:51.646462 2705 scheduler.cpp:370] Ignoring disconnection attempt
from stale connection
I0315 04:16:51.646507 2705 scheduler.cpp:370] Ignoring disconnection attempt
from stale connection
[ OK ] MasterMaintenanceTest.InverseOffers (992 ms)
[ RUN ] MasterMaintenanceTest.InverseOffersFilters
*** Aborted at 1458015411 (unix time) try "date -d @1458015411" if you are
using GNU date ***
PC: @ 0x172ca21
testing::internal::UntypedFunctionMockerBase::UntypedInvokeWith()
*** SIGSEGV (@0x0) received by PID 2681 (TID 0x2afe25c47700) from PID 0; stack
trace: ***
@ 0x2afe689dfff7 (unknown)
@ 0x2afe689e4159 (unknown)
@ 0x2afe1b57d340 (unknown)
@ 0x172ca21
testing::internal::UntypedFunctionMockerBase::UntypedInvokeWith()
@ 0xf494ff testing::internal::FunctionMockerBase<>::InvokeWith()
@ 0xf43663 testing::internal::FunctionMocker<>::Invoke()
@ 0xf42920
mesos::internal::tests::MasterMaintenanceTest::Callbacks::disconnected()
@ 0xf5ab55
_ZNKSt7_Mem_fnIMN5mesos8internal5tests21MasterMaintenanceTest9CallbacksEFvvEEclIJEvEEvRS4_DpOT_
@ 0xf57120
_ZNSt5_BindIFSt7_Mem_fnIMN5mesos8internal5tests21MasterMaintenanceTest9CallbacksEFvvEESt17reference_wrapperIS5_EEE6__callIvJEJLm0EEEET_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE
@ 0xf52d84 std::_Bind<>::operator()<>()
@ 0xf4e099 std::_Function_handler<>::_M_invoke()
@ 0x99f3ac std::function<>::operator()()
I0315 04:16:51.810700 2681 leveldb.cpp:174] Opened db in 153.621998ms
@ 0x2afe188c14e9 process::AsyncExecutorProcess::execute<>()
@ 0x2afe188c8d09
_ZZN7process8dispatchI7NothingNS_20AsyncExecutorProcessERKSt8functionIFvvEEPvS5_S8_EENS_6FutureIT_EERKNS_3PIDIT0_EEMSD_FSA_T1_T2_ET3_T4_ENKUlPNS_11ProcessBaseEE_clESO_
@ 0x2afe188d48b1
_ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8dispatchI7NothingNS0_20AsyncExecutorProcessERKSt8functionIFvvEEPvS9_SC_EENS0_6FutureIT_EERKNS0_3PIDIT0_EEMSH_FSE_T1_T2_ET3_T4_EUlS2_E_E9_M_invokeERKSt9_Any_dataS2_
@ 0x2afe197a8c61 std::function<>::operator()()
I0315 04:16:51.855080 2681 leveldb.cpp:181] Compacted db in 44.189206ms
I0315 04:16:51.855180 2681 leveldb.cpp:196] Created db iterator in 27246ns
I0315 04:16:51.855200 2681 leveldb.cpp:202] Seeked to beginning of db in 3314ns
I0315 04:16:51.855211 2681 leveldb.cpp:271] Iterated through 0 keys in the db
in 364ns
I0315 04:16:51.855265 2681 replica.cpp:779] Replica recovered with log
positions 0 -> 0 with 1 holes and 0 unlearned
I0315 04:16:51.856449 2681 cluster.cpp:183] Creating default 'local' authorizer
I0315 04:16:51.859966 2709 master.cpp:376] Master
d429b4cf-027e-46a9-97af-226792924cc4 (01fcd642f65f) started on 172.17.0.4:39845
@ 0x2afe1978ee7f process::ProcessBase::visit()
I0315 04:16:51.860005 2709 master.cpp:378] Flags at startup: --acls=""
--allocation_interval="1secs" --allocator="HierarchicalDRF"
--authenticate="false" --authenticate_http="true" --authenticate_slaves="true"
--authenticators="crammd5" --authorizers="local"
--credentials="/tmp/rHaIvb/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.29.0/_inst/share/mesos/webui"
--work_dir="/tmp/rHaIvb/master" --zk_session_timeout="10secs"
I0315 04:16:51.860431 2709 master.cpp:425] Master allowing unauthenticated
frameworks to register
I0315 04:16:51.860445 2709 master.cpp:428] Master only allowing authenticated
slaves to register
I0315 04:16:51.860453 2709 credentials.hpp:35] Loading credentials for
authentication from '/tmp/rHaIvb/credentials'
I0315 04:16:51.861218 2709 master.cpp:468] Using default 'crammd5'
authenticator
I0315 04:16:51.861392 2709 master.cpp:537] Using default 'basic' HTTP
authenticator
I0315 04:16:51.861528 2709 master.cpp:571] Authorization enabled
I0315 04:16:51.861888 2706 hierarchical.cpp:144] Initialized hierarchical
allocator process
I0315 04:16:51.861968 2706 whitelist_watcher.cpp:77] No whitelist given
I0315 04:16:51.862046 2714 recover.cpp:447] Starting replica recovery
I0315 04:16:51.862376 2714 recover.cpp:473] Replica is in EMPTY status
I0315 04:16:51.867487 2705 replica.cpp:673] Replica in EMPTY status received a
broadcasted recover request from (4813)@172.17.0.4:39845
I0315 04:16:51.868098 2713 recover.cpp:193] Received a recover response from a
replica in EMPTY status
@ 0x2afe19794e0c process::DispatchEvent::visit()
I0315 04:16:51.868788 2715 recover.cpp:564] Updating replica status to STARTING
I0315 04:16:51.871018 2701 master.cpp:1806] The newly elected leader is
[email protected]:39845 with id d429b4cf-027e-46a9-97af-226792924cc4
I0315 04:16:51.871063 2701 master.cpp:1819] Elected as the leading master!
I0315 04:16:51.871083 2701 master.cpp:1508] Recovering from registrar
I0315 04:16:51.871234 2707 registrar.cpp:307] Recovering registrar
@ 0x99d90c process::ProcessBase::serve()
@ 0x2afe1978b078 process::ProcessManager::resume()
@ 0x2afe19788112
_ZZN7process14ProcessManager12init_threadsEvENKUlRKSt11atomic_boolE_clES3_
@ 0x2afe197945ce
_ZNSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS3_EEE6__callIvIEILm0EEEET_OSt5tupleIIDpT0_EESt12_Index_tupleIIXspT1_EEE
@ 0x2afe1979457e
_ZNSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS3_EEEclIIEvEET0_DpOT_
@ 0x2afe19794510
_ZNSt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS4_EEEvEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
@ 0x2afe19794467
_ZNSt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS4_EEEvEEclEv
@ 0x2afe19794400
_ZNSt6thread5_ImplISt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS6_EEEvEEE6_M_runEv
@ 0x2afe1adfea60 (unknown)
@ 0x2afe1b575182 start_thread
@ 0x2afe1b88547d (unknown)
make[4]: *** [check-local] Segmentation fault
make[4]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-0.29.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1458012352-18905
Untagged: mesos-1458012352-18905:latest
Deleted: 136cfc69a211fc726228e37ee0b50f9d79ef349a6c5e2ac33c569c68057ab614
Deleted: fc91397a445e569ffadf2e537efdd1207bfad4d82534049de6d641ba98daa368
Deleted: b69b88c1e1cd00181d5c9154f3e9619ec8fb3afe892aeb0490f0765aebf780d8
Deleted: 17e1610f1e27666a13f8ca079e9ebb11c24494b8a5ed4ed5df877691ba470435
Deleted: d5fa89bf05553adfc6f954ce4ba7d916e71341915211c817d05975f52f4bc12e
Deleted: 144027a85962f820f57caaf7d2104455214a428b1d0af893c9a8de74edd97e45
Deleted: 848daccb153b7aa6ff4a229278d24d945b6ea23e2ad8b06ecdc0f389c641da1a
Deleted: 38957fcac7db8839ad02f28f40499a2207cc5950800d749ca6039073ffcca741
Deleted: d4c338b5a13fffa3aa27b7883e0eaf819948aa7c44ba88d294f32343fd62eec0
Deleted: 7477643b2cce0c37f0ca58fff6d9faeed377218cd81c26395557c08ca6913c9f
Deleted: f6e006f6d02695a98bec8e3962e21cff0cda0293bc07880a8943cd1c0ec9cb2e
Deleted: 65dc81e742400834c56b316b9ebaa09d8c3812ff8864ba1ccbae2f99badaa425
Deleted: 735b32b15c2d6bf3b1b0796ae49fda0cdc5e85106273bf943d1cf1ad1aa9f204
Deleted: f8c3ca62f0644c95f1499f0cac5da0680dc3d6533ed9bd5050429a27d0a497d3
Deleted: 87d93f820d589b1eb5a106762f6ae63ba67d2e7623783d07df14dd3599b9d3a0
Deleted: 7d6b1a49cb8025d36f0a6b29bfcdec395d23c88a00bad57fb0f4eca8667b9f53
Build step 'Execute shell' marked build as failure
{code}
> Move maintenance tests to use the new scheduler library interface.
> ------------------------------------------------------------------
>
> Key: MESOS-4948
> URL: https://issues.apache.org/jira/browse/MESOS-4948
> Project: Mesos
> Issue Type: Bug
> Components: tests
> Environment: Ubuntu 14.04, using gcc, with libevent and SSL enabled
> (on ASF CI)
> Reporter: Greg Mann
> Labels: flaky-test, maintenance, mesosphere, newbie
>
> We need to move the existing maintenance tests to use the new scheduler
> interface. We have already moved 1 test
> {{MasterMaintenanceTest.PendingUnavailabilityTest}} to use the new interface.
> It would be good to move the other 2 remaining tests to the new interface
> since it can lead to failures around the stack object being referenced after
> has been already destroyed. Detailed log from an ASF CI build failure.
> {code}
> [ RUN ] MasterMaintenanceTest.InverseOffers
> I0315 04:16:50.786032 2681 leveldb.cpp:174] Opened db in 125.361171ms
> I0315 04:16:50.836374 2681 leveldb.cpp:181] Compacted db in 50.254411ms
> I0315 04:16:50.836470 2681 leveldb.cpp:196] Created db iterator in 25917ns
> I0315 04:16:50.836488 2681 leveldb.cpp:202] Seeked to beginning of db in
> 3291ns
> I0315 04:16:50.836498 2681 leveldb.cpp:271] Iterated through 0 keys in the
> db in 253ns
> I0315 04:16:50.836549 2681 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0315 04:16:50.837474 2702 recover.cpp:447] Starting replica recovery
> I0315 04:16:50.837565 2681 cluster.cpp:183] Creating default 'local'
> authorizer
> I0315 04:16:50.838191 2702 recover.cpp:473] Replica is in EMPTY status
> I0315 04:16:50.839532 2704 replica.cpp:673] Replica in EMPTY status received
> a broadcasted recover request from (4784)@172.17.0.4:39845
> I0315 04:16:50.839754 2705 recover.cpp:193] Received a recover response from
> a replica in EMPTY status
> I0315 04:16:50.841893 2704 recover.cpp:564] Updating replica status to
> STARTING
> I0315 04:16:50.842566 2703 master.cpp:376] Master
> c326bc68-2581-48d4-9dc4-0d6f270bdda1 (01fcd642f65f) started on
> 172.17.0.4:39845
> I0315 04:16:50.842644 2703 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/DE2Uaw/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.29.0/_inst/share/mesos/webui"
> --work_dir="/tmp/DE2Uaw/master" --zk_session_timeout="10secs"
> I0315 04:16:50.843168 2703 master.cpp:425] Master allowing unauthenticated
> frameworks to register
> I0315 04:16:50.843227 2703 master.cpp:428] Master only allowing
> authenticated slaves to register
> I0315 04:16:50.843302 2703 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/DE2Uaw/credentials'
> I0315 04:16:50.843737 2703 master.cpp:468] Using default 'crammd5'
> authenticator
> I0315 04:16:50.843969 2703 master.cpp:537] Using default 'basic' HTTP
> authenticator
> I0315 04:16:50.844177 2703 master.cpp:571] Authorization enabled
> I0315 04:16:50.844360 2708 hierarchical.cpp:144] Initialized hierarchical
> allocator process
> I0315 04:16:50.844430 2708 whitelist_watcher.cpp:77] No whitelist given
> I0315 04:16:50.848227 2703 master.cpp:1806] The newly elected leader is
> [email protected]:39845 with id c326bc68-2581-48d4-9dc4-0d6f270bdda1
> I0315 04:16:50.848269 2703 master.cpp:1819] Elected as the leading master!
> I0315 04:16:50.848292 2703 master.cpp:1508] Recovering from registrar
> I0315 04:16:50.848563 2703 registrar.cpp:307] Recovering registrar
> I0315 04:16:50.876277 2711 leveldb.cpp:304] Persisting metadata (8 bytes) to
> leveldb took 34.178445ms
> I0315 04:16:50.876365 2711 replica.cpp:320] Persisted replica status to
> STARTING
> I0315 04:16:50.876776 2711 recover.cpp:473] Replica is in STARTING status
> I0315 04:16:50.878779 2706 replica.cpp:673] Replica in STARTING status
> received a broadcasted recover request from (4786)@172.17.0.4:39845
> I0315 04:16:50.879240 2706 recover.cpp:193] Received a recover response from
> a replica in STARTING status
> I0315 04:16:50.880100 2701 recover.cpp:564] Updating replica status to VOTING
> I0315 04:16:50.915776 2701 leveldb.cpp:304] Persisting metadata (8 bytes) to
> leveldb took 35.472106ms
> I0315 04:16:50.915868 2701 replica.cpp:320] Persisted replica status to
> VOTING
> I0315 04:16:50.916158 2701 recover.cpp:578] Successfully joined the Paxos
> group
> I0315 04:16:50.916363 2701 recover.cpp:462] Recover process terminated
> I0315 04:16:50.917192 2701 log.cpp:659] Attempting to start the writer
> I0315 04:16:50.919196 2714 replica.cpp:493] Replica received implicit
> promise request from (4787)@172.17.0.4:39845 with proposal 1
> I0315 04:16:50.957757 2714 leveldb.cpp:304] Persisting metadata (8 bytes) to
> leveldb took 38.496305ms
> I0315 04:16:50.957844 2714 replica.cpp:342] Persisted promised to 1
> I0315 04:16:50.959254 2714 coordinator.cpp:238] Coordinator attempting to
> fill missing positions
> I0315 04:16:50.960928 2712 replica.cpp:388] Replica received explicit
> promise request from (4788)@172.17.0.4:39845 for position 0 with proposal 2
> I0315 04:16:51.000308 2712 leveldb.cpp:341] Persisting action (8 bytes) to
> leveldb took 39.300546ms
> I0315 04:16:51.000401 2712 replica.cpp:712] Persisted action at 0
> I0315 04:16:51.002223 2707 replica.cpp:537] Replica received write request
> for position 0 from (4789)@172.17.0.4:39845
> I0315 04:16:51.002362 2707 leveldb.cpp:436] Reading position from leveldb
> took 83026ns
> I0315 04:16:51.035646 2707 leveldb.cpp:341] Persisting action (14 bytes) to
> leveldb took 33.201925ms
> I0315 04:16:51.035750 2707 replica.cpp:712] Persisted action at 0
> I0315 04:16:51.036618 2707 replica.cpp:691] Replica received learned notice
> for position 0 from @0.0.0.0:0
> I0315 04:16:51.056340 2707 leveldb.cpp:341] Persisting action (16 bytes) to
> leveldb took 19.66721ms
> I0315 04:16:51.056438 2707 replica.cpp:712] Persisted action at 0
> I0315 04:16:51.056480 2707 replica.cpp:697] Replica learned NOP action at
> position 0
> I0315 04:16:51.057850 2715 log.cpp:675] Writer started with ending position 0
> I0315 04:16:51.059509 2709 leveldb.cpp:436] Reading position from leveldb
> took 75281ns
> I0315 04:16:51.061115 2709 registrar.cpp:340] Successfully fetched the
> registry (0B) in 212.499968ms
> I0315 04:16:51.061276 2709 registrar.cpp:439] Applied 1 operations in
> 44901ns; attempting to update the 'registry'
> I0315 04:16:51.062515 2702 log.cpp:683] Attempting to append 170 bytes to
> the log
> I0315 04:16:51.062980 2709 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 1
> I0315 04:16:51.064456 2709 replica.cpp:537] Replica received write request
> for position 1 from (4790)@172.17.0.4:39845
> I0315 04:16:51.098196 2709 leveldb.cpp:341] Persisting action (189 bytes) to
> leveldb took 33.666091ms
> I0315 04:16:51.098292 2709 replica.cpp:712] Persisted action at 1
> I0315 04:16:51.099901 2709 replica.cpp:691] Replica received learned notice
> for position 1 from @0.0.0.0:0
> I0315 04:16:51.142916 2709 leveldb.cpp:341] Persisting action (191 bytes) to
> leveldb took 42.95982ms
> I0315 04:16:51.143008 2709 replica.cpp:712] Persisted action at 1
> I0315 04:16:51.143048 2709 replica.cpp:697] Replica learned APPEND action at
> position 1
> I0315 04:16:51.145321 2709 registrar.cpp:484] Successfully updated the
> 'registry' in 83.969024ms
> I0315 04:16:51.145479 2709 registrar.cpp:370] Successfully recovered
> registrar
> I0315 04:16:51.145836 2702 log.cpp:702] Attempting to truncate the log to 1
> I0315 04:16:51.146333 2706 master.cpp:1616] Recovered 0 slaves from the
> Registry (131B) ; allowing 10mins for slaves to re-register
> I0315 04:16:51.146528 2700 hierarchical.cpp:171] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0315 04:16:51.147137 2700 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 2
> I0315 04:16:51.148613 2700 replica.cpp:537] Replica received write request
> for position 2 from (4791)@172.17.0.4:39845
> I0315 04:16:51.181690 2700 leveldb.cpp:341] Persisting action (16 bytes) to
> leveldb took 32.919462ms
> I0315 04:16:51.181779 2700 replica.cpp:712] Persisted action at 2
> I0315 04:16:51.183358 2700 replica.cpp:691] Replica received learned notice
> for position 2 from @0.0.0.0:0
> I0315 04:16:51.215826 2700 leveldb.cpp:341] Persisting action (18 bytes) to
> leveldb took 32.418101ms
> I0315 04:16:51.215983 2700 leveldb.cpp:399] Deleting ~1 keys from leveldb
> took 75363ns
> I0315 04:16:51.216012 2700 replica.cpp:712] Persisted action at 2
> I0315 04:16:51.216049 2700 replica.cpp:697] Replica learned TRUNCATE action
> at position 2
> I0315 04:16:51.230171 2700 slave.cpp:193] Slave started on
> 117)@172.17.0.4:39845
> I0315 04:16:51.230217 2700 slave.cpp:194] Flags at startup:
> --appc_simple_discovery_uri_prefix="http://";
> --appc_store_dir="/tmp/mesos/store/appc" --authenticatee="crammd5"
> --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false"
> --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false"
> --cgroups_root="mesos" --container_disk_watch_interval="15secs"
> --containerizers="mesos"
> --credential="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/credential"
> --default_role="*" --disk_watch_interval="1mins" --docker="docker"
> --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io";
> --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock"
> --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker"
> --enforce_container_disk_quota="false"
> --executor_registration_timeout="1mins"
> --executor_shutdown_grace_period="5secs"
> --fetcher_cache_dir="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/fetch"
> --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
> --gc_disk_headroom="0.1" --hadoop_home="" --help="false"
> --hostname="maintenance-host" --hostname_lookup="true"
> --image_provisioner_backend="copy" --initialize_driver_logging="true"
> --isolation="posix/cpu,posix/mem"
> --launcher_dir="/mesos/mesos-0.29.0/_build/src" --logbufsecs="0"
> --logging_level="INFO" --oversubscribed_resources_interval="15secs"
> --perf_duration="10secs" --perf_interval="1mins"
> --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect"
> --recovery_timeout="15mins" --registration_backoff_factor="10ms"
> --resources="cpus:2;mem:1024;disk:1024;ports:[31000-32000]"
> --revocable_cpu_low_priority="true" --sandbox_directory="/mnt/mesos/sandbox"
> --strict="true" --switch_user="true" --systemd_enable_support="true"
> --systemd_runtime_directory="/run/systemd/system" --version="false"
> --work_dir="/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV"
> I0315 04:16:51.230711 2700 credentials.hpp:83] Loading credential for
> authentication from
> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/credential'
> I0315 04:16:51.230989 2700 slave.cpp:324] Slave using credential for:
> test-principal
> I0315 04:16:51.231161 2700 resources.cpp:572] Parsing resources as JSON
> failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000]
> Trying semicolon-delimited string format instead
> I0315 04:16:51.231653 2700 slave.cpp:464] Slave resources: cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0315 04:16:51.232312 2700 slave.cpp:472] Slave attributes: [ ]
> I0315 04:16:51.232403 2700 slave.cpp:477] Slave hostname: maintenance-host
> I0315 04:16:51.235890 2705 state.cpp:58] Recovering state from
> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/meta'
> I0315 04:16:51.236862 2705 status_update_manager.cpp:200] Recovering status
> update manager
> I0315 04:16:51.237467 2705 slave.cpp:4565] Finished recovery
> I0315 04:16:51.237757 2715 process.cpp:3136] Handling HTTP event for process
> 'master' with path: '/master/maintenance/schedule'
> I0315 04:16:51.238085 2705 slave.cpp:4737] Querying resource estimator for
> oversubscribable resources
> I0315 04:16:51.239225 2715 http.cpp:312] HTTP POST for
> /master/maintenance/schedule from 172.17.0.4:53179
> I0315 04:16:51.240380 2715 registrar.cpp:439] Applied 1 operations in
> 144666ns; attempting to update the 'registry'
> I0315 04:16:51.242146 2708 log.cpp:683] Attempting to append 292 bytes to
> the log
> I0315 04:16:51.242471 2708 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 3
> I0315 04:16:51.243657 2708 replica.cpp:537] Replica received write request
> for position 3 from (4798)@172.17.0.4:39845
> I0315 04:16:51.244132 2705 slave.cpp:4751] Received oversubscribable
> resources from the resource estimator
> I0315 04:16:51.244442 2704 status_update_manager.cpp:174] Pausing sending
> status updates
> I0315 04:16:51.244591 2705 slave.cpp:796] New master detected at
> [email protected]:39845
> I0315 04:16:51.244786 2705 slave.cpp:859] Authenticating with master
> [email protected]:39845
> I0315 04:16:51.244886 2705 slave.cpp:864] Using default CRAM-MD5
> authenticatee
> I0315 04:16:51.245357 2707 authenticatee.cpp:121] Creating new client SASL
> connection
> I0315 04:16:51.245787 2707 master.cpp:5659] Authenticating
> slave(117)@172.17.0.4:39845
> I0315 04:16:51.246064 2707 authenticator.cpp:413] Starting authentication
> session for crammd5_authenticatee(301)@172.17.0.4:39845
> I0315 04:16:51.246462 2707 authenticator.cpp:98] Creating new server SASL
> connection
> I0315 04:16:51.246776 2707 authenticatee.cpp:212] Received SASL
> authentication mechanisms: CRAM-MD5
> I0315 04:16:51.246865 2707 authenticatee.cpp:238] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0315 04:16:51.247047 2707 authenticator.cpp:203] Received SASL
> authentication start
> I0315 04:16:51.247180 2707 authenticator.cpp:325] Authentication requires
> more steps
> I0315 04:16:51.247341 2707 authenticatee.cpp:258] Received SASL
> authentication step
> I0315 04:16:51.247489 2707 authenticator.cpp:231] Received SASL
> authentication step
> I0315 04:16:51.247572 2707 auxprop.cpp:107] Request to lookup properties for
> user: 'test-principal' realm: '01fcd642f65f' server FQDN: '01fcd642f65f'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0315 04:16:51.247640 2707 auxprop.cpp:179] Looking up auxiliary property
> '*userPassword'
> I0315 04:16:51.247807 2707 auxprop.cpp:179] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0315 04:16:51.247920 2707 auxprop.cpp:107] Request to lookup properties for
> user: 'test-principal' realm: '01fcd642f65f' server FQDN: '01fcd642f65f'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0315 04:16:51.248013 2707 auxprop.cpp:129] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0315 04:16:51.248100 2707 auxprop.cpp:129] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0315 04:16:51.248196 2707 authenticator.cpp:317] Authentication success
> I0315 04:16:51.248461 2707 authenticatee.cpp:298] Authentication success
> I0315 04:16:51.248597 2707 master.cpp:5689] Successfully authenticated
> principal 'test-principal' at slave(117)@172.17.0.4:39845
> I0315 04:16:51.248759 2700 authenticator.cpp:431] Authentication session
> cleanup for crammd5_authenticatee(301)@172.17.0.4:39845
> I0315 04:16:51.248988 2705 slave.cpp:832] Detecting new master
> I0315 04:16:51.249363 2705 slave.cpp:927] Successfully authenticated with
> master [email protected]:39845
> I0315 04:16:51.249506 2705 slave.cpp:1321] Will retry registration in
> 9.155413ms if necessary
> I0315 04:16:51.249981 2711 master.cpp:4370] Registering slave at
> slave(117)@172.17.0.4:39845 (maintenance-host) with id
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
> I0315 04:16:51.261998 2711 slave.cpp:1321] Will retry registration in
> 10.936296ms if necessary
> I0315 04:16:51.262398 2711 master.cpp:4358] Ignoring register slave message
> from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already
> in progress
> I0315 04:16:51.275990 2711 slave.cpp:1321] Will retry registration in
> 3.200397ms if necessary
> I0315 04:16:51.276379 2711 master.cpp:4358] Ignoring register slave message
> from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already
> in progress
> I0315 04:16:51.277753 2708 leveldb.cpp:341] Persisting action (311 bytes) to
> leveldb took 33.976895ms
> I0315 04:16:51.277799 2708 replica.cpp:712] Persisted action at 3
> I0315 04:16:51.279341 2708 replica.cpp:691] Replica received learned notice
> for position 3 from @0.0.0.0:0
> I0315 04:16:51.281918 2711 slave.cpp:1321] Will retry registration in
> 131597ns if necessary
> I0315 04:16:51.282146 2700 master.cpp:4358] Ignoring register slave message
> from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already
> in progress
> I0315 04:16:51.283844 2711 slave.cpp:1321] Will retry registration in
> 245.466527ms if necessary
> I0315 04:16:51.284080 2711 master.cpp:4358] Ignoring register slave message
> from slave(117)@172.17.0.4:39845 (maintenance-host) as admission is already
> in progress
> I0315 04:16:51.318001 2708 leveldb.cpp:341] Persisting action (313 bytes) to
> leveldb took 38.528659ms
> I0315 04:16:51.318091 2708 replica.cpp:712] Persisted action at 3
> I0315 04:16:51.318123 2708 replica.cpp:697] Replica learned APPEND action at
> position 3
> I0315 04:16:51.320458 2711 registrar.cpp:484] Successfully updated the
> 'registry' in 79.843072ms
> I0315 04:16:51.320747 2714 log.cpp:702] Attempting to truncate the log to 3
> I0315 04:16:51.320879 2704 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 4
> I0315 04:16:51.320919 2711 registrar.cpp:439] Applied 1 operations in
> 118795ns; attempting to update the 'registry'
> I0315 04:16:51.322357 2704 replica.cpp:537] Replica received write request
> for position 4 from (4799)@172.17.0.4:39845
> I0315 04:16:51.324488 2702 process.cpp:3136] Handling HTTP event for process
> 'master' with path: '/master/maintenance/status'
> I0315 04:16:51.325279 2702 http.cpp:312] HTTP GET for
> /master/maintenance/status from 172.17.0.4:53180
> I0315 04:16:51.328512 2681 scheduler.cpp:172] Version: 0.29.0
> I0315 04:16:51.329731 2703 scheduler.cpp:437] New master detected at
> [email protected]:39845
> I0315 04:16:51.332334 2702 scheduler.cpp:337] Connected with the master at
> http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.333514 2714 scheduler.cpp:230] Sending SUBSCRIBE call to
> http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.334751 2708 process.cpp:3136] Handling HTTP event for process
> 'master' with path: '/master/api/v1/scheduler'
> I0315 04:16:51.335245 2702 http.cpp:312] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:53181
> I0315 04:16:51.335464 2702 master.cpp:2068] Received subscription request
> for HTTP framework 'default'
> I0315 04:16:51.335528 2702 master.cpp:1845] Authorizing framework principal
> 'test-principal' to receive offers for role '*'
> I0315 04:16:51.335896 2713 master.cpp:2159] Subscribing framework 'default'
> with checkpointing disabled and capabilities [ ]
> I0315 04:16:51.337347 2700 hierarchical.cpp:265] Added framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.337435 2700 hierarchical.cpp:1453] No resources available to
> allocate!
> I0315 04:16:51.337471 2700 hierarchical.cpp:1548] No inverse offers to send
> out!
> I0315 04:16:51.337496 2700 hierarchical.cpp:1130] Performed allocation for 0
> slaves in 122430ns
> I0315 04:16:51.337657 2700 master.hpp:1715] Sending heartbeat to
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.338486 2711 scheduler.cpp:612] Enqueuing event SUBSCRIBED
> received from http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.339167 2711 scheduler.cpp:612] Enqueuing event HEARTBEAT
> received from http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.339838 2714 master_maintenance_tests.cpp:179] Ignoring
> HEARTBEAT event
> I0315 04:16:51.359691 2704 leveldb.cpp:341] Persisting action (16 bytes) to
> leveldb took 37.255846ms
> I0315 04:16:51.359787 2704 replica.cpp:712] Persisted action at 4
> I0315 04:16:51.361541 2702 replica.cpp:691] Replica received learned notice
> for position 4 from @0.0.0.0:0
> I0315 04:16:51.393460 2702 leveldb.cpp:341] Persisting action (18 bytes) to
> leveldb took 31.826446ms
> I0315 04:16:51.393631 2702 leveldb.cpp:399] Deleting ~2 keys from leveldb
> took 82223ns
> I0315 04:16:51.393667 2702 replica.cpp:712] Persisted action at 4
> I0315 04:16:51.393718 2702 replica.cpp:697] Replica learned TRUNCATE action
> at position 4
> I0315 04:16:51.395421 2702 log.cpp:683] Attempting to append 465 bytes to
> the log
> I0315 04:16:51.395716 2702 coordinator.cpp:348] Coordinator attempting to
> write APPEND action at position 5
> I0315 04:16:51.397063 2702 replica.cpp:537] Replica received write request
> for position 5 from (4803)@172.17.0.4:39845
> I0315 04:16:51.430773 2702 leveldb.cpp:341] Persisting action (484 bytes) to
> leveldb took 33.553652ms
> I0315 04:16:51.430871 2702 replica.cpp:712] Persisted action at 5
> I0315 04:16:51.432451 2702 replica.cpp:691] Replica received learned notice
> for position 5 from @0.0.0.0:0
> I0315 04:16:51.473805 2702 leveldb.cpp:341] Persisting action (486 bytes) to
> leveldb took 41.212274ms
> I0315 04:16:51.473908 2702 replica.cpp:712] Persisted action at 5
> I0315 04:16:51.473949 2702 replica.cpp:697] Replica learned APPEND action at
> position 5
> I0315 04:16:51.476976 2703 registrar.cpp:484] Successfully updated the
> 'registry' in 155.968768ms
> I0315 04:16:51.477423 2703 log.cpp:702] Attempting to truncate the log to 5
> I0315 04:16:51.477689 2703 coordinator.cpp:348] Coordinator attempting to
> write TRUNCATE action at position 6
> I0315 04:16:51.478329 2702 master.cpp:4438] Registered slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
> (maintenance-host) with cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000]
> I0315 04:16:51.478806 2713 hierarchical.cpp:473] Added slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host) with cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: )
> I0315 04:16:51.479184 2702 replica.cpp:537] Replica received write request
> for position 6 from (4804)@172.17.0.4:39845
> I0315 04:16:51.478400 2703 slave.cpp:3482] Received ping from
> slave-observer(117)@172.17.0.4:39845
> I0315 04:16:51.479872 2703 slave.cpp:971] Registered with master
> [email protected]:39845; given slave ID
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
> I0315 04:16:51.479902 2703 fetcher.cpp:81] Clearing fetcher cache
> I0315 04:16:51.480332 2703 slave.cpp:994] Checkpointing SlaveInfo to
> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/meta/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/slave.info'
> I0315 04:16:51.480789 2712 status_update_manager.cpp:181] Resuming sending
> status updates
> I0315 04:16:51.481290 2713 hierarchical.cpp:1150] Performed allocation for
> slave c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 in 2.431536ms
> I0315 04:16:51.481817 2703 slave.cpp:1030] Forwarding total oversubscribed
> resources
> I0315 04:16:51.482067 2713 master.cpp:5488] Sending 1 offers to framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
> I0315 04:16:51.483192 2713 master.cpp:5578] Sending 1 inverse offers to
> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
> I0315 04:16:51.483569 2713 master.cpp:4782] Received update of slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
> (maintenance-host) with total oversubscribed resources
> I0315 04:16:51.484576 2713 hierarchical.cpp:531] Slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host) updated with
> oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024;
> ports(*):[31000-32000])
> I0315 04:16:51.484849 2713 hierarchical.cpp:1453] No resources available to
> allocate!
> I0315 04:16:51.484966 2701 scheduler.cpp:612] Enqueuing event OFFERS
> received from http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.485061 2713 hierarchical.cpp:1150] Performed allocation for
> slave c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 in 414324ns
> I0315 04:16:51.485884 2701 scheduler.cpp:612] Enqueuing event OFFERS
> received from http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.491091 2701 scheduler.cpp:230] Sending ACCEPT call to
> http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.493937 2712 process.cpp:3136] Handling HTTP event for process
> 'master' with path: '/master/api/v1/scheduler'
> I0315 04:16:51.494441 2714 http.cpp:312] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:53182
> I0315 04:16:51.495529 2714 master.cpp:3268] Processing ACCEPT call for
> offers: [ c326bc68-2581-48d4-9dc4-0d6f270bdda1-O0 ] on slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
> (maintenance-host) for framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> (default)
> I0315 04:16:51.495589 2714 master.cpp:2871] Authorizing framework principal
> 'test-principal' to launch task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 as user
> 'mesos'
> W0315 04:16:51.501534 2714 validation.cpp:404] Executor default for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 uses less CPUs (None) than the minimum
> required (0.01). Please update your executor, as this will be mandatory in
> future releases.
> W0315 04:16:51.501618 2714 validation.cpp:416] Executor default for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 uses less memory (None) than the minimum
> required (32MB). Please update your executor, as this will be mandatory in
> future releases.
> I0315 04:16:51.502182 2714 master.hpp:177] Adding task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 with resources cpus(*):2; mem(*):1024;
> disk(*):1024; ports(*):[31000-32000] on slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 (maintenance-host)
> I0315 04:16:51.502437 2714 master.cpp:3753] Launching task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) with resources cpus(*):2;
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
> (maintenance-host)
> I0315 04:16:51.503787 2700 slave.cpp:1361] Got assigned task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 for framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.504485 2700 slave.cpp:1480] Launching task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 for framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.512953 2700 paths.cpp:528] Trying to chown
> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
> to user 'mesos'
> I0315 04:16:51.519822 2702 leveldb.cpp:341] Persisting action (16 bytes) to
> leveldb took 40.48414ms
> I0315 04:16:51.519923 2702 replica.cpp:712] Persisted action at 6
> I0315 04:16:51.521419 2710 replica.cpp:691] Replica received learned notice
> for position 6 from @0.0.0.0:0
> I0315 04:16:51.524533 2700 slave.cpp:5367] Launching executor default of
> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 with resources in work
> directory
> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
> I0315 04:16:51.527022 2700 exec.cpp:143] Version: 0.29.0
> I0315 04:16:51.527752 2704 exec.cpp:193] Executor started at:
> executor(47)@172.17.0.4:39845 with pid 2681
> I0315 04:16:51.527802 2700 slave.cpp:1698] Queuing task
> 'ce9b06cb-9896-4c2e-9fad-ea8538541cf4' for executor 'default' of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.527966 2700 slave.cpp:749] Successfully attached file
> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
> I0315 04:16:51.528192 2700 slave.cpp:2643] Got registration for executor
> 'default' of framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from
> executor(47)@172.17.0.4:39845
> I0315 04:16:51.529881 2706 exec.cpp:217] Executor registered on slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
> I0315 04:16:51.529955 2706 exec.cpp:229] Executor::registered took 36242ns
> I0315 04:16:51.530278 2700 slave.cpp:1863] Sending queued task
> 'ce9b06cb-9896-4c2e-9fad-ea8538541cf4' to executor 'default' of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 at executor(47)@172.17.0.4:39845
> I0315 04:16:51.530894 2708 exec.cpp:304] Executor asked to run task
> 'ce9b06cb-9896-4c2e-9fad-ea8538541cf4'
> I0315 04:16:51.530988 2708 exec.cpp:313] Executor::launchTask took 67937ns
> I0315 04:16:51.531083 2708 exec.cpp:526] Executor sending status update
> TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.531365 2708 slave.cpp:3002] Handling status update
> TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from executor(47)@172.17.0.4:39845
> I0315 04:16:51.532158 2708 status_update_manager.cpp:320] Received status
> update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.532274 2708 status_update_manager.cpp:497] Creating
> StatusUpdate stream for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of
> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.532951 2708 status_update_manager.cpp:374] Forwarding update
> TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to the slave
> I0315 04:16:51.533524 2708 slave.cpp:3400] Forwarding the update
> TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to [email protected]:39845
> I0315 04:16:51.533817 2708 slave.cpp:3294] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.533936 2708 slave.cpp:3310] Sending acknowledgement for
> status update TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for
> task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 to executor(47)@172.17.0.4:39845
> I0315 04:16:51.534340 2708 master.cpp:4927] Status update TASK_RUNNING
> (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
> (maintenance-host)
> I0315 04:16:51.534457 2708 master.cpp:4975] Forwarding status update
> TASK_RUNNING (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.534803 2701 exec.cpp:350] Executor received status update
> acknowledgement 5c63475c-af40-417d-9368-b7e3ede4a30e for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.535385 2708 master.cpp:6585] Updating the state of task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (latest state: TASK_RUNNING, status
> update state: TASK_RUNNING)
> I0315 04:16:51.537346 2704 scheduler.cpp:612] Enqueuing event UPDATE
> received from http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.541487 2708 scheduler.cpp:230] Sending ACKNOWLEDGE call to
> http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.542043 2708 scheduler.cpp:230] Sending DECLINE call to
> http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.543292 2708 process.cpp:3136] Handling HTTP event for process
> 'master' with path: '/master/api/v1/scheduler'
> I0315 04:16:51.543979 2708 http.cpp:312] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:53182
> I0315 04:16:51.544251 2708 master.cpp:4082] Processing ACKNOWLEDGE call
> 5c63475c-af40-417d-9368-b7e3ede4a30e for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default) on slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
> I0315 04:16:51.544818 2708 status_update_manager.cpp:392] Received status
> update acknowledgement (UUID: 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.545315 2708 slave.cpp:2412] Status update manager
> successfully handled status update acknowledgement (UUID:
> 5c63475c-af40-417d-9368-b7e3ede4a30e) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.546144 2702 process.cpp:3136] Handling HTTP event for process
> 'master' with path: '/master/api/v1/scheduler'
> I0315 04:16:51.546668 2702 http.cpp:312] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:53182
> I0315 04:16:51.547322 2702 master.cpp:3805] Processing DECLINE call for
> offers: [ c326bc68-2581-48d4-9dc4-0d6f270bdda1-O1 ] for framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
> I0315 04:16:51.565781 2710 leveldb.cpp:341] Persisting action (18 bytes) to
> leveldb took 44.297436ms
> I0315 04:16:51.565945 2710 leveldb.cpp:399] Deleting ~2 keys from leveldb
> took 76582ns
> I0315 04:16:51.565978 2710 replica.cpp:712] Persisted action at 6
> I0315 04:16:51.566015 2710 replica.cpp:697] Replica learned TRUNCATE action
> at position 6
> I0315 04:16:51.570482 2707 hierarchical.cpp:1453] No resources available to
> allocate!
> I0315 04:16:51.570847 2707 hierarchical.cpp:1130] Performed allocation for 1
> slaves in 640118ns
> I0315 04:16:51.571091 2707 master.cpp:5578] Sending 1 inverse offers to
> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
> I0315 04:16:51.573333 2712 scheduler.cpp:612] Enqueuing event OFFERS
> received from http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.581941 2713 process.cpp:3136] Handling HTTP event for process
> 'master' with path: '/master/maintenance/status'
> I0315 04:16:51.582535 2706 http.cpp:312] HTTP GET for
> /master/maintenance/status from 172.17.0.4:53183
> I0315 04:16:51.587846 2715 scheduler.cpp:230] Sending ACCEPT call to
> http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.589800 2715 process.cpp:3136] Handling HTTP event for process
> 'master' with path: '/master/api/v1/scheduler'
> I0315 04:16:51.590328 2715 http.cpp:312] HTTP POST for
> /master/api/v1/scheduler from 172.17.0.4:53182
> W0315 04:16:51.590833 2715 master.cpp:3231] ACCEPT call used invalid offers
> '[ c326bc68-2581-48d4-9dc4-0d6f270bdda1-O2 ]': Offer
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-O2 is no longer valid
> I0315 04:16:51.603070 2706 hierarchical.cpp:1453] No resources available to
> allocate!
> I0315 04:16:51.603425 2706 hierarchical.cpp:1130] Performed allocation for 1
> slaves in 570929ns
> I0315 04:16:51.603674 2706 master.cpp:5578] Sending 1 inverse offers to
> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 (default)
> I0315 04:16:51.605583 2711 scheduler.cpp:612] Enqueuing event OFFERS
> received from http://172.17.0.4:39845/master/api/v1/scheduler
> I0315 04:16:51.614972 2709 process.cpp:3136] Handling HTTP event for process
> 'master' with path: '/master/maintenance/status'
> I0315 04:16:51.616044 2713 http.cpp:312] HTTP GET for
> /master/maintenance/status from 172.17.0.4:53184
> I0315 04:16:51.620043 2681 master.cpp:1065] Master terminating
> W0315 04:16:51.620407 2681 master.cpp:6637] Removing task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 with resources cpus(*):2; mem(*):1024;
> disk(*):1024; ports(*):[31000-32000] of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 on slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
> (maintenance-host) in non-terminal state TASK_RUNNING
> I0315 04:16:51.621245 2712 hierarchical.cpp:505] Removed slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0
> I0315 04:16:51.621573 2681 master.cpp:6680] Removing executor 'default' with
> resources of framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 on slave
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0 at slave(117)@172.17.0.4:39845
> (maintenance-host)
> I0315 04:16:51.622886 2704 hierarchical.cpp:326] Removed framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> E0315 04:16:51.624392 2705 scheduler.cpp:585] End-Of-File received from
> master. The master closed the event stream
> I0315 04:16:51.628783 2703 slave.cpp:3528] [email protected]:39845 exited
> W0315 04:16:51.628839 2703 slave.cpp:3531] Master disconnected! Waiting for
> a new master to be elected
> I0315 04:16:51.632709 2704 slave.cpp:3528] executor(47)@172.17.0.4:39845
> exited
> I0315 04:16:51.633152 2704 slave.cpp:3886] Executor 'default' of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 exited with status 0
> I0315 04:16:51.633311 2704 slave.cpp:3002] Handling status update
> TASK_FAILED (UUID: f793d2cc-720c-4d89-91d5-3f45e73ad6ea) for task
> ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 from @0.0.0.0:0
> I0315 04:16:51.641787 2704 slave.cpp:668] Slave terminating
> I0315 04:16:51.641914 2704 slave.cpp:2079] Asked to shut down framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 by @0.0.0.0:0
> I0315 04:16:51.641957 2704 slave.cpp:2104] Shutting down framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.642027 2704 slave.cpp:3990] Cleaning up executor 'default' of
> framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000 at
> executor(47)@172.17.0.4:39845
> I0315 04:16:51.642453 2704 slave.cpp:4078] Cleaning up framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.642616 2707 gc.cpp:55] Scheduling
> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default/runs/1489bb75-64bd-4078-b589-49e953bc4d4b'
> for gc 6.99999256701333days in the future
> I0315 04:16:51.642633 2710 status_update_manager.cpp:282] Closing status
> update streams for framework c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.642719 2710 status_update_manager.cpp:528] Cleaning up status
> update stream for task ce9b06cb-9896-4c2e-9fad-ea8538541cf4 of framework
> c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000
> I0315 04:16:51.643265 2707 gc.cpp:55] Scheduling
> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000/executors/default'
> for gc 6.99999256488296days in the future
> I0315 04:16:51.643373 2707 gc.cpp:55] Scheduling
> '/tmp/MasterMaintenanceTest_InverseOffers_7G6uyV/slaves/c326bc68-2581-48d4-9dc4-0d6f270bdda1-S0/frameworks/c326bc68-2581-48d4-9dc4-0d6f270bdda1-0000'
> for gc 6.99999256301037days in the future
> I0315 04:16:51.646150 2705 scheduler.cpp:419] Re-detecting master
> I0315 04:16:51.646462 2705 scheduler.cpp:370] Ignoring disconnection attempt
> from stale connection
> I0315 04:16:51.646507 2705 scheduler.cpp:370] Ignoring disconnection attempt
> from stale connection
> [ OK ] MasterMaintenanceTest.InverseOffers (992 ms)
> [ RUN ] MasterMaintenanceTest.InverseOffersFilters
> *** Aborted at 1458015411 (unix time) try "date -d @1458015411" if you are
> using GNU date ***
> PC: @ 0x172ca21
> testing::internal::UntypedFunctionMockerBase::UntypedInvokeWith()
> *** SIGSEGV (@0x0) received by PID 2681 (TID 0x2afe25c47700) from PID 0;
> stack trace: ***
> @ 0x2afe689dfff7 (unknown)
> @ 0x2afe689e4159 (unknown)
> @ 0x2afe1b57d340 (unknown)
> @ 0x172ca21
> testing::internal::UntypedFunctionMockerBase::UntypedInvokeWith()
> @ 0xf494ff testing::internal::FunctionMockerBase<>::InvokeWith()
> @ 0xf43663 testing::internal::FunctionMocker<>::Invoke()
> @ 0xf42920
> mesos::internal::tests::MasterMaintenanceTest::Callbacks::disconnected()
> @ 0xf5ab55
> _ZNKSt7_Mem_fnIMN5mesos8internal5tests21MasterMaintenanceTest9CallbacksEFvvEEclIJEvEEvRS4_DpOT_
> @ 0xf57120
> _ZNSt5_BindIFSt7_Mem_fnIMN5mesos8internal5tests21MasterMaintenanceTest9CallbacksEFvvEESt17reference_wrapperIS5_EEE6__callIvJEJLm0EEEET_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE
> @ 0xf52d84 std::_Bind<>::operator()<>()
> @ 0xf4e099 std::_Function_handler<>::_M_invoke()
> @ 0x99f3ac std::function<>::operator()()
> I0315 04:16:51.810700 2681 leveldb.cpp:174] Opened db in 153.621998ms
> @ 0x2afe188c14e9 process::AsyncExecutorProcess::execute<>()
> @ 0x2afe188c8d09
> _ZZN7process8dispatchI7NothingNS_20AsyncExecutorProcessERKSt8functionIFvvEEPvS5_S8_EENS_6FutureIT_EERKNS_3PIDIT0_EEMSD_FSA_T1_T2_ET3_T4_ENKUlPNS_11ProcessBaseEE_clESO_
> @ 0x2afe188d48b1
> _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8dispatchI7NothingNS0_20AsyncExecutorProcessERKSt8functionIFvvEEPvS9_SC_EENS0_6FutureIT_EERKNS0_3PIDIT0_EEMSH_FSE_T1_T2_ET3_T4_EUlS2_E_E9_M_invokeERKSt9_Any_dataS2_
> @ 0x2afe197a8c61 std::function<>::operator()()
> I0315 04:16:51.855080 2681 leveldb.cpp:181] Compacted db in 44.189206ms
> I0315 04:16:51.855180 2681 leveldb.cpp:196] Created db iterator in 27246ns
> I0315 04:16:51.855200 2681 leveldb.cpp:202] Seeked to beginning of db in
> 3314ns
> I0315 04:16:51.855211 2681 leveldb.cpp:271] Iterated through 0 keys in the
> db in 364ns
> I0315 04:16:51.855265 2681 replica.cpp:779] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0315 04:16:51.856449 2681 cluster.cpp:183] Creating default 'local'
> authorizer
> I0315 04:16:51.859966 2709 master.cpp:376] Master
> d429b4cf-027e-46a9-97af-226792924cc4 (01fcd642f65f) started on
> 172.17.0.4:39845
> @ 0x2afe1978ee7f process::ProcessBase::visit()
> I0315 04:16:51.860005 2709 master.cpp:378] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="false" --authenticate_http="true"
> --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/rHaIvb/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.29.0/_inst/share/mesos/webui"
> --work_dir="/tmp/rHaIvb/master" --zk_session_timeout="10secs"
> I0315 04:16:51.860431 2709 master.cpp:425] Master allowing unauthenticated
> frameworks to register
> I0315 04:16:51.860445 2709 master.cpp:428] Master only allowing
> authenticated slaves to register
> I0315 04:16:51.860453 2709 credentials.hpp:35] Loading credentials for
> authentication from '/tmp/rHaIvb/credentials'
> I0315 04:16:51.861218 2709 master.cpp:468] Using default 'crammd5'
> authenticator
> I0315 04:16:51.861392 2709 master.cpp:537] Using default 'basic' HTTP
> authenticator
> I0315 04:16:51.861528 2709 master.cpp:571] Authorization enabled
> I0315 04:16:51.861888 2706 hierarchical.cpp:144] Initialized hierarchical
> allocator process
> I0315 04:16:51.861968 2706 whitelist_watcher.cpp:77] No whitelist given
> I0315 04:16:51.862046 2714 recover.cpp:447] Starting replica recovery
> I0315 04:16:51.862376 2714 recover.cpp:473] Replica is in EMPTY status
> I0315 04:16:51.867487 2705 replica.cpp:673] Replica in EMPTY status received
> a broadcasted recover request from (4813)@172.17.0.4:39845
> I0315 04:16:51.868098 2713 recover.cpp:193] Received a recover response from
> a replica in EMPTY status
> @ 0x2afe19794e0c process::DispatchEvent::visit()
> I0315 04:16:51.868788 2715 recover.cpp:564] Updating replica status to
> STARTING
> I0315 04:16:51.871018 2701 master.cpp:1806] The newly elected leader is
> [email protected]:39845 with id d429b4cf-027e-46a9-97af-226792924cc4
> I0315 04:16:51.871063 2701 master.cpp:1819] Elected as the leading master!
> I0315 04:16:51.871083 2701 master.cpp:1508] Recovering from registrar
> I0315 04:16:51.871234 2707 registrar.cpp:307] Recovering registrar
> @ 0x99d90c process::ProcessBase::serve()
> @ 0x2afe1978b078 process::ProcessManager::resume()
> @ 0x2afe19788112
> _ZZN7process14ProcessManager12init_threadsEvENKUlRKSt11atomic_boolE_clES3_
> @ 0x2afe197945ce
> _ZNSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS3_EEE6__callIvIEILm0EEEET_OSt5tupleIIDpT0_EESt12_Index_tupleIIXspT1_EEE
> @ 0x2afe1979457e
> _ZNSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS3_EEEclIIEvEET0_DpOT_
> @ 0x2afe19794510
> _ZNSt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS4_EEEvEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
> @ 0x2afe19794467
> _ZNSt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS4_EEEvEEclEv
> @ 0x2afe19794400
> _ZNSt6thread5_ImplISt12_Bind_simpleIFSt5_BindIFZN7process14ProcessManager12init_threadsEvEUlRKSt11atomic_boolE_St17reference_wrapperIS6_EEEvEEE6_M_runEv
> @ 0x2afe1adfea60 (unknown)
> @ 0x2afe1b575182 start_thread
> @ 0x2afe1b88547d (unknown)
> make[4]: *** [check-local] Segmentation fault
> make[4]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[3]: *** [check-am] Error 2
> make[3]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[2]: *** [check] Error 2
> make[2]: Leaving directory `/mesos/mesos-0.29.0/_build/src'
> make[1]: *** [check-recursive] Error 1
> make[1]: Leaving directory `/mesos/mesos-0.29.0/_build'
> make: *** [distcheck] Error 1
> + docker rmi mesos-1458012352-18905
> Untagged: mesos-1458012352-18905:latest
> Deleted: 136cfc69a211fc726228e37ee0b50f9d79ef349a6c5e2ac33c569c68057ab614
> Deleted: fc91397a445e569ffadf2e537efdd1207bfad4d82534049de6d641ba98daa368
> Deleted: b69b88c1e1cd00181d5c9154f3e9619ec8fb3afe892aeb0490f0765aebf780d8
> Deleted: 17e1610f1e27666a13f8ca079e9ebb11c24494b8a5ed4ed5df877691ba470435
> Deleted: d5fa89bf05553adfc6f954ce4ba7d916e71341915211c817d05975f52f4bc12e
> Deleted: 144027a85962f820f57caaf7d2104455214a428b1d0af893c9a8de74edd97e45
> Deleted: 848daccb153b7aa6ff4a229278d24d945b6ea23e2ad8b06ecdc0f389c641da1a
> Deleted: 38957fcac7db8839ad02f28f40499a2207cc5950800d749ca6039073ffcca741
> Deleted: d4c338b5a13fffa3aa27b7883e0eaf819948aa7c44ba88d294f32343fd62eec0
> Deleted: 7477643b2cce0c37f0ca58fff6d9faeed377218cd81c26395557c08ca6913c9f
> Deleted: f6e006f6d02695a98bec8e3962e21cff0cda0293bc07880a8943cd1c0ec9cb2e
> Deleted: 65dc81e742400834c56b316b9ebaa09d8c3812ff8864ba1ccbae2f99badaa425
> Deleted: 735b32b15c2d6bf3b1b0796ae49fda0cdc5e85106273bf943d1cf1ad1aa9f204
> Deleted: f8c3ca62f0644c95f1499f0cac5da0680dc3d6533ed9bd5050429a27d0a497d3
> Deleted: 87d93f820d589b1eb5a106762f6ae63ba67d2e7623783d07df14dd3599b9d3a0
> Deleted: 7d6b1a49cb8025d36f0a6b29bfcdec395d23c88a00bad57fb0f4eca8667b9f53
> Build step 'Execute shell' marked build as failure
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
