Details
-
Bug
-
Status: Resolved
-
Critical
-
Resolution: Won't Fix
-
1.2.2
-
None
Description
It is possible that a running executor might retry its subscribe request. This can lead to a crash if it previously had any launched tasks. Note that the executor would still be able to subscribe again when the agent process restarts and is recovering.
sudo ./mesos-agent --master=10.0.2.15:5050 --work_dir=/tmp/slave --isolation=cgroups/cpu,cgroups/mem,disk/du,network/cni,filesystem/linux,docker/runtime --image_providers=docker --image_provisioner_backend=overlay --containerizers=mesos --launcher_dir=$(pwd) --executor_environment_variables='{"LD_LIBRARY_PATH": "/home/aaron/Code/src/mesos/build/src/.libs"}' WARNING: Logging before InitGoogleLogging() is written to STDERR I0605 14:58:23.748180 10710 main.cpp:323] Build: 2017-06-02 17:09:05 UTC by aaron I0605 14:58:23.748252 10710 main.cpp:324] Version: 1.4.0 I0605 14:58:23.755409 10710 systemd.cpp:238] systemd version `232` detected I0605 14:58:23.755450 10710 main.cpp:433] Initializing systemd state I0605 14:58:23.763049 10710 systemd.cpp:326] Started systemd slice `mesos_executors.slice` I0605 14:58:23.763777 10710 resolver.cpp:69] Creating default secret resolver I0605 14:58:23.764214 10710 containerizer.cpp:230] Using isolation: cgroups/cpu,cgroups/mem,disk/du,network/cni,filesystem/linux,docker/runtime,volume/image,environment_secret I0605 14:58:23.767192 10710 linux_launcher.cpp:150] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher E0605 14:58:23.770179 10710 shell.hpp:107] Command 'hadoop version 2>&1' failed; this is the output: sh: 1: hadoop: not found I0605 14:58:23.770217 10710 fetcher.cpp:69] Skipping URI fetcher plugin 'hadoop' as it could not be created: Failed to create HDFS client: Failed to execute 'hadoop version 2>&1'; the command was either not found or exited with a non-zero exit status: 127 I0605 14:58:23.770643 10710 provisioner.cpp:255] Using default backend 'overlay' I0605 14:58:23.785892 10710 slave.cpp:248] Mesos agent started on (1)@127.0.1.1:5051 I0605 14:58:23.785957 10710 slave.cpp:249] Flags at startup: --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="false" --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" --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_environment_variables="{"LD_LIBRARY_PATH":"\/home\/aaron\/Code\/src\/mesos\/build\/src\/.libs"}" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_heartbeat_interval="30secs" --image_providers="docker" --image_provisioner_backend="overlay" --initialize_driver_logging="true" --isolation="cgroups/cpu,cgroups/mem,disk/du,network/cni,filesystem/linux,docker/runtime" --launcher="linux" --launcher_dir="/home/aaron/Code/src/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --master="10.0.2.15:5050" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --revocable_cpu_low_priority="true" --runtime_dir="/var/run/mesos" --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/slave" I0605 14:58:23.786392 10710 slave.cpp:552] Agent resources: cpus(*):6; mem(*):6956; disk(*):41113; ports(*):[31000-32000] I0605 14:58:23.786437 10710 slave.cpp:560] Agent attributes: [ ] I0605 14:58:23.786468 10710 slave.cpp:565] Agent hostname: U64 I0605 14:58:23.786574 10714 status_update_manager.cpp:177] Pausing sending status updates I0605 14:58:23.787470 10718 state.cpp:62] Recovering state from '/tmp/slave/meta' I0605 14:58:23.787698 10713 status_update_manager.cpp:203] Recovering status update manager I0605 14:58:23.787755 10713 containerizer.cpp:582] Recovering containerizer I0605 14:58:23.788499 10714 linux_launcher.cpp:291] Recovered container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.788805 10714 linux_launcher.cpp:373] 0fbfe58f-a1bf-4128-83ed-81c2901299b7 is a known orphaned container I0605 14:58:23.790591 10714 memory.cpp:479] Started listening for OOM events for container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.791183 10714 memory.cpp:590] Started listening on 'low' memory pressure events for container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.791714 10714 memory.cpp:590] Started listening on 'medium' memory pressure events for container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.792260 10714 memory.cpp:590] Started listening on 'critical' memory pressure events for container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.792899 10717 provisioner.cpp:372] Recovered container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.793344 10717 metadata_manager.cpp:236] Successfully loaded 1 Docker images I0605 14:58:23.793432 10717 provisioner.cpp:416] Provisioner recovery complete I0605 14:58:23.793514 10717 containerizer.cpp:939] Cleaning up orphan container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.793536 10717 containerizer.cpp:2101] Destroying container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 in RUNNING state I0605 14:58:23.793669 10717 slave.cpp:6127] Finished recovery I0605 14:58:23.793853 10711 linux_launcher.cpp:505] Asked to destroy container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.794039 10717 slave.cpp:945] New master detected at master@10.0.2.15:5050 I0605 14:58:23.794100 10717 slave.cpp:969] No credentials provided. Attempting to register without authentication I0605 14:58:23.794109 10717 slave.cpp:980] Detecting new master I0605 14:58:23.794131 10717 status_update_manager.cpp:177] Pausing sending status updates I0605 14:58:23.794304 10711 linux_launcher.cpp:548] Using freezer to destroy cgroup mesos/0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.794937 10717 cgroups.cpp:2692] Freezing cgroup /sys/fs/cgroup/freezer/mesos/0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.795821 10711 cgroups.cpp:1405] Successfully froze cgroup /sys/fs/cgroup/freezer/mesos/0fbfe58f-a1bf-4128-83ed-81c2901299b7 after 850944ns I0605 14:58:23.813447 10714 cgroups.cpp:2710] Thawing cgroup /sys/fs/cgroup/freezer/mesos/0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.816241 10714 cgroups.cpp:1434] Successfully thawed cgroup /sys/fs/cgroup/freezer/mesos/0fbfe58f-a1bf-4128-83ed-81c2901299b7 after 2.750976ms I0605 14:58:23.851388 10711 containerizer.cpp:2507] Container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 has exited W0605 14:58:23.853590 10712 disk.cpp:448] Ignoring cleanup for unknown container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:23.856833 10711 provisioner.cpp:576] Destroying container rootfs at '/tmp/slave/provisioner/containers/0fbfe58f-a1bf-4128-83ed-81c2901299b7/backends/overlay/rootfses/ade95f11-60ec-47ee-9e4e-bcbc63cc5eaa' for container 0fbfe58f-a1bf-4128-83ed-81c2901299b7 I0605 14:58:24.572808 10712 slave.cpp:1148] Registered with master master@10.0.2.15:5050; given agent ID eb661932-585d-453a-bc64-a720e05ce634-S0 I0605 14:58:24.572888 10711 status_update_manager.cpp:184] Resuming sending status updates I0605 14:58:24.573446 10712 slave.cpp:1206] Forwarding total oversubscribed resources {} I0605 14:58:24.579311 10711 slave.cpp:1632] Got assigned task 'testapp-cc6e64001fee44e3a20d7a15149d8b34' for framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 I0605 14:58:24.580113 10711 slave.cpp:1913] Authorizing task 'testapp-cc6e64001fee44e3a20d7a15149d8b34' for framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 I0605 14:58:24.580293 10711 slave.cpp:2100] Launching task 'testapp-cc6e64001fee44e3a20d7a15149d8b34' for framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 I0605 14:58:24.580703 10711 paths.cpp:573] Trying to chown '/tmp/slave/slaves/eb661932-585d-453a-bc64-a720e05ce634-S0/frameworks/b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001/executors/testapp-cc6e64001fee44e3a20d7a15149d8b34/runs/cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a' to user 'root' I0605 14:58:24.581671 10711 slave.cpp:7086] Launching executor 'testapp-cc6e64001fee44e3a20d7a15149d8b34' of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32 in work directory '/tmp/slave/slaves/eb661932-585d-453a-bc64-a720e05ce634-S0/frameworks/b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001/executors/testapp-cc6e64001fee44e3a20d7a15149d8b34/runs/cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a' I0605 14:58:24.581881 10711 slave.cpp:2795] Launching container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a for executor 'testapp-cc6e64001fee44e3a20d7a15149d8b34' of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 I0605 14:58:24.582072 10712 containerizer.cpp:1056] Starting container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a I0605 14:58:24.582391 10711 slave.cpp:2329] Queued task 'testapp-cc6e64001fee44e3a20d7a15149d8b34' for executor 'testapp-cc6e64001fee44e3a20d7a15149d8b34' of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 I0605 14:58:24.583070 10712 provisioner.cpp:459] Provisioning image rootfs '/tmp/slave/provisioner/containers/cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a/backends/overlay/rootfses/736ac735-51b1-4bc9-892b-15330d0784f9' for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a using overlay backend I0605 14:58:24.587167 10715 memory.cpp:479] Started listening for OOM events for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a I0605 14:58:24.587508 10715 memory.cpp:590] Started listening on 'low' memory pressure events for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a I0605 14:58:24.587805 10715 memory.cpp:590] Started listening on 'medium' memory pressure events for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a I0605 14:58:24.588145 10715 memory.cpp:590] Started listening on 'critical' memory pressure events for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a I0605 14:58:24.588714 10715 memory.cpp:199] Updated 'memory.soft_limit_in_bytes' to 64MB for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a I0605 14:58:24.589285 10715 memory.cpp:228] Updated 'memory.limit_in_bytes' to 64MB for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a I0605 14:58:24.589588 10715 cpu.cpp:101] Updated 'cpu.shares' to 204 (cpus 0.2) for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a I0605 14:58:24.591984 10711 linux_launcher.cpp:429] Launching container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a and cloning with namespaces CLONE_NEWNS I0605 14:58:24.593714 10711 systemd.cpp:96] Assigned child process '10736' to 'mesos_executors.slice' I0605 14:58:24.595461 10712 containerizer.cpp:1722] Checkpointing container's forked pid 10736 to '/tmp/slave/meta/slaves/eb661932-585d-453a-bc64-a720e05ce634-S0/frameworks/b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001/executors/testapp-cc6e64001fee44e3a20d7a15149d8b34/runs/cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a/pids/forked.pid' I0605 14:58:25.247808 10718 slave.cpp:3825] Got registration for executor 'testapp-cc6e64001fee44e3a20d7a15149d8b34' of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 from executor(1)@127.0.1.1:42459 I0605 14:58:25.248884 10715 disk.cpp:208] Updating the disk resources for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a to cpus(*)(allocated: *):0.2; mem(*)(allocated: *):64; disk(*)(allocated: *):1024 I0605 14:58:25.249397 10716 memory.cpp:199] Updated 'memory.soft_limit_in_bytes' to 64MB for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a I0605 14:58:25.250066 10716 cpu.cpp:101] Updated 'cpu.shares' to 204 (cpus 0.2) for container cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a I0605 14:58:25.250365 10715 slave.cpp:2542] Sending queued task 'testapp-cc6e64001fee44e3a20d7a15149d8b34' to executor 'testapp-cc6e64001fee44e3a20d7a15149d8b34' of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 at executor(1)@127.0.1.1:42459 I0605 14:58:25.253556 10716 slave.cpp:4295] Handling status update TASK_RUNNING (UUID: 0292182c-35e6-4df8-8583-fe11f726c211) for task testapp-cc6e64001fee44e3a20d7a15149d8b34 of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 from executor(1)@127.0.1.1:42459 I0605 14:58:25.254091 10714 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 0292182c-35e6-4df8-8583-fe11f726c211) for task testapp-cc6e64001fee44e3a20d7a15149d8b34 of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 I0605 14:58:25.254287 10714 status_update_manager.cpp:834] Checkpointing UPDATE for status update TASK_RUNNING (UUID: 0292182c-35e6-4df8-8583-fe11f726c211) for task testapp-cc6e64001fee44e3a20d7a15149d8b34 of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 I0605 14:58:25.254456 10714 slave.cpp:4735] Forwarding the update TASK_RUNNING (UUID: 0292182c-35e6-4df8-8583-fe11f726c211) for task testapp-cc6e64001fee44e3a20d7a15149d8b34 of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 to master@10.0.2.15:5050 I0605 14:58:25.254534 10714 slave.cpp:4645] Sending acknowledgement for status update TASK_RUNNING (UUID: 0292182c-35e6-4df8-8583-fe11f726c211) for task testapp-cc6e64001fee44e3a20d7a15149d8b34 of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 to executor(1)@127.0.1.1:42459 I0605 14:58:25.260128 10712 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 0292182c-35e6-4df8-8583-fe11f726c211) for task testapp-cc6e64001fee44e3a20d7a15149d8b34 of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 I0605 14:58:25.260184 10712 status_update_manager.cpp:834] Checkpointing ACK for status update TASK_RUNNING (UUID: 0292182c-35e6-4df8-8583-fe11f726c211) for task testapp-cc6e64001fee44e3a20d7a15149d8b34 of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 I0605 14:58:25.352159 10712 http.cpp:1115] HTTP POST for /slave(1)/api/v1/executor from 10.0.2.15:55512 with User-Agent='mesos-framework-sdk' I0605 14:58:25.352342 10712 slave.cpp:3609] Received Subscribe request for HTTP executor 'testapp-cc6e64001fee44e3a20d7a15149d8b34' of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 at executor(1)@127.0.1.1:42459 I0605 14:58:25.352388 10712 slave.cpp:3672] Creating a marker file for HTTP based executor 'testapp-cc6e64001fee44e3a20d7a15149d8b34' of framework b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001 (via HTTP) at path '/tmp/slave/meta/slaves/eb661932-585d-453a-bc64-a720e05ce634-S0/frameworks/b9d7ab7a-f123-4a7c-bfda-07c483ece870-0001/executors/testapp-cc6e64001fee44e3a20d7a15149d8b34/runs/cb57b657-4fbb-4fec-9e00-8ca4f0bd0e4a/http.marker' F0605 14:58:25.352444 10712 slave.cpp:3685] Check failed: executor->launchedTasks.empty() Newly registered executor 'testapp-cc6e64001fee44e3a20d7a15149d8b34' has launched tasks *** Check failure stack trace: *** @ 0x7fb835fe30ed google::LogMessage::Fail() @ 0x7fb835fe4ef0 google::LogMessage::SendToLog() @ 0x7fb835fe2cb3 google::LogMessage::Flush() @ 0x7fb835fe5939 google::LogMessageFatal::~LogMessageFatal() @ 0x7fb8346e126c mesos::internal::slave::Slave::subscribe() @ 0x7fb8345f3169 mesos::internal::slave::Http::executor() @ 0x7fb8346b1107 _ZNSt17_Function_handlerIFN7process6FutureINS0_4http8ResponseEEERKNS2_7RequestERK6OptionINS2_14authentication9PrincipalEEEZN5mesos8internal5slave5Slave10initializeEvEUlS7_SD_E1_E9_M_invokeERKSt9_Any_dataS7_SD_ @ 0x7fb833964a10 _ZNSt17_Function_handlerIFN7process6FutureINS0_4http8ResponseEEEvEZZNKS0_9_DeferredIZZNS0_11ProcessBase6_visitERKNS7_12HttpEndpointERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKNS0_5OwnedINS2_7RequestEEEENKUlRK6OptionINS2_14authentication20AuthenticationResultEEE0_clEST_EUlbE1_EcvSt8functionIFT_T0_EEIS4_RKbEEvENKUlS14_E_clES14_EUlvE_E9_M_invokeERKSt9_Any_data @ 0x7fb83465fffe _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8internal8DispatchINS0_6FutureINS0_4http8ResponseEEEEclIRSt8functionIFS9_vEEEES9_RKNS0_4UPIDEOT_EUlS2_E_E9_M_invokeERKSt9_Any_dataOS2_ @ 0x7fb8339607ec process::ProcessBase::visit() @ 0x7fb83396c03b process::ProcessManager::resume() @ 0x7fb8339755bf _ZNSt6thread11_State_implISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUt_vEEE6_M_runEv @ 0x7fb832a3e83f (unknown) @ 0x7fb83596d6da start_thread @ 0x7fb8324ad17f (unknown) Aborted (core dumped)