mesos-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Anand Mazumdar (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (MESOS-6569) MesosContainerizer/DefaultExecutorTest.KillTask/0 failing on ASF CI
Date Thu, 10 Nov 2016 01:58:58 GMT

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

Anand Mazumdar updated MESOS-6569:
----------------------------------
         Labels: flaky newbie  (was: )
    Description: 

{noformat:title=}
[ RUN      ] MesosContainerizer/DefaultExecutorTest.KillTask/0
I1110 01:20:11.482097 29700 cluster.cpp:158] Creating default 'local' authorizer
I1110 01:20:11.485241 29700 leveldb.cpp:174] Opened db in 2.774513ms
I1110 01:20:11.486237 29700 leveldb.cpp:181] Compacted db in 953614ns
I1110 01:20:11.486299 29700 leveldb.cpp:196] Created db iterator in 24739ns
I1110 01:20:11.486325 29700 leveldb.cpp:202] Seeked to beginning of db in 2300ns
I1110 01:20:11.486344 29700 leveldb.cpp:271] Iterated through 0 keys in the db in 378ns
I1110 01:20:11.486399 29700 replica.cpp:776] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1110 01:20:11.486933 29733 recover.cpp:451] Starting replica recovery
I1110 01:20:11.487289 29733 recover.cpp:477] Replica is in EMPTY status
I1110 01:20:11.488503 29721 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from __req_res__(7318)@172.17.0.3:52462
I1110 01:20:11.488855 29727 recover.cpp:197] Received a recover response from a replica in EMPTY status
I1110 01:20:11.489398 29729 recover.cpp:568] Updating replica status to STARTING
I1110 01:20:11.490223 29723 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 575135ns
I1110 01:20:11.490284 29732 master.cpp:380] Master d28fbae1-c3dc-45fa-8384-32ab9395a975 (3a31be8bf679) started on 172.17.0.3:52462
I1110 01:20:11.490317 29732 master.cpp:382] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/k50x7x/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --quiet="false" --recovery_agent_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-1.2.0/_inst/share/mesos/webui" --work_dir="/tmp/k50x7x/master" --zk_session_timeout="10secs"
I1110 01:20:11.490696 29732 master.cpp:432] Master only allowing authenticated frameworks to register
I1110 01:20:11.490712 29732 master.cpp:446] Master only allowing authenticated agents to register
I1110 01:20:11.490720 29732 master.cpp:459] Master only allowing authenticated HTTP frameworks to register
I1110 01:20:11.490730 29732 credentials.hpp:37] Loading credentials for authentication from '/tmp/k50x7x/credentials'
I1110 01:20:11.490281 29723 replica.cpp:320] Persisted replica status to STARTING
I1110 01:20:11.491210 29732 master.cpp:504] Using default 'crammd5' authenticator
I1110 01:20:11.491225 29720 recover.cpp:477] Replica is in STARTING status
I1110 01:20:11.491394 29732 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1110 01:20:11.491621 29732 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1110 01:20:11.491770 29732 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1110 01:20:11.491937 29732 master.cpp:584] Authorization enabled
I1110 01:20:11.492276 29725 whitelist_watcher.cpp:77] No whitelist given
I1110 01:20:11.492310 29723 hierarchical.cpp:149] Initialized hierarchical allocator process
I1110 01:20:11.492569 29721 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from __req_res__(7319)@172.17.0.3:52462
I1110 01:20:11.492830 29719 recover.cpp:197] Received a recover response from a replica in STARTING status
I1110 01:20:11.493371 29720 recover.cpp:568] Updating replica status to VOTING
I1110 01:20:11.494002 29721 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 367673ns
I1110 01:20:11.494032 29721 replica.cpp:320] Persisted replica status to VOTING
I1110 01:20:11.494218 29734 recover.cpp:582] Successfully joined the Paxos group
I1110 01:20:11.494469 29734 recover.cpp:466] Recover process terminated
I1110 01:20:11.495633 29733 master.cpp:2033] Elected as the leading master!
I1110 01:20:11.495685 29733 master.cpp:1560] Recovering from registrar
I1110 01:20:11.495880 29720 registrar.cpp:329] Recovering registrar
I1110 01:20:11.496842 29730 log.cpp:553] Attempting to start the writer
I1110 01:20:11.498610 29725 replica.cpp:493] Replica received implicit promise request from __req_res__(7320)@172.17.0.3:52462 with proposal 1
I1110 01:20:11.499179 29725 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 524192ns
I1110 01:20:11.499213 29725 replica.cpp:342] Persisted promised to 1
I1110 01:20:11.500258 29726 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1110 01:20:11.501874 29731 replica.cpp:388] Replica received explicit promise request from __req_res__(7321)@172.17.0.3:52462 for position 0 with proposal 2
I1110 01:20:11.502413 29731 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 484138ns
I1110 01:20:11.502457 29731 replica.cpp:708] Persisted action NOP at position 0
I1110 01:20:11.503885 29720 replica.cpp:537] Replica received write request for position 0 from __req_res__(7322)@172.17.0.3:52462
I1110 01:20:11.503985 29720 leveldb.cpp:436] Reading position from leveldb took 56800ns
I1110 01:20:11.504534 29720 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 467426ns
I1110 01:20:11.504566 29720 replica.cpp:708] Persisted action NOP at position 0
I1110 01:20:11.505470 29721 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1110 01:20:11.505988 29721 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 479078ns
I1110 01:20:11.506021 29721 replica.cpp:708] Persisted action NOP at position 0
I1110 01:20:11.506706 29732 log.cpp:569] Writer started with ending position 0
I1110 01:20:11.508041 29734 leveldb.cpp:436] Reading position from leveldb took 50010ns
I1110 01:20:11.509210 29733 registrar.cpp:362] Successfully fetched the registry (0B) in 13.068032ms
I1110 01:20:11.509356 29733 registrar.cpp:461] Applied 1 operations in 27124ns; attempting to update the registry
I1110 01:20:11.510251 29732 log.cpp:577] Attempting to append 168 bytes to the log
I1110 01:20:11.510457 29724 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1110 01:20:11.511355 29728 replica.cpp:537] Replica received write request for position 1 from __req_res__(7323)@172.17.0.3:52462
I1110 01:20:11.511828 29728 leveldb.cpp:341] Persisting action (187 bytes) to leveldb took 423890ns
I1110 01:20:11.511859 29728 replica.cpp:708] Persisted action APPEND at position 1
I1110 01:20:11.512572 29734 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1110 01:20:11.513051 29734 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 368122ns
I1110 01:20:11.513087 29734 replica.cpp:708] Persisted action APPEND at position 1
I1110 01:20:11.514302 29726 registrar.cpp:506] Successfully updated the registry in 4.862976ms
I1110 01:20:11.514503 29726 registrar.cpp:392] Successfully recovered registrar
I1110 01:20:11.514593 29728 log.cpp:596] Attempting to truncate the log to 1
I1110 01:20:11.514760 29730 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1110 01:20:11.515249 29723 master.cpp:1676] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
I1110 01:20:11.515534 29722 hierarchical.cpp:176] Skipping recovery of hierarchical allocator: nothing to recover
I1110 01:20:11.516068 29722 replica.cpp:537] Replica received write request for position 2 from __req_res__(7324)@172.17.0.3:52462
I1110 01:20:11.516619 29722 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 497823ns
I1110 01:20:11.516652 29722 replica.cpp:708] Persisted action TRUNCATE at position 2
I1110 01:20:11.517526 29734 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1110 01:20:11.518040 29734 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 384129ns
I1110 01:20:11.518111 29734 leveldb.cpp:399] Deleting ~1 keys from leveldb took 39398ns
I1110 01:20:11.518138 29734 replica.cpp:708] Persisted action TRUNCATE at position 2
I1110 01:20:11.525027 29700 containerizer.cpp:201] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni
W1110 01:20:11.525806 29700 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges, but is running as user mesos
W1110 01:20:11.526018 29700 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1110 01:20:11.527331 29700 cluster.cpp:435] Creating default 'local' authorizer
I1110 01:20:11.528741 29725 slave.cpp:208] Mesos agent started on (571)@172.17.0.3:52462
I1110 01:20:11.528789 29725 slave.cpp:209] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --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/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_command_executor="false" --http_credentials="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/http_credentials" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.2.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --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;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD"
I1110 01:20:11.529228 29725 credentials.hpp:86] Loading credential for authentication from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/credential'
I1110 01:20:11.529305 29700 scheduler.cpp:176] Version: 1.2.0
I1110 01:20:11.529436 29725 slave.cpp:346] Agent using credential for: test-principal
I1110 01:20:11.529464 29725 credentials.hpp:37] Loading credentials for authentication from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/http_credentials'
I1110 01:20:11.529747 29725 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1110 01:20:11.529855 29729 scheduler.cpp:469] New master detected at master@172.17.0.3:52462
I1110 01:20:11.529884 29729 scheduler.cpp:478] Waiting for 0ns before initiating a re-(connection) attempt with the master
I1110 01:20:11.531039 29725 slave.cpp:533] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1110 01:20:11.531113 29725 slave.cpp:541] Agent attributes: [  ]
I1110 01:20:11.531126 29725 slave.cpp:546] Agent hostname: 3a31be8bf679
I1110 01:20:11.532897 29723 state.cpp:57] Recovering state from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/meta'
I1110 01:20:11.533222 29727 status_update_manager.cpp:203] Recovering status update manager
I1110 01:20:11.533269 29721 scheduler.cpp:353] Connected with the master at http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.533627 29734 containerizer.cpp:557] Recovering containerizer
I1110 01:20:11.534519 29725 scheduler.cpp:235] Sending SUBSCRIBE call to http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.535482 29732 provisioner.cpp:253] Provisioner recovery complete
I1110 01:20:11.535652 29734 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 01:20:11.535815 29724 slave.cpp:5411] Finished recovery
I1110 01:20:11.536440 29724 slave.cpp:5585] Querying resource estimator for oversubscribable resources
I1110 01:20:11.536898 29721 slave.cpp:915] New master detected at master@172.17.0.3:52462
I1110 01:20:11.536906 29731 status_update_manager.cpp:177] Pausing sending status updates
I1110 01:20:11.536941 29721 slave.cpp:974] Authenticating with master master@172.17.0.3:52462
I1110 01:20:11.537076 29721 slave.cpp:985] Using default CRAM-MD5 authenticatee
I1110 01:20:11.537214 29733 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54635
I1110 01:20:11.537353 29719 authenticatee.cpp:121] Creating new client SASL connection
I1110 01:20:11.537256 29721 slave.cpp:947] Detecting new master
I1110 01:20:11.537591 29733 master.cpp:2329] Received subscription request for HTTP framework 'default'
I1110 01:20:11.537611 29721 slave.cpp:5599] Received oversubscribable resources {} from the resource estimator
I1110 01:20:11.537701 29733 master.cpp:2069] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1110 01:20:11.538077 29733 master.cpp:6745] Authenticating slave(571)@172.17.0.3:52462
I1110 01:20:11.538208 29732 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1121)@172.17.0.3:52462
I1110 01:20:11.538291 29733 master.cpp:2427] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I1110 01:20:11.538508 29731 authenticator.cpp:98] Creating new server SASL connection
I1110 01:20:11.538782 29720 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1110 01:20:11.538823 29720 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1110 01:20:11.539227 29730 hierarchical.cpp:275] Added framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.539317 29722 master.hpp:2161] Sending heartbeat to d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.539331 29730 hierarchical.cpp:1694] No allocations performed
I1110 01:20:11.539696 29730 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:11.539818 29730 hierarchical.cpp:1286] Performed allocation for 0 agents in 554795ns
I1110 01:20:11.540354 29720 authenticator.cpp:204] Received SASL authentication start
I1110 01:20:11.540361 29719 scheduler.cpp:675] Enqueuing event SUBSCRIBED received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.540438 29720 authenticator.cpp:326] Authentication requires more steps
I1110 01:20:11.540750 29720 authenticatee.cpp:259] Received SASL authentication step
I1110 01:20:11.541038 29721 authenticator.cpp:232] Received SASL authentication step
I1110 01:20:11.541081 29721 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3a31be8bf679' server FQDN: '3a31be8bf679' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I1110 01:20:11.541112 29721 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1110 01:20:11.541147 29719 scheduler.cpp:675] Enqueuing event HEARTBEAT received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.541178 29721 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1110 01:20:11.541260 29721 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3a31be8bf679' server FQDN: '3a31be8bf679' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I1110 01:20:11.541285 29721 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1110 01:20:11.541307 29721 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1110 01:20:11.541342 29721 authenticator.cpp:318] Authentication success
I1110 01:20:11.541517 29733 authenticatee.cpp:299] Authentication success
I1110 01:20:11.541586 29720 master.cpp:6775] Successfully authenticated principal 'test-principal' at slave(571)@172.17.0.3:52462
I1110 01:20:11.541826 29721 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1121)@172.17.0.3:52462
I1110 01:20:11.542129 29730 slave.cpp:1069] Successfully authenticated with master master@172.17.0.3:52462
I1110 01:20:11.542362 29730 slave.cpp:1483] Will retry registration in 9.532818ms if necessary
I1110 01:20:11.542577 29733 master.cpp:5154] Registering agent at slave(571)@172.17.0.3:52462 (3a31be8bf679) with id d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
I1110 01:20:11.543083 29731 registrar.cpp:461] Applied 1 operations in 60476ns; attempting to update the registry
I1110 01:20:11.543926 29729 log.cpp:577] Attempting to append 337 bytes to the log
I1110 01:20:11.544077 29723 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I1110 01:20:11.545238 29731 replica.cpp:537] Replica received write request for position 3 from __req_res__(7325)@172.17.0.3:52462
I1110 01:20:11.546116 29731 leveldb.cpp:341] Persisting action (356 bytes) to leveldb took 825474ns
I1110 01:20:11.546169 29731 replica.cpp:708] Persisted action APPEND at position 3
I1110 01:20:11.547427 29725 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I1110 01:20:11.547969 29725 leveldb.cpp:341] Persisting action (358 bytes) to leveldb took 483290ns
I1110 01:20:11.548005 29725 replica.cpp:708] Persisted action APPEND at position 3
I1110 01:20:11.550129 29732 registrar.cpp:506] Successfully updated the registry in 6.962944ms
I1110 01:20:11.550396 29726 log.cpp:596] Attempting to truncate the log to 3
I1110 01:20:11.550614 29720 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I1110 01:20:11.551375 29723 slave.cpp:4263] Received ping from slave-observer(531)@172.17.0.3:52462
I1110 01:20:11.551326 29734 master.cpp:5225] Registered agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1110 01:20:11.551720 29730 replica.cpp:537] Replica received write request for position 4 from __req_res__(7326)@172.17.0.3:52462
I1110 01:20:11.551892 29723 slave.cpp:1115] Registered with master master@172.17.0.3:52462; given agent ID d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
I1110 01:20:11.551975 29723 fetcher.cpp:86] Clearing fetcher cache
I1110 01:20:11.552170 29732 hierarchical.cpp:485] Added agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I1110 01:20:11.552338 29721 status_update_manager.cpp:184] Resuming sending status updates
I1110 01:20:11.552486 29730 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 709727ns
I1110 01:20:11.552655 29723 slave.cpp:1138] Checkpointing SlaveInfo to '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/meta/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/slave.info'
I1110 01:20:11.552609 29730 replica.cpp:708] Persisted action TRUNCATE at position 4
I1110 01:20:11.553383 29731 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
I1110 01:20:11.553409 29723 slave.cpp:1175] Forwarding total oversubscribed resources {}
I1110 01:20:11.553653 29732 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:11.553671 29727 master.cpp:5624] Received update of agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) with total oversubscribed resources {}
I1110 01:20:11.553755 29732 hierarchical.cpp:1309] Performed allocation for agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 in 1.528714ms
I1110 01:20:11.553975 29731 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 525057ns
I1110 01:20:11.554072 29731 leveldb.cpp:399] Deleting ~2 keys from leveldb took 59750ns
I1110 01:20:11.554065 29732 hierarchical.cpp:555] Agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679) updated with oversubscribed resources {} (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000])
I1110 01:20:11.554105 29731 replica.cpp:708] Persisted action TRUNCATE at position 4
I1110 01:20:11.554260 29732 hierarchical.cpp:1694] No allocations performed
I1110 01:20:11.554314 29732 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:11.554345 29727 master.cpp:6574] Sending 1 offers to framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:11.554379 29732 hierarchical.cpp:1309] Performed allocation for agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 in 239597ns
I1110 01:20:11.556370 29724 scheduler.cpp:675] Enqueuing event OFFERS received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.559177 29730 scheduler.cpp:235] Sending ACCEPT call to http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.560282 29734 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 01:20:11.561323 29733 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
I1110 01:20:11.562417 29733 master.cpp:3581] Processing ACCEPT call for offers: [ d28fbae1-c3dc-45fa-8384-32ab9395a975-O0 ] on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:11.562584 29733 master.cpp:3173] Authorizing framework principal 'test-principal' to launch task c96eb523-0365-49b2-8b3b-78976ff28797
I1110 01:20:11.563097 29733 master.cpp:3173] Authorizing framework principal 'test-principal' to launch task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba
I1110 01:20:11.567248 29733 master.cpp:8337] Adding task c96eb523-0365-49b2-8b3b-78976ff28797 with resources cpus(*):0.1; mem(*):32; disk(*):32 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679)
I1110 01:20:11.567651 29733 master.cpp:8337] Adding task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba with resources cpus(*):0.1; mem(*):32; disk(*):32 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679)
I1110 01:20:11.567845 29733 master.cpp:4438] Launching task group { 08848440-4c0e-4ad6-a0a9-b5947c5d21ba, c96eb523-0365-49b2-8b3b-78976ff28797 } of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) with resources cpus(*):0.2; mem(*):64; disk(*):64 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:11.568495 29724 slave.cpp:1547] Got assigned task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.569128 29729 hierarchical.cpp:1018] Recovered cpus(*):1.7; mem(*):928; disk(*):928; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):0.3; mem(*):96; disk(*):96) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.569211 29729 hierarchical.cpp:1055] Framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 filtered agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 for 5secs
I1110 01:20:11.570461 29724 slave.cpp:1709] Launching task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.571297 29724 paths.cpp:530] Trying to chown '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06' to user 'mesos'
I1110 01:20:11.580168 29724 slave.cpp:6319] Launching executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 with resources cpus(*):0.1; mem(*):32; disk(*):32 in work directory '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06'
I1110 01:20:11.580930 29734 containerizer.cpp:940] Starting container a283035b-25d3-4b48-b59a-964e5a4dfa06 for executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.581110 29724 slave.cpp:2031] Queued task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] for executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.581214 29724 slave.cpp:868] Successfully attached file '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06'
I1110 01:20:11.585572 29722 containerizer.cpp:1480] Launching 'mesos-containerizer' with flags '--command="{"arguments":["mesos-default-executor","--launcher_dir=\/mesos\/mesos-1.2.0\/_build\/src"],"shell":false,"value":"\/mesos\/mesos-1.2.0\/_build\/src\/mesos-default-executor"}" --help="false" --pipe_read="60" --pipe_write="61" --pre_exec_commands="[]" --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06" --unshare_namespace_mnt="false" --user="mesos" --working_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06"'
I1110 01:20:11.588587 29722 launcher.cpp:127] Forked child with pid '10191' for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06'
I1110 01:20:11.592996 29734 fetcher.cpp:345] Starting to fetch URIs for container: a283035b-25d3-4b48-b59a-964e5a4dfa06, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06
I1110 01:20:11.777189 10229 executor.cpp:189] Version: 1.2.0
I1110 01:20:11.786099 29719 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
I1110 01:20:11.787382 29722 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54638
I1110 01:20:11.787693 29722 slave.cpp:3086] Received Subscribe request for HTTP executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.790436 29730 slave.cpp:2276] Sending queued task group task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] to executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (via HTTP)
I1110 01:20:11.795663 10221 default_executor.cpp:130] Received SUBSCRIBED event
I1110 01:20:11.797111 10221 default_executor.cpp:134] Subscribed executor on 3a31be8bf679
I1110 01:20:11.797611 10221 default_executor.cpp:130] Received LAUNCH_GROUP event
I1110 01:20:11.801981 29729 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.802435 29729 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.803306 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54640
I1110 01:20:11.803452 29723 http.cpp:353] Processing call LAUNCH_NESTED_CONTAINER
I1110 01:20:11.803827 29727 containerizer.cpp:1685] Starting nested container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
I1110 01:20:11.803865 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54640
I1110 01:20:11.803978 29723 http.cpp:353] Processing call LAUNCH_NESTED_CONTAINER
I1110 01:20:11.804236 29727 containerizer.cpp:1709] Trying to chown '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d' to user 'mesos'
I1110 01:20:11.814858 29727 containerizer.cpp:1685] Starting nested container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
I1110 01:20:11.815129 29727 containerizer.cpp:1709] Trying to chown '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611' to user 'mesos'
I1110 01:20:11.824666 29727 containerizer.cpp:1480] Launching 'mesos-containerizer' with flags '--command="{"shell":true,"value":"sleep 1000"}" --help="false" --pipe_read="63" --pipe_write="64" --pre_exec_commands="[]" --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d" --unshare_namespace_mnt="false" --user="mesos" --working_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d"'
I1110 01:20:11.826855 29727 launcher.cpp:127] Forked child with pid '10240' for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d'
I1110 01:20:11.828918 29727 containerizer.cpp:1480] Launching 'mesos-containerizer' with flags '--command="{"shell":true,"value":"sleep 1000"}" --help="false" --pipe_read="65" --pipe_write="66" --pre_exec_commands="[]" --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611" --unshare_namespace_mnt="false" --user="mesos" --working_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611"'
I1110 01:20:11.831428 29727 launcher.cpp:127] Forked child with pid '10241' for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611'
I1110 01:20:11.834421 29731 fetcher.cpp:345] Starting to fetch URIs for container: a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d
I1110 01:20:11.837882 29731 fetcher.cpp:345] Starting to fetch URIs for container: a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611
I1110 01:20:11.847651 10227 default_executor.cpp:470] Successfully launched child containers [ a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d, a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 ] for tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ]
I1110 01:20:11.849225 29728 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
I1110 01:20:11.850085 10226 default_executor.cpp:546] Waiting for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d of task 'c96eb523-0365-49b2-8b3b-78976ff28797'
I1110 01:20:11.850145 29734 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
I1110 01:20:11.850405 10226 default_executor.cpp:546] Waiting for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 of task '08848440-4c0e-4ad6-a0a9-b5947c5d21ba'
I1110 01:20:11.850746 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
I1110 01:20:11.851114 29726 slave.cpp:3740] Handling status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.851552 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
I1110 01:20:11.851727 29726 slave.cpp:3740] Handling status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.852295 29726 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.852826 29726 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.853938 29724 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.854076 29724 status_update_manager.cpp:500] Creating StatusUpdate stream for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.854460 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54641
I1110 01:20:11.854559 29726 http.cpp:353] Processing call WAIT_NESTED_CONTAINER
I1110 01:20:11.854610 29724 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
I1110 01:20:11.855126 29724 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.855190 29724 status_update_manager.cpp:500] Creating StatusUpdate stream for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.855200 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54642
I1110 01:20:11.855409 29726 http.cpp:353] Processing call WAIT_NESTED_CONTAINER
I1110 01:20:11.855608 29724 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
I1110 01:20:11.855803 29726 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
I1110 01:20:11.856199 29726 slave.cpp:4075] Status update manager successfully handled status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.856346 29725 master.cpp:5760] Status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:11.856439 29725 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.856598 29726 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
I1110 01:20:11.856828 29726 slave.cpp:4075] Status update manager successfully handled status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.856998 29725 master.cpp:7715] Updating the state of task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1110 01:20:11.857322 29725 master.cpp:5760] Status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:11.857386 29725 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.857787 29725 master.cpp:7715] Updating the state of task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1110 01:20:11.858124 10226 default_executor.cpp:130] Received ACKNOWLEDGED event
I1110 01:20:11.858530 29725 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.859519 29732 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.859676 10233 default_executor.cpp:130] Received ACKNOWLEDGED event
../../src/tests/default_executor_tests.cpp:338: Failure
Value of: runningUpdate1->status().task_id()
  Actual: 08848440-4c0e-4ad6-a0a9-b5947c5d21ba
