You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Ilya Pronin (JIRA)" <ji...@apache.org> on 2016/10/06 22:51:20 UTC
[jira] [Commented] (MESOS-4948) Move maintenance tests to use the
new scheduler library interface.
[ https://issues.apache.org/jira/browse/MESOS-4948?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15553459#comment-15553459 ]
Ilya Pronin commented on MESOS-4948:
------------------------------------
Review request: https://reviews.apache.org/r/52620/
> 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
> Assignee: Ilya Pronin
> 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 master@172.17.0.4: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 master@172.17.0.4:39845
> I0315 04:16:51.244786 2705 slave.cpp:859] Authenticating with master master@172.17.0.4: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 master@172.17.0.4: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 master@172.17.0.4: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 master@172.17.0.4: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 master@172.17.0.4: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] master@172.17.0.4: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 master@172.17.0.4: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)