Joseph, can you please triage this maintenance test failure? I've pasted the logs here in case they get deleted from jenkins:
[ RUN ] MasterMaintenanceTest.InverseOffersFilters I1203 18:20:07.989888 341 leveldb.cpp:174] Opened db in 2.612076ms I1203 18:20:07.990701 341 leveldb.cpp:181] Compacted db in 679308ns I1203 18:20:07.990825 341 leveldb.cpp:196] Created db iterator in 36559ns I1203 18:20:07.990929 341 leveldb.cpp:202] Seeked to beginning of db in 2343ns I1203 18:20:07.991020 341 leveldb.cpp:271] Iterated through 0 keys in the db in 592ns I1203 18:20:07.991153 341 replica.cpp:778] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I1203 18:20:07.991922 369 recover.cpp:447] Starting replica recovery I1203 18:20:07.992287 372 recover.cpp:473] Replica is in EMPTY status I1203 18:20:07.993533 372 replica.cpp:674] Replica in EMPTY status received a broadcasted recover request from (3826)@172.17.0.1:38193 I1203 18:20:07.994379 369 recover.cpp:193] Received a recover response from a replica in EMPTY status I1203 18:20:07.994819 375 recover.cpp:564] Updating replica status to STARTING I1203 18:20:07.995513 375 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 452853ns I1203 18:20:07.995543 375 replica.cpp:321] Persisted replica status to STARTING I1203 18:20:07.995748 375 recover.cpp:473] Replica is in STARTING status I1203 18:20:07.996718 375 master.cpp:365] Master 78046f05-cfb7-4478-8385-528382f71b9e (d0573e529de6) started on 172.17.0.1:38193 I1203 18:20:07.996747 375 master.cpp:367] Flags at startup: --acls="" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate="false" --authenticate_slaves="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/QOkgIh/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_slave_ping_timeouts="5" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_ping_timeout="15secs" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-0.27.0/_inst/share/mesos/webui" --work_dir="/tmp/QOkgIh/master" --zk_session_timeout="10secs" I1203 18:20:07.997158 375 master.cpp:414] Master allowing unauthenticated frameworks to register I1203 18:20:07.997176 375 master.cpp:417] Master only allowing authenticated slaves to register I1203 18:20:07.997187 375 credentials.hpp:35] Loading credentials for authentication from '/tmp/QOkgIh/credentials' I1203 18:20:07.997517 375 master.cpp:456] Using default 'crammd5' authenticator I1203 18:20:07.997722 375 master.cpp:493] Authorization enabled I1203 18:20:07.997894 368 replica.cpp:674] Replica in STARTING status received a broadcasted recover request from (3827)@172.17.0.1:38193 I1203 18:20:07.998193 363 hierarchical.cpp:162] Initialized hierarchical allocator process I1203 18:20:07.998301 363 recover.cpp:193] Received a recover response from a replica in STARTING status I1203 18:20:07.998512 368 whitelist_watcher.cpp:77] No whitelist given I1203 18:20:07.998734 367 recover.cpp:564] Updating replica status to VOTING I1203 18:20:07.999285 363 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 341976ns I1203 18:20:07.999315 363 replica.cpp:321] Persisted replica status to VOTING I1203 18:20:07.999421 367 recover.cpp:578] Successfully joined the Paxos group I1203 18:20:07.999645 367 recover.cpp:462] Recover process terminated I1203 18:20:08.001030 363 master.cpp:1637] The newly elected leader is [email protected]:38193 with id 78046f05-cfb7-4478-8385-528382f71b9e I1203 18:20:08.001060 363 master.cpp:1650] Elected as the leading master! I1203 18:20:08.001078 363 master.cpp:1395] Recovering from registrar I1203 18:20:08.001444 363 registrar.cpp:307] Recovering registrar I1203 18:20:08.002307 368 log.cpp:659] Attempting to start the writer I1203 18:20:08.005077 369 replica.cpp:494] Replica received implicit promise request from (3828)@172.17.0.1:38193 with proposal 1 I1203 18:20:08.005841 369 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 688704ns I1203 18:20:08.005873 369 replica.cpp:343] Persisted promised to 1 I1203 18:20:08.007071 369 coordinator.cpp:238] Coordinator attempting to fill missing positions I1203 18:20:08.008887 374 replica.cpp:389] Replica received explicit promise request from (3829)@172.17.0.1:38193 for position 0 with proposal 2 I1203 18:20:08.009847 374 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 897100ns I1203 18:20:08.009886 374 replica.cpp:713] Persisted action at 0 I1203 18:20:08.011418 365 replica.cpp:538] Replica received write request for position 0 from (3830)@172.17.0.1:38193 I1203 18:20:08.011507 365 leveldb.cpp:436] Reading position from leveldb took 42134ns I1203 18:20:08.011895 365 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 334607ns I1203 18:20:08.011924 365 replica.cpp:713] Persisted action at 0 I1203 18:20:08.012511 372 replica.cpp:692] Replica received learned notice for position 0 from @0.0.0.0:0 I1203 18:20:08.012949 372 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 409370ns I1203 18:20:08.012974 372 replica.cpp:713] Persisted action at 0 I1203 18:20:08.012995 372 replica.cpp:698] Replica learned NOP action at position 0 I1203 18:20:08.013542 367 log.cpp:675] Writer started with ending position 0 I1203 18:20:08.014807 365 leveldb.cpp:436] Reading position from leveldb took 31850ns I1203 18:20:08.015921 365 registrar.cpp:340] Successfully fetched the registry (0B) in 14.438912ms I1203 18:20:08.016036 365 registrar.cpp:439] Applied 1 operations in 32373ns; attempting to update the 'registry' I1203 18:20:08.017218 370 log.cpp:683] Attempting to append 170 bytes to the log I1203 18:20:08.017415 371 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1 I1203 18:20:08.018331 372 replica.cpp:538] Replica received write request for position 1 from (3831)@172.17.0.1:38193 I1203 18:20:08.018755 372 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 324453ns I1203 18:20:08.018846 372 replica.cpp:713] Persisted action at 1 I1203 18:20:08.019677 370 replica.cpp:692] Replica received learned notice for position 1 from @0.0.0.0:0 I1203 18:20:08.020063 370 leveldb.cpp:341] Persisting action (191 bytes) to leveldb took 354812ns I1203 18:20:08.020088 370 replica.cpp:713] Persisted action at 1 I1203 18:20:08.020113 370 replica.cpp:698] Replica learned APPEND action at position 1 I1203 18:20:08.021123 367 registrar.cpp:484] Successfully updated the 'registry' in 5.03296ms I1203 18:20:08.021312 367 registrar.cpp:370] Successfully recovered registrar I1203 18:20:08.021391 372 log.cpp:702] Attempting to truncate the log to 1 I1203 18:20:08.021559 372 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2 I1203 18:20:08.021745 367 master.cpp:1447] Recovered 0 slaves from the Registry (131B) ; allowing 10mins for slaves to re-register I1203 18:20:08.021903 371 hierarchical.cpp:174] Allocator recovery is not supported yet I1203 18:20:08.023030 367 replica.cpp:538] Replica received write request for position 2 from (3832)@172.17.0.1:38193 I1203 18:20:08.023634 367 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 366368ns I1203 18:20:08.023663 367 replica.cpp:713] Persisted action at 2 I1203 18:20:08.024610 363 replica.cpp:692] Replica received learned notice for position 2 from @0.0.0.0:0 I1203 18:20:08.025135 363 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 451065ns I1203 18:20:08.025202 363 leveldb.cpp:399] Deleting ~1 keys from leveldb took 36771ns I1203 18:20:08.025223 363 replica.cpp:713] Persisted action at 2 I1203 18:20:08.025254 363 replica.cpp:698] Replica learned TRUNCATE action at position 2 I1203 18:20:08.039106 362 slave.cpp:189] Slave started on 111)@172.17.0.1:38193 I1203 18:20:08.039152 362 slave.cpp:190] Flags at startup: --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_InverseOffersFilters_t0jUCH/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="auth.docker.io" --docker_auth_server_port="443" --docker_kill_orphans="true" --docker_local_archives_dir="/tmp/mesos/images/docker" --docker_puller="local" --docker_puller_timeout="60" --docker_registry="registry-1.docker.io" --docker_registry_port="443" --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_InverseOffersFilters_t0jUCH/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.27.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_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MasterMaintenanceTest_InverseOffersFilters_t0jUCH" I1203 18:20:08.039780 362 credentials.hpp:83] Loading credential for authentication from '/tmp/MasterMaintenanceTest_InverseOffersFilters_t0jUCH/credential' I1203 18:20:08.040057 362 slave.cpp:320] Slave using credential for: test-principal I1203 18:20:08.040267 362 resources.cpp:478] Parsing resources as JSON failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000] Trying semicolon-delimited string format instead I1203 18:20:08.040693 362 slave.cpp:390] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1203 18:20:08.040769 362 slave.cpp:398] Slave attributes: [ ] I1203 18:20:08.040783 362 slave.cpp:403] Slave hostname: maintenance-host I1203 18:20:08.040803 362 slave.cpp:408] Slave checkpoint: true I1203 18:20:08.042142 368 state.cpp:52] Recovering state from '/tmp/MasterMaintenanceTest_InverseOffersFilters_t0jUCH/meta' I1203 18:20:08.042562 368 status_update_manager.cpp:200] Recovering status update manager I1203 18:20:08.042896 370 slave.cpp:4258] Finished recovery I1203 18:20:08.043488 370 slave.cpp:4430] Querying resource estimator for oversubscribable resources I1203 18:20:08.044051 370 slave.cpp:727] New master detected at [email protected]:38193 I1203 18:20:08.044172 370 slave.cpp:790] Authenticating with master [email protected]:38193 I1203 18:20:08.044195 370 slave.cpp:795] Using default CRAM-MD5 authenticatee I1203 18:20:08.044390 370 slave.cpp:763] Detecting new master I1203 18:20:08.044513 370 slave.cpp:4444] Received oversubscribable resources from the resource estimator I1203 18:20:08.044610 370 status_update_manager.cpp:174] Pausing sending status updates I1203 18:20:08.044750 370 authenticatee.cpp:121] Creating new client SASL connection I1203 18:20:08.045251 370 master.cpp:5308] Authenticating slave(111)@172.17.0.1:38193 I1203 18:20:08.045435 370 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(288)@172.17.0.1:38193 I1203 18:20:08.045776 370 authenticator.cpp:98] Creating new server SASL connection I1203 18:20:08.046074 370 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1203 18:20:08.046924 370 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1203 18:20:08.047127 370 authenticator.cpp:203] Received SASL authentication start I1203 18:20:08.047277 370 authenticator.cpp:325] Authentication requires more steps I1203 18:20:08.047448 370 authenticatee.cpp:258] Received SASL authentication step I1203 18:20:08.047642 370 authenticator.cpp:231] Received SASL authentication step I1203 18:20:08.047777 370 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'd0573e529de6' server FQDN: 'd0573e529de6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1203 18:20:08.047886 370 auxprop.cpp:179] Looking up auxiliary property '*userPassword' I1203 18:20:08.048015 370 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1203 18:20:08.048136 370 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'd0573e529de6' server FQDN: 'd0573e529de6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1203 18:20:08.048228 370 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1203 18:20:08.048313 370 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1203 18:20:08.048408 370 authenticator.cpp:317] Authentication success I1203 18:20:08.048717 367 master.cpp:5338] Successfully authenticated principal 'test-principal' at slave(111)@172.17.0.1:38193 I1203 18:20:08.048852 374 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(288)@172.17.0.1:38193 I1203 18:20:08.048727 370 authenticatee.cpp:298] Authentication success I1203 18:20:08.049576 370 slave.cpp:858] Successfully authenticated with master [email protected]:38193 I1203 18:20:08.049768 370 slave.cpp:1252] Will retry registration in 17.23988ms if necessary I1203 18:20:08.049981 372 master.cpp:4017] Registering slave at slave(111)@172.17.0.1:38193 (maintenance-host) with id 78046f05-cfb7-4478-8385-528382f71b9e-S0 I1203 18:20:08.050596 372 registrar.cpp:439] Applied 1 operations in 143816ns; attempting to update the 'registry' I1203 18:20:08.051640 372 log.cpp:683] Attempting to append 343 bytes to the log I1203 18:20:08.051849 366 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3 I1203 18:20:08.052887 365 replica.cpp:538] Replica received write request for position 3 from (3837)@172.17.0.1:38193 I1203 18:20:08.053539 365 leveldb.cpp:341] Persisting action (362 bytes) to leveldb took 600279ns I1203 18:20:08.053568 365 replica.cpp:713] Persisted action at 3 I1203 18:20:08.054618 363 replica.cpp:692] Replica received learned notice for position 3 from @0.0.0.0:0 I1203 18:20:08.055068 363 leveldb.cpp:341] Persisting action (364 bytes) to leveldb took 414797ns I1203 18:20:08.055097 363 replica.cpp:713] Persisted action at 3 I1203 18:20:08.055121 363 replica.cpp:698] Replica learned APPEND action at position 3 I1203 18:20:08.056676 372 registrar.cpp:484] Successfully updated the 'registry' in 6.00192ms I1203 18:20:08.057006 375 log.cpp:702] Attempting to truncate the log to 3 I1203 18:20:08.057199 369 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4 I1203 18:20:08.057880 374 slave.cpp:3197] Received ping from slave-observer(114)@172.17.0.1:38193 I1203 18:20:08.058136 372 master.cpp:4085] Registered slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 (maintenance-host) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1203 18:20:08.058403 363 slave.cpp:902] Registered with master [email protected]:38193; given slave ID 78046f05-cfb7-4478-8385-528382f71b9e-S0 I1203 18:20:08.058429 363 fetcher.cpp:79] Clearing fetcher cache I1203 18:20:08.058434 367 hierarchical.cpp:380] Added slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 (maintenance-host) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: ) I1203 18:20:08.058631 367 hierarchical.cpp:1062] No resources available to allocate! I1203 18:20:08.058681 367 hierarchical.cpp:1155] No inverse offers to send out! I1203 18:20:08.058703 367 hierarchical.cpp:973] Performed allocation for slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 in 234246ns I1203 18:20:08.058832 371 status_update_manager.cpp:181] Resuming sending status updates I1203 18:20:08.058789 363 slave.cpp:925] Checkpointing SlaveInfo to '/tmp/MasterMaintenanceTest_InverseOffersFilters_t0jUCH/meta/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S0/slave.info' I1203 18:20:08.059510 363 slave.cpp:961] Forwarding total oversubscribed resources I1203 18:20:08.059532 367 replica.cpp:538] Replica received write request for position 4 from (3838)@172.17.0.1:38193 I1203 18:20:08.059667 363 master.cpp:4427] Received update of slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 (maintenance-host) with total oversubscribed resources I1203 18:20:08.060132 367 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 562001ns I1203 18:20:08.060159 367 replica.cpp:713] Persisted action at 4 I1203 18:20:08.060317 375 hierarchical.cpp:434] Slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 (maintenance-host) updated with oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: ) I1203 18:20:08.060480 375 hierarchical.cpp:1062] No resources available to allocate! I1203 18:20:08.060520 375 hierarchical.cpp:1155] No inverse offers to send out! I1203 18:20:08.060542 375 hierarchical.cpp:973] Performed allocation for slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 in 186336ns I1203 18:20:08.061152 367 replica.cpp:692] Replica received learned notice for position 4 from @0.0.0.0:0 I1203 18:20:08.061512 367 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 328936ns I1203 18:20:08.061578 367 leveldb.cpp:399] Deleting ~2 keys from leveldb took 38088ns I1203 18:20:08.061597 367 replica.cpp:713] Persisted action at 4 I1203 18:20:08.061619 367 replica.cpp:698] Replica learned TRUNCATE action at position 4 I1203 18:20:08.064887 375 slave.cpp:189] Slave started on 112)@172.17.0.1:38193 I1203 18:20:08.064918 375 slave.cpp:190] Flags at startup: --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_InverseOffersFilters_XSU2vX/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_auth_server="auth.docker.io" --docker_auth_server_port="443" --docker_kill_orphans="true" --docker_local_archives_dir="/tmp/mesos/images/docker" --docker_puller="local" --docker_puller_timeout="60" --docker_registry="registry-1.docker.io" --docker_registry_port="443" --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_InverseOffersFilters_XSU2vX/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname="maintenance-host-2" --hostname_lookup="true" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher_dir="/mesos/mesos-0.27.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_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX" I1203 18:20:08.065491 375 credentials.hpp:83] Loading credential for authentication from '/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX/credential' I1203 18:20:08.065738 375 slave.cpp:320] Slave using credential for: test-principal I1203 18:20:08.065961 375 resources.cpp:478] Parsing resources as JSON failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000] Trying semicolon-delimited string format instead I1203 18:20:08.066398 375 slave.cpp:390] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1203 18:20:08.066473 375 slave.cpp:398] Slave attributes: [ ] I1203 18:20:08.066488 375 slave.cpp:403] Slave hostname: maintenance-host-2 I1203 18:20:08.066498 375 slave.cpp:408] Slave checkpoint: true I1203 18:20:08.068333 368 state.cpp:52] Recovering state from '/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX/meta' I1203 18:20:08.068681 368 status_update_manager.cpp:200] Recovering status update manager I1203 18:20:08.069042 371 slave.cpp:4258] Finished recovery I1203 18:20:08.069588 371 slave.cpp:4430] Querying resource estimator for oversubscribable resources I1203 18:20:08.069870 371 slave.cpp:4444] Received oversubscribable resources from the resource estimator I1203 18:20:08.070039 371 slave.cpp:727] New master detected at [email protected]:38193 I1203 18:20:08.070108 368 status_update_manager.cpp:174] Pausing sending status updates I1203 18:20:08.070122 371 slave.cpp:790] Authenticating with master [email protected]:38193 I1203 18:20:08.070286 371 slave.cpp:795] Using default CRAM-MD5 authenticatee I1203 18:20:08.070444 371 slave.cpp:763] Detecting new master I1203 18:20:08.070648 371 authenticatee.cpp:121] Creating new client SASL connection I1203 18:20:08.071916 360 master.cpp:5308] Authenticating slave(112)@172.17.0.1:38193 I1203 18:20:08.072032 374 authenticator.cpp:413] Starting authentication session for crammd5_authenticatee(289)@172.17.0.1:38193 I1203 18:20:08.072621 373 authenticator.cpp:98] Creating new server SASL connection I1203 18:20:08.073480 373 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1203 18:20:08.073634 373 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1203 18:20:08.074204 373 authenticator.cpp:203] Received SASL authentication start I1203 18:20:08.074339 373 authenticator.cpp:325] Authentication requires more steps I1203 18:20:08.074533 373 authenticatee.cpp:258] Received SASL authentication step I1203 18:20:08.074730 373 authenticator.cpp:231] Received SASL authentication step I1203 18:20:08.074868 373 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'd0573e529de6' server FQDN: 'd0573e529de6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1203 18:20:08.074981 373 auxprop.cpp:179] Looking up auxiliary property '*userPassword' I1203 18:20:08.075132 373 auxprop.cpp:179] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1203 18:20:08.075253 373 auxprop.cpp:107] Request to lookup properties for user: 'test-principal' realm: 'd0573e529de6' server FQDN: 'd0573e529de6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1203 18:20:08.075352 373 auxprop.cpp:129] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1203 18:20:08.075449 373 auxprop.cpp:129] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1203 18:20:08.075562 373 authenticator.cpp:317] Authentication success I1203 18:20:08.076290 373 authenticatee.cpp:298] Authentication success I1203 18:20:08.076690 373 master.cpp:5338] Successfully authenticated principal 'test-principal' at slave(112)@172.17.0.1:38193 I1203 18:20:08.076859 367 authenticator.cpp:431] Authentication session cleanup for crammd5_authenticatee(289)@172.17.0.1:38193 I1203 18:20:08.077364 373 slave.cpp:858] Successfully authenticated with master [email protected]:38193 I1203 18:20:08.077898 373 slave.cpp:1252] Will retry registration in 2.893325ms if necessary I1203 18:20:08.078421 370 master.cpp:4017] Registering slave at slave(112)@172.17.0.1:38193 (maintenance-host-2) with id 78046f05-cfb7-4478-8385-528382f71b9e-S1 I1203 18:20:08.079151 371 registrar.cpp:439] Applied 1 operations in 116404ns; attempting to update the 'registry' I1203 18:20:08.080432 368 log.cpp:683] Attempting to append 515 bytes to the log I1203 18:20:08.080684 368 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5 I1203 18:20:08.081620 368 slave.cpp:1252] Will retry registration in 18.60268ms if necessary I1203 18:20:08.081985 362 master.cpp:4005] Ignoring register slave message from slave(112)@172.17.0.1:38193 (maintenance-host-2) as admission is already in progress I1203 18:20:08.082072 362 replica.cpp:538] Replica received write request for position 5 from (3843)@172.17.0.1:38193 I1203 18:20:08.082326 362 leveldb.cpp:341] Persisting action (534 bytes) to leveldb took 221545ns I1203 18:20:08.082352 362 replica.cpp:713] Persisted action at 5 I1203 18:20:08.083313 362 replica.cpp:692] Replica received learned notice for position 5 from @0.0.0.0:0 I1203 18:20:08.083830 362 leveldb.cpp:341] Persisting action (536 bytes) to leveldb took 489932ns I1203 18:20:08.083856 362 replica.cpp:713] Persisted action at 5 I1203 18:20:08.083878 362 replica.cpp:698] Replica learned APPEND action at position 5 I1203 18:20:08.086607 365 registrar.cpp:484] Successfully updated the 'registry' in 7.361024ms I1203 18:20:08.086846 362 log.cpp:702] Attempting to truncate the log to 5 I1203 18:20:08.087077 362 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 6 I1203 18:20:08.088059 375 master.cpp:4085] Registered slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 (maintenance-host-2) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1203 18:20:08.088321 362 hierarchical.cpp:380] Added slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 (maintenance-host-2) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: ) I1203 18:20:08.088524 362 hierarchical.cpp:1062] No resources available to allocate! I1203 18:20:08.088575 362 hierarchical.cpp:1155] No inverse offers to send out! I1203 18:20:08.088601 362 hierarchical.cpp:973] Performed allocation for slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 in 240968ns I1203 18:20:08.088644 360 replica.cpp:538] Replica received write request for position 6 from (3844)@172.17.0.1:38193 I1203 18:20:08.088717 361 slave.cpp:3197] Received ping from slave-observer(115)@172.17.0.1:38193 I1203 18:20:08.089000 361 slave.cpp:902] Registered with master [email protected]:38193; given slave ID 78046f05-cfb7-4478-8385-528382f71b9e-S1 I1203 18:20:08.089025 361 fetcher.cpp:79] Clearing fetcher cache I1203 18:20:08.089114 360 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 427596ns I1203 18:20:08.089143 360 replica.cpp:713] Persisted action at 6 I1203 18:20:08.089632 374 status_update_manager.cpp:181] Resuming sending status updates I1203 18:20:08.089820 361 slave.cpp:925] Checkpointing SlaveInfo to '/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX/meta/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S1/slave.info' I1203 18:20:08.090217 361 slave.cpp:961] Forwarding total oversubscribed resources I1203 18:20:08.090314 360 replica.cpp:692] Replica received learned notice for position 6 from @0.0.0.0:0 I1203 18:20:08.090492 361 master.cpp:4427] Received update of slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 (maintenance-host-2) with total oversubscribed resources I1203 18:20:08.090750 360 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 402522ns I1203 18:20:08.090843 360 leveldb.cpp:399] Deleting ~2 keys from leveldb took 64765ns I1203 18:20:08.090870 360 replica.cpp:713] Persisted action at 6 I1203 18:20:08.090895 360 replica.cpp:698] Replica learned TRUNCATE action at position 6 I1203 18:20:08.090980 361 hierarchical.cpp:434] Slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 (maintenance-host-2) updated with oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: ) I1203 18:20:08.091161 361 hierarchical.cpp:1062] No resources available to allocate! I1203 18:20:08.091203 361 hierarchical.cpp:1155] No inverse offers to send out! I1203 18:20:08.091225 361 hierarchical.cpp:973] Performed allocation for slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 in 203111ns I1203 18:20:08.094625 375 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/maintenance/schedule' I1203 18:20:08.094715 375 http.cpp:336] HTTP POST for /master/maintenance/schedule from 172.17.0.1:35704 I1203 18:20:08.095815 367 registrar.cpp:439] Applied 1 operations in 233576ns; attempting to update the 'registry' I1203 18:20:08.097347 374 log.cpp:683] Attempting to append 734 bytes to the log I1203 18:20:08.097617 374 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 7 I1203 18:20:08.098783 374 replica.cpp:538] Replica received write request for position 7 from (3845)@172.17.0.1:38193 I1203 18:20:08.099269 374 leveldb.cpp:341] Persisting action (753 bytes) to leveldb took 422267ns I1203 18:20:08.099300 374 replica.cpp:713] Persisted action at 7 I1203 18:20:08.100100 374 replica.cpp:692] Replica received learned notice for position 7 from @0.0.0.0:0 I1203 18:20:08.100509 374 leveldb.cpp:341] Persisting action (755 bytes) to leveldb took 378294ns I1203 18:20:08.100538 374 replica.cpp:713] Persisted action at 7 I1203 18:20:08.100560 374 replica.cpp:698] Replica learned APPEND action at position 7 I1203 18:20:08.103358 368 registrar.cpp:484] Successfully updated the 'registry' in 7.382784ms I1203 18:20:08.103742 374 log.cpp:702] Attempting to truncate the log to 7 I1203 18:20:08.104044 362 master.cpp:4483] Updating unavailability of slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 (maintenance-host-2), starting at 2399.10961820361weeks I1203 18:20:08.104357 374 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 8 I1203 18:20:08.105026 362 master.cpp:4483] Updating unavailability of slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 (maintenance-host), starting at 2399.10961820361weeks I1203 18:20:08.105545 363 hierarchical.cpp:1062] No resources available to allocate! I1203 18:20:08.105623 363 hierarchical.cpp:1155] No inverse offers to send out! I1203 18:20:08.105664 363 hierarchical.cpp:973] Performed allocation for slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 in 323361ns I1203 18:20:08.105907 363 hierarchical.cpp:1062] No resources available to allocate! I1203 18:20:08.105969 363 hierarchical.cpp:1155] No inverse offers to send out! I1203 18:20:08.105998 363 hierarchical.cpp:973] Performed allocation for slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 in 227967ns I1203 18:20:08.106138 362 master.cpp:4483] Updating unavailability of slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 (maintenance-host), starting at 2399.10961820361weeks I1203 18:20:08.106348 362 master.cpp:4483] Updating unavailability of slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 (maintenance-host-2), starting at 2399.10961820361weeks I1203 18:20:08.106581 364 replica.cpp:538] Replica received write request for position 8 from (3846)@172.17.0.1:38193 I1203 18:20:08.106816 370 hierarchical.cpp:1062] No resources available to allocate! I1203 18:20:08.106873 370 hierarchical.cpp:1155] No inverse offers to send out! I1203 18:20:08.107069 370 hierarchical.cpp:973] Performed allocation for slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 in 554269ns I1203 18:20:08.107333 364 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 640014ns I1203 18:20:08.107363 364 replica.cpp:713] Persisted action at 8 I1203 18:20:08.107599 370 hierarchical.cpp:1062] No resources available to allocate! I1203 18:20:08.107808 370 hierarchical.cpp:1155] No inverse offers to send out! I1203 18:20:08.107841 370 hierarchical.cpp:973] Performed allocation for slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 in 380899ns I1203 18:20:08.109459 371 replica.cpp:692] Replica received learned notice for position 8 from @0.0.0.0:0 I1203 18:20:08.110229 341 scheduler.cpp:154] Version: 0.27.0 I1203 18:20:08.110628 371 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 1.126432ms I1203 18:20:08.110713 371 leveldb.cpp:399] Deleting ~2 keys from leveldb took 42772ns I1203 18:20:08.110736 371 replica.cpp:713] Persisted action at 8 I1203 18:20:08.110766 371 replica.cpp:698] Replica learned TRUNCATE action at position 8 I1203 18:20:08.111073 370 scheduler.cpp:236] New master detected at [email protected]:38193 I1203 18:20:08.121060 370 scheduler.cpp:298] Sending SUBSCRIBE call to [email protected]:38193 I1203 18:20:08.123993 370 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I1203 18:20:08.124058 370 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:35705 I1203 18:20:08.124267 370 master.cpp:1899] Received subscription request for HTTP framework 'default' I1203 18:20:08.124351 370 master.cpp:1676] Authorizing framework principal 'test-principal' to receive offers for role '*' I1203 18:20:08.124866 360 master.cpp:1991] Subscribing framework 'default' with checkpointing disabled and capabilities [ ] I1203 18:20:08.125830 371 master.hpp:1583] Sending heartbeat to 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.125911 370 hierarchical.cpp:220] Added framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.127351 360 scheduler.cpp:457] Enqueuing event SUBSCRIBED received from [email protected]:38193 I1203 18:20:08.127707 370 hierarchical.cpp:957] Performed allocation for 2 slaves in 1.763005ms I1203 18:20:08.127928 370 scheduler.cpp:457] Enqueuing event HEARTBEAT received from [email protected]:38193 I1203 18:20:08.128466 370 master_maintenance_tests.cpp:172] Ignoring HEARTBEAT event I1203 18:20:08.128676 360 master.cpp:5137] Sending 2 offers to framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) I1203 18:20:08.129547 360 master.cpp:5227] Sending 2 inverse offers to framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) I1203 18:20:08.131640 372 scheduler.cpp:457] Enqueuing event OFFERS received from [email protected]:38193 I1203 18:20:08.132640 372 scheduler.cpp:457] Enqueuing event OFFERS received from [email protected]:38193 I1203 18:20:08.142935 368 hierarchical.cpp:1062] No resources available to allocate! I1203 18:20:08.143271 368 hierarchical.cpp:957] Performed allocation for 2 slaves in 1.280338ms I1203 18:20:08.154265 363 scheduler.cpp:298] Sending ACCEPT call to [email protected]:38193 I1203 18:20:08.156982 373 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I1203 18:20:08.157058 373 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:35706 I1203 18:20:08.158001 373 master.cpp:3010] Processing ACCEPT call for offers: [ 78046f05-cfb7-4478-8385-528382f71b9e-O0 ] on slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 (maintenance-host) for framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) I1203 18:20:08.158068 373 master.cpp:2742] Authorizing framework principal 'test-principal' to launch task e0957182-29d5-4591-938c-583b94075cac as user 'mesos' W1203 18:20:08.160732 373 validation.cpp:420] Executor executor-1 for task e0957182-29d5-4591-938c-583b94075cac uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases. W1203 18:20:08.160810 373 validation.cpp:432] Executor executor-1 for task e0957182-29d5-4591-938c-583b94075cac uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. I1203 18:20:08.161272 373 master.hpp:176] Adding task e0957182-29d5-4591-938c-583b94075cac with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 (maintenance-host) I1203 18:20:08.161528 373 master.cpp:3403] Launching task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 (maintenance-host) I1203 18:20:08.163053 361 slave.cpp:1292] Got assigned task e0957182-29d5-4591-938c-583b94075cac for framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.163275 373 scheduler.cpp:298] Sending ACCEPT call to [email protected]:38193 I1203 18:20:08.165091 361 slave.cpp:1411] Launching task e0957182-29d5-4591-938c-583b94075cac for framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.166036 361 paths.cpp:434] Trying to chown '/tmp/MasterMaintenanceTest_InverseOffersFilters_t0jUCH/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S0/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-1/runs/21ad7ee3-0cf3-4cba-a600-9a92469c806d' to user 'mesos' I1203 18:20:08.169783 365 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I1203 18:20:08.170961 365 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:35707 I1203 18:20:08.172499 365 master.cpp:3010] Processing ACCEPT call for offers: [ 78046f05-cfb7-4478-8385-528382f71b9e-O1 ] on slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 (maintenance-host-2) for framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) I1203 18:20:08.172575 365 master.cpp:2742] Authorizing framework principal 'test-principal' to launch task 124ff0e0-2a13-44e9-930a-3064718f86ae as user 'mesos' I1203 18:20:08.173951 361 slave.cpp:5042] Launching executor executor-1 of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 with resources in work directory '/tmp/MasterMaintenanceTest_InverseOffersFilters_t0jUCH/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S0/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-1/runs/21ad7ee3-0cf3-4cba-a600-9a92469c806d' I1203 18:20:08.176758 361 exec.cpp:134] Version: 0.27.0 W1203 18:20:08.178130 362 validation.cpp:420] Executor executor-2 for task 124ff0e0-2a13-44e9-930a-3064718f86ae uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases. W1203 18:20:08.178272 362 validation.cpp:432] Executor executor-2 for task 124ff0e0-2a13-44e9-930a-3064718f86ae uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. I1203 18:20:08.178927 362 master.hpp:176] Adding task 124ff0e0-2a13-44e9-930a-3064718f86ae with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 (maintenance-host-2) I1203 18:20:08.179332 362 master.cpp:3403] Launching task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 (maintenance-host-2) I1203 18:20:08.180057 362 slave.cpp:1292] Got assigned task 124ff0e0-2a13-44e9-930a-3064718f86ae for framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.180531 361 slave.cpp:1629] Queuing task 'e0957182-29d5-4591-938c-583b94075cac' for executor 'executor-1' of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.180651 365 exec.cpp:184] Executor started at: executor(48)@172.17.0.1:38193 with pid 341 I1203 18:20:08.181100 362 slave.cpp:1411] Launching task 124ff0e0-2a13-44e9-930a-3064718f86ae for framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.181176 361 slave.cpp:680] Successfully attached file '/tmp/MasterMaintenanceTest_InverseOffersFilters_t0jUCH/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S0/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-1/runs/21ad7ee3-0cf3-4cba-a600-9a92469c806d' I1203 18:20:08.181932 361 slave.cpp:2406] Got registration for executor 'executor-1' of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 from executor(48)@172.17.0.1:38193 I1203 18:20:08.181985 362 paths.cpp:434] Trying to chown '/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S1/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-2/runs/6104f936-ea54-4f01-a5f9-01dd606a7215' to user 'mesos' I1203 18:20:08.185151 374 exec.cpp:208] Executor registered on slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 I1203 18:20:08.185253 374 exec.cpp:220] Executor::registered took 50794ns I1203 18:20:08.185778 361 slave.cpp:1794] Sending queued task 'e0957182-29d5-4591-938c-583b94075cac' to executor 'executor-1' of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 at executor(48)@172.17.0.1:38193 I1203 18:20:08.186409 370 exec.cpp:295] Executor asked to run task 'e0957182-29d5-4591-938c-583b94075cac' I1203 18:20:08.186703 370 exec.cpp:304] Executor::launchTask took 265614ns I1203 18:20:08.187018 370 exec.cpp:517] Executor sending status update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.187510 370 slave.cpp:2763] Handling status update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 from executor(48)@172.17.0.1:38193 I1203 18:20:08.188098 371 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.188145 371 status_update_manager.cpp:497] Creating StatusUpdate stream for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.188643 371 status_update_manager.cpp:374] Forwarding update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 to the slave I1203 18:20:08.189015 366 slave.cpp:3115] Forwarding the update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 to [email protected]:38193 I1203 18:20:08.189395 366 slave.cpp:3009] Status update manager successfully handled status update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.189781 372 master.cpp:4572] Status update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 from slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 (maintenance-host) I1203 18:20:08.190065 372 master.cpp:4620] Forwarding status update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.190698 372 master.cpp:6224] Updating the state of task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING) I1203 18:20:08.191265 366 slave.cpp:3025] Sending acknowledgement for status update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 to executor(48)@172.17.0.1:38193 I1203 18:20:08.191725 366 exec.cpp:341] Executor received status update acknowledgement a4153a7a-bb32-41cc-9457-841754508d66 for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.193317 363 scheduler.cpp:457] Enqueuing event UPDATE received from [email protected]:38193 I1203 18:20:08.194072 362 slave.cpp:5042] Launching executor executor-2 of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 with resources in work directory '/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S1/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-2/runs/6104f936-ea54-4f01-a5f9-01dd606a7215' I1203 18:20:08.196590 362 exec.cpp:134] Version: 0.27.0 I1203 18:20:08.197185 369 exec.cpp:184] Executor started at: executor(49)@172.17.0.1:38193 with pid 341 I1203 18:20:08.197547 362 slave.cpp:1629] Queuing task '124ff0e0-2a13-44e9-930a-3064718f86ae' for executor 'executor-2' of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.197845 362 slave.cpp:680] Successfully attached file '/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S1/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-2/runs/6104f936-ea54-4f01-a5f9-01dd606a7215' I1203 18:20:08.198031 362 slave.cpp:2406] Got registration for executor 'executor-2' of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 from executor(49)@172.17.0.1:38193 I1203 18:20:08.198644 369 exec.cpp:208] Executor registered on slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 I1203 18:20:08.198714 369 exec.cpp:220] Executor::registered took 38382ns I1203 18:20:08.199406 362 slave.cpp:1794] Sending queued task '124ff0e0-2a13-44e9-930a-3064718f86ae' to executor 'executor-2' of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 at executor(49)@172.17.0.1:38193 I1203 18:20:08.199937 369 exec.cpp:295] Executor asked to run task '124ff0e0-2a13-44e9-930a-3064718f86ae' I1203 18:20:08.200042 369 exec.cpp:304] Executor::launchTask took 77814ns I1203 18:20:08.200152 369 exec.cpp:517] Executor sending status update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.200451 369 slave.cpp:2763] Handling status update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 from executor(49)@172.17.0.1:38193 I1203 18:20:08.200881 368 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.201140 368 status_update_manager.cpp:497] Creating StatusUpdate stream for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.201761 368 status_update_manager.cpp:374] Forwarding update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 to the slave I1203 18:20:08.202327 371 slave.cpp:3115] Forwarding the update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 to [email protected]:38193 I1203 18:20:08.202533 371 slave.cpp:3009] Status update manager successfully handled status update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.202585 371 slave.cpp:3025] Sending acknowledgement for status update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 to executor(49)@172.17.0.1:38193 I1203 18:20:08.202899 371 master.cpp:4572] Status update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 from slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 (maintenance-host-2) I1203 18:20:08.202953 371 master.cpp:4620] Forwarding status update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.203388 371 master.cpp:6224] Updating the state of task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING) I1203 18:20:08.203501 371 exec.cpp:341] Executor received status update acknowledgement 63ef56ab-2f32-4945-9f6d-f35829c3dc86 for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.205032 372 scheduler.cpp:457] Enqueuing event UPDATE received from [email protected]:38193 I1203 18:20:08.228276 360 scheduler.cpp:298] Sending ACKNOWLEDGE call to [email protected]:38193 I1203 18:20:08.230792 364 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I1203 18:20:08.230885 364 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:35708 I1203 18:20:08.231041 364 master.cpp:3729] Processing ACKNOWLEDGE call a4153a7a-bb32-41cc-9457-841754508d66 for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) on slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 I1203 18:20:08.231542 372 status_update_manager.cpp:392] Received status update acknowledgement (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.231957 364 slave.cpp:2346] Status update manager successfully handled status update acknowledgement (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task e0957182-29d5-4591-938c-583b94075cac of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.239132 372 scheduler.cpp:298] Sending ACKNOWLEDGE call to [email protected]:38193 I1203 18:20:08.241991 360 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I1203 18:20:08.242050 360 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:35709 I1203 18:20:08.242168 360 master.cpp:3729] Processing ACKNOWLEDGE call 63ef56ab-2f32-4945-9f6d-f35829c3dc86 for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) on slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 I1203 18:20:08.242746 360 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.243091 360 slave.cpp:2346] Status update manager successfully handled status update acknowledgement (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.244417 360 scheduler.cpp:298] Sending DECLINE call to [email protected]:38193 I1203 18:20:08.246664 374 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I1203 18:20:08.246726 374 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:35710 I1203 18:20:08.246840 374 master.cpp:3455] Processing DECLINE call for offers: [ 78046f05-cfb7-4478-8385-528382f71b9e-O3 ] for framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) I1203 18:20:08.247181 371 hierarchical.cpp:699] Framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 filtered inverse offers from slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 for 101secs I1203 18:20:08.248678 364 scheduler.cpp:298] Sending ACCEPT call to [email protected]:38193 I1203 18:20:08.250946 374 process.cpp:3067] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I1203 18:20:08.251015 374 http.cpp:336] HTTP POST for /master/api/v1/scheduler from 172.17.0.1:35711 W1203 18:20:08.251413 374 master.cpp:2973] ACCEPT call used invalid offers '[ 78046f05-cfb7-4478-8385-528382f71b9e-O2 ]': Offer 78046f05-cfb7-4478-8385-528382f71b9e-O2 is no longer valid I1203 18:20:08.251454 366 hierarchical.cpp:1062] No resources available to allocate! I1203 18:20:08.251724 366 hierarchical.cpp:1272] Filtered unavailability on slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 for framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:08.251934 366 hierarchical.cpp:957] Performed allocation for 2 slaves in 1.499989ms 2015-12-03 18:20:09,158:341(0x7f61e908c700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:43036] zk retcode=-4, errno=111(Connection refused): server refused to accept the client 2015-12-03 18:20:12,495:341(0x7f61e908c700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:43036] zk retcode=-4, errno=111(Connection refused): server refused to accept the client 2015-12-03 18:20:15,832:341(0x7f61e908c700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:43036] zk retcode=-4, errno=111(Connection refused): server refused to accept the client 2015-12-03 18:20:19,167:341(0x7f61e908c700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:43036] zk retcode=-4, errno=111(Connection refused): server refused to accept the client 2015-12-03 18:20:22,503:341(0x7f61e908c700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:43036] zk retcode=-4, errno=111(Connection refused): server refused to accept the client ../../src/tests/master_maintenance_tests.cpp:1559: Failure Failed to wait 15secs for event I1203 18:20:23.261693 365 master.cpp:938] Master terminating W1203 18:20:23.261994 365 master.cpp:6276] Removing task 124ff0e0-2a13-44e9-930a-3064718f86ae with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 on slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 (maintenance-host-2) in non-terminal state TASK_RUNNING I1203 18:20:23.263239 368 hierarchical.cpp:410] Removed slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 I1203 18:20:23.263739 365 master.cpp:6319] Removing executor 'executor-2' with resources of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 on slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 (maintenance-host-2) W1203 18:20:23.264315 365 master.cpp:6276] Removing task e0957182-29d5-4591-938c-583b94075cac with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 on slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 (maintenance-host) in non-terminal state TASK_RUNNING I1203 18:20:23.264825 367 hierarchical.cpp:410] Removed slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 I1203 18:20:23.265086 365 master.cpp:6319] Removing executor 'executor-1' with resources of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 on slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 (maintenance-host) I1203 18:20:23.265804 372 hierarchical.cpp:260] Removed framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 I1203 18:20:23.267813 367 slave.cpp:3243] [email protected]:38193 exited W1203 18:20:23.267844 367 slave.cpp:3246] Master disconnected! Waiting for a new master to be elected I1203 18:20:23.267884 365 slave.cpp:3243] [email protected]:38193 exited W1203 18:20:23.267940 365 slave.cpp:3246] Master disconnected! Waiting for a new master to be elected F1203 18:20:23.267940 341 logging.cpp:55] RAW: Pure virtual method called @ 0x7f628594a4ae google::LogMessage::Fail() @ 0x7f628594fa04 google::RawLog__() @ 0x7f6284b9f030 __cxa_pure_virtual @ 0x9eb126 mesos::internal::tests::Cluster::Slaves::shutdown() @ 0xf0fb90 mesos::internal::tests::MesosTest::ShutdownSlaves() @ 0xf0fb52 mesos::internal::tests::MesosTest::Shutdown() @ 0xf0c12b mesos::internal::tests::MesosTest::TearDown() @ 0x15037ca testing::internal::HandleSehExceptionsInMethodIfSupported<>() @ 0x14fe6a4 testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x14dfcc6 testing::Test::Run() @ 0x14e0400 testing::TestInfo::Run() @ 0x14e0a46 testing::TestCase::Run() @ 0x14e7320 testing::internal::UnitTestImpl::RunAllTests() @ 0x15043ef testing::internal::HandleSehExceptionsInMethodIfSupported<>() @ 0x14ff21a testing::internal::HandleExceptionsInMethodIfSupported<>() @ 0x14e6066 testing::UnitTest::Run() @ 0xd0eba0 RUN_ALL_TESTS() @ 0xd0e77e main @ 0x7f62800d3af5 __libc_start_main @ 0x939379 (unknown) On Thu, Dec 3, 2015 at 10:20 AM, Apache Jenkins Server < [email protected]> wrote: > See < > https://builds.apache.org/job/Mesos/COMPILER=gcc,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,OS=centos%3A7,label_exp=docker%7C%7CHadoop/1315/ > > > > ------------------------------------------ > [...truncated 65719 lines...] > I1203 18:20:08.083830 362 leveldb.cpp:341] Persisting action (536 bytes) > to leveldb took 489932ns > I1203 18:20:08.083856 362 replica.cpp:713] Persisted action at 5 > I1203 18:20:08.083878 362 replica.cpp:698] Replica learned APPEND action > at position 5 > I1203 18:20:08.086607 365 registrar.cpp:484] Successfully updated the > 'registry' in 7.361024ms > I1203 18:20:08.086846 362 log.cpp:702] Attempting to truncate the log to > 5 > I1203 18:20:08.087077 362 coordinator.cpp:348] Coordinator attempting to > write TRUNCATE action at position 6 > I1203 18:20:08.088059 375 master.cpp:4085] Registered slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 > (maintenance-host-2) with cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000] > I1203 18:20:08.088321 362 hierarchical.cpp:380] Added slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 (maintenance-host-2) with > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: ) > I1203 18:20:08.088524 362 hierarchical.cpp:1062] No resources available > to allocate! > I1203 18:20:08.088575 362 hierarchical.cpp:1155] No inverse offers to > send out! > I1203 18:20:08.088601 362 hierarchical.cpp:973] Performed allocation for > slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 in 240968ns > I1203 18:20:08.088644 360 replica.cpp:538] Replica received write > request for position 6 from (3844)@172.17.0.1:38193 > I1203 18:20:08.088717 361 slave.cpp:3197] Received ping from > slave-observer(115)@172.17.0.1:38193 > I1203 18:20:08.089000 361 slave.cpp:902] Registered with master > [email protected]:38193; given slave ID > 78046f05-cfb7-4478-8385-528382f71b9e-S1 > I1203 18:20:08.089025 361 fetcher.cpp:79] Clearing fetcher cache > I1203 18:20:08.089114 360 leveldb.cpp:341] Persisting action (16 bytes) > to leveldb took 427596ns > I1203 18:20:08.089143 360 replica.cpp:713] Persisted action at 6 > I1203 18:20:08.089632 374 status_update_manager.cpp:181] Resuming > sending status updates > I1203 18:20:08.089820 361 slave.cpp:925] Checkpointing SlaveInfo to > '/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX/meta/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S1/ > slave.info' > I1203 18:20:08.090217 361 slave.cpp:961] Forwarding total oversubscribed > resources > I1203 18:20:08.090314 360 replica.cpp:692] Replica received learned > notice for position 6 from @0.0.0.0:0 > I1203 18:20:08.090492 361 master.cpp:4427] Received update of slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 > (maintenance-host-2) with total oversubscribed resources > I1203 18:20:08.090750 360 leveldb.cpp:341] Persisting action (18 bytes) > to leveldb took 402522ns > I1203 18:20:08.090843 360 leveldb.cpp:399] Deleting ~2 keys from leveldb > took 64765ns > I1203 18:20:08.090870 360 replica.cpp:713] Persisted action at 6 > I1203 18:20:08.090895 360 replica.cpp:698] Replica learned TRUNCATE > action at position 6 > I1203 18:20:08.090980 361 hierarchical.cpp:434] Slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 (maintenance-host-2) updated with > oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000], allocated: ) > I1203 18:20:08.091161 361 hierarchical.cpp:1062] No resources available > to allocate! > I1203 18:20:08.091203 361 hierarchical.cpp:1155] No inverse offers to > send out! > I1203 18:20:08.091225 361 hierarchical.cpp:973] Performed allocation for > slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 in 203111ns > I1203 18:20:08.094625 375 process.cpp:3067] Handling HTTP event for > process 'master' with path: '/master/maintenance/schedule' > I1203 18:20:08.094715 375 http.cpp:336] HTTP POST for > /master/maintenance/schedule from 172.17.0.1:35704 > I1203 18:20:08.095815 367 registrar.cpp:439] Applied 1 operations in > 233576ns; attempting to update the 'registry' > I1203 18:20:08.097347 374 log.cpp:683] Attempting to append 734 bytes to > the log > I1203 18:20:08.097617 374 coordinator.cpp:348] Coordinator attempting to > write APPEND action at position 7 > I1203 18:20:08.098783 374 replica.cpp:538] Replica received write > request for position 7 from (3845)@172.17.0.1:38193 > I1203 18:20:08.099269 374 leveldb.cpp:341] Persisting action (753 bytes) > to leveldb took 422267ns > I1203 18:20:08.099300 374 replica.cpp:713] Persisted action at 7 > I1203 18:20:08.100100 374 replica.cpp:692] Replica received learned > notice for position 7 from @0.0.0.0:0 > I1203 18:20:08.100509 374 leveldb.cpp:341] Persisting action (755 bytes) > to leveldb took 378294ns > I1203 18:20:08.100538 374 replica.cpp:713] Persisted action at 7 > I1203 18:20:08.100560 374 replica.cpp:698] Replica learned APPEND action > at position 7 > I1203 18:20:08.103358 368 registrar.cpp:484] Successfully updated the > 'registry' in 7.382784ms > I1203 18:20:08.103742 374 log.cpp:702] Attempting to truncate the log to > 7 > I1203 18:20:08.104044 362 master.cpp:4483] Updating unavailability of > slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@ > 172.17.0.1:38193 (maintenance-host-2), starting at 2399.10961820361weeks > I1203 18:20:08.104357 374 coordinator.cpp:348] Coordinator attempting to > write TRUNCATE action at position 8 > I1203 18:20:08.105026 362 master.cpp:4483] Updating unavailability of > slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@ > 172.17.0.1:38193 (maintenance-host), starting at 2399.10961820361weeks > I1203 18:20:08.105545 363 hierarchical.cpp:1062] No resources available > to allocate! > I1203 18:20:08.105623 363 hierarchical.cpp:1155] No inverse offers to > send out! > I1203 18:20:08.105664 363 hierarchical.cpp:973] Performed allocation for > slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 in 323361ns > I1203 18:20:08.105907 363 hierarchical.cpp:1062] No resources available > to allocate! > I1203 18:20:08.105969 363 hierarchical.cpp:1155] No inverse offers to > send out! > I1203 18:20:08.105998 363 hierarchical.cpp:973] Performed allocation for > slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 in 227967ns > I1203 18:20:08.106138 362 master.cpp:4483] Updating unavailability of > slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@ > 172.17.0.1:38193 (maintenance-host), starting at 2399.10961820361weeks > I1203 18:20:08.106348 362 master.cpp:4483] Updating unavailability of > slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@ > 172.17.0.1:38193 (maintenance-host-2), starting at 2399.10961820361weeks > I1203 18:20:08.106581 364 replica.cpp:538] Replica received write > request for position 8 from (3846)@172.17.0.1:38193 > I1203 18:20:08.106816 370 hierarchical.cpp:1062] No resources available > to allocate! > I1203 18:20:08.106873 370 hierarchical.cpp:1155] No inverse offers to > send out! > I1203 18:20:08.107069 370 hierarchical.cpp:973] Performed allocation for > slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 in 554269ns > I1203 18:20:08.107333 364 leveldb.cpp:341] Persisting action (16 bytes) > to leveldb took 640014ns > I1203 18:20:08.107363 364 replica.cpp:713] Persisted action at 8 > I1203 18:20:08.107599 370 hierarchical.cpp:1062] No resources available > to allocate! > I1203 18:20:08.107808 370 hierarchical.cpp:1155] No inverse offers to > send out! > I1203 18:20:08.107841 370 hierarchical.cpp:973] Performed allocation for > slave 78046f05-cfb7-4478-8385-528382f71b9e-S1 in 380899ns > I1203 18:20:08.109459 371 replica.cpp:692] Replica received learned > notice for position 8 from @0.0.0.0:0 > I1203 18:20:08.110229 341 scheduler.cpp:154] Version: 0.27.0 > I1203 18:20:08.110628 371 leveldb.cpp:341] Persisting action (18 bytes) > to leveldb took 1.126432ms > I1203 18:20:08.110713 371 leveldb.cpp:399] Deleting ~2 keys from leveldb > took 42772ns > I1203 18:20:08.110736 371 replica.cpp:713] Persisted action at 8 > I1203 18:20:08.110766 371 replica.cpp:698] Replica learned TRUNCATE > action at position 8 > I1203 18:20:08.111073 370 scheduler.cpp:236] New master detected at > [email protected]:38193 > I1203 18:20:08.121060 370 scheduler.cpp:298] Sending SUBSCRIBE call to > [email protected]:38193 > I1203 18:20:08.123993 370 process.cpp:3067] Handling HTTP event for > process 'master' with path: '/master/api/v1/scheduler' > I1203 18:20:08.124058 370 http.cpp:336] HTTP POST for > /master/api/v1/scheduler from 172.17.0.1:35705 > I1203 18:20:08.124267 370 master.cpp:1899] Received subscription request > for HTTP framework 'default' > I1203 18:20:08.124351 370 master.cpp:1676] Authorizing framework > principal 'test-principal' to receive offers for role '*' > I1203 18:20:08.124866 360 master.cpp:1991] Subscribing framework > 'default' with checkpointing disabled and capabilities [ ] > I1203 18:20:08.125830 371 master.hpp:1583] Sending heartbeat to > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.125911 370 hierarchical.cpp:220] Added framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.127351 360 scheduler.cpp:457] Enqueuing event SUBSCRIBED > received from [email protected]:38193 > I1203 18:20:08.127707 370 hierarchical.cpp:957] Performed allocation for > 2 slaves in 1.763005ms > I1203 18:20:08.127928 370 scheduler.cpp:457] Enqueuing event HEARTBEAT > received from [email protected]:38193 > I1203 18:20:08.128466 370 master_maintenance_tests.cpp:172] Ignoring > HEARTBEAT event > I1203 18:20:08.128676 360 master.cpp:5137] Sending 2 offers to framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) > I1203 18:20:08.129547 360 master.cpp:5227] Sending 2 inverse offers to > framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) > I1203 18:20:08.131640 372 scheduler.cpp:457] Enqueuing event OFFERS > received from [email protected]:38193 > I1203 18:20:08.132640 372 scheduler.cpp:457] Enqueuing event OFFERS > received from [email protected]:38193 > I1203 18:20:08.142935 368 hierarchical.cpp:1062] No resources available > to allocate! > I1203 18:20:08.143271 368 hierarchical.cpp:957] Performed allocation for > 2 slaves in 1.280338ms > I1203 18:20:08.154265 363 scheduler.cpp:298] Sending ACCEPT call to > [email protected]:38193 > I1203 18:20:08.156982 373 process.cpp:3067] Handling HTTP event for > process 'master' with path: '/master/api/v1/scheduler' > I1203 18:20:08.157058 373 http.cpp:336] HTTP POST for > /master/api/v1/scheduler from 172.17.0.1:35706 > I1203 18:20:08.158001 373 master.cpp:3010] Processing ACCEPT call for > offers: [ 78046f05-cfb7-4478-8385-528382f71b9e-O0 ] on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 > (maintenance-host) for framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 > (default) > I1203 18:20:08.158068 373 master.cpp:2742] Authorizing framework > principal 'test-principal' to launch task > e0957182-29d5-4591-938c-583b94075cac as user 'mesos' > W1203 18:20:08.160732 373 validation.cpp:420] Executor executor-1 for > task e0957182-29d5-4591-938c-583b94075cac uses less CPUs (None) than the > minimum required (0.01). Please update your executor, as this will be > mandatory in future releases. > W1203 18:20:08.160810 373 validation.cpp:432] Executor executor-1 for > task e0957182-29d5-4591-938c-583b94075cac uses less memory (None) than the > minimum required (32MB). Please update your executor, as this will be > mandatory in future releases. > I1203 18:20:08.161272 373 master.hpp:176] Adding task > e0957182-29d5-4591-938c-583b94075cac with resources cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000] on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S0 (maintenance-host) > I1203 18:20:08.161528 373 master.cpp:3403] Launching task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) with resources > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 > (maintenance-host) > I1203 18:20:08.163053 361 slave.cpp:1292] Got assigned task > e0957182-29d5-4591-938c-583b94075cac for framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.163275 373 scheduler.cpp:298] Sending ACCEPT call to > [email protected]:38193 > I1203 18:20:08.165091 361 slave.cpp:1411] Launching task > e0957182-29d5-4591-938c-583b94075cac for framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.166036 361 paths.cpp:434] Trying to chown > '/tmp/MasterMaintenanceTest_InverseOffersFilters_t0jUCH/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S0/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-1/runs/21ad7ee3-0cf3-4cba-a600-9a92469c806d' > to user 'mesos' > I1203 18:20:08.169783 365 process.cpp:3067] Handling HTTP event for > process 'master' with path: '/master/api/v1/scheduler' > I1203 18:20:08.170961 365 http.cpp:336] HTTP POST for > /master/api/v1/scheduler from 172.17.0.1:35707 > I1203 18:20:08.172499 365 master.cpp:3010] Processing ACCEPT call for > offers: [ 78046f05-cfb7-4478-8385-528382f71b9e-O1 ] on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 > (maintenance-host-2) for framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) > I1203 18:20:08.172575 365 master.cpp:2742] Authorizing framework > principal 'test-principal' to launch task > 124ff0e0-2a13-44e9-930a-3064718f86ae as user 'mesos' > I1203 18:20:08.173951 361 slave.cpp:5042] Launching executor executor-1 > of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 with resources in > work directory > '/tmp/MasterMaintenanceTest_InverseOffersFilters_t0jUCH/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S0/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-1/runs/21ad7ee3-0cf3-4cba-a600-9a92469c806d' > I1203 18:20:08.176758 361 exec.cpp:134] Version: 0.27.0 > W1203 18:20:08.178130 362 validation.cpp:420] Executor executor-2 for > task 124ff0e0-2a13-44e9-930a-3064718f86ae uses less CPUs (None) than the > minimum required (0.01). Please update your executor, as this will be > mandatory in future releases. > W1203 18:20:08.178272 362 validation.cpp:432] Executor executor-2 for > task 124ff0e0-2a13-44e9-930a-3064718f86ae uses less memory (None) than the > minimum required (32MB). Please update your executor, as this will be > mandatory in future releases. > I1203 18:20:08.178927 362 master.hpp:176] Adding task > 124ff0e0-2a13-44e9-930a-3064718f86ae with resources cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000] on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 (maintenance-host-2) > I1203 18:20:08.179332 362 master.cpp:3403] Launching task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) with resources > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 > (maintenance-host-2) > I1203 18:20:08.180057 362 slave.cpp:1292] Got assigned task > 124ff0e0-2a13-44e9-930a-3064718f86ae for framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.180531 361 slave.cpp:1629] Queuing task > 'e0957182-29d5-4591-938c-583b94075cac' for executor 'executor-1' of > framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.180651 365 exec.cpp:184] Executor started at: > executor(48)@172.17.0.1:38193 with pid 341 > I1203 18:20:08.181100 362 slave.cpp:1411] Launching task > 124ff0e0-2a13-44e9-930a-3064718f86ae for framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.181176 361 slave.cpp:680] Successfully attached file > '/tmp/MasterMaintenanceTest_InverseOffersFilters_t0jUCH/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S0/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-1/runs/21ad7ee3-0cf3-4cba-a600-9a92469c806d' > I1203 18:20:08.181932 361 slave.cpp:2406] Got registration for executor > 'executor-1' of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 from > executor(48)@172.17.0.1:38193 > I1203 18:20:08.181985 362 paths.cpp:434] Trying to chown > '/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S1/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-2/runs/6104f936-ea54-4f01-a5f9-01dd606a7215' > to user 'mesos' > I1203 18:20:08.185151 374 exec.cpp:208] Executor registered on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S0 > I1203 18:20:08.185253 374 exec.cpp:220] Executor::registered took 50794ns > I1203 18:20:08.185778 361 slave.cpp:1794] Sending queued task > 'e0957182-29d5-4591-938c-583b94075cac' to executor 'executor-1' of > framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 at executor(48)@ > 172.17.0.1:38193 > I1203 18:20:08.186409 370 exec.cpp:295] Executor asked to run task > 'e0957182-29d5-4591-938c-583b94075cac' > I1203 18:20:08.186703 370 exec.cpp:304] Executor::launchTask took > 265614ns > I1203 18:20:08.187018 370 exec.cpp:517] Executor sending status update > TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.187510 370 slave.cpp:2763] Handling status update > TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 from executor(48)@ > 172.17.0.1:38193 > I1203 18:20:08.188098 371 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.188145 371 status_update_manager.cpp:497] Creating > StatusUpdate stream for task e0957182-29d5-4591-938c-583b94075cac of > framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.188643 371 status_update_manager.cpp:374] Forwarding > update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 to the slave > I1203 18:20:08.189015 366 slave.cpp:3115] Forwarding the update > TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 to [email protected]:38193 > I1203 18:20:08.189395 366 slave.cpp:3009] Status update manager > successfully handled status update TASK_RUNNING (UUID: > a4153a7a-bb32-41cc-9457-841754508d66) for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.189781 372 master.cpp:4572] Status update TASK_RUNNING > (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 from slave > 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 > (maintenance-host) > I1203 18:20:08.190065 372 master.cpp:4620] Forwarding status update > TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.190698 372 master.cpp:6224] Updating the state of task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 (latest state: TASK_RUNNING, > status update state: TASK_RUNNING) > I1203 18:20:08.191265 366 slave.cpp:3025] Sending acknowledgement for > status update TASK_RUNNING (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for > task e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 to executor(48)@172.17.0.1:38193 > I1203 18:20:08.191725 366 exec.cpp:341] Executor received status update > acknowledgement a4153a7a-bb32-41cc-9457-841754508d66 for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.193317 363 scheduler.cpp:457] Enqueuing event UPDATE > received from [email protected]:38193 > I1203 18:20:08.194072 362 slave.cpp:5042] Launching executor executor-2 > of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 with resources in > work directory > '/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S1/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-2/runs/6104f936-ea54-4f01-a5f9-01dd606a7215' > I1203 18:20:08.196590 362 exec.cpp:134] Version: 0.27.0 > I1203 18:20:08.197185 369 exec.cpp:184] Executor started at: > executor(49)@172.17.0.1:38193 with pid 341 > I1203 18:20:08.197547 362 slave.cpp:1629] Queuing task > '124ff0e0-2a13-44e9-930a-3064718f86ae' for executor 'executor-2' of > framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.197845 362 slave.cpp:680] Successfully attached file > '/tmp/MasterMaintenanceTest_InverseOffersFilters_XSU2vX/slaves/78046f05-cfb7-4478-8385-528382f71b9e-S1/frameworks/78046f05-cfb7-4478-8385-528382f71b9e-0000/executors/executor-2/runs/6104f936-ea54-4f01-a5f9-01dd606a7215' > I1203 18:20:08.198031 362 slave.cpp:2406] Got registration for executor > 'executor-2' of framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 from > executor(49)@172.17.0.1:38193 > I1203 18:20:08.198644 369 exec.cpp:208] Executor registered on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 > I1203 18:20:08.198714 369 exec.cpp:220] Executor::registered took 38382ns > I1203 18:20:08.199406 362 slave.cpp:1794] Sending queued task > '124ff0e0-2a13-44e9-930a-3064718f86ae' to executor 'executor-2' of > framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 at executor(49)@ > 172.17.0.1:38193 > I1203 18:20:08.199937 369 exec.cpp:295] Executor asked to run task > '124ff0e0-2a13-44e9-930a-3064718f86ae' > I1203 18:20:08.200042 369 exec.cpp:304] Executor::launchTask took 77814ns > I1203 18:20:08.200152 369 exec.cpp:517] Executor sending status update > TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.200451 369 slave.cpp:2763] Handling status update > TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 from executor(49)@ > 172.17.0.1:38193 > I1203 18:20:08.200881 368 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.201140 368 status_update_manager.cpp:497] Creating > StatusUpdate stream for task 124ff0e0-2a13-44e9-930a-3064718f86ae of > framework 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.201761 368 status_update_manager.cpp:374] Forwarding > update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 to the slave > I1203 18:20:08.202327 371 slave.cpp:3115] Forwarding the update > TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 to [email protected]:38193 > I1203 18:20:08.202533 371 slave.cpp:3009] Status update manager > successfully handled status update TASK_RUNNING (UUID: > 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.202585 371 slave.cpp:3025] Sending acknowledgement for > status update TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for > task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 to executor(49)@172.17.0.1:38193 > I1203 18:20:08.202899 371 master.cpp:4572] Status update TASK_RUNNING > (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 from slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 > (maintenance-host-2) > I1203 18:20:08.202953 371 master.cpp:4620] Forwarding status update > TASK_RUNNING (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.203388 371 master.cpp:6224] Updating the state of task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 (latest state: TASK_RUNNING, > status update state: TASK_RUNNING) > I1203 18:20:08.203501 371 exec.cpp:341] Executor received status update > acknowledgement 63ef56ab-2f32-4945-9f6d-f35829c3dc86 for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.205032 372 scheduler.cpp:457] Enqueuing event UPDATE > received from [email protected]:38193 > I1203 18:20:08.228276 360 scheduler.cpp:298] Sending ACKNOWLEDGE call to > [email protected]:38193 > I1203 18:20:08.230792 364 process.cpp:3067] Handling HTTP event for > process 'master' with path: '/master/api/v1/scheduler' > I1203 18:20:08.230885 364 http.cpp:336] HTTP POST for > /master/api/v1/scheduler from 172.17.0.1:35708 > I1203 18:20:08.231041 364 master.cpp:3729] Processing ACKNOWLEDGE call > a4153a7a-bb32-41cc-9457-841754508d66 for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S0 > I1203 18:20:08.231542 372 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: a4153a7a-bb32-41cc-9457-841754508d66) for > task e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.231957 364 slave.cpp:2346] Status update manager > successfully handled status update acknowledgement (UUID: > a4153a7a-bb32-41cc-9457-841754508d66) for task > e0957182-29d5-4591-938c-583b94075cac of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.239132 372 scheduler.cpp:298] Sending ACKNOWLEDGE call to > [email protected]:38193 > I1203 18:20:08.241991 360 process.cpp:3067] Handling HTTP event for > process 'master' with path: '/master/api/v1/scheduler' > I1203 18:20:08.242050 360 http.cpp:336] HTTP POST for > /master/api/v1/scheduler from 172.17.0.1:35709 > I1203 18:20:08.242168 360 master.cpp:3729] Processing ACKNOWLEDGE call > 63ef56ab-2f32-4945-9f6d-f35829c3dc86 for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 > I1203 18:20:08.242746 360 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for > task 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.243091 360 slave.cpp:2346] Status update manager > successfully handled status update acknowledgement (UUID: > 63ef56ab-2f32-4945-9f6d-f35829c3dc86) for task > 124ff0e0-2a13-44e9-930a-3064718f86ae of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.244417 360 scheduler.cpp:298] Sending DECLINE call to > [email protected]:38193 > I1203 18:20:08.246664 374 process.cpp:3067] Handling HTTP event for > process 'master' with path: '/master/api/v1/scheduler' > I1203 18:20:08.246726 374 http.cpp:336] HTTP POST for > /master/api/v1/scheduler from 172.17.0.1:35710 > I1203 18:20:08.246840 374 master.cpp:3455] Processing DECLINE call for > offers: [ 78046f05-cfb7-4478-8385-528382f71b9e-O3 ] for framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 (default) > I1203 18:20:08.247181 371 hierarchical.cpp:699] Framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 filtered inverse offers from > slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 for 101secs > I1203 18:20:08.248678 364 scheduler.cpp:298] Sending ACCEPT call to > [email protected]:38193 > I1203 18:20:08.250946 374 process.cpp:3067] Handling HTTP event for > process 'master' with path: '/master/api/v1/scheduler' > I1203 18:20:08.251015 374 http.cpp:336] HTTP POST for > /master/api/v1/scheduler from 172.17.0.1:35711 > W1203 18:20:08.251413 374 master.cpp:2973] ACCEPT call used invalid > offers '[ 78046f05-cfb7-4478-8385-528382f71b9e-O2 ]': Offer > 78046f05-cfb7-4478-8385-528382f71b9e-O2 is no longer valid > I1203 18:20:08.251454 366 hierarchical.cpp:1062] No resources available > to allocate! > I1203 18:20:08.251724 366 hierarchical.cpp:1272] Filtered unavailability > on slave 78046f05-cfb7-4478-8385-528382f71b9e-S0 for framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:08.251934 366 hierarchical.cpp:957] Performed allocation for > 2 slaves in 1.499989ms > 2015-12-03 > 18:20:09,158:341(0x7f61e908c700):ZOO_ERROR@handle_socket_error_msg@1697: > Socket [127.0.0.1:43036] zk retcode=-4, errno=111(Connection refused): > server refused to accept the client > 2015-12-03 > 18:20:12,495:341(0x7f61e908c700):ZOO_ERROR@handle_socket_error_msg@1697: > Socket [127.0.0.1:43036] zk retcode=-4, errno=111(Connection refused): > server refused to accept the client > 2015-12-03 > 18:20:15,832:341(0x7f61e908c700):ZOO_ERROR@handle_socket_error_msg@1697: > Socket [127.0.0.1:43036] zk retcode=-4, errno=111(Connection refused): > server refused to accept the client > 2015-12-03 > 18:20:19,167:341(0x7f61e908c700):ZOO_ERROR@handle_socket_error_msg@1697: > Socket [127.0.0.1:43036] zk retcode=-4, errno=111(Connection refused): > server refused to accept the client > 2015-12-03 > 18:20:22,503:341(0x7f61e908c700):ZOO_ERROR@handle_socket_error_msg@1697: > Socket [127.0.0.1:43036] zk retcode=-4, errno=111(Connection refused): > server refused to accept the client > ../../src/tests/master_maintenance_tests.cpp:1559: Failure > Failed to wait 15secs for event > I1203 18:20:23.261693 365 master.cpp:938] Master terminating > W1203 18:20:23.261994 365 master.cpp:6276] Removing task > 124ff0e0-2a13-44e9-930a-3064718f86ae with resources cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000] of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 > (maintenance-host-2) in non-terminal state TASK_RUNNING > I1203 18:20:23.263239 368 hierarchical.cpp:410] Removed slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 > I1203 18:20:23.263739 365 master.cpp:6319] Removing executor > 'executor-2' with resources of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S1 at slave(112)@172.17.0.1:38193 > (maintenance-host-2) > W1203 18:20:23.264315 365 master.cpp:6276] Removing task > e0957182-29d5-4591-938c-583b94075cac with resources cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000] of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 > (maintenance-host) in non-terminal state TASK_RUNNING > I1203 18:20:23.264825 367 hierarchical.cpp:410] Removed slave > 78046f05-cfb7-4478-8385-528382f71b9e-S0 > I1203 18:20:23.265086 365 master.cpp:6319] Removing executor > 'executor-1' with resources of framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 on slave > 78046f05-cfb7-4478-8385-528382f71b9e-S0 at slave(111)@172.17.0.1:38193 > (maintenance-host) > I1203 18:20:23.265804 372 hierarchical.cpp:260] Removed framework > 78046f05-cfb7-4478-8385-528382f71b9e-0000 > I1203 18:20:23.267813 367 slave.cpp:3243] [email protected]:38193 exited > W1203 18:20:23.267844 367 slave.cpp:3246] Master disconnected! Waiting > for a new master to be elected > I1203 18:20:23.267884 365 slave.cpp:3243] [email protected]:38193 exited > W1203 18:20:23.267940 365 slave.cpp:3246] Master disconnected! Waiting > for a new master to be elected > F1203 18:20:23.267940 341 logging.cpp:55] RAW: Pure virtual method called > @ 0x7f628594a4ae google::LogMessage::Fail() > @ 0x7f628594fa04 google::RawLog__() > @ 0x7f6284b9f030 __cxa_pure_virtual > @ 0x9eb126 > mesos::internal::tests::Cluster::Slaves::shutdown() > @ 0xf0fb90 > mesos::internal::tests::MesosTest::ShutdownSlaves() > @ 0xf0fb52 mesos::internal::tests::MesosTest::Shutdown() > @ 0xf0c12b mesos::internal::tests::MesosTest::TearDown() > @ 0x15037ca > testing::internal::HandleSehExceptionsInMethodIfSupported<>() > @ 0x14fe6a4 > testing::internal::HandleExceptionsInMethodIfSupported<>() > @ 0x14dfcc6 testing::Test::Run() > @ 0x14e0400 testing::TestInfo::Run() > @ 0x14e0a46 testing::TestCase::Run() > @ 0x14e7320 testing::internal::UnitTestImpl::RunAllTests() > @ 0x15043ef > testing::internal::HandleSehExceptionsInMethodIfSupported<>() > @ 0x14ff21a > testing::internal::HandleExceptionsInMethodIfSupported<>() > @ 0x14e6066 testing::UnitTest::Run() > @ 0xd0eba0 RUN_ALL_TESTS() > @ 0xd0e77e main > @ 0x7f62800d3af5 __libc_start_main > @ 0x939379 (unknown) > make[4]: *** [check-local] Aborted > make[4]: Leaving directory `/mesos/mesos-0.27.0/_build/src' > make[3]: *** [check-am] Error 2 > make[3]: Leaving directory `/mesos/mesos-0.27.0/_build/src' > make[2]: *** [check] Error 2 > make[2]: Leaving directory `/mesos/mesos-0.27.0/_build/src' > make[1]: *** [check-recursive] Error 1 > make[1]: Leaving directory `/mesos/mesos-0.27.0/_build' > make: *** [distcheck] Error 1 > + docker rmi mesos-1449165142-11808 > Untagged: mesos-1449165142-11808:latest > Deleted: db54fc17d43deb93a90e8fabb7824e24f491aafdfabd44cf81a28768e7498566 > Deleted: 28ad8a4d4601593fd69c107f55038fb162cb367a553e5cd1c46d59cf898afed6 > Deleted: a5760177aedb0acea3825781c16f792b06232601577db17da79670a23a8116de > Deleted: 99bebc3204f26ca4a07830e98ac2c646f4b7188df0674758191a99d8c58d88ad > Deleted: 9ff79d453151387cfe33d186170f9771af1b94420d5acd2917e642a56a8aa0ba > Deleted: 406ad7284996fbb203714adaf5e0f71d2b66aaf90bf1f2ddef4983389ae73307 > Deleted: acfc0dc0a0f449b7471e73c200f401cd5983b972548402d786f366eba1a7f3b1 > Deleted: 6bfe4589d9179945d0a56ee8e1405f4d2b0dbdbc97d2d80ba41b371fe92bbe63 > Deleted: 394453c00da5c216f70ec2ea855be7c5881914c5f9e8d6b5ac83aeacf6a9f73b > Deleted: 3f817f3f0e4d357fb448a08ccf88cf269c41ab6ae2ddebb346ad3c5a1fca2d99 > Deleted: 5819519622c001b957e40e81e38b8492649b96ab52157f952a28c72b5c716a82 > Deleted: b5aacb8d1b68aafaba0d668495a0e1c6e61a15c7224f8e667241e2748688ef52 > Build step 'Execute shell' marked build as failure >
