[ https://issues.apache.org/jira/browse/MESOS-4024?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15040775#comment-15040775 ]
haosdent commented on MESOS-4024: --------------------------------- Sorry for the dalay, I would try to investigate this at this weekend. > HealthCheckTest.CheckCommandTimeout is flaky. > --------------------------------------------- > > Key: MESOS-4024 > URL: https://issues.apache.org/jira/browse/MESOS-4024 > Project: Mesos > Issue Type: Bug > Reporter: haosdent > Assignee: haosdent > Labels: flaky-test > Attachments: HealthCheckTest_CheckCommandTimeout.log > > > {noformat: title=Failed Run} > [ RUN ] HealthCheckTest.CheckCommandTimeout > I1201 13:03:15.211911 30288 leveldb.cpp:174] Opened db in 126.548747ms > I1201 13:03:15.254041 30288 leveldb.cpp:181] Compacted db in 42.053948ms > I1201 13:03:15.254226 30288 leveldb.cpp:196] Created db iterator in 25588ns > I1201 13:03:15.254281 30288 leveldb.cpp:202] Seeked to beginning of db in > 3231ns > I1201 13:03:15.254294 30288 leveldb.cpp:271] Iterated through 0 keys in the > db in 256ns > I1201 13:03:15.254348 30288 replica.cpp:778] Replica recovered with log > positions 0 -> 0 with 1 holes and 0 unlearned > I1201 13:03:15.255162 30311 recover.cpp:447] Starting replica recovery > I1201 13:03:15.255502 30311 recover.cpp:473] Replica is in EMPTY status > I1201 13:03:15.257158 30311 replica.cpp:674] Replica in EMPTY status received > a broadcasted recover request from (1898)@172.17.21.0:52024 > I1201 13:03:15.258224 30318 recover.cpp:193] Received a recover response from > a replica in EMPTY status > I1201 13:03:15.259735 30310 recover.cpp:564] Updating replica status to > STARTING > I1201 13:03:15.265080 30322 master.cpp:365] Master > dd5bff66-362f-4efc-963a-54756b2edcce (fa812f474cf4) started on > 172.17.21.0:52024 > I1201 13:03:15.265121 30322 master.cpp:367] Flags at startup: --acls="" > --allocation_interval="1secs" --allocator="HierarchicalDRF" > --authenticate="true" --authenticate_slaves="true" --authenticators="crammd5" > --authorizers="local" --credentials="/tmp/IaRntP/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/IaRntP/master" --zk_session_timeout="10secs" > I1201 13:03:15.265487 30322 master.cpp:412] Master only allowing > authenticated frameworks to register > I1201 13:03:15.265504 30322 master.cpp:417] Master only allowing > authenticated slaves to register > I1201 13:03:15.265513 30322 credentials.hpp:35] Loading credentials for > authentication from '/tmp/IaRntP/credentials' > I1201 13:03:15.265842 30322 master.cpp:456] Using default 'crammd5' > authenticator > I1201 13:03:15.266006 30322 master.cpp:493] Authorization enabled > I1201 13:03:15.266464 30308 hierarchical.cpp:162] Initialized hierarchical > allocator process > I1201 13:03:15.267225 30321 whitelist_watcher.cpp:77] No whitelist given > I1201 13:03:15.268847 30322 master.cpp:1637] The newly elected leader is > master@172.17.21.0:52024 with id dd5bff66-362f-4efc-963a-54756b2edcce > I1201 13:03:15.268887 30322 master.cpp:1650] Elected as the leading master! > I1201 13:03:15.268905 30322 master.cpp:1395] Recovering from registrar > I1201 13:03:15.270830 30322 registrar.cpp:307] Recovering registrar > I1201 13:03:15.291272 30318 leveldb.cpp:304] Persisting metadata (8 bytes) to > leveldb took 31.410668ms > I1201 13:03:15.291363 30318 replica.cpp:321] Persisted replica status to > STARTING > I1201 13:03:15.291733 30318 recover.cpp:473] Replica is in STARTING status > I1201 13:03:15.293392 30318 replica.cpp:674] Replica in STARTING status > received a broadcasted recover request from (1900)@172.17.21.0:52024 > I1201 13:03:15.294251 30307 recover.cpp:193] Received a recover response from > a replica in STARTING status > I1201 13:03:15.294756 30307 recover.cpp:564] Updating replica status to VOTING > I1201 13:03:15.338260 30307 leveldb.cpp:304] Persisting metadata (8 bytes) to > leveldb took 43.256127ms > I1201 13:03:15.338348 30307 replica.cpp:321] Persisted replica status to > VOTING > I1201 13:03:15.338601 30307 recover.cpp:578] Successfully joined the Paxos > group > I1201 13:03:15.338803 30307 recover.cpp:462] Recover process terminated > I1201 13:03:15.339624 30307 log.cpp:659] Attempting to start the writer > I1201 13:03:15.342535 30316 replica.cpp:494] Replica received implicit > promise request from (1901)@172.17.21.0:52024 with proposal 1 > I1201 13:03:15.383368 30316 leveldb.cpp:304] Persisting metadata (8 bytes) to > leveldb took 40.616854ms > I1201 13:03:15.383433 30316 replica.cpp:343] Persisted promised to 1 > I1201 13:03:15.389814 30312 coordinator.cpp:238] Coordinator attempting to > fill missing positions > I1201 13:03:15.391582 30316 replica.cpp:389] Replica received explicit > promise request from (1902)@172.17.21.0:52024 for position 0 with proposal 2 > I1201 13:03:15.434260 30316 leveldb.cpp:341] Persisting action (8 bytes) to > leveldb took 42.530151ms > I1201 13:03:15.434340 30316 replica.cpp:713] Persisted action at 0 > I1201 13:03:15.438995 30315 replica.cpp:538] Replica received write request > for position 0 from (1903)@172.17.21.0:52024 > I1201 13:03:15.439116 30315 leveldb.cpp:436] Reading position from leveldb > took 52656ns > I1201 13:03:15.468266 30315 leveldb.cpp:341] Persisting action (14 bytes) to > leveldb took 29.058804ms > I1201 13:03:15.468354 30315 replica.cpp:713] Persisted action at 0 > I1201 13:03:15.469364 30308 replica.cpp:692] Replica received learned notice > for position 0 from @0.0.0.0:0 > I1201 13:03:15.500910 30308 leveldb.cpp:341] Persisting action (16 bytes) to > leveldb took 31.499794ms > I1201 13:03:15.500991 30308 replica.cpp:713] Persisted action at 0 > I1201 13:03:15.501029 30308 replica.cpp:698] Replica learned NOP action at > position 0 > I1201 13:03:15.502320 30308 log.cpp:675] Writer started with ending position 0 > I1201 13:03:15.503906 30308 leveldb.cpp:436] Reading position from leveldb > took 58333ns > I1201 13:03:15.505216 30321 registrar.cpp:340] Successfully fetched the > registry (0B) in 234.329856ms > I1201 13:03:15.505354 30321 registrar.cpp:439] Applied 1 operations in > 37858ns; attempting to update the 'registry' > I1201 13:03:15.506649 30321 log.cpp:683] Attempting to append 171 bytes to > the log > I1201 13:03:15.506898 30321 coordinator.cpp:348] Coordinator attempting to > write APPEND action at position 1 > I1201 13:03:15.508052 30308 replica.cpp:538] Replica received write request > for position 1 from (1904)@172.17.21.0:52024 > I1201 13:03:15.571291 30308 leveldb.cpp:341] Persisting action (190 bytes) to > leveldb took 63.17935ms > I1201 13:03:15.571372 30308 replica.cpp:713] Persisted action at 1 > I1201 13:03:15.572895 30308 replica.cpp:692] Replica received learned notice > for position 1 from @0.0.0.0:0 > I1201 13:03:15.605268 30308 leveldb.cpp:341] Persisting action (192 bytes) to > leveldb took 32.320829ms > I1201 13:03:15.605357 30308 replica.cpp:713] Persisted action at 1 > I1201 13:03:15.605394 30308 replica.cpp:698] Replica learned APPEND action at > position 1 > I1201 13:03:15.611315 30318 registrar.cpp:484] Successfully updated the > 'registry' in 105.864192ms > I1201 13:03:15.611776 30318 registrar.cpp:370] Successfully recovered > registrar > I1201 13:03:15.612607 30322 master.cpp:1447] Recovered 0 slaves from the > Registry (132B) ; allowing 10mins for slaves to re-register > I1201 13:03:15.613045 30322 hierarchical.cpp:174] Allocator recovery is not > supported yet > I1201 13:03:15.614012 30308 log.cpp:702] Attempting to truncate the log to 1 > I1201 13:03:15.614817 30307 coordinator.cpp:348] Coordinator attempting to > write TRUNCATE action at position 2 > I1201 13:03:15.616644 30307 replica.cpp:538] Replica received write request > for position 2 from (1905)@172.17.21.0:52024 > I1201 13:03:15.630637 30307 leveldb.cpp:341] Persisting action (16 bytes) to > leveldb took 13.701643ms > I1201 13:03:15.630728 30307 replica.cpp:713] Persisted action at 2 > I1201 13:03:15.632129 30307 replica.cpp:692] Replica received learned notice > for position 2 from @0.0.0.0:0 > I1201 13:03:15.677260 30307 leveldb.cpp:341] Persisting action (18 bytes) to > leveldb took 45.085356ms > I1201 13:03:15.677404 30307 leveldb.cpp:399] Deleting ~1 keys from leveldb > took 64881ns > I1201 13:03:15.677433 30307 replica.cpp:713] Persisted action at 2 > I1201 13:03:15.677469 30307 replica.cpp:698] Replica learned TRUNCATE action > at position 2 > I1201 13:03:15.680896 30288 containerizer.cpp:141] Using isolation: > posix/cpu,posix/mem,filesystem/posix > W1201 13:03:15.681568 30288 backend.cpp:48] Failed to create 'bind' backend: > BindBackend requires root privileges > I1201 13:03:15.717629 30317 slave.cpp:189] Slave started on > 61)@172.17.21.0:52024 > I1201 13:03:15.717674 30317 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/HealthCheckTest_CheckCommandTimeout_6kGYjg/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/HealthCheckTest_CheckCommandTimeout_6kGYjg/fetch" > --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" > --gc_disk_headroom="0.1" --hadoop_home="" --help="false" > --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/HealthCheckTest_CheckCommandTimeout_6kGYjg" > I1201 13:03:15.718204 30317 credentials.hpp:83] Loading credential for > authentication from > '/tmp/HealthCheckTest_CheckCommandTimeout_6kGYjg/credential' > I1201 13:03:15.718427 30317 slave.cpp:320] Slave using credential for: > test-principal > I1201 13:03:15.718590 30317 resources.cpp:478] Parsing resources as JSON > failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000] > Trying semicolon-delimited string format instead > I1201 13:03:15.719068 30317 slave.cpp:390] Slave resources: cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] > I1201 13:03:15.719142 30317 slave.cpp:398] Slave attributes: [ ] > I1201 13:03:15.719156 30317 slave.cpp:403] Slave hostname: fa812f474cf4 > I1201 13:03:15.719182 30317 slave.cpp:408] Slave checkpoint: true > I1201 13:03:15.720470 30308 state.cpp:52] Recovering state from > '/tmp/HealthCheckTest_CheckCommandTimeout_6kGYjg/meta' > I1201 13:03:15.721117 30319 status_update_manager.cpp:200] Recovering status > update manager > I1201 13:03:15.721451 30319 containerizer.cpp:383] Recovering containerizer > I1201 13:03:15.722421 30288 sched.cpp:164] Version: 0.27.0 > I1201 13:03:15.723305 30307 slave.cpp:4258] Finished recovery > I1201 13:03:15.723848 30307 slave.cpp:4430] Querying resource estimator for > oversubscribable resources > I1201 13:03:15.724340 30308 slave.cpp:727] New master detected at > master@172.17.21.0:52024 > I1201 13:03:15.724370 30311 status_update_manager.cpp:174] Pausing sending > status updates > I1201 13:03:15.724428 30308 slave.cpp:790] Authenticating with master > master@172.17.21.0:52024 > I1201 13:03:15.724447 30308 slave.cpp:795] Using default CRAM-MD5 > authenticatee > I1201 13:03:15.724616 30308 slave.cpp:763] Detecting new master > I1201 13:03:15.724714 30319 authenticatee.cpp:121] Creating new client SASL > connection > I1201 13:03:15.724731 30308 slave.cpp:4444] Received oversubscribable > resources from the resource estimator > I1201 13:03:15.724836 30308 sched.cpp:262] New master detected at > master@172.17.21.0:52024 > I1201 13:03:15.724911 30308 sched.cpp:318] Authenticating with master > master@172.17.21.0:52024 > I1201 13:03:15.724928 30308 sched.cpp:325] Using default CRAM-MD5 > authenticatee > I1201 13:03:15.725319 30308 authenticatee.cpp:121] Creating new client SASL > connection > I1201 13:03:15.725348 30319 master.cpp:5181] Authenticating > slave(61)@172.17.21.0:52024 > I1201 13:03:15.725872 30319 master.cpp:5181] Authenticating > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 > I1201 13:03:15.725978 30321 authenticator.cpp:413] Starting authentication > session for crammd5_authenticatee(169)@172.17.21.0:52024 > I1201 13:03:15.726480 30321 authenticator.cpp:413] Starting authentication > session for crammd5_authenticatee(170)@172.17.21.0:52024 > I1201 13:03:15.726966 30321 authenticator.cpp:98] Creating new server SASL > connection > I1201 13:03:15.726670 30316 authenticator.cpp:98] Creating new server SASL > connection > I1201 13:03:15.727452 30316 authenticatee.cpp:212] Received SASL > authentication mechanisms: CRAM-MD5 > I1201 13:03:15.727605 30316 authenticatee.cpp:238] Attempting to authenticate > with mechanism 'CRAM-MD5' > I1201 13:03:15.727756 30316 authenticator.cpp:203] Received SASL > authentication start > I1201 13:03:15.727913 30316 authenticator.cpp:325] Authentication requires > more steps > I1201 13:03:15.728073 30316 authenticatee.cpp:258] Received SASL > authentication step > I1201 13:03:15.728250 30316 authenticator.cpp:231] Received SASL > authentication step > I1201 13:03:15.728638 30316 auxprop.cpp:107] Request to lookup properties for > user: 'test-principal' realm: 'fa812f474cf4' server FQDN: 'fa812f474cf4' > SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false > SASL_AUXPROP_AUTHZID: false > I1201 13:03:15.728721 30316 auxprop.cpp:179] Looking up auxiliary property > '*userPassword' > I1201 13:03:15.728854 30316 auxprop.cpp:179] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I1201 13:03:15.728977 30316 auxprop.cpp:107] Request to lookup properties for > user: 'test-principal' realm: 'fa812f474cf4' server FQDN: 'fa812f474cf4' > SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false > SASL_AUXPROP_AUTHZID: true > I1201 13:03:15.729069 30316 auxprop.cpp:129] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I1201 13:03:15.729154 30316 auxprop.cpp:129] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I1201 13:03:15.729269 30316 authenticator.cpp:317] Authentication success > I1201 13:03:15.729555 30316 authenticatee.cpp:298] Authentication success > I1201 13:03:15.730110 30316 slave.cpp:858] Successfully authenticated with > master master@172.17.21.0:52024 > I1201 13:03:15.730420 30316 slave.cpp:1252] Will retry registration in > 9.588533ms if necessary > I1201 13:03:15.728505 30321 authenticatee.cpp:212] Received SASL > authentication mechanisms: CRAM-MD5 > I1201 13:03:15.730845 30321 authenticatee.cpp:238] Attempting to authenticate > with mechanism 'CRAM-MD5' > I1201 13:03:15.731009 30321 authenticator.cpp:203] Received SASL > authentication start > I1201 13:03:15.729656 30314 master.cpp:5211] Successfully authenticated > principal 'test-principal' at slave(61)@172.17.21.0:52024 > I1201 13:03:15.731493 30314 master.cpp:3890] Registering slave at > slave(61)@172.17.21.0:52024 (fa812f474cf4) with id > dd5bff66-362f-4efc-963a-54756b2edcce-S0 > I1201 13:03:15.729717 30311 authenticator.cpp:431] Authentication session > cleanup for crammd5_authenticatee(169)@172.17.21.0:52024 > I1201 13:03:15.732597 30314 registrar.cpp:439] Applied 1 operations in > 486128ns; attempting to update the 'registry' > I1201 13:03:15.733901 30311 log.cpp:683] Attempting to append 340 bytes to > the log > I1201 13:03:15.734225 30310 coordinator.cpp:348] Coordinator attempting to > write APPEND action at position 3 > I1201 13:03:15.735477 30318 replica.cpp:538] Replica received write request > for position 3 from (1917)@172.17.21.0:52024 > I1201 13:03:15.734043 30321 authenticator.cpp:325] Authentication requires > more steps > I1201 13:03:15.735970 30321 authenticatee.cpp:258] Received SASL > authentication step > I1201 13:03:15.736068 30321 authenticator.cpp:231] Received SASL > authentication step > I1201 13:03:15.736107 30321 auxprop.cpp:107] Request to lookup properties for > user: 'test-principal' realm: 'fa812f474cf4' server FQDN: 'fa812f474cf4' > SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false > SASL_AUXPROP_AUTHZID: false > I1201 13:03:15.736120 30321 auxprop.cpp:179] Looking up auxiliary property > '*userPassword' > I1201 13:03:15.736423 30321 auxprop.cpp:179] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I1201 13:03:15.736464 30321 auxprop.cpp:107] Request to lookup properties for > user: 'test-principal' realm: 'fa812f474cf4' server FQDN: 'fa812f474cf4' > SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false > SASL_AUXPROP_AUTHZID: true > I1201 13:03:15.736480 30321 auxprop.cpp:129] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I1201 13:03:15.736490 30321 auxprop.cpp:129] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I1201 13:03:15.736508 30321 authenticator.cpp:317] Authentication success > I1201 13:03:15.736748 30310 authenticatee.cpp:298] Authentication success > I1201 13:03:15.736846 30310 master.cpp:5211] Successfully authenticated > principal 'test-principal' at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 > I1201 13:03:15.737114 30310 sched.cpp:407] Successfully authenticated with > master master@172.17.21.0:52024 > I1201 13:03:15.737138 30310 sched.cpp:714] Sending SUBSCRIBE call to > master@172.17.21.0:52024 > I1201 13:03:15.737776 30310 sched.cpp:747] Will retry registration in > 175.278268ms if necessary > I1201 13:03:15.737962 30310 master.cpp:2207] Received SUBSCRIBE call for > framework 'default' at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 > I1201 13:03:15.738026 30310 master.cpp:1676] Authorizing framework principal > 'test-principal' to receive offers for role '*' > I1201 13:03:15.738289 30321 authenticator.cpp:431] Authentication session > cleanup for crammd5_authenticatee(170)@172.17.21.0:52024 > I1201 13:03:15.738601 30310 master.cpp:2278] Subscribing framework default > with checkpointing disabled and capabilities [ ] > I1201 13:03:15.739156 30310 hierarchical.cpp:220] Added framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:15.739486 30310 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:15.739528 30310 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:15.739559 30310 hierarchical.cpp:957] Performed allocation for 0 > slaves in 113362ns > I1201 13:03:15.739363 30321 sched.cpp:641] Framework registered with > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:15.739622 30321 sched.cpp:655] Scheduler::registered took 25557ns > I1201 13:03:15.741346 30312 master.cpp:3878] Ignoring register slave message > from slave(61)@172.17.21.0:52024 (fa812f474cf4) as admission is already in > progress > I1201 13:03:15.741147 30316 slave.cpp:1252] Will retry registration in > 9.901407ms if necessary > I1201 13:03:15.752579 30322 slave.cpp:1252] Will retry registration in > 54.177145ms if necessary > I1201 13:03:15.752959 30320 master.cpp:3878] Ignoring register slave message > from slave(61)@172.17.21.0:52024 (fa812f474cf4) as admission is already in > progress > I1201 13:03:15.756857 30318 leveldb.cpp:341] Persisting action (359 bytes) to > leveldb took 21.322978ms > I1201 13:03:15.757028 30318 replica.cpp:713] Persisted action at 3 > I1201 13:03:15.758445 30309 replica.cpp:692] Replica received learned notice > for position 3 from @0.0.0.0:0 > I1201 13:03:15.809561 30315 slave.cpp:1252] Will retry registration in > 90.392215ms if necessary > I1201 13:03:15.809877 30315 master.cpp:3878] Ignoring register slave message > from slave(61)@172.17.21.0:52024 (fa812f474cf4) as admission is already in > progress > I1201 13:03:15.811102 30309 leveldb.cpp:341] Persisting action (361 bytes) to > leveldb took 52.532272ms > I1201 13:03:15.811142 30309 replica.cpp:713] Persisted action at 3 > I1201 13:03:15.811187 30309 replica.cpp:698] Replica learned APPEND action at > position 3 > I1201 13:03:15.813498 30315 registrar.cpp:484] Successfully updated the > 'registry' in 80.742912ms > I1201 13:03:15.814883 30315 master.cpp:3958] Registered slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 at slave(61)@172.17.21.0:52024 > (fa812f474cf4) with cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000] > I1201 13:03:15.815547 30320 hierarchical.cpp:380] Added slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 (fa812f474cf4) with cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: ) > I1201 13:03:15.817054 30320 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:15.817100 30320 hierarchical.cpp:973] Performed allocation for > slave dd5bff66-362f-4efc-963a-54756b2edcce-S0 in 989520ns > I1201 13:03:15.815670 30318 slave.cpp:902] Registered with master > master@172.17.21.0:52024; given slave ID > dd5bff66-362f-4efc-963a-54756b2edcce-S0 > I1201 13:03:15.817320 30318 fetcher.cpp:79] Clearing fetcher cache > I1201 13:03:15.818097 30320 master.cpp:5010] Sending 1 offers to framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 > I1201 13:03:15.818240 30314 status_update_manager.cpp:181] Resuming sending > status updates > I1201 13:03:15.818553 30318 slave.cpp:925] Checkpointing SlaveInfo to > '/tmp/HealthCheckTest_CheckCommandTimeout_6kGYjg/meta/slaves/dd5bff66-362f-4efc-963a-54756b2edcce-S0/slave.info' > I1201 13:03:15.818996 30318 slave.cpp:961] Forwarding total oversubscribed > resources > I1201 13:03:15.819099 30318 slave.cpp:3197] Received ping from > slave-observer(58)@172.17.21.0:52024 > I1201 13:03:15.819594 30320 master.cpp:4300] Received update of slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 at slave(61)@172.17.21.0:52024 > (fa812f474cf4) with total oversubscribed resources > I1201 13:03:15.820132 30320 sched.cpp:811] Scheduler::resourceOffers took > 130339ns > I1201 13:03:15.820576 30314 hierarchical.cpp:434] Slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 (fa812f474cf4) updated with > oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000]) > I1201 13:03:15.821035 30314 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:15.821076 30314 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:15.821096 30314 hierarchical.cpp:973] Performed allocation for > slave dd5bff66-362f-4efc-963a-54756b2edcce-S0 in 469026ns > I1201 13:03:15.822010 30309 log.cpp:702] Attempting to truncate the log to 3 > I1201 13:03:15.822232 30318 coordinator.cpp:348] Coordinator attempting to > write TRUNCATE action at position 4 > I1201 13:03:15.823371 30310 replica.cpp:538] Replica received write request > for position 4 from (1918)@172.17.21.0:52024 > I1201 13:03:15.824892 30316 master.cpp:2946] Processing ACCEPT call for > offers: [ dd5bff66-362f-4efc-963a-54756b2edcce-O0 ] on slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 at slave(61)@172.17.21.0:52024 > (fa812f474cf4) for framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > (default) at scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 > I1201 13:03:15.824942 30316 master.cpp:2742] Authorizing framework principal > 'test-principal' to launch task 1 as user 'mesos' > I1201 13:03:15.826663 30316 master.hpp:176] Adding task 1 with resources > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 (fa812f474cf4) > I1201 13:03:15.826897 30316 master.cpp:3276] Launching task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 with > resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on > slave dd5bff66-362f-4efc-963a-54756b2edcce-S0 at slave(61)@172.17.21.0:52024 > (fa812f474cf4) > I1201 13:03:15.827376 30322 slave.cpp:1292] Got assigned task 1 for framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:15.827641 30322 resources.cpp:478] Parsing resources as JSON > failed: cpus:0.1;mem:32 > Trying semicolon-delimited string format instead > I1201 13:03:15.828306 30322 slave.cpp:1411] Launching task 1 for framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:15.828402 30322 resources.cpp:478] Parsing resources as JSON > failed: cpus:0.1;mem:32 > Trying semicolon-delimited string format instead > I1201 13:03:15.851069 30322 paths.cpp:434] Trying to chown > '/tmp/HealthCheckTest_CheckCommandTimeout_6kGYjg/slaves/dd5bff66-362f-4efc-963a-54756b2edcce-S0/frameworks/dd5bff66-362f-4efc-963a-54756b2edcce-0000/executors/1/runs/8d8aa0bb-fad5-4715-a14f-62783b07da81' > to user 'mesos' > I1201 13:03:15.856019 30310 leveldb.cpp:341] Persisting action (16 bytes) to > leveldb took 32.584609ms > I1201 13:03:15.856098 30310 replica.cpp:713] Persisted action at 4 > I1201 13:03:15.856991 30322 slave.cpp:5042] Launching executor 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 with resources cpus(*):0.1; > mem(*):32 in work directory > '/tmp/HealthCheckTest_CheckCommandTimeout_6kGYjg/slaves/dd5bff66-362f-4efc-963a-54756b2edcce-S0/frameworks/dd5bff66-362f-4efc-963a-54756b2edcce-0000/executors/1/runs/8d8aa0bb-fad5-4715-a14f-62783b07da81' > I1201 13:03:15.857708 30322 slave.cpp:1629] Queuing task '1' for executor '1' > of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:15.857856 30322 slave.cpp:680] Successfully attached file > '/tmp/HealthCheckTest_CheckCommandTimeout_6kGYjg/slaves/dd5bff66-362f-4efc-963a-54756b2edcce-S0/frameworks/dd5bff66-362f-4efc-963a-54756b2edcce-0000/executors/1/runs/8d8aa0bb-fad5-4715-a14f-62783b07da81' > I1201 13:03:15.857945 30322 replica.cpp:692] Replica received learned notice > for position 4 from @0.0.0.0:0 > I1201 13:03:15.857978 30310 containerizer.cpp:617] Starting container > '8d8aa0bb-fad5-4715-a14f-62783b07da81' for executor '1' of framework > 'dd5bff66-362f-4efc-963a-54756b2edcce-0000' > I1201 13:03:15.862118 30312 launcher.cpp:132] Forked child with pid '3131' > for container '8d8aa0bb-fad5-4715-a14f-62783b07da81' > I1201 13:03:15.891278 30322 leveldb.cpp:341] Persisting action (18 bytes) to > leveldb took 33.273317ms > I1201 13:03:15.891428 30322 leveldb.cpp:399] Deleting ~2 keys from leveldb > took 84833ns > I1201 13:03:15.891456 30322 replica.cpp:713] Persisted action at 4 > I1201 13:03:15.891494 30322 replica.cpp:698] Replica learned TRUNCATE action > at position 4 > I1201 13:03:16.100318 30322 slave.cpp:2406] Got registration for executor '1' > of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 from > executor(1)@172.17.21.0:58381 > I1201 13:03:16.104367 30317 slave.cpp:1794] Sending queued task '1' to > executor '1' of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 at > executor(1)@172.17.21.0:58381 > I1201 13:03:16.142390 30311 slave.cpp:2763] Handling status update > TASK_RUNNING (UUID: cfdb8408-a2e8-441b-836c-3368e93ac6e2) for task 1 of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 from > executor(1)@172.17.21.0:58381 > I1201 13:03:16.142907 30311 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: cfdb8408-a2e8-441b-836c-3368e93ac6e2) for task 1 > of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:16.142951 30311 status_update_manager.cpp:497] Creating > StatusUpdate stream for task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:16.143543 30311 status_update_manager.cpp:374] Forwarding update > TASK_RUNNING (UUID: cfdb8408-a2e8-441b-836c-3368e93ac6e2) for task 1 of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 to the slave > I1201 13:03:16.144052 30311 slave.cpp:3115] Forwarding the update > TASK_RUNNING (UUID: cfdb8408-a2e8-441b-836c-3368e93ac6e2) for task 1 of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 to > master@172.17.21.0:52024 > I1201 13:03:16.145408 30311 slave.cpp:3009] Status update manager > successfully handled status update TASK_RUNNING (UUID: > cfdb8408-a2e8-441b-836c-3368e93ac6e2) for task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:16.145467 30311 slave.cpp:3025] Sending acknowledgement for > status update TASK_RUNNING (UUID: cfdb8408-a2e8-441b-836c-3368e93ac6e2) for > task 1 of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 to > executor(1)@172.17.21.0:58381 > I1201 13:03:16.147138 30311 master.cpp:4445] Status update TASK_RUNNING > (UUID: cfdb8408-a2e8-441b-836c-3368e93ac6e2) for task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 from slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 at slave(61)@172.17.21.0:52024 > (fa812f474cf4) > I1201 13:03:16.147233 30311 master.cpp:4493] Forwarding status update > TASK_RUNNING (UUID: cfdb8408-a2e8-441b-836c-3368e93ac6e2) for task 1 of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:16.147439 30311 master.cpp:6097] Updating the state of task 1 of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 (latest state: > TASK_RUNNING, status update state: TASK_RUNNING) > I1201 13:03:16.147747 30311 sched.cpp:919] Scheduler::statusUpdate took > 122865ns > I1201 13:03:16.148129 30311 master.cpp:3602] Processing ACKNOWLEDGE call > cfdb8408-a2e8-441b-836c-3368e93ac6e2 for task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 on slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 > I1201 13:03:16.148674 30311 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: cfdb8408-a2e8-441b-836c-3368e93ac6e2) for task > 1 of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:16.149813 30320 slave.cpp:2346] Status update manager > successfully handled status update acknowledgement (UUID: > cfdb8408-a2e8-441b-836c-3368e93ac6e2) for task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:16.269222 30322 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:16.269312 30322 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:16.269347 30322 hierarchical.cpp:957] Performed allocation for 1 > slaves in 777937ns > I1201 13:03:17.270767 30322 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:17.270853 30322 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:17.270884 30322 hierarchical.cpp:957] Performed allocation for 1 > slaves in 793428ns > I1201 13:03:18.273021 30318 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:18.273107 30318 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:18.273138 30318 hierarchical.cpp:957] Performed allocation for 1 > slaves in 668062ns > I1201 13:03:19.274287 30321 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:19.274371 30321 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:19.274402 30321 hierarchical.cpp:957] Performed allocation for 1 > slaves in 705640ns > I1201 13:03:20.276296 30313 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:20.276381 30313 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:20.276412 30313 hierarchical.cpp:957] Performed allocation for 1 > slaves in 681486ns > I1201 13:03:21.277920 30320 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:21.278004 30320 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:21.278034 30320 hierarchical.cpp:957] Performed allocation for 1 > slaves in 673270ns > I1201 13:03:21.281448 30312 slave.cpp:2763] Handling status update > TASK_RUNNING (UUID: a820acb1-a9ed-46f5-83c2-1a6504f5c584) for task 1 in > health state unhealthy of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > from executor(1)@172.17.21.0:58381 > I1201 13:03:21.282423 30312 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: a820acb1-a9ed-46f5-83c2-1a6504f5c584) for task 1 > in health state unhealthy of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:21.283000 30312 status_update_manager.cpp:374] Forwarding update > TASK_RUNNING (UUID: a820acb1-a9ed-46f5-83c2-1a6504f5c584) for task 1 in > health state unhealthy of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > to the slave > I1201 13:03:21.283670 30312 slave.cpp:3115] Forwarding the update > TASK_RUNNING (UUID: a820acb1-a9ed-46f5-83c2-1a6504f5c584) for task 1 in > health state unhealthy of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > to master@172.17.21.0:52024 > I1201 13:03:21.284276 30312 slave.cpp:3009] Status update manager > successfully handled status update TASK_RUNNING (UUID: > a820acb1-a9ed-46f5-83c2-1a6504f5c584) for task 1 in health state unhealthy of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:21.284979 30312 slave.cpp:3025] Sending acknowledgement for > status update TASK_RUNNING (UUID: a820acb1-a9ed-46f5-83c2-1a6504f5c584) for > task 1 in health state unhealthy of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 to executor(1)@172.17.21.0:58381 > I1201 13:03:21.284695 30317 master.cpp:4445] Status update TASK_RUNNING > (UUID: a820acb1-a9ed-46f5-83c2-1a6504f5c584) for task 1 in health state > unhealthy of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 from slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 at slave(61)@172.17.21.0:52024 > (fa812f474cf4) > I1201 13:03:21.285204 30317 master.cpp:4493] Forwarding status update > TASK_RUNNING (UUID: a820acb1-a9ed-46f5-83c2-1a6504f5c584) for task 1 in > health state unhealthy of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:21.285403 30317 master.cpp:6097] Updating the state of task 1 of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 (latest state: > TASK_RUNNING, status update state: TASK_RUNNING) > I1201 13:03:21.285719 30317 sched.cpp:919] Scheduler::statusUpdate took > 124592ns > I1201 13:03:21.286097 30317 master.cpp:3602] Processing ACKNOWLEDGE call > a820acb1-a9ed-46f5-83c2-1a6504f5c584 for task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 on slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 > I1201 13:03:21.287281 30317 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: a820acb1-a9ed-46f5-83c2-1a6504f5c584) for task > 1 of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:21.287904 30322 slave.cpp:2346] Status update manager > successfully handled status update acknowledgement (UUID: > a820acb1-a9ed-46f5-83c2-1a6504f5c584) for task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:22.279230 30311 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:22.279326 30311 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:22.279361 30311 hierarchical.cpp:957] Performed allocation for 1 > slaves in 718578ns > I1201 13:03:23.281947 30309 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:23.282080 30309 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:23.282142 30309 hierarchical.cpp:957] Performed allocation for 1 > slaves in 830902ns > I1201 13:03:24.283694 30316 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:24.283906 30316 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:24.284049 30316 hierarchical.cpp:957] Performed allocation for 1 > slaves in 980771ns > I1201 13:03:25.285796 30310 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:25.285877 30310 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:25.285908 30310 hierarchical.cpp:957] Performed allocation for 1 > slaves in 671191ns > I1201 13:03:26.287158 30314 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:26.287240 30314 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:26.287271 30314 hierarchical.cpp:957] Performed allocation for 1 > slaves in 650436ns > I1201 13:03:26.292038 30316 slave.cpp:2763] Handling status update > TASK_RUNNING (UUID: 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd) for task 1 in > health state unhealthy of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > from executor(1)@172.17.21.0:58381 > I1201 13:03:26.292533 30316 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd) for task 1 > in health state unhealthy of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:26.292721 30316 status_update_manager.cpp:374] Forwarding update > TASK_RUNNING (UUID: 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd) for task 1 in > health state unhealthy of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > to the slave > I1201 13:03:26.293148 30316 slave.cpp:3115] Forwarding the update > TASK_RUNNING (UUID: 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd) for task 1 in > health state unhealthy of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > to master@172.17.21.0:52024 > I1201 13:03:26.293442 30316 slave.cpp:3009] Status update manager > successfully handled status update TASK_RUNNING (UUID: > 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd) for task 1 in health state unhealthy of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:26.293485 30316 slave.cpp:3025] Sending acknowledgement for > status update TASK_RUNNING (UUID: 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd) for > task 1 in health state unhealthy of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 to executor(1)@172.17.21.0:58381 > I1201 13:03:26.294077 30316 master.cpp:4445] Status update TASK_RUNNING > (UUID: 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd) for task 1 in health state > unhealthy of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 from slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 at slave(61)@172.17.21.0:52024 > (fa812f474cf4) > I1201 13:03:26.294124 30316 master.cpp:4493] Forwarding status update > TASK_RUNNING (UUID: 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd) for task 1 in > health state unhealthy of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:26.294373 30316 master.cpp:6097] Updating the state of task 1 of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 (latest state: > TASK_RUNNING, status update state: TASK_RUNNING) > I1201 13:03:26.294651 30316 sched.cpp:919] Scheduler::statusUpdate took > 114245ns > I1201 13:03:26.295001 30316 master.cpp:3602] Processing ACKNOWLEDGE call > 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd for task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 on slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 > I1201 13:03:26.295910 30318 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd) for task > 1 of framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:26.296237 30322 slave.cpp:2346] Status update manager > successfully handled status update acknowledgement (UUID: > 7b7c6e1a-d3b1-4b7c-8113-f9eeb6d7e5dd) for task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:27.289466 30316 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:27.289551 30316 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:27.289582 30316 hierarchical.cpp:957] Performed allocation for 1 > slaves in 692419ns > I1201 13:03:28.291142 30312 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:28.291239 30312 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:28.291270 30312 hierarchical.cpp:957] Performed allocation for 1 > slaves in 659702ns > I1201 13:03:29.293304 30312 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:29.293390 30312 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:29.293421 30312 hierarchical.cpp:957] Performed allocation for 1 > slaves in 665396ns > I1201 13:03:30.294711 30320 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:30.294805 30320 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:30.294842 30320 hierarchical.cpp:957] Performed allocation for 1 > slaves in 710415ns > I1201 13:03:30.725651 30322 slave.cpp:4430] Querying resource estimator for > oversubscribable resources > I1201 13:03:30.725958 30322 slave.cpp:4444] Received oversubscribable > resources from the resource estimator > I1201 13:03:30.817693 30312 slave.cpp:3197] Received ping from > slave-observer(58)@172.17.21.0:52024 > I1201 13:03:31.296576 30316 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:31.296658 30316 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:31.296687 30316 hierarchical.cpp:957] Performed allocation for 1 > slaves in 652455ns > I1201 13:03:32.298235 30314 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:32.298336 30314 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:32.298370 30314 hierarchical.cpp:957] Performed allocation for 1 > slaves in 729548ns > I1201 13:03:33.301245 30308 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:33.301337 30308 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:33.301372 30308 hierarchical.cpp:957] Performed allocation for 1 > slaves in 745296ns > I1201 13:03:34.303215 30311 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:34.303298 30311 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:34.303329 30311 hierarchical.cpp:957] Performed allocation for 1 > slaves in 652065ns > I1201 13:03:35.304294 30315 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:35.304369 30315 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:35.304400 30315 hierarchical.cpp:957] Performed allocation for 1 > slaves in 652578ns > I1201 13:03:36.305637 30310 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:36.305721 30310 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:36.305757 30310 hierarchical.cpp:957] Performed allocation for 1 > slaves in 571872ns > I1201 13:03:37.307134 30311 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:37.307222 30311 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:37.307257 30311 hierarchical.cpp:957] Performed allocation for 1 > slaves in 685927ns > I1201 13:03:38.310041 30315 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:38.310129 30315 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:38.310173 30315 hierarchical.cpp:957] Performed allocation for 1 > slaves in 668279ns > I1201 13:03:39.311493 30312 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:39.311586 30312 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:39.311621 30312 hierarchical.cpp:957] Performed allocation for 1 > slaves in 728179ns > I1201 13:03:40.312849 30319 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:40.312922 30319 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:40.312954 30319 hierarchical.cpp:957] Performed allocation for 1 > slaves in 637308ns > ../../src/tests/health_check_tests.cpp:919: Failure > Failed to wait 15secs for status3 > ../../src/tests/health_check_tests.cpp:899: Failure > Actual function call count doesn't match EXPECT_CALL(sched, > statusUpdate(&driver, _))... > Expected: to be called 5 times > Actual: called 3 times - unsatisfied and active > I1201 13:03:41.312536 30309 master.cpp:1138] Framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 disconnected > I1201 13:03:41.312664 30309 master.cpp:2503] Disconnecting framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 > I1201 13:03:41.312759 30309 master.cpp:2527] Deactivating framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 > I1201 13:03:41.312952 30309 master.cpp:1162] Giving framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 0ns to > failover > I1201 13:03:41.313508 30316 hierarchical.cpp:303] Deactivated framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:41.314739 30316 hierarchical.cpp:1062] No resources available to > allocate! > I1201 13:03:41.314862 30316 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 13:03:41.314971 30316 hierarchical.cpp:957] Performed allocation for 1 > slaves in 619616ns > I1201 13:03:41.314245 30320 master.cpp:4858] Framework failover timeout, > removing framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 > I1201 13:03:41.315183 30320 master.cpp:5590] Removing framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 (default) at > scheduler-05ae72c3-af75-4cab-b2df-764ef7c26d35@172.17.21.0:52024 > I1201 13:03:41.315469 30320 master.cpp:6097] Updating the state of task 1 of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 (latest state: > TASK_KILLED, status update state: TASK_KILLED) > I1201 13:03:41.315685 30318 slave.cpp:2010] Asked to shut down framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 by master@172.17.21.0:52024 > I1201 13:03:41.316105 30320 master.cpp:6163] Removing task 1 with resources > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 on slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 at slave(61)@172.17.21.0:52024 > (fa812f474cf4) > I1201 13:03:41.316380 30314 hierarchical.cpp:791] Recovered cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: ) on slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 from framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:41.316309 30318 slave.cpp:2035] Shutting down framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:41.316668 30318 slave.cpp:3891] Shutting down executor '1' of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 at > executor(1)@172.17.21.0:58381 > I1201 13:03:41.317257 30319 hierarchical.cpp:260] Removed framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:41.316704 30320 master.cpp:938] Master terminating > I1201 13:03:41.318066 30312 hierarchical.cpp:410] Removed slave > dd5bff66-362f-4efc-963a-54756b2edcce-S0 > I1201 13:03:41.318724 30320 slave.cpp:3243] master@172.17.21.0:52024 exited > W1201 13:03:41.318749 30320 slave.cpp:3246] Master disconnected! Waiting for > a new master to be elected > I1201 13:03:41.324950 30308 containerizer.cpp:1073] Destroying container > '8d8aa0bb-fad5-4715-a14f-62783b07da81' > I1201 13:03:41.425364 30310 containerizer.cpp:1256] Executor for container > '8d8aa0bb-fad5-4715-a14f-62783b07da81' has exited > I1201 13:03:41.427952 30312 slave.cpp:3581] Executor '1' of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 terminated with signal Killed > I1201 13:03:41.428019 30312 slave.cpp:3685] Cleaning up executor '1' of > framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 at > executor(1)@172.17.21.0:58381 > I1201 13:03:41.428724 30312 slave.cpp:3773] Cleaning up framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:41.428715 30307 gc.cpp:54] Scheduling > '/tmp/HealthCheckTest_CheckCommandTimeout_6kGYjg/slaves/dd5bff66-362f-4efc-963a-54756b2edcce-S0/frameworks/dd5bff66-362f-4efc-963a-54756b2edcce-0000/executors/1/runs/8d8aa0bb-fad5-4715-a14f-62783b07da81' > for gc 6.99999504180444days in the future > I1201 13:03:41.428894 30307 gc.cpp:54] Scheduling > '/tmp/HealthCheckTest_CheckCommandTimeout_6kGYjg/slaves/dd5bff66-362f-4efc-963a-54756b2edcce-S0/frameworks/dd5bff66-362f-4efc-963a-54756b2edcce-0000/executors/1' > for gc 6.99999503861037days in the future > I1201 13:03:41.428920 30312 status_update_manager.cpp:282] Closing status > update streams for framework dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:41.428980 30312 status_update_manager.cpp:528] Cleaning up status > update stream for task 1 of framework > dd5bff66-362f-4efc-963a-54756b2edcce-0000 > I1201 13:03:41.429021 30307 gc.cpp:54] Scheduling > '/tmp/HealthCheckTest_CheckCommandTimeout_6kGYjg/slaves/dd5bff66-362f-4efc-963a-54756b2edcce-S0/frameworks/dd5bff66-362f-4efc-963a-54756b2edcce-0000' > for gc 6.99999503674963days in the future > I1201 13:03:41.429925 30315 slave.cpp:599] Slave terminating > [ FAILED ] HealthCheckTest.CheckCommandTimeout (26359 ms) > {noformat} > {noformat: title=Good Run} > [ RUN ] HealthCheckTest.CheckCommandTimeout > I1201 14:14:26.562675 30295 leveldb.cpp:174] Opened db in 128.451766ms > I1201 14:14:26.589201 30295 leveldb.cpp:181] Compacted db in 26.446367ms > I1201 14:14:26.589298 30295 leveldb.cpp:196] Created db iterator in 27631ns > I1201 14:14:26.589318 30295 leveldb.cpp:202] Seeked to beginning of db in > 3097ns > I1201 14:14:26.589329 30295 leveldb.cpp:271] Iterated through 0 keys in the > db in 210ns > I1201 14:14:26.589382 30295 replica.cpp:778] Replica recovered with log > positions 0 -> 0 with 1 holes and 0 unlearned > I1201 14:14:26.590701 30321 recover.cpp:447] Starting replica recovery > I1201 14:14:26.591117 30321 recover.cpp:473] Replica is in EMPTY status > I1201 14:14:26.592706 30317 replica.cpp:674] Replica in EMPTY status received > a broadcasted recover request from (1903)@172.17.21.7:43732 > I1201 14:14:26.593225 30328 recover.cpp:193] Received a recover response from > a replica in EMPTY status > I1201 14:14:26.593907 30328 recover.cpp:564] Updating replica status to > STARTING > I1201 14:14:26.604007 30316 master.cpp:365] Master > 587d1fd5-db6b-4af4-9267-ce84ac458470 (ca6f16e00db6) started on > 172.17.21.7:43732 > I1201 14:14:26.604156 30316 master.cpp:367] Flags at startup: --acls="" > --allocation_interval="1secs" --allocator="HierarchicalDRF" > --authenticate="true" --authenticate_slaves="true" --authenticators="crammd5" > --authorizers="local" --credentials="/tmp/9rplBs/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/9rplBs/master" --zk_session_timeout="10secs" > I1201 14:14:26.604524 30316 master.cpp:412] Master only allowing > authenticated frameworks to register > I1201 14:14:26.604540 30316 master.cpp:417] Master only allowing > authenticated slaves to register > I1201 14:14:26.604550 30316 credentials.hpp:35] Loading credentials for > authentication from '/tmp/9rplBs/credentials' > I1201 14:14:26.613284 30316 master.cpp:456] Using default 'crammd5' > authenticator > I1201 14:14:26.613517 30316 master.cpp:493] Authorization enabled > I1201 14:14:26.614346 30324 hierarchical.cpp:162] Initialized hierarchical > allocator process > I1201 14:14:26.614435 30324 whitelist_watcher.cpp:77] No whitelist given > I1201 14:14:26.616992 30316 master.cpp:1637] The newly elected leader is > master@172.17.21.7:43732 with id 587d1fd5-db6b-4af4-9267-ce84ac458470 > I1201 14:14:26.617038 30316 master.cpp:1650] Elected as the leading master! > I1201 14:14:26.617058 30316 master.cpp:1395] Recovering from registrar > I1201 14:14:26.617224 30324 registrar.cpp:307] Recovering registrar > I1201 14:14:26.621055 30319 leveldb.cpp:304] Persisting metadata (8 bytes) to > leveldb took 26.839241ms > I1201 14:14:26.621105 30319 replica.cpp:321] Persisted replica status to > STARTING > I1201 14:14:26.621538 30319 recover.cpp:473] Replica is in STARTING status > I1201 14:14:26.623247 30315 replica.cpp:674] Replica in STARTING status > received a broadcasted recover request from (1904)@172.17.21.7:43732 > I1201 14:14:26.623631 30315 recover.cpp:193] Received a recover response from > a replica in STARTING status > I1201 14:14:26.624241 30322 recover.cpp:564] Updating replica status to VOTING > I1201 14:14:26.657734 30315 leveldb.cpp:304] Persisting metadata (8 bytes) to > leveldb took 33.355865ms > I1201 14:14:26.657809 30315 replica.cpp:321] Persisted replica status to > VOTING > I1201 14:14:26.658102 30315 recover.cpp:578] Successfully joined the Paxos > group > I1201 14:14:26.658396 30315 recover.cpp:462] Recover process terminated > I1201 14:14:26.659047 30315 log.cpp:659] Attempting to start the writer > I1201 14:14:26.660820 30323 replica.cpp:494] Replica received implicit > promise request from (1905)@172.17.21.7:43732 with proposal 1 > I1201 14:14:26.724722 30323 leveldb.cpp:304] Persisting metadata (8 bytes) to > leveldb took 63.712877ms > I1201 14:14:26.725214 30323 replica.cpp:343] Persisted promised to 1 > I1201 14:14:26.726558 30322 coordinator.cpp:238] Coordinator attempting to > fill missing positions > I1201 14:14:26.728757 30316 replica.cpp:389] Replica received explicit > promise request from (1906)@172.17.21.7:43732 for position 0 with proposal 2 > I1201 14:14:26.783602 30316 leveldb.cpp:341] Persisting action (8 bytes) to > leveldb took 54.554561ms > I1201 14:14:26.783695 30316 replica.cpp:713] Persisted action at 0 > I1201 14:14:26.785193 30321 replica.cpp:538] Replica received write request > for position 0 from (1907)@172.17.21.7:43732 > I1201 14:14:26.785289 30321 leveldb.cpp:436] Reading position from leveldb > took 49720ns > I1201 14:14:26.830451 30321 leveldb.cpp:341] Persisting action (14 bytes) to > leveldb took 45.082632ms > I1201 14:14:26.830551 30321 replica.cpp:713] Persisted action at 0 > I1201 14:14:26.831938 30317 replica.cpp:692] Replica received learned notice > for position 0 from @0.0.0.0:0 > I1201 14:14:26.881292 30317 leveldb.cpp:341] Persisting action (16 bytes) to > leveldb took 49.170442ms > I1201 14:14:26.881369 30317 replica.cpp:713] Persisted action at 0 > I1201 14:14:26.881402 30317 replica.cpp:698] Replica learned NOP action at > position 0 > I1201 14:14:26.882609 30323 log.cpp:675] Writer started with ending position 0 > I1201 14:14:26.884533 30324 leveldb.cpp:436] Reading position from leveldb > took 76333ns > I1201 14:14:26.886106 30324 registrar.cpp:340] Successfully fetched the > registry (0B) in 268.833024ms > I1201 14:14:26.886435 30324 registrar.cpp:439] Applied 1 operations in > 42802ns; attempting to update the 'registry' > I1201 14:14:26.888010 30318 log.cpp:683] Attempting to append 173 bytes to > the log > I1201 14:14:26.888236 30326 coordinator.cpp:348] Coordinator attempting to > write APPEND action at position 1 > I1201 14:14:26.890637 30328 replica.cpp:538] Replica received write request > for position 1 from (1908)@172.17.21.7:43732 > I1201 14:14:26.921727 30328 leveldb.cpp:341] Persisting action (192 bytes) to > leveldb took 30.998029ms > I1201 14:14:26.922299 30328 replica.cpp:713] Persisted action at 1 > I1201 14:14:26.924146 30315 replica.cpp:692] Replica received learned notice > for position 1 from @0.0.0.0:0 > I1201 14:14:26.956274 30315 leveldb.cpp:341] Persisting action (194 bytes) to > leveldb took 31.633545ms > I1201 14:14:26.956370 30315 replica.cpp:713] Persisted action at 1 > I1201 14:14:26.956411 30315 replica.cpp:698] Replica learned APPEND action at > position 1 > I1201 14:14:26.958438 30317 registrar.cpp:484] Successfully updated the > 'registry' in 71.918848ms > I1201 14:14:26.958627 30317 registrar.cpp:370] Successfully recovered > registrar > I1201 14:14:26.959338 30320 hierarchical.cpp:174] Allocator recovery is not > supported yet > I1201 14:14:26.959838 30323 log.cpp:702] Attempting to truncate the log to 1 > I1201 14:14:26.960106 30323 coordinator.cpp:348] Coordinator attempting to > write TRUNCATE action at position 2 > I1201 14:14:26.959147 30317 master.cpp:1447] Recovered 0 slaves from the > Registry (134B) ; allowing 10mins for slaves to re-register > I1201 14:14:26.961684 30323 replica.cpp:538] Replica received write request > for position 2 from (1909)@172.17.21.7:43732 > I1201 14:14:27.055438 30323 leveldb.cpp:341] Persisting action (16 bytes) to > leveldb took 93.663564ms > I1201 14:14:27.055536 30323 replica.cpp:713] Persisted action at 2 > I1201 14:14:27.056959 30320 replica.cpp:692] Replica received learned notice > for position 2 from @0.0.0.0:0 > I1201 14:14:27.118288 30320 leveldb.cpp:341] Persisting action (18 bytes) to > leveldb took 60.990962ms > I1201 14:14:27.118451 30320 leveldb.cpp:399] Deleting ~1 keys from leveldb > took 77007ns > I1201 14:14:27.118479 30320 replica.cpp:713] Persisted action at 2 > I1201 14:14:27.118516 30320 replica.cpp:698] Replica learned TRUNCATE action > at position 2 > I1201 14:14:27.131505 30295 containerizer.cpp:141] Using isolation: > posix/cpu,posix/mem,filesystem/posix > W1201 14:14:27.131902 30295 backend.cpp:48] Failed to create 'bind' backend: > BindBackend requires root privileges > I1201 14:14:27.143996 30327 slave.cpp:189] Slave started on > 61)@172.17.21.7:43732 > I1201 14:14:27.144155 30327 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/HealthCheckTest_CheckCommandTimeout_DODrUR/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/HealthCheckTest_CheckCommandTimeout_DODrUR/fetch" > --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" > --gc_disk_headroom="0.1" --hadoop_home="" --help="false" > --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/HealthCheckTest_CheckCommandTimeout_DODrUR" > I1201 14:14:27.144866 30327 credentials.hpp:83] Loading credential for > authentication from > '/tmp/HealthCheckTest_CheckCommandTimeout_DODrUR/credential' > I1201 14:14:27.145210 30327 slave.cpp:320] Slave using credential for: > test-principal > I1201 14:14:27.145454 30327 resources.cpp:478] Parsing resources as JSON > failed: cpus:2;mem:1024;disk:1024;ports:[31000-32000] > Trying semicolon-delimited string format instead > I1201 14:14:27.146003 30327 slave.cpp:390] Slave resources: cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] > I1201 14:14:27.146389 30327 slave.cpp:398] Slave attributes: [ ] > I1201 14:14:27.146450 30327 slave.cpp:403] Slave hostname: ca6f16e00db6 > I1201 14:14:27.146512 30327 slave.cpp:408] Slave checkpoint: true > I1201 14:14:27.148231 30326 state.cpp:52] Recovering state from > '/tmp/HealthCheckTest_CheckCommandTimeout_DODrUR/meta' > I1201 14:14:27.153398 30295 sched.cpp:164] Version: 0.27.0 > I1201 14:14:27.153487 30327 status_update_manager.cpp:200] Recovering status > update manager > I1201 14:14:27.154454 30327 containerizer.cpp:383] Recovering containerizer > I1201 14:14:27.155915 30321 slave.cpp:4258] Finished recovery > I1201 14:14:27.156283 30315 sched.cpp:262] New master detected at > master@172.17.21.7:43732 > I1201 14:14:27.156508 30315 sched.cpp:318] Authenticating with master > master@172.17.21.7:43732 > I1201 14:14:27.156584 30315 sched.cpp:325] Using default CRAM-MD5 > authenticatee > I1201 14:14:27.157011 30315 authenticatee.cpp:121] Creating new client SASL > connection > I1201 14:14:27.157587 30325 master.cpp:5181] Authenticating > scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 > I1201 14:14:27.157835 30325 authenticator.cpp:413] Starting authentication > session for crammd5_authenticatee(168)@172.17.21.7:43732 > I1201 14:14:27.158241 30325 authenticator.cpp:98] Creating new server SASL > connection > I1201 14:14:27.158654 30315 authenticatee.cpp:212] Received SASL > authentication mechanisms: CRAM-MD5 > I1201 14:14:27.158753 30315 authenticatee.cpp:238] Attempting to authenticate > with mechanism 'CRAM-MD5' > I1201 14:14:27.158895 30315 authenticator.cpp:203] Received SASL > authentication start > I1201 14:14:27.159062 30315 authenticator.cpp:325] Authentication requires > more steps > I1201 14:14:27.159219 30325 authenticatee.cpp:258] Received SASL > authentication step > I1201 14:14:27.159415 30315 authenticator.cpp:231] Received SASL > authentication step > I1201 14:14:27.159498 30315 auxprop.cpp:107] Request to lookup properties for > user: 'test-principal' realm: 'ca6f16e00db6' server FQDN: 'ca6f16e00db6' > SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false > SASL_AUXPROP_AUTHZID: false > I1201 14:14:27.159566 30315 auxprop.cpp:179] Looking up auxiliary property > '*userPassword' > I1201 14:14:27.159669 30315 auxprop.cpp:179] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I1201 14:14:27.159757 30315 auxprop.cpp:107] Request to lookup properties for > user: 'test-principal' realm: 'ca6f16e00db6' server FQDN: 'ca6f16e00db6' > SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false > SASL_AUXPROP_AUTHZID: true > I1201 14:14:27.159826 30315 auxprop.cpp:129] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I1201 14:14:27.159883 30315 auxprop.cpp:129] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I1201 14:14:27.159953 30315 authenticator.cpp:317] Authentication success > I1201 14:14:27.160225 30318 master.cpp:5211] Successfully authenticated > principal 'test-principal' at > scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 > I1201 14:14:27.160372 30318 authenticator.cpp:431] Authentication session > cleanup for crammd5_authenticatee(168)@172.17.21.7:43732 > I1201 14:14:27.160688 30315 authenticatee.cpp:298] Authentication success > I1201 14:14:27.161622 30315 sched.cpp:407] Successfully authenticated with > master master@172.17.21.7:43732 > I1201 14:14:27.162294 30315 sched.cpp:714] Sending SUBSCRIBE call to > master@172.17.21.7:43732 > I1201 14:14:27.162508 30315 sched.cpp:747] Will retry registration in > 1.129902694secs if necessary > I1201 14:14:27.162696 30318 master.cpp:2207] Received SUBSCRIBE call for > framework 'default' at > scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 > I1201 14:14:27.163007 30318 master.cpp:1676] Authorizing framework principal > 'test-principal' to receive offers for role '*' > I1201 14:14:27.161137 30321 slave.cpp:4430] Querying resource estimator for > oversubscribable resources > I1201 14:14:27.164012 30321 slave.cpp:727] New master detected at > master@172.17.21.7:43732 > I1201 14:14:27.164070 30328 status_update_manager.cpp:174] Pausing sending > status updates > I1201 14:14:27.164103 30321 slave.cpp:790] Authenticating with master > master@172.17.21.7:43732 > I1201 14:14:27.164119 30321 slave.cpp:795] Using default CRAM-MD5 > authenticatee > I1201 14:14:27.164353 30321 slave.cpp:763] Detecting new master > I1201 14:14:27.164423 30317 authenticatee.cpp:121] Creating new client SASL > connection > I1201 14:14:27.164472 30321 slave.cpp:4444] Received oversubscribable > resources from the resource estimator > I1201 14:14:27.164697 30318 master.cpp:5181] Authenticating > slave(61)@172.17.21.7:43732 > I1201 14:14:27.165030 30328 authenticator.cpp:413] Starting authentication > session for crammd5_authenticatee(169)@172.17.21.7:43732 > I1201 14:14:27.165266 30324 authenticator.cpp:98] Creating new server SASL > connection > I1201 14:14:27.165489 30321 authenticatee.cpp:212] Received SASL > authentication mechanisms: CRAM-MD5 > I1201 14:14:27.165514 30321 authenticatee.cpp:238] Attempting to authenticate > with mechanism 'CRAM-MD5' > I1201 14:14:27.165596 30321 authenticator.cpp:203] Received SASL > authentication start > I1201 14:14:27.166223 30321 authenticator.cpp:325] Authentication requires > more steps > I1201 14:14:27.166311 30321 authenticatee.cpp:258] Received SASL > authentication step > I1201 14:14:27.166394 30321 authenticator.cpp:231] Received SASL > authentication step > I1201 14:14:27.166424 30321 auxprop.cpp:107] Request to lookup properties for > user: 'test-principal' realm: 'ca6f16e00db6' server FQDN: 'ca6f16e00db6' > SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false > SASL_AUXPROP_AUTHZID: false > I1201 14:14:27.166435 30321 auxprop.cpp:179] Looking up auxiliary property > '*userPassword' > I1201 14:14:27.166481 30321 auxprop.cpp:179] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I1201 14:14:27.166504 30321 auxprop.cpp:107] Request to lookup properties for > user: 'test-principal' realm: 'ca6f16e00db6' server FQDN: 'ca6f16e00db6' > SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false > SASL_AUXPROP_AUTHZID: true > I1201 14:14:27.166514 30321 auxprop.cpp:129] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I1201 14:14:27.166522 30321 auxprop.cpp:129] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I1201 14:14:27.166538 30321 authenticator.cpp:317] Authentication success > I1201 14:14:27.166679 30321 authenticatee.cpp:298] Authentication success > I1201 14:14:27.166760 30321 master.cpp:5211] Successfully authenticated > principal 'test-principal' at slave(61)@172.17.21.7:43732 > I1201 14:14:27.166833 30321 authenticator.cpp:431] Authentication session > cleanup for crammd5_authenticatee(169)@172.17.21.7:43732 > I1201 14:14:27.167089 30321 slave.cpp:858] Successfully authenticated with > master master@172.17.21.7:43732 > I1201 14:14:27.167477 30322 master.cpp:3890] Registering slave at > slave(61)@172.17.21.7:43732 (ca6f16e00db6) with id > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 > I1201 14:14:27.167721 30321 slave.cpp:1252] Will retry registration in > 2.161007ms if necessary > I1201 14:14:27.168022 30316 registrar.cpp:439] Applied 1 operations in > 80369ns; attempting to update the 'registry' > I1201 14:14:27.168381 30323 master.cpp:2278] Subscribing framework default > with checkpointing disabled and capabilities [ ] > I1201 14:14:27.169057 30316 hierarchical.cpp:220] Added framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.169118 30316 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:27.169164 30316 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:27.169214 30316 hierarchical.cpp:957] Performed allocation for 0 > slaves in 129635ns > I1201 14:14:27.169347 30321 sched.cpp:641] Framework registered with > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.169394 30321 sched.cpp:655] Scheduler::registered took 23910ns > I1201 14:14:27.169589 30322 log.cpp:683] Attempting to append 342 bytes to > the log > I1201 14:14:27.170240 30319 coordinator.cpp:348] Coordinator attempting to > write APPEND action at position 3 > I1201 14:14:27.170464 30329 slave.cpp:1252] Will retry registration in > 33.87185ms if necessary > I1201 14:14:27.170650 30319 master.cpp:3878] Ignoring register slave message > from slave(61)@172.17.21.7:43732 (ca6f16e00db6) as admission is already in > progress > I1201 14:14:27.171053 30322 replica.cpp:538] Replica received write request > for position 3 from (1921)@172.17.21.7:43732 > I1201 14:14:27.185808 30322 leveldb.cpp:341] Persisting action (361 bytes) to > leveldb took 14.695502ms > I1201 14:14:27.185899 30322 replica.cpp:713] Persisted action at 3 > I1201 14:14:27.187346 30314 replica.cpp:692] Replica received learned notice > for position 3 from @0.0.0.0:0 > I1201 14:14:27.206691 30322 slave.cpp:1252] Will retry registration in > 21.161456ms if necessary > I1201 14:14:27.207093 30322 master.cpp:3878] Ignoring register slave message > from slave(61)@172.17.21.7:43732 (ca6f16e00db6) as admission is already in > progress > I1201 14:14:27.215098 30314 leveldb.cpp:341] Persisting action (363 bytes) to > leveldb took 27.696174ms > I1201 14:14:27.215196 30314 replica.cpp:713] Persisted action at 3 > I1201 14:14:27.215239 30314 replica.cpp:698] Replica learned APPEND action at > position 3 > I1201 14:14:27.218340 30314 registrar.cpp:484] Successfully updated the > 'registry' in 50.230016ms > I1201 14:14:27.218909 30314 log.cpp:702] Attempting to truncate the log to 3 > I1201 14:14:27.220247 30322 coordinator.cpp:348] Coordinator attempting to > write TRUNCATE action at position 4 > I1201 14:14:27.220552 30328 hierarchical.cpp:380] Added slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 (ca6f16e00db6) with cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: ) > I1201 14:14:27.220841 30322 slave.cpp:902] Registered with master > master@172.17.21.7:43732; given slave ID > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 > I1201 14:14:27.220865 30322 fetcher.cpp:79] Clearing fetcher cache > I1201 14:14:27.220121 30314 master.cpp:3958] Registered slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 at slave(61)@172.17.21.7:43732 > (ca6f16e00db6) with cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000] > I1201 14:14:27.221568 30328 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:27.221766 30322 slave.cpp:925] Checkpointing SlaveInfo to > '/tmp/HealthCheckTest_CheckCommandTimeout_DODrUR/meta/slaves/587d1fd5-db6b-4af4-9267-ce84ac458470-S0/slave.info' > I1201 14:14:27.221575 30314 status_update_manager.cpp:181] Resuming sending > status updates > I1201 14:14:27.221885 30328 hierarchical.cpp:973] Performed allocation for > slave 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 in 1.185334ms > I1201 14:14:27.222190 30317 master.cpp:5010] Sending 1 offers to framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (default) at > scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 > I1201 14:14:27.222575 30322 slave.cpp:961] Forwarding total oversubscribed > resources > I1201 14:14:27.222957 30317 sched.cpp:811] Scheduler::resourceOffers took > 146960ns > I1201 14:14:27.223748 30319 replica.cpp:538] Replica received write request > for position 4 from (1922)@172.17.21.7:43732 > I1201 14:14:27.223976 30322 slave.cpp:3197] Received ping from > slave-observer(58)@172.17.21.7:43732 > I1201 14:14:27.224243 30325 master.cpp:4300] Received update of slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 at slave(61)@172.17.21.7:43732 > (ca6f16e00db6) with total oversubscribed resources > I1201 14:14:27.225162 30325 hierarchical.cpp:434] Slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 (ca6f16e00db6) updated with > oversubscribed resources (total: cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000]) > I1201 14:14:27.225759 30325 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:27.226012 30325 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:27.226039 30325 hierarchical.cpp:973] Performed allocation for > slave 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 in 751766ns > I1201 14:14:27.228044 30321 master.cpp:2946] Processing ACCEPT call for > offers: [ 587d1fd5-db6b-4af4-9267-ce84ac458470-O0 ] on slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 at slave(61)@172.17.21.7:43732 > (ca6f16e00db6) for framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > (default) at scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 > I1201 14:14:27.228107 30321 master.cpp:2742] Authorizing framework principal > 'test-principal' to launch task 1 as user 'mesos' > I1201 14:14:27.230907 30323 master.hpp:176] Adding task 1 with resources > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 (ca6f16e00db6) > I1201 14:14:27.231200 30323 master.cpp:3276] Launching task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (default) at > scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 with > resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on > slave 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 at slave(61)@172.17.21.7:43732 > (ca6f16e00db6) > I1201 14:14:27.231850 30323 slave.cpp:1292] Got assigned task 1 for framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.232142 30323 resources.cpp:478] Parsing resources as JSON > failed: cpus:0.1;mem:32 > Trying semicolon-delimited string format instead > I1201 14:14:27.233273 30323 slave.cpp:1411] Launching task 1 for framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.233381 30323 resources.cpp:478] Parsing resources as JSON > failed: cpus:0.1;mem:32 > Trying semicolon-delimited string format instead > I1201 14:14:27.249552 30323 paths.cpp:434] Trying to chown > '/tmp/HealthCheckTest_CheckCommandTimeout_DODrUR/slaves/587d1fd5-db6b-4af4-9267-ce84ac458470-S0/frameworks/587d1fd5-db6b-4af4-9267-ce84ac458470-0000/executors/1/runs/e5213230-3cf6-4e8c-b7cd-f4e2615df70f' > to user 'mesos' > I1201 14:14:27.255273 30323 slave.cpp:5042] Launching executor 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 with resources cpus(*):0.1; > mem(*):32 in work directory > '/tmp/HealthCheckTest_CheckCommandTimeout_DODrUR/slaves/587d1fd5-db6b-4af4-9267-ce84ac458470-S0/frameworks/587d1fd5-db6b-4af4-9267-ce84ac458470-0000/executors/1/runs/e5213230-3cf6-4e8c-b7cd-f4e2615df70f' > I1201 14:14:27.256011 30323 slave.cpp:1629] Queuing task '1' for executor '1' > of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.256116 30327 containerizer.cpp:617] Starting container > 'e5213230-3cf6-4e8c-b7cd-f4e2615df70f' for executor '1' of framework > '587d1fd5-db6b-4af4-9267-ce84ac458470-0000' > I1201 14:14:27.257302 30319 leveldb.cpp:341] Persisting action (16 bytes) to > leveldb took 33.493331ms > I1201 14:14:27.257356 30319 replica.cpp:713] Persisted action at 4 > I1201 14:14:27.258471 30325 replica.cpp:692] Replica received learned notice > for position 4 from @0.0.0.0:0 > I1201 14:14:27.261706 30321 slave.cpp:680] Successfully attached file > '/tmp/HealthCheckTest_CheckCommandTimeout_DODrUR/slaves/587d1fd5-db6b-4af4-9267-ce84ac458470-S0/frameworks/587d1fd5-db6b-4af4-9267-ce84ac458470-0000/executors/1/runs/e5213230-3cf6-4e8c-b7cd-f4e2615df70f' > I1201 14:14:27.268529 30327 launcher.cpp:132] Forked child with pid '3184' > for container 'e5213230-3cf6-4e8c-b7cd-f4e2615df70f' > I1201 14:14:27.291683 30325 leveldb.cpp:341] Persisting action (18 bytes) to > leveldb took 33.038313ms > I1201 14:14:27.292078 30325 leveldb.cpp:399] Deleting ~2 keys from leveldb > took 87529ns > I1201 14:14:27.292244 30325 replica.cpp:713] Persisted action at 4 > I1201 14:14:27.292456 30325 replica.cpp:698] Replica learned TRUNCATE action > at position 4 > I1201 14:14:27.507856 30325 slave.cpp:2406] Got registration for executor '1' > of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 from > executor(1)@172.17.21.7:46225 > I1201 14:14:27.512398 30314 slave.cpp:1794] Sending queued task '1' to > executor '1' of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 at > executor(1)@172.17.21.7:46225 > I1201 14:14:27.539080 30322 slave.cpp:2763] Handling status update > TASK_RUNNING (UUID: f6c38987-fb13-4ce6-af7f-7839ce3b8ecb) for task 1 of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 from > executor(1)@172.17.21.7:46225 > I1201 14:14:27.540004 30318 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: f6c38987-fb13-4ce6-af7f-7839ce3b8ecb) for task 1 > of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.540385 30318 status_update_manager.cpp:497] Creating > StatusUpdate stream for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.541409 30318 status_update_manager.cpp:374] Forwarding update > TASK_RUNNING (UUID: f6c38987-fb13-4ce6-af7f-7839ce3b8ecb) for task 1 of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 to the slave > I1201 14:14:27.542279 30322 slave.cpp:3115] Forwarding the update > TASK_RUNNING (UUID: f6c38987-fb13-4ce6-af7f-7839ce3b8ecb) for task 1 of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 to > master@172.17.21.7:43732 > I1201 14:14:27.542510 30322 slave.cpp:3009] Status update manager > successfully handled status update TASK_RUNNING (UUID: > f6c38987-fb13-4ce6-af7f-7839ce3b8ecb) for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.542562 30322 slave.cpp:3025] Sending acknowledgement for > status update TASK_RUNNING (UUID: f6c38987-fb13-4ce6-af7f-7839ce3b8ecb) for > task 1 of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 to > executor(1)@172.17.21.7:46225 > I1201 14:14:27.543005 30318 master.cpp:4445] Status update TASK_RUNNING > (UUID: f6c38987-fb13-4ce6-af7f-7839ce3b8ecb) for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 from slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 at slave(61)@172.17.21.7:43732 > (ca6f16e00db6) > I1201 14:14:27.543375 30318 master.cpp:4493] Forwarding status update > TASK_RUNNING (UUID: f6c38987-fb13-4ce6-af7f-7839ce3b8ecb) for task 1 of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.543947 30318 master.cpp:6097] Updating the state of task 1 of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (latest state: > TASK_RUNNING, status update state: TASK_RUNNING) > I1201 14:14:27.544643 30318 sched.cpp:919] Scheduler::statusUpdate took > 137099ns > I1201 14:14:27.545348 30322 master.cpp:3602] Processing ACKNOWLEDGE call > f6c38987-fb13-4ce6-af7f-7839ce3b8ecb for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (default) at > scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 on slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 > I1201 14:14:27.545892 30329 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: f6c38987-fb13-4ce6-af7f-7839ce3b8ecb) for task > 1 of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.546821 30329 slave.cpp:2346] Status update manager > successfully handled status update acknowledgement (UUID: > f6c38987-fb13-4ce6-af7f-7839ce3b8ecb) for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:27.615839 30322 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:27.615924 30322 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:27.615954 30322 hierarchical.cpp:957] Performed allocation for 1 > slaves in 826681ns > I1201 14:14:28.617543 30326 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:28.617914 30326 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:28.618074 30326 hierarchical.cpp:957] Performed allocation for 1 > slaves in 1.123832ms > I1201 14:14:29.619159 30314 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:29.619263 30314 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:29.619300 30314 hierarchical.cpp:957] Performed allocation for 1 > slaves in 726672ns > I1201 14:14:30.622232 30329 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:30.622321 30329 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:30.622359 30329 hierarchical.cpp:957] Performed allocation for 1 > slaves in 719341ns > I1201 14:14:31.625255 30314 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:31.625346 30314 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:31.625383 30314 hierarchical.cpp:957] Performed allocation for 1 > slaves in 743648ns > I1201 14:14:32.628315 30318 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:32.628419 30318 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:32.628478 30318 hierarchical.cpp:957] Performed allocation for 1 > slaves in 809723ns > I1201 14:14:32.744158 30321 slave.cpp:2763] Handling status update > TASK_RUNNING (UUID: a20337d6-2301-44ba-bd7e-60cd5c7ac014) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > from executor(1)@172.17.21.7:46225 > I1201 14:14:32.744817 30319 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: a20337d6-2301-44ba-bd7e-60cd5c7ac014) for task 1 > in health state unhealthy of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:32.745187 30319 status_update_manager.cpp:374] Forwarding update > TASK_RUNNING (UUID: a20337d6-2301-44ba-bd7e-60cd5c7ac014) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > to the slave > I1201 14:14:32.745558 30325 slave.cpp:3115] Forwarding the update > TASK_RUNNING (UUID: a20337d6-2301-44ba-bd7e-60cd5c7ac014) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > to master@172.17.21.7:43732 > I1201 14:14:32.745990 30325 slave.cpp:3009] Status update manager > successfully handled status update TASK_RUNNING (UUID: > a20337d6-2301-44ba-bd7e-60cd5c7ac014) for task 1 in health state unhealthy of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:32.746037 30325 slave.cpp:3025] Sending acknowledgement for > status update TASK_RUNNING (UUID: a20337d6-2301-44ba-bd7e-60cd5c7ac014) for > task 1 in health state unhealthy of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 to executor(1)@172.17.21.7:46225 > I1201 14:14:32.746395 30320 master.cpp:4445] Status update TASK_RUNNING > (UUID: a20337d6-2301-44ba-bd7e-60cd5c7ac014) for task 1 in health state > unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 from slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 at slave(61)@172.17.21.7:43732 > (ca6f16e00db6) > I1201 14:14:32.747027 30320 master.cpp:4493] Forwarding status update > TASK_RUNNING (UUID: a20337d6-2301-44ba-bd7e-60cd5c7ac014) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:32.747349 30320 master.cpp:6097] Updating the state of task 1 of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (latest state: > TASK_RUNNING, status update state: TASK_RUNNING) > I1201 14:14:32.747804 30315 sched.cpp:919] Scheduler::statusUpdate took > 115298ns > I1201 14:14:32.748492 30315 master.cpp:3602] Processing ACKNOWLEDGE call > a20337d6-2301-44ba-bd7e-60cd5c7ac014 for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (default) at > scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 on slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 > I1201 14:14:32.748931 30324 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: a20337d6-2301-44ba-bd7e-60cd5c7ac014) for task > 1 of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:32.749595 30324 slave.cpp:2346] Status update manager > successfully handled status update acknowledgement (UUID: > a20337d6-2301-44ba-bd7e-60cd5c7ac014) for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:33.630220 30321 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:33.630412 30321 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:33.630549 30321 hierarchical.cpp:957] Performed allocation for 1 > slaves in 908929ns > I1201 14:14:34.631630 30324 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:34.631721 30324 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:34.631757 30324 hierarchical.cpp:957] Performed allocation for 1 > slaves in 697251ns > I1201 14:14:35.632884 30322 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:35.632969 30322 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:35.633003 30322 hierarchical.cpp:957] Performed allocation for 1 > slaves in 676552ns > I1201 14:14:36.634296 30315 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:36.634392 30315 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:36.634426 30315 hierarchical.cpp:957] Performed allocation for 1 > slaves in 758855ns > I1201 14:14:37.637233 30323 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:37.637323 30323 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:37.637359 30323 hierarchical.cpp:957] Performed allocation for 1 > slaves in 726275ns > I1201 14:14:37.764578 30326 slave.cpp:2763] Handling status update > TASK_RUNNING (UUID: 01be2c68-5336-411a-aa1e-84a46d11c688) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > from executor(1)@172.17.21.7:46225 > I1201 14:14:37.765316 30326 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: 01be2c68-5336-411a-aa1e-84a46d11c688) for task 1 > in health state unhealthy of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:37.765745 30326 status_update_manager.cpp:374] Forwarding update > TASK_RUNNING (UUID: 01be2c68-5336-411a-aa1e-84a46d11c688) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > to the slave > I1201 14:14:37.766261 30318 slave.cpp:3115] Forwarding the update > TASK_RUNNING (UUID: 01be2c68-5336-411a-aa1e-84a46d11c688) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > to master@172.17.21.7:43732 > I1201 14:14:37.766813 30316 master.cpp:4445] Status update TASK_RUNNING > (UUID: 01be2c68-5336-411a-aa1e-84a46d11c688) for task 1 in health state > unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 from slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 at slave(61)@172.17.21.7:43732 > (ca6f16e00db6) > I1201 14:14:37.767022 30316 master.cpp:4493] Forwarding status update > TASK_RUNNING (UUID: 01be2c68-5336-411a-aa1e-84a46d11c688) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:37.767364 30316 master.cpp:6097] Updating the state of task 1 of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (latest state: > TASK_RUNNING, status update state: TASK_RUNNING) > I1201 14:14:37.767786 30327 sched.cpp:919] Scheduler::statusUpdate took > 123386ns > I1201 14:14:37.771409 30316 master.cpp:3602] Processing ACKNOWLEDGE call > 01be2c68-5336-411a-aa1e-84a46d11c688 for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (default) at > scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 on slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 > I1201 14:14:37.772351 30326 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: 01be2c68-5336-411a-aa1e-84a46d11c688) for task > 1 of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:37.772438 30316 slave.cpp:3009] Status update manager > successfully handled status update TASK_RUNNING (UUID: > 01be2c68-5336-411a-aa1e-84a46d11c688) for task 1 in health state unhealthy of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:37.772816 30316 slave.cpp:3025] Sending acknowledgement for > status update TASK_RUNNING (UUID: 01be2c68-5336-411a-aa1e-84a46d11c688) for > task 1 in health state unhealthy of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 to executor(1)@172.17.21.7:46225 > I1201 14:14:37.773659 30326 slave.cpp:2346] Status update manager > successfully handled status update acknowledgement (UUID: > 01be2c68-5336-411a-aa1e-84a46d11c688) for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:38.639390 30325 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:38.639753 30325 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:38.640020 30325 hierarchical.cpp:957] Performed allocation for 1 > slaves in 1.435634ms > I1201 14:14:39.641808 30329 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:39.641896 30329 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:39.641926 30329 hierarchical.cpp:957] Performed allocation for 1 > slaves in 729812ns > I1201 14:14:40.643889 30320 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:40.643978 30320 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:40.644009 30320 hierarchical.cpp:957] Performed allocation for 1 > slaves in 741824ns > I1201 14:14:41.645243 30327 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:41.645352 30327 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:41.645400 30327 hierarchical.cpp:957] Performed allocation for 1 > slaves in 751314ns > I1201 14:14:42.165752 30329 slave.cpp:4430] Querying resource estimator for > oversubscribable resources > I1201 14:14:42.166100 30329 slave.cpp:4444] Received oversubscribable > resources from the resource estimator > I1201 14:14:42.222800 30317 slave.cpp:3197] Received ping from > slave-observer(58)@172.17.21.7:43732 > I1201 14:14:42.648282 30323 hierarchical.cpp:1062] No resources available to > allocate! > I1201 14:14:42.648391 30323 hierarchical.cpp:1155] No inverse offers to send > out! > I1201 14:14:42.648435 30323 hierarchical.cpp:957] Performed allocation for 1 > slaves in 765531ns > I1201 14:14:42.800969 30320 slave.cpp:2763] Handling status update > TASK_RUNNING (UUID: d6a4f449-13f7-49ec-8e58-ee693cea55b7) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > from executor(1)@172.17.21.7:46225 > I1201 14:14:42.801570 30320 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: d6a4f449-13f7-49ec-8e58-ee693cea55b7) for task 1 > in health state unhealthy of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.801789 30320 status_update_manager.cpp:374] Forwarding update > TASK_RUNNING (UUID: d6a4f449-13f7-49ec-8e58-ee693cea55b7) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > to the slave > I1201 14:14:42.802266 30327 slave.cpp:3115] Forwarding the update > TASK_RUNNING (UUID: d6a4f449-13f7-49ec-8e58-ee693cea55b7) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > to master@172.17.21.7:43732 > I1201 14:14:42.802454 30327 slave.cpp:3009] Status update manager > successfully handled status update TASK_RUNNING (UUID: > d6a4f449-13f7-49ec-8e58-ee693cea55b7) for task 1 in health state unhealthy of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.802500 30327 slave.cpp:3025] Sending acknowledgement for > status update TASK_RUNNING (UUID: d6a4f449-13f7-49ec-8e58-ee693cea55b7) for > task 1 in health state unhealthy of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 to executor(1)@172.17.21.7:46225 > I1201 14:14:42.804724 30327 master.cpp:4445] Status update TASK_RUNNING > (UUID: d6a4f449-13f7-49ec-8e58-ee693cea55b7) for task 1 in health state > unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 from slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 at slave(61)@172.17.21.7:43732 > (ca6f16e00db6) > I1201 14:14:42.804810 30327 master.cpp:4493] Forwarding status update > TASK_RUNNING (UUID: d6a4f449-13f7-49ec-8e58-ee693cea55b7) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.805073 30327 master.cpp:6097] Updating the state of task 1 of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (latest state: > TASK_RUNNING, status update state: TASK_RUNNING) > I1201 14:14:42.805578 30327 sched.cpp:919] Scheduler::statusUpdate took > 173590ns > I1201 14:14:42.806002 30327 master.cpp:3602] Processing ACKNOWLEDGE call > d6a4f449-13f7-49ec-8e58-ee693cea55b7 for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (default) at > scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 on slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 > I1201 14:14:42.806567 30326 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: d6a4f449-13f7-49ec-8e58-ee693cea55b7) for task > 1 of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.806990 30326 slave.cpp:2346] Status update manager > successfully handled status update acknowledgement (UUID: > d6a4f449-13f7-49ec-8e58-ee693cea55b7) for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.853611 30321 slave.cpp:2763] Handling status update > TASK_KILLED (UUID: bc631a7f-8b8a-4dd8-a1bb-7a28016108dc) for task 1 in health > state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 from > executor(1)@172.17.21.7:46225 > I1201 14:14:42.853857 30321 slave.cpp:5341] Terminating task 1 > I1201 14:14:42.855967 30321 status_update_manager.cpp:320] Received status > update TASK_KILLED (UUID: bc631a7f-8b8a-4dd8-a1bb-7a28016108dc) for task 1 in > health state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.856298 30321 status_update_manager.cpp:374] Forwarding update > TASK_KILLED (UUID: bc631a7f-8b8a-4dd8-a1bb-7a28016108dc) for task 1 in health > state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 to the > slave > I1201 14:14:42.856757 30321 slave.cpp:3115] Forwarding the update TASK_KILLED > (UUID: bc631a7f-8b8a-4dd8-a1bb-7a28016108dc) for task 1 in health state > unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 to > master@172.17.21.7:43732 > I1201 14:14:42.856945 30321 slave.cpp:3009] Status update manager > successfully handled status update TASK_KILLED (UUID: > bc631a7f-8b8a-4dd8-a1bb-7a28016108dc) for task 1 in health state unhealthy of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.856992 30321 slave.cpp:3025] Sending acknowledgement for > status update TASK_KILLED (UUID: bc631a7f-8b8a-4dd8-a1bb-7a28016108dc) for > task 1 in health state unhealthy of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 to executor(1)@172.17.21.7:46225 > I1201 14:14:42.857553 30319 master.cpp:4445] Status update TASK_KILLED (UUID: > bc631a7f-8b8a-4dd8-a1bb-7a28016108dc) for task 1 in health state unhealthy of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 from slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 at slave(61)@172.17.21.7:43732 > (ca6f16e00db6) > I1201 14:14:42.857599 30319 master.cpp:4493] Forwarding status update > TASK_KILLED (UUID: bc631a7f-8b8a-4dd8-a1bb-7a28016108dc) for task 1 in health > state unhealthy of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.857770 30319 master.cpp:6097] Updating the state of task 1 of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (latest state: > TASK_KILLED, status update state: TASK_KILLED) > I1201 14:14:42.858459 30325 sched.cpp:919] Scheduler::statusUpdate took > 130918ns > I1201 14:14:42.859022 30325 hierarchical.cpp:791] Recovered cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: ) on slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 from framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.859416 30319 master.cpp:3602] Processing ACKNOWLEDGE call > bc631a7f-8b8a-4dd8-a1bb-7a28016108dc for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 (default) at > scheduler-90969aaa-c756-4602-8e8a-c07acb10fcfb@172.17.21.7:43732 on slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 > I1201 14:14:42.859482 30319 master.cpp:6163] Removing task 1 with resources > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 on slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 at slave(61)@172.17.21.7:43732 > (ca6f16e00db6) > I1201 14:14:42.860584 30319 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: bc631a7f-8b8a-4dd8-a1bb-7a28016108dc) for task > 1 of framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.860781 30319 status_update_manager.cpp:528] Cleaning up status > update stream for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.861460 30319 slave.cpp:2346] Status update manager > successfully handled status update acknowledgement (UUID: > bc631a7f-8b8a-4dd8-a1bb-7a28016108dc) for task 1 of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.861522 30319 slave.cpp:5382] Completing task 1 > I1201 14:14:42.861721 30295 sched.cpp:1803] Asked to stop the driver > I1201 14:14:42.861811 30319 sched.cpp:1041] Stopping framework > '587d1fd5-db6b-4af4-9267-ce84ac458470-0000' > I1201 14:14:42.861917 30315 master.cpp:938] Master terminating > I1201 14:14:42.862610 30323 hierarchical.cpp:410] Removed slave > 587d1fd5-db6b-4af4-9267-ce84ac458470-S0 > I1201 14:14:42.863286 30322 hierarchical.cpp:260] Removed framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.863615 30326 slave.cpp:3243] master@172.17.21.7:43732 exited > W1201 14:14:42.863641 30326 slave.cpp:3246] Master disconnected! Waiting for > a new master to be elected > I1201 14:14:42.877462 30318 containerizer.cpp:1073] Destroying container > 'e5213230-3cf6-4e8c-b7cd-f4e2615df70f' > I1201 14:14:42.942379 30314 containerizer.cpp:1256] Executor for container > 'e5213230-3cf6-4e8c-b7cd-f4e2615df70f' has exited > I1201 14:14:42.945029 30329 slave.cpp:3581] Executor '1' of framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 terminated with signal Killed > I1201 14:14:42.945142 30329 slave.cpp:3685] Cleaning up executor '1' of > framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 at > executor(1)@172.17.21.7:46225 > I1201 14:14:42.945504 30326 gc.cpp:54] Scheduling > '/tmp/HealthCheckTest_CheckCommandTimeout_DODrUR/slaves/587d1fd5-db6b-4af4-9267-ce84ac458470-S0/frameworks/587d1fd5-db6b-4af4-9267-ce84ac458470-0000/executors/1/runs/e5213230-3cf6-4e8c-b7cd-f4e2615df70f' > for gc 6.9999890582637days in the future > I1201 14:14:42.945605 30329 slave.cpp:3773] Cleaning up framework > 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.945726 30317 status_update_manager.cpp:282] Closing status > update streams for framework 587d1fd5-db6b-4af4-9267-ce84ac458470-0000 > I1201 14:14:42.945765 30326 gc.cpp:54] Scheduling > '/tmp/HealthCheckTest_CheckCommandTimeout_DODrUR/slaves/587d1fd5-db6b-4af4-9267-ce84ac458470-S0/frameworks/587d1fd5-db6b-4af4-9267-ce84ac458470-0000/executors/1' > for gc 6.99998905620444days in the future > I1201 14:14:42.945861 30326 gc.cpp:54] Scheduling > '/tmp/HealthCheckTest_CheckCommandTimeout_DODrUR/slaves/587d1fd5-db6b-4af4-9267-ce84ac458470-S0/frameworks/587d1fd5-db6b-4af4-9267-ce84ac458470-0000' > for gc 6.99998905409778days in the future > I1201 14:14:42.946763 30295 slave.cpp:599] Slave terminating > [ OK ] HealthCheckTest.CheckCommandTimeout (16537 ms) > {noformat} > Also, this test takes 16 seconds to succeed? :( -- This message was sent by Atlassian JIRA (v6.3.4#6332)