mesos-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Joris Van Remoortere (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (MESOS-4948) Move maintenance tests to use the new scheduler library interface.
Date Fri, 30 Sep 2016 20:12:20 GMT

     [ https://issues.apache.org/jira/browse/MESOS-4948?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Joris Van Remoortere updated MESOS-4948:
----------------------------------------
    Shepherd: Anand Mazumdar

> 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)

Mime
View raw message