Expected: taskInfo1.task_id()
Which is: c96eb523-0365-49b2-8b3b-78976ff28797
../../src/tests/default_executor_tests.cpp:342: Failure
Value of: runningUpdate2->status().task_id()
  Actual: c96eb523-0365-49b2-8b3b-78976ff28797
Expected: taskInfo2.task_id()
Which is: 08848440-4c0e-4ad6-a0a9-b5947c5d21ba
I1110 01:20:11.861587 29733 scheduler.cpp:235] Sending ACKNOWLEDGE call to http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.861948 29733 scheduler.cpp:235] Sending ACKNOWLEDGE call to http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.862280 29733 scheduler.cpp:235] Sending KILL call to http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.862632 29721 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 01:20:11.863528 29719 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
I1110 01:20:11.863664 29719 master.cpp:4870] Processing ACKNOWLEDGE call 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87 for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
I1110 01:20:11.864003 29732 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
W1110 01:20:11.864294 29732 status_update_manager.cpp:769] Unexpected status update acknowledgement (received 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87, expecting d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
E1110 01:20:11.864575 29726 slave.cpp:3015] Failed to handle status update acknowledgement (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000: Duplicate acknowledgement
I1110 01:20:11.864804 29723 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 01:20:11.865231 29723 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 01:20:11.866297 29722 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
I1110 01:20:11.866420 29722 master.cpp:4870] Processing ACKNOWLEDGE call d91c7deb-4646-4b4e-ba1a-5650a256e8d2 for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
I1110 01:20:11.867036 29726 status_update_manager.cpp:395] Received status update acknowledgement (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.867076 29722 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
I1110 01:20:11.867291 29722 master.cpp:4762] Telling agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) to kill task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
W1110 01:20:11.867297 29726 status_update_manager.cpp:769] Unexpected status update acknowledgement (received d91c7deb-4646-4b4e-ba1a-5650a256e8d2, expecting 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.867449 29733 slave.cpp:2344] Asked to kill task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
E1110 01:20:11.867710 29733 slave.cpp:3015] Failed to handle status update acknowledgement (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000: Duplicate acknowledgement
I1110 01:20:11.869391 10228 default_executor.cpp:130] Received KILL event
I1110 01:20:11.869498 10228 default_executor.cpp:810] Received kill for task 'c96eb523-0365-49b2-8b3b-78976ff28797'
I1110 01:20:11.869544 10228 default_executor.cpp:694] Shutting down
I1110 01:20:11.870112 10221 default_executor.cpp:782] Killing child container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
I1110 01:20:11.870338 10221 default_executor.cpp:782] Killing child container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
I1110 01:20:11.870965 29729 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.871399 29730 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.871984 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54643
I1110 01:20:11.872088 29723 http.cpp:353] Processing call KILL_NESTED_CONTAINER
I1110 01:20:11.872284 29726 containerizer.cpp:1973] Destroying container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d in RUNNING state
I1110 01:20:11.872340 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54643
I1110 01:20:11.872416 29723 http.cpp:353] Processing call KILL_NESTED_CONTAINER
I1110 01:20:11.872597 29726 launcher.cpp:143] Asked to destroy container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
I1110 01:20:11.877090 29726 containerizer.cpp:1973] Destroying container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 in RUNNING state
I1110 01:20:11.877320 29726 launcher.cpp:143] Asked to destroy container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
I1110 01:20:11.962539 29729 containerizer.cpp:2336] Container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d has exited
I1110 01:20:11.963811 29733 provisioner.cpp:324] Ignoring destroy request for unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
I1110 01:20:11.963851 29729 containerizer.cpp:2336] Container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 has exited
I1110 01:20:11.964437 29729 containerizer.cpp:2252] Checkpointing termination state to nested container's runtime directory '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d/termination'
I1110 01:20:11.965940 29728 provisioner.cpp:324] Ignoring destroy request for unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
I1110 01:20:11.966202 29732 containerizer.cpp:2252] Checkpointing termination state to nested container's runtime directory '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611/termination'
I1110 01:20:11.970046 10231 default_executor.cpp:663] Successfully waited for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d of task 'c96eb523-0365-49b2-8b3b-78976ff28797' in state TASK_KILLED
I1110 01:20:11.970501 10231 default_executor.cpp:663] Successfully waited for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 of task '08848440-4c0e-4ad6-a0a9-b5947c5d21ba' in state TASK_KILLED
I1110 01:20:11.970559 10231 default_executor.cpp:768] Terminating after 1secs
I1110 01:20:11.971288 29723 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
I1110 01:20:11.972218 29728 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
I1110 01:20:11.972488 29728 slave.cpp:3740] Handling status update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.974179 29719 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
I1110 01:20:11.975229 29726 status_update_manager.cpp:323] Received status update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.975278 29729 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
I1110 01:20:11.975517 29729 slave.cpp:3740] Handling status update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.976048 29729 slave.cpp:4075] Status update manager successfully handled status update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.978132 29720 status_update_manager.cpp:323] Received status update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.978482 29725 slave.cpp:4075] Status update manager successfully handled status update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:12.494274 29725 hierarchical.cpp:1880] Filtered offer with cpus(*):1.7; mem(*):928; disk(*):928; ports(*):[31000-32000] on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:12.494357 29725 hierarchical.cpp:1694] No allocations performed
I1110 01:20:12.494402 29725 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:12.494491 29725 hierarchical.cpp:1286] Performed allocation for 1 agents in 915780ns
I1110 01:20:13.071280 29734 containerizer.cpp:2336] Container a283035b-25d3-4b48-b59a-964e5a4dfa06 has exited
I1110 01:20:13.071339 29734 containerizer.cpp:1973] Destroying container a283035b-25d3-4b48-b59a-964e5a4dfa06 in RUNNING state
I1110 01:20:13.071746 29734 launcher.cpp:143] Asked to destroy container a283035b-25d3-4b48-b59a-964e5a4dfa06
I1110 01:20:13.076637 29723 provisioner.cpp:324] Ignoring destroy request for unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06
I1110 01:20:13.077929 29721 slave.cpp:4672] Executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 exited with status 0
I1110 01:20:13.078433 29732 master.cpp:5884] Executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679): exited with status 0
I1110 01:20:13.078538 29732 master.cpp:7840] Removing executor 'default' with resources cpus(*):0.1; mem(*):32; disk(*):32 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:13.079448 29730 hierarchical.cpp:1018] Recovered cpus(*):0.1; mem(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):0.2; mem(*):64; disk(*):64) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:13.081049 29723 scheduler.cpp:675] Enqueuing event FAILURE received from http://172.17.0.3:52462/master/api/v1/scheduler

