Uploaded image for project: 'Mesos'
  1. Mesos
  2. MESOS-4948

Move maintenance tests to use the new scheduler library interface.

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • None
    • 1.1.0
    • test
    • Ubuntu 14.04, using gcc, with libevent and SSL enabled (on ASF CI)

    Description

      We need to move the existing maintenance tests to use the new scheduler interface. We have already moved 1 test MasterMaintenanceTest.PendingUnavailabilityTest to use the new interface. It would be good to move the other 2 remaining tests to the new interface since it can lead to failures around the stack object being referenced after has been already destroyed. Detailed log from an ASF CI build failure.

      [ 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
      

      Attachments

        Activity

          People

            ipronin Ilya
            greggomann Greg Mann
            Anand Mazumdar Anand Mazumdar
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: