Details
-
Bug
-
Status: Resolved
-
Major
-
Resolution: Fixed
-
None
-
Recent Arch Linux VM, amd64.
-
Mesosphere Sprint 48
-
2
Description
This repros consistently for me (~10 test iterations or fewer). Test log:
[ RUN ] DefaultExecutorTest.KillTaskGroupOnTaskFailure
I1208 03:26:47.461477 28632 cluster.cpp:160] Creating default 'local' authorizer
I1208 03:26:47.462673 28632 replica.cpp:776] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I1208 03:26:47.463248 28650 recover.cpp:451] Starting replica recovery
I1208 03:26:47.463537 28650 recover.cpp:477] Replica is in EMPTY status
I1208 03:26:47.476333 28651 replica.cpp:673] Replica in EMPTY status received a broadcasted recover request from __req_res__(64)@10.0.2.15:46643
I1208 03:26:47.476618 28650 recover.cpp:197] Received a recover response from a replica in EMPTY status
I1208 03:26:47.477242 28649 recover.cpp:568] Updating replica status to STARTING
I1208 03:26:47.477496 28649 replica.cpp:320] Persisted replica status to STARTING
I1208 03:26:47.477607 28649 recover.cpp:477] Replica is in STARTING status
I1208 03:26:47.478910 28653 replica.cpp:673] Replica in STARTING status received a broadcasted recover request from __req_res__(65)@10.0.2.15:46643
I1208 03:26:47.479385 28651 recover.cpp:197] Received a recover response from a replica in STARTING status
I1208 03:26:47.479717 28647 recover.cpp:568] Updating replica status to VOTING
I1208 03:26:47.479996 28648 replica.cpp:320] Persisted replica status to VOTING
I1208 03:26:47.480077 28648 recover.cpp:582] Successfully joined the Paxos group
I1208 03:26:47.763380 28651 master.cpp:380] Master 0bcb0250-4cf5-4209-92fe-ce260518b50f (archlinux.vagrant.vm) started on 10.0.2.15:46643
I1208 03:26:47.763463 28651 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/7lpy50/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="/usr/local/share/mesos/webui" --work_dir="/tmp/7lpy50/master" --zk_session_timeout="10secs"
I1208 03:26:47.764010 28651 master.cpp:432] Master only allowing authenticated frameworks to register
I1208 03:26:47.764070 28651 master.cpp:446] Master only allowing authenticated agents to register
I1208 03:26:47.764076 28651 master.cpp:459] Master only allowing authenticated HTTP frameworks to register
I1208 03:26:47.764081 28651 credentials.hpp:37] Loading credentials for authentication from '/tmp/7lpy50/credentials'
I1208 03:26:47.764482 28651 master.cpp:504] Using default 'crammd5' authenticator
I1208 03:26:47.764659 28651 http.cpp:922] Using default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I1208 03:26:47.764981 28651 http.cpp:922] Using default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I1208 03:26:47.765136 28651 http.cpp:922] Using default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I1208 03:26:47.765231 28651 master.cpp:584] Authorization enabled
I1208 03:26:47.768061 28651 master.cpp:2043] Elected as the leading master!
I1208 03:26:47.768097 28651 master.cpp:1566] Recovering from registrar
I1208 03:26:47.768766 28648 log.cpp:553] Attempting to start the writer
I1208 03:26:47.769899 28653 replica.cpp:493] Replica received implicit promise request from __req_res__(66)@10.0.2.15:46643 with proposal 1
I1208 03:26:47.769984 28653 replica.cpp:342] Persisted promised to 1
I1208 03:26:47.770534 28652 coordinator.cpp:238] Coordinator attempting to fill missing positions
I1208 03:26:47.771479 28652 replica.cpp:388] Replica received explicit promise request from __req_res__(67)@10.0.2.15:46643 for position 0 with proposal 2
I1208 03:26:47.772897 28650 replica.cpp:537] Replica received write request for position 0 from __req_res__(68)@10.0.2.15:46643
I1208 03:26:47.773437 28650 replica.cpp:691] Replica received learned notice for position 0 from @0.0.0.0:0
I1208 03:26:47.774327 28650 log.cpp:569] Writer started with ending position 0
I1208 03:26:47.776505 28647 registrar.cpp:362] Successfully fetched the registry (0B) in 8.211712ms
I1208 03:26:47.776597 28647 registrar.cpp:461] Applied 1 operations in 11511ns; attempting to update the registry
I1208 03:26:47.777253 28653 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
I1208 03:26:47.778172 28648 replica.cpp:537] Replica received write request for position 1 from __req_res__(69)@10.0.2.15:46643
I1208 03:26:47.778695 28646 replica.cpp:691] Replica received learned notice for position 1 from @0.0.0.0:0
I1208 03:26:47.779631 28652 registrar.cpp:506] Successfully updated the registry in 2.979072ms
I1208 03:26:47.779736 28652 registrar.cpp:392] Successfully recovered registrar
I1208 03:26:47.779911 28652 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
I1208 03:26:47.780030 28653 master.cpp:1682] Recovered 0 agents from the registry (145B); allowing 10mins for agents to re-register
I1208 03:26:47.788097 28648 replica.cpp:537] Replica received write request for position 2 from __req_res__(70)@10.0.2.15:46643
I1208 03:26:47.788931 28651 replica.cpp:691] Replica received learned notice for position 2 from @0.0.0.0:0
I1208 03:26:47.844846 28632 containerizer.cpp:207] Using isolation: posix/cpu,posix/mem,filesystem/posix,network/cni
W1208 03:26:47.845237 28632 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I1208 03:26:47.846787 28632 cluster.cpp:446] Creating default 'local' authorizer
I1208 03:26:47.848178 28647 slave.cpp:208] Mesos agent started on (8)@10.0.2.15:46643
I1208 03:26:47.848201 28647 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/DefaultExecutorTest_KillTaskGroupOnTaskFailure_OQh5HL/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/DefaultExecutorTest_KillTaskGroupOnTaskFailure_OQh5HL/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/DefaultExecutorTest_KillTaskGroupOnTaskFailure_OQh5HL/http_credentials" --image_provisioner_backend="copy" --initialize_driver_logging="true" --io_switchboard_enable_server="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/home/vagrant/build-mesos/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/DefaultExecutorTest_KillTaskGroupOnTaskFailure_OQh5HL" --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/DefaultExecutorTest_KillTaskGroupOnTaskFailure_M0FOoo"
I1208 03:26:47.848474 28647 credentials.hpp:86] Loading credential for authentication from '/tmp/DefaultExecutorTest_KillTaskGroupOnTaskFailure_OQh5HL/credential'
I1208 03:26:47.848573 28647 slave.cpp:346] Agent using credential for: test-principal
I1208 03:26:47.848587 28647 credentials.hpp:37] Loading credentials for authentication from '/tmp/DefaultExecutorTest_KillTaskGroupOnTaskFailure_OQh5HL/http_credentials'
I1208 03:26:47.848707 28647 http.cpp:922] Using default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I1208 03:26:47.848764 28632 scheduler.cpp:182] Version: 1.2.0
I1208 03:26:47.921869 28647 slave.cpp:533] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1208 03:26:47.921993 28647 slave.cpp:541] Agent attributes: [ ]
I1208 03:26:47.922003 28647 slave.cpp:546] Agent hostname: archlinux.vagrant.vm
I1208 03:26:47.923415 28649 state.cpp:57] Recovering state from '/tmp/DefaultExecutorTest_KillTaskGroupOnTaskFailure_M0FOoo/meta'
I1208 03:26:47.923770 28651 status_update_manager.cpp:203] Recovering status update manager
I1208 03:26:47.924353 28650 containerizer.cpp:581] Recovering containerizer
I1208 03:26:47.925879 28651 provisioner.cpp:253] Provisioner recovery complete
I1208 03:26:47.926267 28649 slave.cpp:5414] Finished recovery
I1208 03:26:47.926981 28646 slave.cpp:918] New master detected at master@10.0.2.15:46643
I1208 03:26:47.927004 28648 status_update_manager.cpp:177] Pausing sending status updates
I1208 03:26:47.927008 28646 slave.cpp:977] Authenticating with master master@10.0.2.15:46643
I1208 03:26:47.927127 28646 slave.cpp:988] Using default CRAM-MD5 authenticatee
I1208 03:26:47.927259 28646 slave.cpp:950] Detecting new master
I1208 03:26:47.927393 28651 authenticatee.cpp:121] Creating new client SASL connection
I1208 03:26:47.927543 28651 master.cpp:6793] Authenticating slave(8)@10.0.2.15:46643
I1208 03:26:47.927907 28649 authenticator.cpp:98] Creating new server SASL connection
I1208 03:26:47.928110 28648 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I1208 03:26:47.928138 28648 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I1208 03:26:47.928225 28648 authenticator.cpp:204] Received SASL authentication start
I1208 03:26:47.928256 28648 authenticator.cpp:326] Authentication requires more steps
I1208 03:26:47.928315 28648 authenticatee.cpp:259] Received SASL authentication step
I1208 03:26:47.928390 28648 authenticator.cpp:232] Received SASL authentication step
I1208 03:26:47.928442 28648 authenticator.cpp:318] Authentication success
I1208 03:26:47.928549 28651 authenticatee.cpp:299] Authentication success
I1208 03:26:47.928560 28648 master.cpp:6823] Successfully authenticated principal 'test-principal' at slave(8)@10.0.2.15:46643
I1208 03:26:47.928917 28648 slave.cpp:1072] Successfully authenticated with master master@10.0.2.15:46643
I1208 03:26:47.929293 28648 master.cpp:5202] Registering agent at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm) with id 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0
I1208 03:26:47.929668 28652 registrar.cpp:461] Applied 1 operations in 37939ns; attempting to update the registry
I1208 03:26:47.930258 28647 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
I1208 03:26:47.931262 28650 replica.cpp:537] Replica received write request for position 3 from __req_res__(71)@10.0.2.15:46643
I1208 03:26:47.931882 28650 replica.cpp:691] Replica received learned notice for position 3 from @0.0.0.0:0
I1208 03:26:47.932858 28650 registrar.cpp:506] Successfully updated the registry in 3.147008ms
I1208 03:26:47.933434 28650 master.cpp:5273] Registered agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1208 03:26:47.933506 28650 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
I1208 03:26:47.933869 28650 hierarchical.cpp:485] Added agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 (archlinux.vagrant.vm) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I1208 03:26:47.934068 28650 slave.cpp:1118] Registered with master master@10.0.2.15:46643; given agent ID 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0
I1208 03:26:47.934249 28650 slave.cpp:1178] Forwarding total oversubscribed resources {}
I1208 03:26:47.934497 28650 status_update_manager.cpp:184] Resuming sending status updates
I1208 03:26:47.934567 28650 master.cpp:5672] Received update of agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm) with total oversubscribed resources {}
I1208 03:26:47.934734 28650 hierarchical.cpp:555] Agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 (archlinux.vagrant.vm) updated with oversubscribed resources {} (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {})
I1208 03:26:47.935107 28650 replica.cpp:537] Replica received write request for position 4 from __req_res__(72)@10.0.2.15:46643
I1208 03:26:47.935642 28650 replica.cpp:691] Replica received learned notice for position 4 from @0.0.0.0:0
I1208 03:26:50.427475 28648 scheduler.cpp:475] New master detected at master@10.0.2.15:46643
I1208 03:26:50.435571 28648 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 10.0.2.15:50358
I1208 03:26:50.435753 28648 master.cpp:2340] Received subscription request for HTTP framework 'default'
I1208 03:26:50.435832 28648 master.cpp:2079] Authorizing framework principal 'test-principal' to receive offers for role '*'
I1208 03:26:50.436213 28647 master.cpp:2454] Subscribing framework 'default' with checkpointing disabled and capabilities [ ]
I1208 03:26:50.436691 28651 hierarchical.cpp:275] Added framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:50.437602 28647 master.cpp:6622] Sending 1 offers to framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (default)
I1208 03:26:50.442335 28653 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 10.0.2.15:50356
I1208 03:26:50.442852 28653 master.cpp:3629] Processing ACCEPT call for offers: [ 0bcb0250-4cf5-4209-92fe-ce260518b50f-O0 ] on agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm) for framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (default)
I1208 03:26:50.442912 28653 master.cpp:3216] Authorizing framework principal 'test-principal' to launch task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5
I1208 03:26:50.443050 28653 master.cpp:3216] Authorizing framework principal 'test-principal' to launch task bf21fae2-513e-4ea1-b85c-dfd2546e4249
I1208 03:26:50.445271 28653 master.cpp:8424] Adding task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 with resources cpus(*):0.1; mem(*):32; disk(*):32 on agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 (archlinux.vagrant.vm)
I1208 03:26:50.445487 28653 master.cpp:8424] Adding task bf21fae2-513e-4ea1-b85c-dfd2546e4249 with resources cpus(*):0.1; mem(*):32; disk(*):32 on agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 (archlinux.vagrant.vm)
I1208 03:26:50.445565 28653 master.cpp:4486] Launching task group { 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5, bf21fae2-513e-4ea1-b85c-dfd2546e4249 } of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (default) with resources cpus(*):0.2; mem(*):64; disk(*):64 on agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm)
I1208 03:26:50.446413 28653 slave.cpp:1550] Got assigned task group containing tasks [ 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5, bf21fae2-513e-4ea1-b85c-dfd2546e4249 ] for framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:50.446836 28653 slave.cpp:1712] Launching task group containing tasks [ 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5, bf21fae2-513e-4ea1-b85c-dfd2546e4249 ] for framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:50.446993 28653 paths.cpp:530] Trying to chown '/tmp/DefaultExecutorTest_KillTaskGroupOnTaskFailure_M0FOoo/slaves/0bcb0250-4cf5-4209-92fe-ce260518b50f-S0/frameworks/0bcb0250-4cf5-4209-92fe-ce260518b50f-0000/executors/default/runs/725fe374-0d1e-4d9f-b1b0-e5ffb16b1101' to user 'vagrant'
I1208 03:26:50.451642 28653 slave.cpp:6341] Launching executor 'default' of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 with resources cpus(*):0.1; mem(*):32; disk(*):32 in work directory '/tmp/DefaultExecutorTest_KillTaskGroupOnTaskFailure_M0FOoo/slaves/0bcb0250-4cf5-4209-92fe-ce260518b50f-S0/frameworks/0bcb0250-4cf5-4209-92fe-ce260518b50f-0000/executors/default/runs/725fe374-0d1e-4d9f-b1b0-e5ffb16b1101'
I1208 03:26:50.452117 28652 containerizer.cpp:973] Starting container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101 for executor 'default' of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:50.452283 28653 slave.cpp:2034] Queued task group containing tasks [ 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5, bf21fae2-513e-4ea1-b85c-dfd2546e4249 ] for executor 'default' of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:50.456531 28647 launcher.cpp:133] Forked child with pid '29159' for container '725fe374-0d1e-4d9f-b1b0-e5ffb16b1101'
I1208 03:26:53.105209 29173 executor.cpp:189] Version: 1.2.0
I1208 03:26:53.112563 28646 http.cpp:288] HTTP POST for /slave(8)/api/v1/executor from 10.0.2.15:50360
I1208 03:26:53.112725 28646 slave.cpp:3089] Received Subscribe request for HTTP executor 'default' of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.114614 28651 slave.cpp:2279] Sending queued task group task group containing tasks [ 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5, bf21fae2-513e-4ea1-b85c-dfd2546e4249 ] to executor 'default' of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (via HTTP)
I1208 03:26:53.117642 29191 default_executor.cpp:131] Received SUBSCRIBED event
I1208 03:26:53.122820 29191 default_executor.cpp:135] Subscribed executor on archlinux.vagrant.vm
I1208 03:26:53.123080 29191 default_executor.cpp:131] Received LAUNCH_GROUP event
I1208 03:26:53.126833 28653 http.cpp:288] HTTP POST for /slave(8)/api/v1 from 10.0.2.15:50364
I1208 03:26:53.127091 28653 http.cpp:288] HTTP POST for /slave(8)/api/v1 from 10.0.2.15:50364
I1208 03:26:53.127477 28653 http.cpp:449] Processing call LAUNCH_NESTED_CONTAINER
I1208 03:26:53.127671 28653 http.cpp:449] Processing call LAUNCH_NESTED_CONTAINER
I1208 03:26:53.128360 28653 containerizer.cpp:1776] Starting nested container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8
I1208 03:26:53.128434 28653 containerizer.cpp:1800] Trying to chown '/tmp/DefaultExecutorTest_KillTaskGroupOnTaskFailure_M0FOoo/slaves/0bcb0250-4cf5-4209-92fe-ce260518b50f-S0/frameworks/0bcb0250-4cf5-4209-92fe-ce260518b50f-0000/executors/default/runs/725fe374-0d1e-4d9f-b1b0-e5ffb16b1101/containers/a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8' to user 'vagrant'
I1208 03:26:53.134392 28653 containerizer.cpp:1776] Starting nested container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.855fae95-810b-4e9d-8397-7138bdda91b7
I1208 03:26:53.134567 28653 containerizer.cpp:1800] Trying to chown '/tmp/DefaultExecutorTest_KillTaskGroupOnTaskFailure_M0FOoo/slaves/0bcb0250-4cf5-4209-92fe-ce260518b50f-S0/frameworks/0bcb0250-4cf5-4209-92fe-ce260518b50f-0000/executors/default/runs/725fe374-0d1e-4d9f-b1b0-e5ffb16b1101/containers/855fae95-810b-4e9d-8397-7138bdda91b7' to user 'vagrant'
I1208 03:26:53.142004 28653 launcher.cpp:133] Forked child with pid '29198' for container '725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8'
I1208 03:26:53.144634 28653 launcher.cpp:133] Forked child with pid '29199' for container '725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.855fae95-810b-4e9d-8397-7138bdda91b7'
I1208 03:26:53.152432 29187 default_executor.cpp:452] Successfully launched child containers [ 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8, 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.855fae95-810b-4e9d-8397-7138bdda91b7 ] for tasks [ 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5, bf21fae2-513e-4ea1-b85c-dfd2546e4249 ]
I1208 03:26:53.154485 29189 default_executor.cpp:528] Waiting for child container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8 of task '3a8a0c1c-c386-409d-a21c-653dc2d3d7d5'
I1208 03:26:53.154712 29189 default_executor.cpp:528] Waiting for child container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.855fae95-810b-4e9d-8397-7138bdda91b7 of task 'bf21fae2-513e-4ea1-b85c-dfd2546e4249'
I1208 03:26:53.155655 28647 http.cpp:288] HTTP POST for /slave(8)/api/v1/executor from 10.0.2.15:50362
I1208 03:26:53.155807 28647 slave.cpp:3743] Handling status update TASK_RUNNING (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.156080 28647 http.cpp:288] HTTP POST for /slave(8)/api/v1/executor from 10.0.2.15:50362
I1208 03:26:53.156163 28647 slave.cpp:3743] Handling status update TASK_RUNNING (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.157243 28647 http.cpp:288] HTTP POST for /slave(8)/api/v1 from 10.0.2.15:50368
I1208 03:26:53.157467 28647 http.cpp:288] HTTP POST for /slave(8)/api/v1 from 10.0.2.15:50366
I1208 03:26:53.157699 28647 http.cpp:449] Processing call WAIT_NESTED_CONTAINER
I1208 03:26:53.157966 28647 http.cpp:449] Processing call WAIT_NESTED_CONTAINER
I1208 03:26:53.158440 28652 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.159534 28647 slave.cpp:4184] Forwarding the update TASK_RUNNING (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 to master@10.0.2.15:46643
I1208 03:26:53.159840 28651 master.cpp:5808] Status update TASK_RUNNING (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 from agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm)
I1208 03:26:53.159881 28651 master.cpp:5870] Forwarding status update TASK_RUNNING (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.159986 28647 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.160099 28651 master.cpp:7790] Updating the state of task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1208 03:26:53.160365 28647 slave.cpp:4184] Forwarding the update TASK_RUNNING (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 to master@10.0.2.15:46643
I1208 03:26:53.160670 28647 master.cpp:5808] Status update TASK_RUNNING (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 from agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm)
I1208 03:26:53.160711 28647 master.cpp:5870] Forwarding status update TASK_RUNNING (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.160899 28647 master.cpp:7790] Updating the state of task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I1208 03:26:53.162302 29190 default_executor.cpp:131] Received ACKNOWLEDGED event
I1208 03:26:53.162602 29188 default_executor.cpp:131] Received ACKNOWLEDGED event
I1208 03:26:53.213343 28653 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 10.0.2.15:50356
I1208 03:26:53.213508 28653 master.cpp:4918] Processing ACKNOWLEDGE call bfb80b10-da9b-44d2-977a-61b88531e809 for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (default) on agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0
I1208 03:26:53.213838 28648 status_update_manager.cpp:395] Received status update acknowledgement (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
W1208 03:26:53.213982 28648 status_update_manager.cpp:769] Unexpected status update acknowledgement (received bfb80b10-da9b-44d2-977a-61b88531e809, expecting dcdd2cb5-fdea-4556-94e9-ff6246132315) for update TASK_RUNNING (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.214042 28647 http.cpp:391] HTTP POST for /master/api/v1/scheduler from 10.0.2.15:50356
E1208 03:26:53.214143 28648 slave.cpp:3018] Failed to handle status update acknowledgement (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000: Duplicate acknowledgement
I1208 03:26:53.214166 28647 master.cpp:4918] Processing ACKNOWLEDGE call dcdd2cb5-fdea-4556-94e9-ff6246132315 for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (default) on agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0
I1208 03:26:53.214479 28653 status_update_manager.cpp:395] Received status update acknowledgement (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
W1208 03:26:53.214584 28653 status_update_manager.cpp:769] Unexpected status update acknowledgement (received dcdd2cb5-fdea-4556-94e9-ff6246132315, expecting bfb80b10-da9b-44d2-977a-61b88531e809) for update TASK_RUNNING (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
E1208 03:26:53.214701 28653 slave.cpp:3018] Failed to handle status update acknowledgement (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000: Duplicate acknowledgement
I1208 03:26:53.220249 28649 containerizer.cpp:2450] Container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8 has exited
I1208 03:26:53.220296 28649 containerizer.cpp:2087] Destroying container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8 in RUNNING state
I1208 03:26:53.220535 28649 launcher.cpp:149] Asked to destroy container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8
I1208 03:26:53.225530 28650 containerizer.cpp:2366] Checkpointing termination state to nested container's runtime directory '/tmp/DefaultExecutorTest_KillTaskGroupOnTaskFailure_OQh5HL/containers/725fe374-0d1e-4d9f-b1b0-e5ffb16b1101/containers/a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8/termination'
I1208 03:26:53.228024 29188 default_executor.cpp:656] Successfully waited for child container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8 of task '3a8a0c1c-c386-409d-a21c-653dc2d3d7d5' in state TASK_FAILED
E1208 03:26:53.228068 29188 default_executor.cpp:667] Child container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.a532fb7f-fe4c-4588-b1c1-c45dee7fd9c8 terminated with status exited with status 1
I1208 03:26:53.228073 29188 default_executor.cpp:687] Shutting down
I1208 03:26:53.228792 29192 default_executor.cpp:781] Killing child container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.855fae95-810b-4e9d-8397-7138bdda91b7
I1208 03:26:53.230953 28653 http.cpp:288] HTTP POST for /slave(8)/api/v1 from 10.0.2.15:50370
I1208 03:26:53.231276 28653 http.cpp:449] Processing call KILL_NESTED_CONTAINER
I1208 03:26:53.231853 28652 containerizer.cpp:2087] Destroying container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.855fae95-810b-4e9d-8397-7138bdda91b7 in RUNNING state
I1208 03:26:53.232113 28652 launcher.cpp:149] Asked to destroy container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.855fae95-810b-4e9d-8397-7138bdda91b7
I1208 03:26:53.273080 28648 http.cpp:288] HTTP POST for /slave(8)/api/v1/executor from 10.0.2.15:50362
I1208 03:26:53.273331 28648 slave.cpp:3743] Handling status update TASK_FAILED (UUID: ff8338ce-58e5-4508-a2c1-0eb7580aa8f8) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.274930 28650 status_update_manager.cpp:323] Received status update TASK_FAILED (UUID: ff8338ce-58e5-4508-a2c1-0eb7580aa8f8) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.276623 29187 default_executor.cpp:131] Received ACKNOWLEDGED event
I1208 03:26:53.321367 28649 containerizer.cpp:2450] Container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.855fae95-810b-4e9d-8397-7138bdda91b7 has exited
I1208 03:26:53.322789 28649 containerizer.cpp:2366] Checkpointing termination state to nested container's runtime directory '/tmp/DefaultExecutorTest_KillTaskGroupOnTaskFailure_OQh5HL/containers/725fe374-0d1e-4d9f-b1b0-e5ffb16b1101/containers/855fae95-810b-4e9d-8397-7138bdda91b7/termination'
I1208 03:26:53.325847 29194 default_executor.cpp:656] Successfully waited for child container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101.855fae95-810b-4e9d-8397-7138bdda91b7 of task 'bf21fae2-513e-4ea1-b85c-dfd2546e4249' in state TASK_KILLED
I1208 03:26:53.325887 29194 default_executor.cpp:767] Terminating after 1secs
I1208 03:26:53.369621 28648 http.cpp:288] HTTP POST for /slave(8)/api/v1/executor from 10.0.2.15:50362
I1208 03:26:53.369870 28648 slave.cpp:3743] Handling status update TASK_KILLED (UUID: 07d27a3a-c58d-4c2e-8a8f-ee2e4900fb91) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:53.371409 28648 status_update_manager.cpp:323] Received status update TASK_KILLED (UUID: 07d27a3a-c58d-4c2e-8a8f-ee2e4900fb91) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:26:54.335306 28650 containerizer.cpp:2450] Container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101 has exited
I1208 03:26:54.335353 28650 containerizer.cpp:2087] Destroying container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101 in RUNNING state
I1208 03:26:54.335593 28650 launcher.cpp:149] Asked to destroy container 725fe374-0d1e-4d9f-b1b0-e5ffb16b1101
I1208 03:26:54.341533 28652 slave.cpp:4675] Executor 'default' of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 exited with status 0
I1208 03:26:54.341866 28651 master.cpp:5932] Executor 'default' of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 on agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm): exited with status 0
I1208 03:26:54.341914 28651 master.cpp:7915] Removing executor 'default' with resources cpus(*):0.1; mem(*):32; disk(*):32 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 on agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm)
GMOCK WARNING:
Uninteresting mock function call - returning directly.
Function call: failure(0x7ffec532a3f0, @0x7fe234016590 48-byte object <48-2F 78-64 E2-7F 00-00 00-00 00-00 00-00 00-00 07-00 00-00 00-00 00-00 C0-E5 00-34 E2-7F 00-00 90-D9 0A-34 E2-7F 00-00 00-00 00-00 00-00 00-00>)
Stack trace:
I1208 03:26:54.777720 28651 master.cpp:6622] Sending 1 offers to framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (default)
W1208 03:27:03.160513 28646 status_update_manager.cpp:478] Resending status update TASK_RUNNING (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
W1208 03:27:03.160785 28646 status_update_manager.cpp:478] Resending status update TASK_RUNNING (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:27:03.160995 28646 slave.cpp:4184] Forwarding the update TASK_RUNNING (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 to master@10.0.2.15:46643
I1208 03:27:03.161177 28646 slave.cpp:4184] Forwarding the update TASK_RUNNING (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 to master@10.0.2.15:46643
I1208 03:27:03.161424 28646 master.cpp:5808] Status update TASK_RUNNING (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 from agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm)
I1208 03:27:03.161469 28646 master.cpp:5870] Forwarding status update TASK_RUNNING (UUID: dcdd2cb5-fdea-4556-94e9-ff6246132315) for task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:27:03.161887 28646 master.cpp:7790] Updating the state of task 3a8a0c1c-c386-409d-a21c-653dc2d3d7d5 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (latest state: TASK_FAILED, status update state: TASK_RUNNING)
I1208 03:27:03.162178 28646 master.cpp:5808] Status update TASK_RUNNING (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 from agent 0bcb0250-4cf5-4209-92fe-ce260518b50f-S0 at slave(8)@10.0.2.15:46643 (archlinux.vagrant.vm)
I1208 03:27:03.162214 28646 master.cpp:5870] Forwarding status update TASK_RUNNING (UUID: bfb80b10-da9b-44d2-977a-61b88531e809) for task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000
I1208 03:27:03.162407 28646 master.cpp:7790] Updating the state of task bf21fae2-513e-4ea1-b85c-dfd2546e4249 of framework 0bcb0250-4cf5-4209-92fe-ce260518b50f-0000 (latest state: TASK_KILLED, status update state: TASK_RUNNING)
../../mesos/src/tests/default_executor_tests.cpp:610: Failure
Value of: taskStates
Actual: { (3a8a0c1c-c386-409d-a21c-653dc2d3d7d5, TASK_FAILED), (bf21fae2-513e-4ea1-b85c-dfd2546e4249, TASK_KILLED) }
Expected: expectedTaskStates
Which is: { (3a8a0c1c-c386-409d-a21c-653dc2d3d7d5, TASK_RUNNING), (bf21fae2-513e-4ea1-b85c-dfd2546e4249, TASK_RUNNING) }
*** Aborted at 1481128023 (unix time) try "date -d @1481128023" if you are using GNU date ***
PC: @ 0x1bb3ed4 testing::UnitTest::AddTestPartResult()
*** SIGSEGV (@0x0) received by PID 28632 (TID 0x7fe264b7ec40) from PID 0; stack trace: ***
@ 0x7fe25df89080 (unknown)
@ 0x1bb3ed4 testing::UnitTest::AddTestPartResult()
@ 0x1ba86d1 testing::internal::AssertHelper::operator=()
@ 0xe3889c mesos::internal::tests::DefaultExecutorTest_KillTaskGroupOnTaskFailure_Test::TestBody()
@ 0x1bd1df0 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
@ 0x1bcce74 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x1badb08 testing::Test::Run()
@ 0x1bae2c0 testing::TestInfo::Run()
@ 0x1bae8fd testing::TestCase::Run()
@ 0x1bb53f1 testing::internal::UnitTestImpl::RunAllTests()
@ 0x1bd2ab7 testing::internal::HandleSehExceptionsInMethodIfSupported<>()
@ 0x1bcd9b4 testing::internal::HandleExceptionsInMethodIfSupported<>()
@ 0x1bb40f5 testing::UnitTest::Run()
@ 0x118c09e RUN_ALL_TESTS()
@ 0x118bc54 main
@ 0x7fe25bf16291 __libc_start_main
@ 0xa842fa _start
@ 0x0 (unknown)
Install 'notify-send' and try again
Attachments
Issue Links
- is related to
-
-
- Resolved
-
-
-
- Resolved
-