GMOCK WARNING:
Uninteresting mock function call - returning directly.
    Function call: failure(0x7fff1aa9a950, @0x2ab91c02dd10 48-byte object <90-62 27-EC B8-2A 00-00 00-00 00-00 00-00 00-00 07-00 00-00 00-00 00-00 10-CE 01-1C B9-2A 00-00 70-CE 02-1C B9-2A 00-00 00-00 00-00 B8-2A 00-00>)
Stack trace:
I1110 01:20:13.496551 29730 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:13.496680 29730 hierarchical.cpp:1286] Performed allocation for 1 agents in 1.498625ms
I1110 01:20:13.497339 29729 master.cpp:6574] Sending 1 offers to framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:13.499797 29721 scheduler.cpp:675] Enqueuing event OFFERS received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:14.497707 29732 hierarchical.cpp:1694] No allocations performed
I1110 01:20:14.497795 29732 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:14.497895 29732 hierarchical.cpp:1286] Performed allocation for 1 agents in 410313ns
I1110 01:20:15.499423 29728 hierarchical.cpp:1694] No allocations performed
I1110 01:20:15.499526 29728 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:15.499658 29728 hierarchical.cpp:1286] Performed allocation for 1 agents in 547651ns
I1110 01:20:16.500463 29729 hierarchical.cpp:1694] No allocations performed
I1110 01:20:16.500581 29729 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:16.500699 29729 hierarchical.cpp:1286] Performed allocation for 1 agents in 505442ns
I1110 01:20:17.502176 29727 hierarchical.cpp:1694] No allocations performed
I1110 01:20:17.502262 29727 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:17.502367 29727 hierarchical.cpp:1286] Performed allocation for 1 agents in 464526ns
I1110 01:20:18.503680 29723 hierarchical.cpp:1694] No allocations performed
I1110 01:20:18.503762 29723 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:18.503851 29723 hierarchical.cpp:1286] Performed allocation for 1 agents in 425163ns
I1110 01:20:19.505476 29723 hierarchical.cpp:1694] No allocations performed
I1110 01:20:19.505586 29723 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:19.505705 29723 hierarchical.cpp:1286] Performed allocation for 1 agents in 590762ns
I1110 01:20:20.507310 29724 hierarchical.cpp:1694] No allocations performed
I1110 01:20:20.507390 29724 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:20.507477 29724 hierarchical.cpp:1286] Performed allocation for 1 agents in 411721ns
I1110 01:20:21.508368 29729 hierarchical.cpp:1694] No allocations performed
I1110 01:20:21.508458 29729 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:21.508564 29729 hierarchical.cpp:1286] Performed allocation for 1 agents in 432440ns
W1110 01:20:21.855908 29728 status_update_manager.cpp:478] Resending status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.856066 29728 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
I1110 01:20:21.856652 29734 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
W1110 01:20:21.857002 29727 status_update_manager.cpp:478] Resending status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.857069 29727 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
I1110 01:20:21.857378 29733 master.cpp:5760] Status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.857475 29733 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.857662 29722 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
I1110 01:20:21.858206 29733 master.cpp:7715] Updating the state of task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_RUNNING)
I1110 01:20:21.858988 29733 master.cpp:5760] Status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.859259 29733 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.859647 29725 hierarchical.cpp:1018] Recovered cpus(*):0.1; mem(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):1.9; mem(*):992; disk(*):992; ports(*):[31000-32000]) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.859845 29725 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:21.859979 29733 master.cpp:7715] Updating the state of task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_RUNNING)
I1110 01:20:21.860970 29729 hierarchical.cpp:1018] Recovered cpus(*):0.1; mem(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000]) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.861687 29725 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
../../src/tests/default_executor_tests.cpp:400: Failure
Value of: killedUpdate1->status().state()
  Actual: TASK_RUNNING
Expected: TASK_KILLED
I1110 01:20:21.864666 29721 master.cpp:1297] Framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) disconnected
I1110 01:20:21.864765 29721 master.cpp:2918] Disconnecting framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:21.864820 29721 master.cpp:2942] Deactivating framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:21.865016 29732 hierarchical.cpp:386] Deactivated framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
W1110 01:20:21.865586 29721 master.hpp:2264] Master attempted to send message to disconnected framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
W1110 01:20:21.865691 29721 master.hpp:2270] Unable to send event to framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default): connection closed
I1110 01:20:21.865777 29721 master.cpp:1310] Giving framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) 0ns to failover
I1110 01:20:21.866277 29728 hierarchical.cpp:1018] Recovered cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.867295 29733 master.cpp:6426] Framework failover timeout, removing framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:21.867328 29733 master.cpp:7170] Removing framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:21.867539 29733 master.cpp:7715] Updating the state of task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
I1110 01:20:21.867559 29731 slave.cpp:2575] Asked to shut down framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 by master@172.17.0.3:52462
I1110 01:20:21.867617 29731 slave.cpp:2600] Shutting down framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.867585 29733 master.cpp:7811] Removing task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba with resources cpus(*):0.1; mem(*):32; disk(*):32 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.867707 29731 slave.cpp:4776] Cleaning up executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (via HTTP)
I1110 01:20:21.867904 29733 master.cpp:7715] Updating the state of task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
I1110 01:20:21.868042 29729 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06' for gc 6.99998999732444days in the future
I1110 01:20:21.867939 29733 master.cpp:7811] Removing task c96eb523-0365-49b2-8b3b-78976ff28797 with resources cpus(*):0.1; mem(*):32; disk(*):32 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.868232 29731 slave.cpp:4864] Cleaning up framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.868252 29729 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default' for gc 6.99998999732444days in the future
I1110 01:20:21.868422 29725 status_update_manager.cpp:285] Closing status update streams for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.868484 29725 status_update_manager.cpp:531] Cleaning up status update stream for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.868777 29721 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000' for gc 6.99998999732444days in the future
I1110 01:20:21.868926 29720 hierarchical.cpp:337] Removed framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.869235 29725 status_update_manager.cpp:531] Cleaning up status update stream for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.870568 29730 slave.cpp:787] Agent terminating
I1110 01:20:21.870795 29732 master.cpp:1258] Agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) disconnected
I1110 01:20:21.870825 29732 master.cpp:2977] Disconnecting agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.870930 29732 master.cpp:2996] Deactivating agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.871158 29726 hierarchical.cpp:584] Agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 deactivated
I1110 01:20:21.876986 29733 master.cpp:1097] Master terminating
I1110 01:20:21.877754 29724 hierarchical.cpp:517] Removed agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
[  FAILED  ] MesosContainerizer/DefaultExecutorTest.KillTask/0, where GetParam() = "mesos" (10406 ms)
{noformat}

  was:


{noformat:title=}
[ RUN      ] MesosContainerizer/DefaultExecutorTest.KillTask/0
I1110 01:20:11.482097 29700 cluster.cpp:158] Creating default 'local' authorizer
I1110 01:20:11.485241 29700 leveldb.cpp:174] Opened db in 2.774513ms
I1110 01:20:11.486237 29700 leveldb.cpp:181] Compacted db in 953614ns
I1110 01:20:11.486299 29700 leveldb.cpp:196] Created db iterator in 24739ns
I1110 01:20:11.486325 29700 leveldb.cpp:202] Seeked to beginning of db in 2300ns
I1110 01:20:11.486344 29700 leveldb.cpp:271] Iterated through 0 keys in the db in 378ns
I1110 01:20:11.486399 29700 replica.cpp:776] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1110 01:20:11.486933 29733 recover.cpp:451] Starting replica recovery
I1110 01:20:11.487289 29733 recover.cpp:477] Replica is in EMPTY status
I1110 01:20:11.488503 29721 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from __req_res__(7318)@172.17.0.3:52462
I1110 01:20:11.488855 29727 recover.cpp:197] Received a recover response from a replica in EMPTY status
I1110 01:20:11.489398 29729 recover.cpp:568] Updating replica status to STARTING
I1110 01:20:11.490223 29723 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 575135ns
I1110 01:20:11.490284 29732 master.cpp:380] Master d28fbae1-c3dc-45fa-8384-32ab9395a975 (3a31be8bf679) started on 172.17.0.3:52462
I1110 01:20:11.490317 29732 master.cpp:382] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/k50x7x/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --quiet="false" --recovery_agent_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-1.2.0/_inst/share/mesos/webui" --work_dir="/tmp/k50x7x/master" --zk_session_timeout="10secs"
I1110 01:20:11.490696 29732 master.cpp:432] Master only allowing authenticated frameworks to register
I1110 01:20:11.490712 29732 master.cpp:446] Master only allowing authenticated agents to register
I1110 01:20:11.490720 29732 master.cpp:459] Master only allowing authenticated HTTP frameworks to register
I1110 01:20:11.490730 29732 credentials.hpp:37] Loading credentials for authentication from '/tmp/k50x7x/credentials'
I1110 01:20:11.490281 29723 replica.cpp:320] Persisted replica status to STARTING
I1110 01:20:11.491210 29732 master.cpp:504] Using default 'crammd5' authenticator
I1110 01:20:11.491225 29720 recover.cpp:477] Replica is in STARTING status
I1110 01:20:11.491394 29732 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1110 01:20:11.491621 29732 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1110 01:20:11.491770 29732 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1110 01:20:11.491937 29732 master.cpp:584] Authorization enabled
I1110 01:20:11.492276 29725 whitelist_watcher.cpp:77] No whitelist given
I1110 01:20:11.492310 29723 hierarchical.cpp:149] Initialized hierarchical allocator process
I1110 01:20:11.492569 29721 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from __req_res__(7319)@172.17.0.3:52462
I1110 01:20:11.492830 29719 recover.cpp:197] Received a recover response from a replica in STARTING status
I1110 01:20:11.493371 29720 recover.cpp:568] Updating replica status to VOTING
I1110 01:20:11.494002 29721 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 367673ns
I1110 01:20:11.494032 29721 replica.cpp:320] Persisted replica status to VOTING
I1110 01:20:11.494218 29734 recover.cpp:582] Successfully joined the Paxos group
I1110 01:20:11.494469 29734 recover.cpp:466] Recover process terminated
I1110 01:20:11.495633 29733 master.cpp:2033] Elected as the leading master!
I1110 01:20:11.495685 29733 master.cpp:1560] Recovering from registrar
I1110 01:20:11.495880 29720 registrar.cpp:329] Recovering registrar
I1110 01:20:11.496842 29730 log.cpp:553] Attempting to start the writer
I1110 01:20:11.498610 29725 replica.cpp:493] Replica received implicit promise request from __req_res__(7320)@172.17.0.3:52462 with proposal 1
I1110 01:20:11.499179 29725 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 524192ns
I1110 01:20:11.499213 29725 replica.cpp:342] Persisted promised to 1
I1110 01:20:11.500258 29726 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1110 01:20:11.501874 29731 replica.cpp:388] Replica received explicit promise request from __req_res__(7321)@172.17.0.3:52462 for position 0 with proposal 2
I1110 01:20:11.502413 29731 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 484138ns
I1110 01:20:11.502457 29731 replica.cpp:708] Persisted action NOP at position 0
I1110 01:20:11.503885 29720 replica.cpp:537] Replica received write request for position 0 from __req_res__(7322)@172.17.0.3:52462
I1110 01:20:11.503985 29720 leveldb.cpp:436] Reading position from leveldb took 56800ns
I1110 01:20:11.504534 29720 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 467426ns
I1110 01:20:11.504566 29720 replica.cpp:708] Persisted action NOP at position 0
I1110 01:20:11.505470 29721 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1110 01:20:11.505988 29721 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 479078ns
I1110 01:20:11.506021 29721 replica.cpp:708] Persisted action NOP at position 0
I1110 01:20:11.506706 29732 log.cpp:569] Writer started with ending position 0
I1110 01:20:11.508041 29734 leveldb.cpp:436] Reading position from leveldb took 50010ns
I1110 01:20:11.509210 29733 registrar.cpp:362] Successfully fetched the registry (0B) in 13.068032ms
I1110 01:20:11.509356 29733 registrar.cpp:461] Applied 1 operations in 27124ns; attempting to update the registry
I1110 01:20:11.510251 29732 log.cpp:577] Attempting to append 168 bytes to the log
I1110 01:20:11.510457 29724 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1110 01:20:11.511355 29728 replica.cpp:537] Replica received write request for position 1 from __req_res__(7323)@172.17.0.3:52462
I1110 01:20:11.511828 29728 leveldb.cpp:341] Persisting action (187 bytes) to leveldb took 423890ns
I1110 01:20:11.511859 29728 replica.cpp:708] Persisted action APPEND at position 1
I1110 01:20:11.512572 29734 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1110 01:20:11.513051 29734 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 368122ns
I1110 01:20:11.513087 29734 replica.cpp:708] Persisted action APPEND at position 1
I1110 01:20:11.514302 29726 registrar.cpp:506] Successfully updated the registry in 4.862976ms
I1110 01:20:11.514503 29726 registrar.cpp:392] Successfully recovered registrar
I1110 01:20:11.514593 29728 log.cpp:596] Attempting to truncate the log to 1
I1110 01:20:11.514760 29730 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1110 01:20:11.515249 29723 master.cpp:1676] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
I1110 01:20:11.515534 29722 hierarchical.cpp:176] Skipping recovery of hierarchical allocator: nothing to recover
I1110 01:20:11.516068 29722 replica.cpp:537] Replica received write request for position 2 from __req_res__(7324)@172.17.0.3:52462
I1110 01:20:11.516619 29722 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 497823ns
I1110 01:20:11.516652 29722 replica.cpp:708] Persisted action TRUNCATE at position 2
I1110 01:20:11.517526 29734 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1110 01:20:11.518040 29734 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 384129ns
I1110 01:20:11.518111 29734 leveldb.cpp:399] Deleting ~1 keys from leveldb took 39398ns
I1110 01:20:11.518138 29734 replica.cpp:708] Persisted action TRUNCATE at position 2
I1110 01:20:11.525027 29700 containerizer.cpp:201] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni
W1110 01:20:11.525806 29700 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges, but is running as user mesos
W1110 01:20:11.526018 29700 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1110 01:20:11.527331 29700 cluster.cpp:435] Creating default 'local' authorizer
I1110 01:20:11.528741 29725 slave.cpp:208] Mesos agent started on (571)@172.17.0.3:52462
I1110 01:20:11.528789 29725 slave.cpp:209] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --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/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_command_executor="false" --http_credentials="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/http_credentials" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.2.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --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;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD"
I1110 01:20:11.529228 29725 credentials.hpp:86] Loading credential for authentication from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/credential'
I1110 01:20:11.529305 29700 scheduler.cpp:176] Version: 1.2.0
I1110 01:20:11.529436 29725 slave.cpp:346] Agent using credential for: test-principal
I1110 01:20:11.529464 29725 credentials.hpp:37] Loading credentials for authentication from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/http_credentials'
I1110 01:20:11.529747 29725 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1110 01:20:11.529855 29729 scheduler.cpp:469] New master detected at master@172.17.0.3:52462
I1110 01:20:11.529884 29729 scheduler.cpp:478] Waiting for 0ns before initiating a re-(connection) attempt with the master
I1110 01:20:11.531039 29725 slave.cpp:533] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1110 01:20:11.531113 29725 slave.cpp:541] Agent attributes: [  ]
I1110 01:20:11.531126 29725 slave.cpp:546] Agent hostname: 3a31be8bf679
I1110 01:20:11.532897 29723 state.cpp:57] Recovering state from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/meta'
I1110 01:20:11.533222 29727 status_update_manager.cpp:203] Recovering status update manager
I1110 01:20:11.533269 29721 scheduler.cpp:353] Connected with the master at http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.533627 29734 containerizer.cpp:557] Recovering containerizer
I1110 01:20:11.534519 29725 scheduler.cpp:235] Sending SUBSCRIBE call to http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.535482 29732 provisioner.cpp:253] Provisioner recovery complete
I1110 01:20:11.535652 29734 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 01:20:11.535815 29724 slave.cpp:5411] Finished recovery
I1110 01:20:11.536440 29724 slave.cpp:5585] Querying resource estimator for oversubscribable resources
I1110 01:20:11.536898 29721 slave.cpp:915] New master detected at master@172.17.0.3:52462
I1110 01:20:11.536906 29731 status_update_manager.cpp:177] Pausing sending status updates
I1110 01:20:11.536941 29721 slave.cpp:974] Authenticating with master master@172.17.0.3:52462
I1110 01:20:11.537076 29721 slave.cpp:985] Using default CRAM-MD5 authenticatee
I1110 01:20:11.537214 29733 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54635
I1110 01:20:11.537353 29719 authenticatee.cpp:121] Creating new client SASL connection
I1110 01:20:11.537256 29721 slave.cpp:947] Detecting new master
I1110 01:20:11.537591 29733 master.cpp:2329] Received subscription request for HTTP framework 'default'
I1110 01:20:11.537611 29721 slave.cpp:5599] Received oversubscribable resources {} from the resource estimator
I1110 01:20:11.537701 29733 master.cpp:2069] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1110 01:20:11.538077 29733 master.cpp:6745] Authenticating slave(571)@172.17.0.3:52462
I1110 01:20:11.538208 29732 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1121)@172.17.0.3:52462
I1110 01:20:11.538291 29733 master.cpp:2427] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
I1110 01:20:11.538508 29731 authenticator.cpp:98] Creating new server SASL connection
I1110 01:20:11.538782 29720 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1110 01:20:11.538823 29720 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1110 01:20:11.539227 29730 hierarchical.cpp:275] Added framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.539317 29722 master.hpp:2161] Sending heartbeat to d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.539331 29730 hierarchical.cpp:1694] No allocations performed
I1110 01:20:11.539696 29730 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:11.539818 29730 hierarchical.cpp:1286] Performed allocation for 0 agents in 554795ns
I1110 01:20:11.540354 29720 authenticator.cpp:204] Received SASL authentication start
I1110 01:20:11.540361 29719 scheduler.cpp:675] Enqueuing event SUBSCRIBED received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.540438 29720 authenticator.cpp:326] Authentication requires more steps
I1110 01:20:11.540750 29720 authenticatee.cpp:259] Received SASL authentication step
I1110 01:20:11.541038 29721 authenticator.cpp:232] Received SASL authentication step
I1110 01:20:11.541081 29721 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3a31be8bf679' server FQDN: '3a31be8bf679' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I1110 01:20:11.541112 29721 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I1110 01:20:11.541147 29719 scheduler.cpp:675] Enqueuing event HEARTBEAT received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.541178 29721 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1110 01:20:11.541260 29721 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3a31be8bf679' server FQDN: '3a31be8bf679' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I1110 01:20:11.541285 29721 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1110 01:20:11.541307 29721 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1110 01:20:11.541342 29721 authenticator.cpp:318] Authentication success
I1110 01:20:11.541517 29733 authenticatee.cpp:299] Authentication success
I1110 01:20:11.541586 29720 master.cpp:6775] Successfully authenticated principal 'test-principal' at slave(571)@172.17.0.3:52462
I1110 01:20:11.541826 29721 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1121)@172.17.0.3:52462
I1110 01:20:11.542129 29730 slave.cpp:1069] Successfully authenticated with master master@172.17.0.3:52462
I1110 01:20:11.542362 29730 slave.cpp:1483] Will retry registration in 9.532818ms if necessary
I1110 01:20:11.542577 29733 master.cpp:5154] Registering agent at slave(571)@172.17.0.3:52462 (3a31be8bf679) with id d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
I1110 01:20:11.543083 29731 registrar.cpp:461] Applied 1 operations in 60476ns; attempting to update the registry
I1110 01:20:11.543926 29729 log.cpp:577] Attempting to append 337 bytes to the log
I1110 01:20:11.544077 29723 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I1110 01:20:11.545238 29731 replica.cpp:537] Replica received write request for position 3 from __req_res__(7325)@172.17.0.3:52462
I1110 01:20:11.546116 29731 leveldb.cpp:341] Persisting action (356 bytes) to leveldb took 825474ns
I1110 01:20:11.546169 29731 replica.cpp:708] Persisted action APPEND at position 3
I1110 01:20:11.547427 29725 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I1110 01:20:11.547969 29725 leveldb.cpp:341] Persisting action (358 bytes) to leveldb took 483290ns
I1110 01:20:11.548005 29725 replica.cpp:708] Persisted action APPEND at position 3
I1110 01:20:11.550129 29732 registrar.cpp:506] Successfully updated the registry in 6.962944ms
I1110 01:20:11.550396 29726 log.cpp:596] Attempting to truncate the log to 3
I1110 01:20:11.550614 29720 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I1110 01:20:11.551375 29723 slave.cpp:4263] Received ping from slave-observer(531)@172.17.0.3:52462
I1110 01:20:11.551326 29734 master.cpp:5225] Registered agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1110 01:20:11.551720 29730 replica.cpp:537] Replica received write request for position 4 from __req_res__(7326)@172.17.0.3:52462
I1110 01:20:11.551892 29723 slave.cpp:1115] Registered with master master@172.17.0.3:52462; given agent ID d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
I1110 01:20:11.551975 29723 fetcher.cpp:86] Clearing fetcher cache
I1110 01:20:11.552170 29732 hierarchical.cpp:485] Added agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I1110 01:20:11.552338 29721 status_update_manager.cpp:184] Resuming sending status updates
I1110 01:20:11.552486 29730 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 709727ns
I1110 01:20:11.552655 29723 slave.cpp:1138] Checkpointing SlaveInfo to '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/meta/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/slave.info'
I1110 01:20:11.552609 29730 replica.cpp:708] Persisted action TRUNCATE at position 4
I1110 01:20:11.553383 29731 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
I1110 01:20:11.553409 29723 slave.cpp:1175] Forwarding total oversubscribed resources {}
I1110 01:20:11.553653 29732 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:11.553671 29727 master.cpp:5624] Received update of agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) with total oversubscribed resources {}
I1110 01:20:11.553755 29732 hierarchical.cpp:1309] Performed allocation for agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 in 1.528714ms
I1110 01:20:11.553975 29731 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 525057ns
I1110 01:20:11.554072 29731 leveldb.cpp:399] Deleting ~2 keys from leveldb took 59750ns
I1110 01:20:11.554065 29732 hierarchical.cpp:555] Agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679) updated with oversubscribed resources {} (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000])
I1110 01:20:11.554105 29731 replica.cpp:708] Persisted action TRUNCATE at position 4
I1110 01:20:11.554260 29732 hierarchical.cpp:1694] No allocations performed
I1110 01:20:11.554314 29732 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:11.554345 29727 master.cpp:6574] Sending 1 offers to framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:11.554379 29732 hierarchical.cpp:1309] Performed allocation for agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 in 239597ns
I1110 01:20:11.556370 29724 scheduler.cpp:675] Enqueuing event OFFERS received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.559177 29730 scheduler.cpp:235] Sending ACCEPT call to http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.560282 29734 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 01:20:11.561323 29733 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
I1110 01:20:11.562417 29733 master.cpp:3581] Processing ACCEPT call for offers: [ d28fbae1-c3dc-45fa-8384-32ab9395a975-O0 ] on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:11.562584 29733 master.cpp:3173] Authorizing framework principal 'test-principal' to launch task c96eb523-0365-49b2-8b3b-78976ff28797
I1110 01:20:11.563097 29733 master.cpp:3173] Authorizing framework principal 'test-principal' to launch task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba
I1110 01:20:11.567248 29733 master.cpp:8337] Adding task c96eb523-0365-49b2-8b3b-78976ff28797 with resources cpus(*):0.1; mem(*):32; disk(*):32 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679)
I1110 01:20:11.567651 29733 master.cpp:8337] Adding task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba with resources cpus(*):0.1; mem(*):32; disk(*):32 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679)
I1110 01:20:11.567845 29733 master.cpp:4438] Launching task group { 08848440-4c0e-4ad6-a0a9-b5947c5d21ba, c96eb523-0365-49b2-8b3b-78976ff28797 } of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) with resources cpus(*):0.2; mem(*):64; disk(*):64 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:11.568495 29724 slave.cpp:1547] Got assigned task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.569128 29729 hierarchical.cpp:1018] Recovered cpus(*):1.7; mem(*):928; disk(*):928; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):0.3; mem(*):96; disk(*):96) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.569211 29729 hierarchical.cpp:1055] Framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 filtered agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 for 5secs
I1110 01:20:11.570461 29724 slave.cpp:1709] Launching task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.571297 29724 paths.cpp:530] Trying to chown '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06' to user 'mesos'
I1110 01:20:11.580168 29724 slave.cpp:6319] Launching executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 with resources cpus(*):0.1; mem(*):32; disk(*):32 in work directory '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06'
I1110 01:20:11.580930 29734 containerizer.cpp:940] Starting container a283035b-25d3-4b48-b59a-964e5a4dfa06 for executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.581110 29724 slave.cpp:2031] Queued task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] for executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.581214 29724 slave.cpp:868] Successfully attached file '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06'
I1110 01:20:11.585572 29722 containerizer.cpp:1480] Launching 'mesos-containerizer' with flags '--command="{"arguments":["mesos-default-executor","--launcher_dir=\/mesos\/mesos-1.2.0\/_build\/src"],"shell":false,"value":"\/mesos\/mesos-1.2.0\/_build\/src\/mesos-default-executor"}" --help="false" --pipe_read="60" --pipe_write="61" --pre_exec_commands="[]" --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06" --unshare_namespace_mnt="false" --user="mesos" --working_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06"'
I1110 01:20:11.588587 29722 launcher.cpp:127] Forked child with pid '10191' for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06'
I1110 01:20:11.592996 29734 fetcher.cpp:345] Starting to fetch URIs for container: a283035b-25d3-4b48-b59a-964e5a4dfa06, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06
I1110 01:20:11.777189 10229 executor.cpp:189] Version: 1.2.0
I1110 01:20:11.786099 29719 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
I1110 01:20:11.787382 29722 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54638
I1110 01:20:11.787693 29722 slave.cpp:3086] Received Subscribe request for HTTP executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.790436 29730 slave.cpp:2276] Sending queued task group task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] to executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (via HTTP)
I1110 01:20:11.795663 10221 default_executor.cpp:130] Received SUBSCRIBED event
I1110 01:20:11.797111 10221 default_executor.cpp:134] Subscribed executor on 3a31be8bf679
I1110 01:20:11.797611 10221 default_executor.cpp:130] Received LAUNCH_GROUP event
I1110 01:20:11.801981 29729 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.802435 29729 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.803306 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54640
I1110 01:20:11.803452 29723 http.cpp:353] Processing call LAUNCH_NESTED_CONTAINER
I1110 01:20:11.803827 29727 containerizer.cpp:1685] Starting nested container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
I1110 01:20:11.803865 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54640
I1110 01:20:11.803978 29723 http.cpp:353] Processing call LAUNCH_NESTED_CONTAINER
I1110 01:20:11.804236 29727 containerizer.cpp:1709] Trying to chown '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d' to user 'mesos'
I1110 01:20:11.814858 29727 containerizer.cpp:1685] Starting nested container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
I1110 01:20:11.815129 29727 containerizer.cpp:1709] Trying to chown '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611' to user 'mesos'
I1110 01:20:11.824666 29727 containerizer.cpp:1480] Launching 'mesos-containerizer' with flags '--command="{"shell":true,"value":"sleep 1000"}" --help="false" --pipe_read="63" --pipe_write="64" --pre_exec_commands="[]" --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d" --unshare_namespace_mnt="false" --user="mesos" --working_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d"'
I1110 01:20:11.826855 29727 launcher.cpp:127] Forked child with pid '10240' for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d'
I1110 01:20:11.828918 29727 containerizer.cpp:1480] Launching 'mesos-containerizer' with flags '--command="{"shell":true,"value":"sleep 1000"}" --help="false" --pipe_read="65" --pipe_write="66" --pre_exec_commands="[]" --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611" --unshare_namespace_mnt="false" --user="mesos" --working_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611"'
I1110 01:20:11.831428 29727 launcher.cpp:127] Forked child with pid '10241' for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611'
I1110 01:20:11.834421 29731 fetcher.cpp:345] Starting to fetch URIs for container: a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d
I1110 01:20:11.837882 29731 fetcher.cpp:345] Starting to fetch URIs for container: a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611
I1110 01:20:11.847651 10227 default_executor.cpp:470] Successfully launched child containers [ a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d, a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 ] for tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ]
I1110 01:20:11.849225 29728 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
I1110 01:20:11.850085 10226 default_executor.cpp:546] Waiting for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d of task 'c96eb523-0365-49b2-8b3b-78976ff28797'
I1110 01:20:11.850145 29734 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
I1110 01:20:11.850405 10226 default_executor.cpp:546] Waiting for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 of task '08848440-4c0e-4ad6-a0a9-b5947c5d21ba'
I1110 01:20:11.850746 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
I1110 01:20:11.851114 29726 slave.cpp:3740] Handling status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.851552 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
I1110 01:20:11.851727 29726 slave.cpp:3740] Handling status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.852295 29726 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.852826 29726 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.853938 29724 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.854076 29724 status_update_manager.cpp:500] Creating StatusUpdate stream for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.854460 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54641
I1110 01:20:11.854559 29726 http.cpp:353] Processing call WAIT_NESTED_CONTAINER
I1110 01:20:11.854610 29724 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
I1110 01:20:11.855126 29724 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.855190 29724 status_update_manager.cpp:500] Creating StatusUpdate stream for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.855200 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54642
I1110 01:20:11.855409 29726 http.cpp:353] Processing call WAIT_NESTED_CONTAINER
I1110 01:20:11.855608 29724 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
I1110 01:20:11.855803 29726 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
I1110 01:20:11.856199 29726 slave.cpp:4075] Status update manager successfully handled status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.856346 29725 master.cpp:5760] Status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:11.856439 29725 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.856598 29726 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
I1110 01:20:11.856828 29726 slave.cpp:4075] Status update manager successfully handled status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.856998 29725 master.cpp:7715] Updating the state of task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1110 01:20:11.857322 29725 master.cpp:5760] Status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:11.857386 29725 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.857787 29725 master.cpp:7715] Updating the state of task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1110 01:20:11.858124 10226 default_executor.cpp:130] Received ACKNOWLEDGED event
I1110 01:20:11.858530 29725 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.859519 29732 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.859676 10233 default_executor.cpp:130] Received ACKNOWLEDGED event
../../src/tests/default_executor_tests.cpp:338: Failure
Value of: runningUpdate1->status().task_id()
  Actual: 08848440-4c0e-4ad6-a0a9-b5947c5d21ba
Expected: taskInfo1.task_id()
Which is: c96eb523-0365-49b2-8b3b-78976ff28797
../../src/tests/default_executor_tests.cpp:342: Failure
Value of: runningUpdate2->status().task_id()
  Actual: c96eb523-0365-49b2-8b3b-78976ff28797
Expected: taskInfo2.task_id()
Which is: 08848440-4c0e-4ad6-a0a9-b5947c5d21ba
I1110 01:20:11.861587 29733 scheduler.cpp:235] Sending ACKNOWLEDGE call to http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.861948 29733 scheduler.cpp:235] Sending ACKNOWLEDGE call to http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.862280 29733 scheduler.cpp:235] Sending KILL call to http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:11.862632 29721 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 01:20:11.863528 29719 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
I1110 01:20:11.863664 29719 master.cpp:4870] Processing ACKNOWLEDGE call 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87 for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
I1110 01:20:11.864003 29732 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
W1110 01:20:11.864294 29732 status_update_manager.cpp:769] Unexpected status update acknowledgement (received 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87, expecting d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
E1110 01:20:11.864575 29726 slave.cpp:3015] Failed to handle status update acknowledgement (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000: Duplicate acknowledgement
I1110 01:20:11.864804 29723 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 01:20:11.865231 29723 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I1110 01:20:11.866297 29722 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
I1110 01:20:11.866420 29722 master.cpp:4870] Processing ACKNOWLEDGE call d91c7deb-4646-4b4e-ba1a-5650a256e8d2 for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
I1110 01:20:11.867036 29726 status_update_manager.cpp:395] Received status update acknowledgement (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.867076 29722 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
I1110 01:20:11.867291 29722 master.cpp:4762] Telling agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) to kill task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
W1110 01:20:11.867297 29726 status_update_manager.cpp:769] Unexpected status update acknowledgement (received d91c7deb-4646-4b4e-ba1a-5650a256e8d2, expecting 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.867449 29733 slave.cpp:2344] Asked to kill task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
E1110 01:20:11.867710 29733 slave.cpp:3015] Failed to handle status update acknowledgement (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000: Duplicate acknowledgement
I1110 01:20:11.869391 10228 default_executor.cpp:130] Received KILL event
I1110 01:20:11.869498 10228 default_executor.cpp:810] Received kill for task 'c96eb523-0365-49b2-8b3b-78976ff28797'
I1110 01:20:11.869544 10228 default_executor.cpp:694] Shutting down
I1110 01:20:11.870112 10221 default_executor.cpp:782] Killing child container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
I1110 01:20:11.870338 10221 default_executor.cpp:782] Killing child container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
I1110 01:20:11.870965 29729 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.871399 29730 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
I1110 01:20:11.871984 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54643
I1110 01:20:11.872088 29723 http.cpp:353] Processing call KILL_NESTED_CONTAINER
I1110 01:20:11.872284 29726 containerizer.cpp:1973] Destroying container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d in RUNNING state
I1110 01:20:11.872340 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54643
I1110 01:20:11.872416 29723 http.cpp:353] Processing call KILL_NESTED_CONTAINER
I1110 01:20:11.872597 29726 launcher.cpp:143] Asked to destroy container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
I1110 01:20:11.877090 29726 containerizer.cpp:1973] Destroying container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 in RUNNING state
I1110 01:20:11.877320 29726 launcher.cpp:143] Asked to destroy container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
I1110 01:20:11.962539 29729 containerizer.cpp:2336] Container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d has exited
I1110 01:20:11.963811 29733 provisioner.cpp:324] Ignoring destroy request for unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
I1110 01:20:11.963851 29729 containerizer.cpp:2336] Container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 has exited
I1110 01:20:11.964437 29729 containerizer.cpp:2252] Checkpointing termination state to nested container's runtime directory '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d/termination'
I1110 01:20:11.965940 29728 provisioner.cpp:324] Ignoring destroy request for unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
I1110 01:20:11.966202 29732 containerizer.cpp:2252] Checkpointing termination state to nested container's runtime directory '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611/termination'
I1110 01:20:11.970046 10231 default_executor.cpp:663] Successfully waited for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d of task 'c96eb523-0365-49b2-8b3b-78976ff28797' in state TASK_KILLED
I1110 01:20:11.970501 10231 default_executor.cpp:663] Successfully waited for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 of task '08848440-4c0e-4ad6-a0a9-b5947c5d21ba' in state TASK_KILLED
I1110 01:20:11.970559 10231 default_executor.cpp:768] Terminating after 1secs
I1110 01:20:11.971288 29723 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
I1110 01:20:11.972218 29728 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
I1110 01:20:11.972488 29728 slave.cpp:3740] Handling status update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.974179 29719 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
I1110 01:20:11.975229 29726 status_update_manager.cpp:323] Received status update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.975278 29729 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
I1110 01:20:11.975517 29729 slave.cpp:3740] Handling status update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.976048 29729 slave.cpp:4075] Status update manager successfully handled status update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.978132 29720 status_update_manager.cpp:323] Received status update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:11.978482 29725 slave.cpp:4075] Status update manager successfully handled status update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:12.494274 29725 hierarchical.cpp:1880] Filtered offer with cpus(*):1.7; mem(*):928; disk(*):928; ports(*):[31000-32000] on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:12.494357 29725 hierarchical.cpp:1694] No allocations performed
I1110 01:20:12.494402 29725 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:12.494491 29725 hierarchical.cpp:1286] Performed allocation for 1 agents in 915780ns
I1110 01:20:13.071280 29734 containerizer.cpp:2336] Container a283035b-25d3-4b48-b59a-964e5a4dfa06 has exited
I1110 01:20:13.071339 29734 containerizer.cpp:1973] Destroying container a283035b-25d3-4b48-b59a-964e5a4dfa06 in RUNNING state
I1110 01:20:13.071746 29734 launcher.cpp:143] Asked to destroy container a283035b-25d3-4b48-b59a-964e5a4dfa06
I1110 01:20:13.076637 29723 provisioner.cpp:324] Ignoring destroy request for unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06
I1110 01:20:13.077929 29721 slave.cpp:4672] Executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 exited with status 0
I1110 01:20:13.078433 29732 master.cpp:5884] Executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679): exited with status 0
I1110 01:20:13.078538 29732 master.cpp:7840] Removing executor 'default' with resources cpus(*):0.1; mem(*):32; disk(*):32 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:13.079448 29730 hierarchical.cpp:1018] Recovered cpus(*):0.1; mem(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):0.2; mem(*):64; disk(*):64) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:13.081049 29723 scheduler.cpp:675] Enqueuing event FAILURE received from http://172.17.0.3:52462/master/api/v1/scheduler

GMOCK WARNING:
Uninteresting mock function call - returning directly.
    Function call: failure(0x7fff1aa9a950, @0x2ab91c02dd10 48-byte object <90-62 27-EC B8-2A 00-00 00-00 00-00 00-00 00-00 07-00 00-00 00-00 00-00 10-CE 01-1C B9-2A 00-00 70-CE 02-1C B9-2A 00-00 00-00 00-00 B8-2A 00-00>)
Stack trace:
I1110 01:20:13.496551 29730 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:13.496680 29730 hierarchical.cpp:1286] Performed allocation for 1 agents in 1.498625ms
I1110 01:20:13.497339 29729 master.cpp:6574] Sending 1 offers to framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:13.499797 29721 scheduler.cpp:675] Enqueuing event OFFERS received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:14.497707 29732 hierarchical.cpp:1694] No allocations performed
I1110 01:20:14.497795 29732 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:14.497895 29732 hierarchical.cpp:1286] Performed allocation for 1 agents in 410313ns
I1110 01:20:15.499423 29728 hierarchical.cpp:1694] No allocations performed
I1110 01:20:15.499526 29728 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:15.499658 29728 hierarchical.cpp:1286] Performed allocation for 1 agents in 547651ns
I1110 01:20:16.500463 29729 hierarchical.cpp:1694] No allocations performed
I1110 01:20:16.500581 29729 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:16.500699 29729 hierarchical.cpp:1286] Performed allocation for 1 agents in 505442ns
I1110 01:20:17.502176 29727 hierarchical.cpp:1694] No allocations performed
I1110 01:20:17.502262 29727 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:17.502367 29727 hierarchical.cpp:1286] Performed allocation for 1 agents in 464526ns
I1110 01:20:18.503680 29723 hierarchical.cpp:1694] No allocations performed
I1110 01:20:18.503762 29723 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:18.503851 29723 hierarchical.cpp:1286] Performed allocation for 1 agents in 425163ns
I1110 01:20:19.505476 29723 hierarchical.cpp:1694] No allocations performed
I1110 01:20:19.505586 29723 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:19.505705 29723 hierarchical.cpp:1286] Performed allocation for 1 agents in 590762ns
I1110 01:20:20.507310 29724 hierarchical.cpp:1694] No allocations performed
I1110 01:20:20.507390 29724 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:20.507477 29724 hierarchical.cpp:1286] Performed allocation for 1 agents in 411721ns
I1110 01:20:21.508368 29729 hierarchical.cpp:1694] No allocations performed
I1110 01:20:21.508458 29729 hierarchical.cpp:1789] No inverse offers to send out!
I1110 01:20:21.508564 29729 hierarchical.cpp:1286] Performed allocation for 1 agents in 432440ns
W1110 01:20:21.855908 29728 status_update_manager.cpp:478] Resending status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.856066 29728 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
I1110 01:20:21.856652 29734 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
W1110 01:20:21.857002 29727 status_update_manager.cpp:478] Resending status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.857069 29727 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
I1110 01:20:21.857378 29733 master.cpp:5760] Status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.857475 29733 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.857662 29722 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
I1110 01:20:21.858206 29733 master.cpp:7715] Updating the state of task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_RUNNING)
I1110 01:20:21.858988 29733 master.cpp:5760] Status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.859259 29733 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.859647 29725 hierarchical.cpp:1018] Recovered cpus(*):0.1; mem(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):1.9; mem(*):992; disk(*):992; ports(*):[31000-32000]) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.859845 29725 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
I1110 01:20:21.859979 29733 master.cpp:7715] Updating the state of task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_RUNNING)
I1110 01:20:21.860970 29729 hierarchical.cpp:1018] Recovered cpus(*):0.1; mem(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000]) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.861687 29725 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
../../src/tests/default_executor_tests.cpp:400: Failure
Value of: killedUpdate1->status().state()
  Actual: TASK_RUNNING
Expected: TASK_KILLED
I1110 01:20:21.864666 29721 master.cpp:1297] Framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) disconnected
I1110 01:20:21.864765 29721 master.cpp:2918] Disconnecting framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:21.864820 29721 master.cpp:2942] Deactivating framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:21.865016 29732 hierarchical.cpp:386] Deactivated framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
W1110 01:20:21.865586 29721 master.hpp:2264] Master attempted to send message to disconnected framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
W1110 01:20:21.865691 29721 master.hpp:2270] Unable to send event to framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default): connection closed
I1110 01:20:21.865777 29721 master.cpp:1310] Giving framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) 0ns to failover
I1110 01:20:21.866277 29728 hierarchical.cpp:1018] Recovered cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.867295 29733 master.cpp:6426] Framework failover timeout, removing framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:21.867328 29733 master.cpp:7170] Removing framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
I1110 01:20:21.867539 29733 master.cpp:7715] Updating the state of task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
I1110 01:20:21.867559 29731 slave.cpp:2575] Asked to shut down framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 by master@172.17.0.3:52462
I1110 01:20:21.867617 29731 slave.cpp:2600] Shutting down framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.867585 29733 master.cpp:7811] Removing task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba with resources cpus(*):0.1; mem(*):32; disk(*):32 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.867707 29731 slave.cpp:4776] Cleaning up executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (via HTTP)
I1110 01:20:21.867904 29733 master.cpp:7715] Updating the state of task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
I1110 01:20:21.868042 29729 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06' for gc 6.99998999732444days in the future
I1110 01:20:21.867939 29733 master.cpp:7811] Removing task c96eb523-0365-49b2-8b3b-78976ff28797 with resources cpus(*):0.1; mem(*):32; disk(*):32 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.868232 29731 slave.cpp:4864] Cleaning up framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.868252 29729 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default' for gc 6.99998999732444days in the future
I1110 01:20:21.868422 29725 status_update_manager.cpp:285] Closing status update streams for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.868484 29725 status_update_manager.cpp:531] Cleaning up status update stream for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.868777 29721 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000' for gc 6.99998999732444days in the future
I1110 01:20:21.868926 29720 hierarchical.cpp:337] Removed framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.869235 29725 status_update_manager.cpp:531] Cleaning up status update stream for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
I1110 01:20:21.870568 29730 slave.cpp:787] Agent terminating
I1110 01:20:21.870795 29732 master.cpp:1258] Agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) disconnected
I1110 01:20:21.870825 29732 master.cpp:2977] Disconnecting agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.870930 29732 master.cpp:2996] Deactivating agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
I1110 01:20:21.871158 29726 hierarchical.cpp:584] Agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 deactivated
I1110 01:20:21.876986 29733 master.cpp:1097] Master terminating
I1110 01:20:21.877754 29724 hierarchical.cpp:517] Removed agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
[  FAILED  ] MesosContainerizer/DefaultExecutorTest.KillTask/0, where GetParam() = "mesos" (10406 ms)
{noformat}


> MesosContainerizer/DefaultExecutorTest.KillTask/0 failing on ASF CI
> -------------------------------------------------------------------
>
>                 Key: MESOS-6569
>                 URL: https://issues.apache.org/jira/browse/MESOS-6569
>             Project: Mesos
>          Issue Type: Bug
>    Affects Versions: 1.1.0
>         Environment: https://builds.apache.org/job/Mesos/BUILDTOOL=autotools,COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu:14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)&&(!ubuntu-6)&&(!ubuntu-eu2)/
>            Reporter: Yan Xu
>              Labels: flaky, newbie
>
> {noformat:title=}
> [ RUN      ] MesosContainerizer/DefaultExecutorTest.KillTask/0
> I1110 01:20:11.482097 29700 cluster.cpp:158] Creating default 'local' authorizer
> I1110 01:20:11.485241 29700 leveldb.cpp:174] Opened db in 2.774513ms
> I1110 01:20:11.486237 29700 leveldb.cpp:181] Compacted db in 953614ns
> I1110 01:20:11.486299 29700 leveldb.cpp:196] Created db iterator in 24739ns
> I1110 01:20:11.486325 29700 leveldb.cpp:202] Seeked to beginning of db in 2300ns
> I1110 01:20:11.486344 29700 leveldb.cpp:271] Iterated through 0 keys in the db in 378ns
> I1110 01:20:11.486399 29700 replica.cpp:776] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I1110 01:20:11.486933 29733 recover.cpp:451] Starting replica recovery
> I1110 01:20:11.487289 29733 recover.cpp:477] Replica is in EMPTY status
> I1110 01:20:11.488503 29721 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from __req_res__(7318)@172.17.0.3:52462
> I1110 01:20:11.488855 29727 recover.cpp:197] Received a recover response from a replica in EMPTY status
> I1110 01:20:11.489398 29729 recover.cpp:568] Updating replica status to STARTING
> I1110 01:20:11.490223 29723 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 575135ns
> I1110 01:20:11.490284 29732 master.cpp:380] Master d28fbae1-c3dc-45fa-8384-32ab9395a975 (3a31be8bf679) started on 172.17.0.3:52462
> I1110 01:20:11.490317 29732 master.cpp:382] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/k50x7x/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --quiet="false" --recovery_agent_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-1.2.0/_inst/share/mesos/webui" --work_dir="/tmp/k50x7x/master" --zk_session_timeout="10secs"
> I1110 01:20:11.490696 29732 master.cpp:432] Master only allowing authenticated frameworks to register
> I1110 01:20:11.490712 29732 master.cpp:446] Master only allowing authenticated agents to register
> I1110 01:20:11.490720 29732 master.cpp:459] Master only allowing authenticated HTTP frameworks to register
> I1110 01:20:11.490730 29732 credentials.hpp:37] Loading credentials for authentication from '/tmp/k50x7x/credentials'
> I1110 01:20:11.490281 29723 replica.cpp:320] Persisted replica status to STARTING
> I1110 01:20:11.491210 29732 master.cpp:504] Using default 'crammd5' authenticator
> I1110 01:20:11.491225 29720 recover.cpp:477] Replica is in STARTING status
> I1110 01:20:11.491394 29732 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
> I1110 01:20:11.491621 29732 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
> I1110 01:20:11.491770 29732 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
> I1110 01:20:11.491937 29732 master.cpp:584] Authorization enabled
> I1110 01:20:11.492276 29725 whitelist_watcher.cpp:77] No whitelist given
> I1110 01:20:11.492310 29723 hierarchical.cpp:149] Initialized hierarchical allocator process
> I1110 01:20:11.492569 29721 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from __req_res__(7319)@172.17.0.3:52462
> I1110 01:20:11.492830 29719 recover.cpp:197] Received a recover response from a replica in STARTING status
> I1110 01:20:11.493371 29720 recover.cpp:568] Updating replica status to VOTING
> I1110 01:20:11.494002 29721 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 367673ns
> I1110 01:20:11.494032 29721 replica.cpp:320] Persisted replica status to VOTING
> I1110 01:20:11.494218 29734 recover.cpp:582] Successfully joined the Paxos group
> I1110 01:20:11.494469 29734 recover.cpp:466] Recover process terminated
> I1110 01:20:11.495633 29733 master.cpp:2033] Elected as the leading master!
> I1110 01:20:11.495685 29733 master.cpp:1560] Recovering from registrar
> I1110 01:20:11.495880 29720 registrar.cpp:329] Recovering registrar
> I1110 01:20:11.496842 29730 log.cpp:553] Attempting to start the writer
> I1110 01:20:11.498610 29725 replica.cpp:493] Replica received implicit promise request from __req_res__(7320)@172.17.0.3:52462 with proposal 1
> I1110 01:20:11.499179 29725 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 524192ns
> I1110 01:20:11.499213 29725 replica.cpp:342] Persisted promised to 1
> I1110 01:20:11.500258 29726 coordinator.cpp:238] Coordinator attempting to fill missing positions
> I1110 01:20:11.501874 29731 replica.cpp:388] Replica received explicit promise request from __req_res__(7321)@172.17.0.3:52462 for position 0 with proposal 2
> I1110 01:20:11.502413 29731 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 484138ns
> I1110 01:20:11.502457 29731 replica.cpp:708] Persisted action NOP at position 0
> I1110 01:20:11.503885 29720 replica.cpp:537] Replica received write request for position 0 from __req_res__(7322)@172.17.0.3:52462
> I1110 01:20:11.503985 29720 leveldb.cpp:436] Reading position from leveldb took 56800ns
> I1110 01:20:11.504534 29720 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 467426ns
> I1110 01:20:11.504566 29720 replica.cpp:708] Persisted action NOP at position 0
> I1110 01:20:11.505470 29721 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
> I1110 01:20:11.505988 29721 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 479078ns
> I1110 01:20:11.506021 29721 replica.cpp:708] Persisted action NOP at position 0
> I1110 01:20:11.506706 29732 log.cpp:569] Writer started with ending position 0
> I1110 01:20:11.508041 29734 leveldb.cpp:436] Reading position from leveldb took 50010ns
> I1110 01:20:11.509210 29733 registrar.cpp:362] Successfully fetched the registry (0B) in 13.068032ms
> I1110 01:20:11.509356 29733 registrar.cpp:461] Applied 1 operations in 27124ns; attempting to update the registry
> I1110 01:20:11.510251 29732 log.cpp:577] Attempting to append 168 bytes to the log
> I1110 01:20:11.510457 29724 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
> I1110 01:20:11.511355 29728 replica.cpp:537] Replica received write request for position 1 from __req_res__(7323)@172.17.0.3:52462
> I1110 01:20:11.511828 29728 leveldb.cpp:341] Persisting action (187 bytes) to leveldb took 423890ns
> I1110 01:20:11.511859 29728 replica.cpp:708] Persisted action APPEND at position 1
> I1110 01:20:11.512572 29734 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
> I1110 01:20:11.513051 29734 leveldb.cpp:341] Persisting action (189 bytes) to leveldb took 368122ns
> I1110 01:20:11.513087 29734 replica.cpp:708] Persisted action APPEND at position 1
> I1110 01:20:11.514302 29726 registrar.cpp:506] Successfully updated the registry in 4.862976ms
> I1110 01:20:11.514503 29726 registrar.cpp:392] Successfully recovered registrar
> I1110 01:20:11.514593 29728 log.cpp:596] Attempting to truncate the log to 1
> I1110 01:20:11.514760 29730 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
> I1110 01:20:11.515249 29723 master.cpp:1676] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
> I1110 01:20:11.515534 29722 hierarchical.cpp:176] Skipping recovery of hierarchical allocator: nothing to recover
> I1110 01:20:11.516068 29722 replica.cpp:537] Replica received write request for position 2 from __req_res__(7324)@172.17.0.3:52462
> I1110 01:20:11.516619 29722 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 497823ns
> I1110 01:20:11.516652 29722 replica.cpp:708] Persisted action TRUNCATE at position 2
> I1110 01:20:11.517526 29734 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
> I1110 01:20:11.518040 29734 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 384129ns
> I1110 01:20:11.518111 29734 leveldb.cpp:399] Deleting ~1 keys from leveldb took 39398ns
> I1110 01:20:11.518138 29734 replica.cpp:708] Persisted action TRUNCATE at position 2
> I1110 01:20:11.525027 29700 containerizer.cpp:201] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni
> W1110 01:20:11.525806 29700 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges, but is running as user mesos
> W1110 01:20:11.526018 29700 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
> I1110 01:20:11.527331 29700 cluster.cpp:435] Creating default 'local' authorizer
> I1110 01:20:11.528741 29725 slave.cpp:208] Mesos agent started on (571)@172.17.0.3:52462
> I1110 01:20:11.528789 29725 slave.cpp:209] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --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/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io" --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_command_executor="false" --http_credentials="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/http_credentials" --image_provisioner_backend="copy" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.2.0/_build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --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;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD"
> I1110 01:20:11.529228 29725 credentials.hpp:86] Loading credential for authentication from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/credential'
> I1110 01:20:11.529305 29700 scheduler.cpp:176] Version: 1.2.0
> I1110 01:20:11.529436 29725 slave.cpp:346] Agent using credential for: test-principal
> I1110 01:20:11.529464 29725 credentials.hpp:37] Loading credentials for authentication from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/http_credentials'
> I1110 01:20:11.529747 29725 http.cpp:895] Using default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
> I1110 01:20:11.529855 29729 scheduler.cpp:469] New master detected at master@172.17.0.3:52462
> I1110 01:20:11.529884 29729 scheduler.cpp:478] Waiting for 0ns before initiating a re-(connection) attempt with the master
> I1110 01:20:11.531039 29725 slave.cpp:533] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I1110 01:20:11.531113 29725 slave.cpp:541] Agent attributes: [  ]
> I1110 01:20:11.531126 29725 slave.cpp:546] Agent hostname: 3a31be8bf679
> I1110 01:20:11.532897 29723 state.cpp:57] Recovering state from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/meta'
> I1110 01:20:11.533222 29727 status_update_manager.cpp:203] Recovering status update manager
> I1110 01:20:11.533269 29721 scheduler.cpp:353] Connected with the master at http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.533627 29734 containerizer.cpp:557] Recovering containerizer
> I1110 01:20:11.534519 29725 scheduler.cpp:235] Sending SUBSCRIBE call to http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.535482 29732 provisioner.cpp:253] Provisioner recovery complete
> I1110 01:20:11.535652 29734 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1110 01:20:11.535815 29724 slave.cpp:5411] Finished recovery
> I1110 01:20:11.536440 29724 slave.cpp:5585] Querying resource estimator for oversubscribable resources
> I1110 01:20:11.536898 29721 slave.cpp:915] New master detected at master@172.17.0.3:52462
> I1110 01:20:11.536906 29731 status_update_manager.cpp:177] Pausing sending status updates
> I1110 01:20:11.536941 29721 slave.cpp:974] Authenticating with master master@172.17.0.3:52462
> I1110 01:20:11.537076 29721 slave.cpp:985] Using default CRAM-MD5 authenticatee
> I1110 01:20:11.537214 29733 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54635
> I1110 01:20:11.537353 29719 authenticatee.cpp:121] Creating new client SASL connection
> I1110 01:20:11.537256 29721 slave.cpp:947] Detecting new master
> I1110 01:20:11.537591 29733 master.cpp:2329] Received subscription request for HTTP framework 'default'
> I1110 01:20:11.537611 29721 slave.cpp:5599] Received oversubscribable resources {} from the resource estimator
> I1110 01:20:11.537701 29733 master.cpp:2069] Authorizing framework principal 'test-principal' to receive offers for role '*'
> I1110 01:20:11.538077 29733 master.cpp:6745] Authenticating slave(571)@172.17.0.3:52462
> I1110 01:20:11.538208 29732 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1121)@172.17.0.3:52462
> I1110 01:20:11.538291 29733 master.cpp:2427] Subscribing framework 'default' with checkpointing disabled and capabilities [  ]
> I1110 01:20:11.538508 29731 authenticator.cpp:98] Creating new server SASL connection
> I1110 01:20:11.538782 29720 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
> I1110 01:20:11.538823 29720 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
> I1110 01:20:11.539227 29730 hierarchical.cpp:275] Added framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.539317 29722 master.hpp:2161] Sending heartbeat to d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.539331 29730 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:11.539696 29730 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:11.539818 29730 hierarchical.cpp:1286] Performed allocation for 0 agents in 554795ns
> I1110 01:20:11.540354 29720 authenticator.cpp:204] Received SASL authentication start
> I1110 01:20:11.540361 29719 scheduler.cpp:675] Enqueuing event SUBSCRIBED received from http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.540438 29720 authenticator.cpp:326] Authentication requires more steps
> I1110 01:20:11.540750 29720 authenticatee.cpp:259] Received SASL authentication step
> I1110 01:20:11.541038 29721 authenticator.cpp:232] Received SASL authentication step
> I1110 01:20:11.541081 29721 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3a31be8bf679' server FQDN: '3a31be8bf679' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
> I1110 01:20:11.541112 29721 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
> I1110 01:20:11.541147 29719 scheduler.cpp:675] Enqueuing event HEARTBEAT received from http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.541178 29721 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I1110 01:20:11.541260 29721 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3a31be8bf679' server FQDN: '3a31be8bf679' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
> I1110 01:20:11.541285 29721 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I1110 01:20:11.541307 29721 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I1110 01:20:11.541342 29721 authenticator.cpp:318] Authentication success
> I1110 01:20:11.541517 29733 authenticatee.cpp:299] Authentication success
> I1110 01:20:11.541586 29720 master.cpp:6775] Successfully authenticated principal 'test-principal' at slave(571)@172.17.0.3:52462
> I1110 01:20:11.541826 29721 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1121)@172.17.0.3:52462
> I1110 01:20:11.542129 29730 slave.cpp:1069] Successfully authenticated with master master@172.17.0.3:52462
> I1110 01:20:11.542362 29730 slave.cpp:1483] Will retry registration in 9.532818ms if necessary
> I1110 01:20:11.542577 29733 master.cpp:5154] Registering agent at slave(571)@172.17.0.3:52462 (3a31be8bf679) with id d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
> I1110 01:20:11.543083 29731 registrar.cpp:461] Applied 1 operations in 60476ns; attempting to update the registry
> I1110 01:20:11.543926 29729 log.cpp:577] Attempting to append 337 bytes to the log
> I1110 01:20:11.544077 29723 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
> I1110 01:20:11.545238 29731 replica.cpp:537] Replica received write request for position 3 from __req_res__(7325)@172.17.0.3:52462
> I1110 01:20:11.546116 29731 leveldb.cpp:341] Persisting action (356 bytes) to leveldb took 825474ns
> I1110 01:20:11.546169 29731 replica.cpp:708] Persisted action APPEND at position 3
> I1110 01:20:11.547427 29725 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
> I1110 01:20:11.547969 29725 leveldb.cpp:341] Persisting action (358 bytes) to leveldb took 483290ns
> I1110 01:20:11.548005 29725 replica.cpp:708] Persisted action APPEND at position 3
> I1110 01:20:11.550129 29732 registrar.cpp:506] Successfully updated the registry in 6.962944ms
> I1110 01:20:11.550396 29726 log.cpp:596] Attempting to truncate the log to 3
> I1110 01:20:11.550614 29720 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
> I1110 01:20:11.551375 29723 slave.cpp:4263] Received ping from slave-observer(531)@172.17.0.3:52462
> I1110 01:20:11.551326 29734 master.cpp:5225] Registered agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I1110 01:20:11.551720 29730 replica.cpp:537] Replica received write request for position 4 from __req_res__(7326)@172.17.0.3:52462
> I1110 01:20:11.551892 29723 slave.cpp:1115] Registered with master master@172.17.0.3:52462; given agent ID d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
> I1110 01:20:11.551975 29723 fetcher.cpp:86] Clearing fetcher cache
> I1110 01:20:11.552170 29732 hierarchical.cpp:485] Added agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
> I1110 01:20:11.552338 29721 status_update_manager.cpp:184] Resuming sending status updates
> I1110 01:20:11.552486 29730 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 709727ns
> I1110 01:20:11.552655 29723 slave.cpp:1138] Checkpointing SlaveInfo to '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/meta/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/slave.info'
> I1110 01:20:11.552609 29730 replica.cpp:708] Persisted action TRUNCATE at position 4
> I1110 01:20:11.553383 29731 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
> I1110 01:20:11.553409 29723 slave.cpp:1175] Forwarding total oversubscribed resources {}
> I1110 01:20:11.553653 29732 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:11.553671 29727 master.cpp:5624] Received update of agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) with total oversubscribed resources {}
> I1110 01:20:11.553755 29732 hierarchical.cpp:1309] Performed allocation for agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 in 1.528714ms
> I1110 01:20:11.553975 29731 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 525057ns
> I1110 01:20:11.554072 29731 leveldb.cpp:399] Deleting ~2 keys from leveldb took 59750ns
> I1110 01:20:11.554065 29732 hierarchical.cpp:555] Agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679) updated with oversubscribed resources {} (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000])
> I1110 01:20:11.554105 29731 replica.cpp:708] Persisted action TRUNCATE at position 4
> I1110 01:20:11.554260 29732 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:11.554314 29732 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:11.554345 29727 master.cpp:6574] Sending 1 offers to framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
> I1110 01:20:11.554379 29732 hierarchical.cpp:1309] Performed allocation for agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 in 239597ns
> I1110 01:20:11.556370 29724 scheduler.cpp:675] Enqueuing event OFFERS received from http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.559177 29730 scheduler.cpp:235] Sending ACCEPT call to http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.560282 29734 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1110 01:20:11.561323 29733 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
> I1110 01:20:11.562417 29733 master.cpp:3581] Processing ACCEPT call for offers: [ d28fbae1-c3dc-45fa-8384-32ab9395a975-O0 ] on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
> I1110 01:20:11.562584 29733 master.cpp:3173] Authorizing framework principal 'test-principal' to launch task c96eb523-0365-49b2-8b3b-78976ff28797
> I1110 01:20:11.563097 29733 master.cpp:3173] Authorizing framework principal 'test-principal' to launch task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba
> I1110 01:20:11.567248 29733 master.cpp:8337] Adding task c96eb523-0365-49b2-8b3b-78976ff28797 with resources cpus(*):0.1; mem(*):32; disk(*):32 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679)
> I1110 01:20:11.567651 29733 master.cpp:8337] Adding task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba with resources cpus(*):0.1; mem(*):32; disk(*):32 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679)
> I1110 01:20:11.567845 29733 master.cpp:4438] Launching task group { 08848440-4c0e-4ad6-a0a9-b5947c5d21ba, c96eb523-0365-49b2-8b3b-78976ff28797 } of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) with resources cpus(*):0.2; mem(*):64; disk(*):64 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
> I1110 01:20:11.568495 29724 slave.cpp:1547] Got assigned task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.569128 29729 hierarchical.cpp:1018] Recovered cpus(*):1.7; mem(*):928; disk(*):928; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):0.3; mem(*):96; disk(*):96) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.569211 29729 hierarchical.cpp:1055] Framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 filtered agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 for 5secs
> I1110 01:20:11.570461 29724 slave.cpp:1709] Launching task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.571297 29724 paths.cpp:530] Trying to chown '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06' to user 'mesos'
> I1110 01:20:11.580168 29724 slave.cpp:6319] Launching executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 with resources cpus(*):0.1; mem(*):32; disk(*):32 in work directory '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06'
> I1110 01:20:11.580930 29734 containerizer.cpp:940] Starting container a283035b-25d3-4b48-b59a-964e5a4dfa06 for executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.581110 29724 slave.cpp:2031] Queued task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] for executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.581214 29724 slave.cpp:868] Successfully attached file '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06'
> I1110 01:20:11.585572 29722 containerizer.cpp:1480] Launching 'mesos-containerizer' with flags '--command="{"arguments":["mesos-default-executor","--launcher_dir=\/mesos\/mesos-1.2.0\/_build\/src"],"shell":false,"value":"\/mesos\/mesos-1.2.0\/_build\/src\/mesos-default-executor"}" --help="false" --pipe_read="60" --pipe_write="61" --pre_exec_commands="[]" --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06" --unshare_namespace_mnt="false" --user="mesos" --working_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06"'
> I1110 01:20:11.588587 29722 launcher.cpp:127] Forked child with pid '10191' for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06'
> I1110 01:20:11.592996 29734 fetcher.cpp:345] Starting to fetch URIs for container: a283035b-25d3-4b48-b59a-964e5a4dfa06, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06
> I1110 01:20:11.777189 10229 executor.cpp:189] Version: 1.2.0
> I1110 01:20:11.786099 29719 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
> I1110 01:20:11.787382 29722 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54638
> I1110 01:20:11.787693 29722 slave.cpp:3086] Received Subscribe request for HTTP executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.790436 29730 slave.cpp:2276] Sending queued task group task group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ] to executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (via HTTP)
> I1110 01:20:11.795663 10221 default_executor.cpp:130] Received SUBSCRIBED event
> I1110 01:20:11.797111 10221 default_executor.cpp:134] Subscribed executor on 3a31be8bf679
> I1110 01:20:11.797611 10221 default_executor.cpp:130] Received LAUNCH_GROUP event
> I1110 01:20:11.801981 29729 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
> I1110 01:20:11.802435 29729 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
> I1110 01:20:11.803306 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54640
> I1110 01:20:11.803452 29723 http.cpp:353] Processing call LAUNCH_NESTED_CONTAINER
> I1110 01:20:11.803827 29727 containerizer.cpp:1685] Starting nested container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
> I1110 01:20:11.803865 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54640
> I1110 01:20:11.803978 29723 http.cpp:353] Processing call LAUNCH_NESTED_CONTAINER
> I1110 01:20:11.804236 29727 containerizer.cpp:1709] Trying to chown '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d' to user 'mesos'
> I1110 01:20:11.814858 29727 containerizer.cpp:1685] Starting nested container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
> I1110 01:20:11.815129 29727 containerizer.cpp:1709] Trying to chown '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611' to user 'mesos'
> I1110 01:20:11.824666 29727 containerizer.cpp:1480] Launching 'mesos-containerizer' with flags '--command="{"shell":true,"value":"sleep 1000"}" --help="false" --pipe_read="63" --pipe_write="64" --pre_exec_commands="[]" --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d" --unshare_namespace_mnt="false" --user="mesos" --working_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d"'
> I1110 01:20:11.826855 29727 launcher.cpp:127] Forked child with pid '10240' for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d'
> I1110 01:20:11.828918 29727 containerizer.cpp:1480] Launching 'mesos-containerizer' with flags '--command="{"shell":true,"value":"sleep 1000"}" --help="false" --pipe_read="65" --pipe_write="66" --pre_exec_commands="[]" --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611" --unshare_namespace_mnt="false" --user="mesos" --working_directory="/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611"'
> I1110 01:20:11.831428 29727 launcher.cpp:127] Forked child with pid '10241' for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611'
> I1110 01:20:11.834421 29731 fetcher.cpp:345] Starting to fetch URIs for container: a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d
> I1110 01:20:11.837882 29731 fetcher.cpp:345] Starting to fetch URIs for container: a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611
> I1110 01:20:11.847651 10227 default_executor.cpp:470] Successfully launched child containers [ a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d, a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 ] for tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5d21ba ]
> I1110 01:20:11.849225 29728 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
> I1110 01:20:11.850085 10226 default_executor.cpp:546] Waiting for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d of task 'c96eb523-0365-49b2-8b3b-78976ff28797'
> I1110 01:20:11.850145 29734 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
> I1110 01:20:11.850405 10226 default_executor.cpp:546] Waiting for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 of task '08848440-4c0e-4ad6-a0a9-b5947c5d21ba'
> I1110 01:20:11.850746 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
> I1110 01:20:11.851114 29726 slave.cpp:3740] Handling status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.851552 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
> I1110 01:20:11.851727 29726 slave.cpp:3740] Handling status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.852295 29726 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
> I1110 01:20:11.852826 29726 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
> I1110 01:20:11.853938 29724 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.854076 29724 status_update_manager.cpp:500] Creating StatusUpdate stream for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.854460 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54641
> I1110 01:20:11.854559 29726 http.cpp:353] Processing call WAIT_NESTED_CONTAINER
> I1110 01:20:11.854610 29724 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
> I1110 01:20:11.855126 29724 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.855190 29724 status_update_manager.cpp:500] Creating StatusUpdate stream for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.855200 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54642
> I1110 01:20:11.855409 29726 http.cpp:353] Processing call WAIT_NESTED_CONTAINER
> I1110 01:20:11.855608 29724 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
> I1110 01:20:11.855803 29726 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
> I1110 01:20:11.856199 29726 slave.cpp:4075] Status update manager successfully handled status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.856346 29725 master.cpp:5760] Status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
> I1110 01:20:11.856439 29725 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.856598 29726 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
> I1110 01:20:11.856828 29726 slave.cpp:4075] Status update manager successfully handled status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.856998 29725 master.cpp:7715] Updating the state of task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
> I1110 01:20:11.857322 29725 master.cpp:5760] Status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
> I1110 01:20:11.857386 29725 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.857787 29725 master.cpp:7715] Updating the state of task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
> I1110 01:20:11.858124 10226 default_executor.cpp:130] Received ACKNOWLEDGED event
> I1110 01:20:11.858530 29725 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.859519 29732 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.859676 10233 default_executor.cpp:130] Received ACKNOWLEDGED event
> ../../src/tests/default_executor_tests.cpp:338: Failure
> Value of: runningUpdate1->status().task_id()
>   Actual: 08848440-4c0e-4ad6-a0a9-b5947c5d21ba
> Expected: taskInfo1.task_id()
> Which is: c96eb523-0365-49b2-8b3b-78976ff28797
> ../../src/tests/default_executor_tests.cpp:342: Failure
> Value of: runningUpdate2->status().task_id()
>   Actual: c96eb523-0365-49b2-8b3b-78976ff28797
> Expected: taskInfo2.task_id()
> Which is: 08848440-4c0e-4ad6-a0a9-b5947c5d21ba
> I1110 01:20:11.861587 29733 scheduler.cpp:235] Sending ACKNOWLEDGE call to http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.861948 29733 scheduler.cpp:235] Sending ACKNOWLEDGE call to http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.862280 29733 scheduler.cpp:235] Sending KILL call to http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:11.862632 29721 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1110 01:20:11.863528 29719 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
> I1110 01:20:11.863664 29719 master.cpp:4870] Processing ACKNOWLEDGE call 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87 for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
> I1110 01:20:11.864003 29732 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> W1110 01:20:11.864294 29732 status_update_manager.cpp:769] Unexpected status update acknowledgement (received 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87, expecting d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> E1110 01:20:11.864575 29726 slave.cpp:3015] Failed to handle status update acknowledgement (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000: Duplicate acknowledgement
> I1110 01:20:11.864804 29723 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1110 01:20:11.865231 29723 process.cpp:3570] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
> I1110 01:20:11.866297 29722 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
> I1110 01:20:11.866420 29722 master.cpp:4870] Processing ACKNOWLEDGE call d91c7deb-4646-4b4e-ba1a-5650a256e8d2 for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
> I1110 01:20:11.867036 29726 status_update_manager.cpp:395] Received status update acknowledgement (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.867076 29722 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 172.17.0.3:54634
> I1110 01:20:11.867291 29722 master.cpp:4762] Telling agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) to kill task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
> W1110 01:20:11.867297 29726 status_update_manager.cpp:769] Unexpected status update acknowledgement (received d91c7deb-4646-4b4e-ba1a-5650a256e8d2, expecting 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.867449 29733 slave.cpp:2344] Asked to kill task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> E1110 01:20:11.867710 29733 slave.cpp:3015] Failed to handle status update acknowledgement (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000: Duplicate acknowledgement
> I1110 01:20:11.869391 10228 default_executor.cpp:130] Received KILL event
> I1110 01:20:11.869498 10228 default_executor.cpp:810] Received kill for task 'c96eb523-0365-49b2-8b3b-78976ff28797'
> I1110 01:20:11.869544 10228 default_executor.cpp:694] Shutting down
> I1110 01:20:11.870112 10221 default_executor.cpp:782] Killing child container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
> I1110 01:20:11.870338 10221 default_executor.cpp:782] Killing child container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
> I1110 01:20:11.870965 29729 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
> I1110 01:20:11.871399 29730 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1'
> I1110 01:20:11.871984 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54643
> I1110 01:20:11.872088 29723 http.cpp:353] Processing call KILL_NESTED_CONTAINER
> I1110 01:20:11.872284 29726 containerizer.cpp:1973] Destroying container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d in RUNNING state
> I1110 01:20:11.872340 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 from 172.17.0.3:54643
> I1110 01:20:11.872416 29723 http.cpp:353] Processing call KILL_NESTED_CONTAINER
> I1110 01:20:11.872597 29726 launcher.cpp:143] Asked to destroy container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
> I1110 01:20:11.877090 29726 containerizer.cpp:1973] Destroying container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 in RUNNING state
> I1110 01:20:11.877320 29726 launcher.cpp:143] Asked to destroy container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
> I1110 01:20:11.962539 29729 containerizer.cpp:2336] Container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d has exited
> I1110 01:20:11.963811 29733 provisioner.cpp:324] Ignoring destroy request for unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d
> I1110 01:20:11.963851 29729 containerizer.cpp:2336] Container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 has exited
> I1110 01:20:11.964437 29729 containerizer.cpp:2252] Checkpointing termination state to nested container's runtime directory '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d/termination'
> I1110 01:20:11.965940 29728 provisioner.cpp:324] Ignoring destroy request for unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611
> I1110 01:20:11.966202 29732 containerizer.cpp:2252] Checkpointing termination state to nested container's runtime directory '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611/termination'
> I1110 01:20:11.970046 10231 default_executor.cpp:663] Successfully waited for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d of task 'c96eb523-0365-49b2-8b3b-78976ff28797' in state TASK_KILLED
> I1110 01:20:11.970501 10231 default_executor.cpp:663] Successfully waited for child container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 of task '08848440-4c0e-4ad6-a0a9-b5947c5d21ba' in state TASK_KILLED
> I1110 01:20:11.970559 10231 default_executor.cpp:768] Terminating after 1secs
> I1110 01:20:11.971288 29723 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
> I1110 01:20:11.972218 29728 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
> I1110 01:20:11.972488 29728 slave.cpp:3740] Handling status update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.974179 29719 process.cpp:3570] Handling HTTP event for process 'slave(571)' with path: '/slave(571)/api/v1/executor'
> I1110 01:20:11.975229 29726 status_update_manager.cpp:323] Received status update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.975278 29729 http.cpp:277] HTTP POST for /slave(571)/api/v1/executor from 172.17.0.3:54639
> I1110 01:20:11.975517 29729 slave.cpp:3740] Handling status update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.976048 29729 slave.cpp:4075] Status update manager successfully handled status update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.978132 29720 status_update_manager.cpp:323] Received status update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:11.978482 29725 slave.cpp:4075] Status update manager successfully handled status update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:12.494274 29725 hierarchical.cpp:1880] Filtered offer with cpus(*):1.7; mem(*):928; disk(*):928; ports(*):[31000-32000] on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:12.494357 29725 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:12.494402 29725 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:12.494491 29725 hierarchical.cpp:1286] Performed allocation for 1 agents in 915780ns
> I1110 01:20:13.071280 29734 containerizer.cpp:2336] Container a283035b-25d3-4b48-b59a-964e5a4dfa06 has exited
> I1110 01:20:13.071339 29734 containerizer.cpp:1973] Destroying container a283035b-25d3-4b48-b59a-964e5a4dfa06 in RUNNING state
> I1110 01:20:13.071746 29734 launcher.cpp:143] Asked to destroy container a283035b-25d3-4b48-b59a-964e5a4dfa06
> I1110 01:20:13.076637 29723 provisioner.cpp:324] Ignoring destroy request for unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06
> I1110 01:20:13.077929 29721 slave.cpp:4672] Executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 exited with status 0
> I1110 01:20:13.078433 29732 master.cpp:5884] Executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679): exited with status 0
> I1110 01:20:13.078538 29732 master.cpp:7840] Removing executor 'default' with resources cpus(*):0.1; mem(*):32; disk(*):32 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
> I1110 01:20:13.079448 29730 hierarchical.cpp:1018] Recovered cpus(*):0.1; mem(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):0.2; mem(*):64; disk(*):64) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:13.081049 29723 scheduler.cpp:675] Enqueuing event FAILURE received from http://172.17.0.3:52462/master/api/v1/scheduler
> GMOCK WARNING:
> Uninteresting mock function call - returning directly.
>     Function call: failure(0x7fff1aa9a950, @0x2ab91c02dd10 48-byte object <90-62 27-EC B8-2A 00-00 00-00 00-00 00-00 00-00 07-00 00-00 00-00 00-00 10-CE 01-1C B9-2A 00-00 70-CE 02-1C B9-2A 00-00 00-00 00-00 B8-2A 00-00>)
> Stack trace:
> I1110 01:20:13.496551 29730 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:13.496680 29730 hierarchical.cpp:1286] Performed allocation for 1 agents in 1.498625ms
> I1110 01:20:13.497339 29729 master.cpp:6574] Sending 1 offers to framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
> I1110 01:20:13.499797 29721 scheduler.cpp:675] Enqueuing event OFFERS received from http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:14.497707 29732 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:14.497795 29732 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:14.497895 29732 hierarchical.cpp:1286] Performed allocation for 1 agents in 410313ns
> I1110 01:20:15.499423 29728 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:15.499526 29728 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:15.499658 29728 hierarchical.cpp:1286] Performed allocation for 1 agents in 547651ns
> I1110 01:20:16.500463 29729 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:16.500581 29729 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:16.500699 29729 hierarchical.cpp:1286] Performed allocation for 1 agents in 505442ns
> I1110 01:20:17.502176 29727 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:17.502262 29727 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:17.502367 29727 hierarchical.cpp:1286] Performed allocation for 1 agents in 464526ns
> I1110 01:20:18.503680 29723 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:18.503762 29723 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:18.503851 29723 hierarchical.cpp:1286] Performed allocation for 1 agents in 425163ns
> I1110 01:20:19.505476 29723 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:19.505586 29723 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:19.505705 29723 hierarchical.cpp:1286] Performed allocation for 1 agents in 590762ns
> I1110 01:20:20.507310 29724 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:20.507390 29724 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:20.507477 29724 hierarchical.cpp:1286] Performed allocation for 1 agents in 411721ns
> I1110 01:20:21.508368 29729 hierarchical.cpp:1694] No allocations performed
> I1110 01:20:21.508458 29729 hierarchical.cpp:1789] No inverse offers to send out!
> I1110 01:20:21.508564 29729 hierarchical.cpp:1286] Performed allocation for 1 agents in 432440ns
> W1110 01:20:21.855908 29728 status_update_manager.cpp:478] Resending status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.856066 29728 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
> I1110 01:20:21.856652 29734 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
> W1110 01:20:21.857002 29727 status_update_manager.cpp:478] Resending status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.857069 29727 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to the agent
> I1110 01:20:21.857378 29733 master.cpp:5760] Status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
> I1110 01:20:21.857475 29733 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.857662 29722 slave.cpp:4181] Forwarding the update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 to master@172.17.0.3:52462
> I1110 01:20:21.858206 29733 master.cpp:7715] Updating the state of task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_RUNNING)
> I1110 01:20:21.858988 29733 master.cpp:5760] Status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
> I1110 01:20:21.859259 29733 master.cpp:5822] Forwarding status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.859647 29725 hierarchical.cpp:1018] Recovered cpus(*):0.1; mem(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):1.9; mem(*):992; disk(*):992; ports(*):[31000-32000]) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.859845 29725 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
> I1110 01:20:21.859979 29733 master.cpp:7715] Updating the state of task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_RUNNING)
> I1110 01:20:21.860970 29729 hierarchical.cpp:1018] Recovered cpus(*):0.1; mem(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000]) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.861687 29725 scheduler.cpp:675] Enqueuing event UPDATE received from http://172.17.0.3:52462/master/api/v1/scheduler
> ../../src/tests/default_executor_tests.cpp:400: Failure
> Value of: killedUpdate1->status().state()
>   Actual: TASK_RUNNING
> Expected: TASK_KILLED
> I1110 01:20:21.864666 29721 master.cpp:1297] Framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) disconnected
> I1110 01:20:21.864765 29721 master.cpp:2918] Disconnecting framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
> I1110 01:20:21.864820 29721 master.cpp:2942] Deactivating framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
> I1110 01:20:21.865016 29732 hierarchical.cpp:386] Deactivated framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> W1110 01:20:21.865586 29721 master.hpp:2264] Master attempted to send message to disconnected framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
> W1110 01:20:21.865691 29721 master.hpp:2270] Unable to send event to framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default): connection closed
> I1110 01:20:21.865777 29721 master.cpp:1310] Giving framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) 0ns to failover
> I1110 01:20:21.866277 29728 hierarchical.cpp:1018] Recovered cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.867295 29733 master.cpp:6426] Framework failover timeout, removing framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
> I1110 01:20:21.867328 29733 master.cpp:7170] Removing framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default)
> I1110 01:20:21.867539 29733 master.cpp:7715] Updating the state of task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
> I1110 01:20:21.867559 29731 slave.cpp:2575] Asked to shut down framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 by master@172.17.0.3:52462
> I1110 01:20:21.867617 29731 slave.cpp:2600] Shutting down framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.867585 29733 master.cpp:7811] Removing task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba with resources cpus(*):0.1; mem(*):32; disk(*):32 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
> I1110 01:20:21.867707 29731 slave.cpp:4776] Cleaning up executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (via HTTP)
> I1110 01:20:21.867904 29733 master.cpp:7715] Updating the state of task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
> I1110 01:20:21.868042 29729 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06' for gc 6.99998999732444days in the future
> I1110 01:20:21.867939 29733 master.cpp:7811] Removing task c96eb523-0365-49b2-8b3b-78976ff28797 with resources cpus(*):0.1; mem(*):32; disk(*):32 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
> I1110 01:20:21.868232 29731 slave.cpp:4864] Cleaning up framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.868252 29729 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default' for gc 6.99998999732444days in the future
> I1110 01:20:21.868422 29725 status_update_manager.cpp:285] Closing status update streams for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.868484 29725 status_update_manager.cpp:531] Cleaning up status update stream for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.868777 29721 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000' for gc 6.99998999732444days in the future
> I1110 01:20:21.868926 29720 hierarchical.cpp:337] Removed framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.869235 29725 status_update_manager.cpp:531] Cleaning up status update stream for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000
> I1110 01:20:21.870568 29730 slave.cpp:787] Agent terminating
> I1110 01:20:21.870795 29732 master.cpp:1258] Agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) disconnected
> I1110 01:20:21.870825 29732 master.cpp:2977] Disconnecting agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
> I1110 01:20:21.870930 29732 master.cpp:2996] Deactivating agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679)
> I1110 01:20:21.871158 29726 hierarchical.cpp:584] Agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 deactivated
> I1110 01:20:21.876986 29733 master.cpp:1097] Master terminating
> I1110 01:20:21.877754 29724 hierarchical.cpp:517] Removed agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0
> [  FAILED  ] MesosContainerizer/DefaultExecutorTest.KillTask/0, where GetParam() = "mesos" (10406 ms)
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message