[MESOS-9256] Segfault in PersistentVolumeDefaultExecutor.ROOT_TasksSharingViaSandboxVolumes test - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Resolved
Priority: Major
Resolution: Duplicate
Affects Version/s: None
Fix Version/s: None
Component/s: None
Labels:
None

Description

Observed on an internal CI system:

*** SIGSEGV (@0x0) received by PID 7654 (TID 0x7f7f62fe6700) from PID 0; stack trace: ***
    @     0x7f7f38b6f362 (unknown)
    @     0x7f7f38b738b9 (unknown)
    @     0x7f7f38b66f78 (unknown)
    @     0x7f7f6ca2e390 (unknown)
    @     0x7f7f6fa73373 mesos::v1::scheduler::Mesos::send()
    @     0x55b5fa8a8af6 _ZNK5mesos8internal5tests2v19scheduler23SendAcknowledgeActionP2INS_2v111FrameworkIDENS5_7AgentIDEE10gmock_ImplIFvPNS5_9scheduler5MesosERKNSA_12Event_UpdateEEE17gmock_PerformImplISC_SF_N7testing8internal12ExcessiveArgESL_SL_SL_SL_SL_SL_SL_EEvRKSt5tupleIJSC_SF_EET_T0_T1_T2_T3_T4_T5_T6_T7_T8_
    @     0x55b5fa8a8c70 _ZN5mesos8internal5tests2v19scheduler23SendAcknowledgeActionP2INS_2v111FrameworkIDENS5_7AgentIDEE10gmock_ImplIFvPNS5_9scheduler5MesosERKNSA_12Event_UpdateEEE7PerformERKSt5tupleIJSC_SF_EE
    @     0x55b5fa792fbe _ZN7testing8internal12DoBothActionI17PromiseArgActionPILi1EPN7process7PromiseIN5mesos2v19scheduler12Event_UpdateEEEENS5_8internal5tests2v19scheduler23SendAcknowledgeActionP2INS6_11FrameworkIDENS6_7AgentIDEEEE4ImplIFvPNS7_5MesosERKS8_EE7PerformERKSt5tupleIJSN_SP_EE
    @     0x55b5fa7c7957 testing::internal::FunctionMockerBase<>::UntypedPerformAction()
    @     0x55b5fbc36409 testing::internal::UntypedFunctionMockerBase::UntypedInvokeWith()
    @     0x55b5fa8b6f1a mesos::internal::tests::scheduler::MockHTTPScheduler<>::events()
    @     0x55b5fa828b76 std::_Function_handler<>::_M_invoke()
    @     0x7f7f6fa78358 process::AsyncExecutorProcess::execute<>()
    @     0x7f7f6fa82fdd _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchI7NothingNS1_20AsyncExecutorProcessERKSt8functionIFvRKSt5queueIN5mesos2v19scheduler5EventESt5dequeISH_SaISH_EEEEESL_SR_RSL_EENS1_6FutureIT_EERKNS1_3PIDIT0_EEMSX_FSU_T1_T2_EOT3_OT4_EUlSt10unique_ptrINS1_7PromiseISA_EESt14default_deleteIS1B_EEOSP_OSL_S3_E_IS1E_SP_SL_St12_PlaceholderILi1EEEEEEclEOS3_
    @     0x7f7f70870ff1 process::ProcessBase::consume()
    @     0x7f7f7089351a process::ProcessManager::resume()
    @     0x7f7f70897256 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
    @     0x7f7f6d211c80 (unknown)
    @     0x7f7f6ca246ba start_thread
    @     0x7f7f6c75a41d (unknown)
timeout: the monitored command dumped core
./mesos-ci/mesos_ci: line 161:  7652 Segmentation fault      (core dumped)

This apparently happens while the test is trying to shut down.

Full log:

[ RUN      ] LauncherAndIsolationParam/PersistentVolumeDefaultExecutor.ROOT_TasksSharingViaSandboxVolumes/2
I0925 01:02:09.754863  7654 cluster.cpp:173] Creating default 'local' authorizer
I0925 01:02:09.755894 29988 master.cpp:413] Master bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3 (ip-172-16-10-100.ec2.internal) started on 172.16.10.100:46052
I0925 01:02:09.755976 29988 master.cpp:416] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="hierarchical" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/XVQWXD/credentials" --filter_gpu_resources="true" --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" --max_unreachable_tasks_per_framework="1000" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --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" --require_agent_domain="false" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/XVQWXD/master" --zk_session_timeout="10secs"
I0925 01:02:09.756116 29988 master.cpp:465] Master only allowing authenticated frameworks to register
I0925 01:02:09.756127 29988 master.cpp:471] Master only allowing authenticated agents to register
I0925 01:02:09.756134 29988 master.cpp:477] Master only allowing authenticated HTTP frameworks to register
I0925 01:02:09.756140 29988 credentials.hpp:37] Loading credentials for authentication from '/tmp/XVQWXD/credentials'
I0925 01:02:09.756214 29988 master.cpp:521] Using default 'crammd5' authenticator
I0925 01:02:09.756271 29988 http.cpp:1037] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0925 01:02:09.756320 29988 http.cpp:1037] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0925 01:02:09.756356 29988 http.cpp:1037] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0925 01:02:09.756384 29988 master.cpp:602] Authorization enabled
I0925 01:02:09.756505 29986 hierarchical.cpp:182] Initialized hierarchical allocator process
I0925 01:02:09.756721 29986 whitelist_watcher.cpp:77] No whitelist given
I0925 01:02:09.757391 29991 master.cpp:2083] Elected as the leading master!
I0925 01:02:09.757413 29991 master.cpp:1638] Recovering from registrar
I0925 01:02:09.757454 29991 registrar.cpp:339] Recovering registrar
I0925 01:02:09.757650 29986 registrar.cpp:383] Successfully fetched the registry (0B) in 172032ns
I0925 01:02:09.757691 29986 registrar.cpp:487] Applied 1 operations in 7554ns; attempting to update the registry
I0925 01:02:09.757843 29990 registrar.cpp:544] Successfully updated the registry in 131840ns
I0925 01:02:09.757884 29990 registrar.cpp:416] Successfully recovered registrar
I0925 01:02:09.760943 29990 master.cpp:1752] Recovered 0 agents from the registry (176B); allowing 10mins for agents to reregister
I0925 01:02:09.761042 29988 hierarchical.cpp:220] Skipping recovery of hierarchical allocator: nothing to recover
W0925 01:02:09.762631  7654 process.cpp:2810] Attempted to spawn already running process files@172.16.10.100:46052
I0925 01:02:09.763052  7654 containerizer.cpp:305] Using isolation { environment_secret, volume/host_path, filesystem/linux, volume/sandbox_path, network/cni, volume/image }
I0925 01:02:09.764839  7654 linux_launcher.cpp:144] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
I0925 01:02:09.765285  7654 provisioner.cpp:298] Using default backend 'overlay'
I0925 01:02:09.766428  7654 cluster.cpp:485] Creating default 'local' authorizer
I0925 01:02:09.766952 29986 slave.cpp:267] Mesos agent started on (1142)@172.16.10.100:46052
I0925 01:02:09.767233  7654 scheduler.cpp:189] Version: 1.8.0
I0925 01:02:09.767112 29986 slave.cpp:268] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --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/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --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/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="filesystem/linux,volume/sandbox_path" --launcher="linux" --launcher_dir="/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/Plain/label/mesos-ec2-ubuntu-16.04/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --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/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7" --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/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn" --zk_session_timeout="10secs"
I0925 01:02:09.767598 29990 scheduler.cpp:355] Using default 'basic' HTTP authenticatee
I0925 01:02:09.767776 29990 scheduler.cpp:538] New master detected at master@172.16.10.100:46052
I0925 01:02:09.767801 29990 scheduler.cpp:547] Waiting for 0ns before initiating a re-(connection) attempt with the master
I0925 01:02:09.767663 29986 credentials.hpp:86] Loading credential for authentication from '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/credential'
I0925 01:02:09.767917 29986 slave.cpp:300] Agent using credential for: test-principal
I0925 01:02:09.767938 29986 credentials.hpp:37] Loading credentials for authentication from '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/http_credentials'
I0925 01:02:09.768005 29986 http.cpp:1037] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0925 01:02:09.768110 29986 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
I0925 01:02:09.768517 29986 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I0925 01:02:09.768573 29986 slave.cpp:623] Agent attributes: [  ]
I0925 01:02:09.768584 29986 slave.cpp:632] Agent hostname: ip-172-16-10-100.ec2.internal
I0925 01:02:09.768735 29987 task_status_update_manager.cpp:181] Pausing sending task status updates
I0925 01:02:09.768927 29987 state.cpp:66] Recovering state from '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/meta'
I0925 01:02:09.769170 29993 slave.cpp:6909] Finished recovering checkpointed state from '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/meta', beginning agent recovery
I0925 01:02:09.769215 29993 task_status_update_manager.cpp:207] Recovering task status update manager
I0925 01:02:09.769301 29993 containerizer.cpp:727] Recovering Mesos containers
I0925 01:02:09.769397 29987 linux_launcher.cpp:286] Recovering Linux launcher
I0925 01:02:09.769907 29989 scheduler.cpp:429] Connected with the master at http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:09.770095 29987 containerizer.cpp:1053] Recovering isolators
I0925 01:02:09.770097 29989 scheduler.cpp:248] Sending SUBSCRIBE call to http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:09.770819 29987 containerizer.cpp:1092] Recovering provisioner
I0925 01:02:09.770941 29987 provisioner.cpp:494] Provisioner recovery complete
I0925 01:02:09.771129 29988 composing.cpp:339] Finished recovering all containerizers
I0925 01:02:09.771230 29991 process.cpp:3569] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 01:02:09.771419 29990 slave.cpp:7138] Recovering executors
I0925 01:02:09.771615 29990 slave.cpp:7291] Finished recovery
I0925 01:02:09.771641 29991 http.cpp:1177] HTTP POST for /master/api/v1/scheduler from 172.16.10.100:38904
I0925 01:02:09.771965 29991 master.cpp:2502] Received subscription request for HTTP framework 'default'
I0925 01:02:09.772136 29991 master.cpp:2155] Authorizing framework principal 'test-principal' to receive offers for roles '{ default-role }'
I0925 01:02:09.772085 29988 task_status_update_manager.cpp:181] Pausing sending task status updates
I0925 01:02:09.772403 29991 master.cpp:2637] Subscribing framework 'default' with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I0925 01:02:09.772825 29991 master.cpp:9883] Adding framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) with roles {  } suppressed
I0925 01:02:09.772058 29990 slave.cpp:1254] New master detected at master@172.16.10.100:46052
I0925 01:02:09.773002 29990 slave.cpp:1319] Detecting new master
I0925 01:02:09.773167 29992 hierarchical.cpp:306] Added framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.773355 29990 slave.cpp:1346] Authenticating with master master@172.16.10.100:46052
I0925 01:02:09.773413 29990 slave.cpp:1355] Using default CRAM-MD5 authenticatee
I0925 01:02:09.773525 29992 hierarchical.cpp:1564] Performed allocation for 0 agents in 9040ns
I0925 01:02:09.773530 29990 authenticatee.cpp:121] Creating new client SASL connection
I0925 01:02:09.773943 29988 scheduler.cpp:845] Enqueuing event SUBSCRIBED received from http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:09.774062 29988 master.cpp:9653] Authenticating slave(1142)@172.16.10.100:46052
I0925 01:02:09.774118 29988 scheduler.cpp:845] Enqueuing event HEARTBEAT received from http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:09.774159 29988 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1990)@172.16.10.100:46052
I0925 01:02:09.774228 29988 authenticator.cpp:98] Creating new server SASL connection
I0925 01:02:09.774577 29990 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0925 01:02:09.774602 29990 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0925 01:02:09.774634 29990 authenticator.cpp:204] Received SASL authentication start
I0925 01:02:09.774677 29990 authenticator.cpp:326] Authentication requires more steps
I0925 01:02:09.774718 29990 authenticatee.cpp:259] Received SASL authentication step
I0925 01:02:09.774778 29990 authenticator.cpp:232] Received SASL authentication step
I0925 01:02:09.774813 29990 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-100.ec2.internal' server FQDN: 'ip-172-16-10-100.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0925 01:02:09.774829 29990 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0925 01:02:09.774842 29990 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0925 01:02:09.774850 29990 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-100.ec2.internal' server FQDN: 'ip-172-16-10-100.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0925 01:02:09.774857 29990 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0925 01:02:09.774864 29990 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0925 01:02:09.774876 29990 authenticator.cpp:318] Authentication success
I0925 01:02:09.774914 29990 authenticatee.cpp:299] Authentication success
I0925 01:02:09.774973 29990 master.cpp:9685] Successfully authenticated principal 'test-principal' at slave(1142)@172.16.10.100:46052
I0925 01:02:09.775018 29990 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1990)@172.16.10.100:46052
I0925 01:02:09.775100 29990 slave.cpp:1446] Successfully authenticated with master master@172.16.10.100:46052
I0925 01:02:09.775223 29990 slave.cpp:1877] Will retry registration in 18.062394ms if necessary
I0925 01:02:09.775324 29993 master.cpp:6605] Received register agent message from slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:09.775521 29993 master.cpp:3964] Authorizing agent providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal 'test-principal'
I0925 01:02:09.775787 29987 master.cpp:6672] Authorized registration of agent at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:09.775892 29987 master.cpp:6787] Registering agent at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal) with id bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0
I0925 01:02:09.776064 29987 registrar.cpp:487] Applied 1 operations in 31924ns; attempting to update the registry
I0925 01:02:09.776216 29988 registrar.cpp:544] Successfully updated the registry in 124160ns
I0925 01:02:09.776274 29988 master.cpp:6835] Admitted agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:09.776437 29988 master.cpp:6880] Registered agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0925 01:02:09.776526 29988 slave.cpp:1479] Registered with master master@172.16.10.100:46052; given agent ID bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0
I0925 01:02:09.776643 29993 task_status_update_manager.cpp:188] Resuming sending task status updates
I0925 01:02:09.776706 29988 slave.cpp:1499] Checkpointing SlaveInfo to '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/meta/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/slave.info'
I0925 01:02:09.776938 29991 hierarchical.cpp:601] Added agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 (ip-172-16-10-100.ec2.internal) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I0925 01:02:09.777185 29988 slave.cpp:1548] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"M/Uu5nh9T76msNK5SH348Q=="},"slave_id":{"value":"bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0"},"update_oversubscribed_resources":false}
I0925 01:02:09.777441 29993 master.cpp:7939] Ignoring update on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal) as it reports no changes
I0925 01:02:09.777598 29991 hierarchical.cpp:1564] Performed allocation for 1 agents in 468721ns
I0925 01:02:09.777724 29991 master.cpp:9468] Sending offers [ bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-O0 ] to framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default)
I0925 01:02:09.778156 29990 scheduler.cpp:845] Enqueuing event OFFERS received from http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:09.778748 29987 scheduler.cpp:248] Sending ACCEPT call to http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:09.779168 29991 process.cpp:3569] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 01:02:09.779448 29986 http.cpp:1177] HTTP POST for /master/api/v1/scheduler from 172.16.10.100:38902
I0925 01:02:09.779665 29986 master.cpp:11462] Removing offer bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-O0
I0925 01:02:09.779881 29986 master.cpp:4467] Processing ACCEPT call for offers: [ bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-O0 ] on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal) for framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default)
I0925 01:02:09.779939 29986 master.cpp:3609] Authorizing principal 'test-principal' to reserve resources 'cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.3; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):96; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):96'
I0925 01:02:09.780071 29986 master.cpp:3744] Authorizing principal 'test-principal' to create volumes '[{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"executor","principal":"test-principal"},"volume":{"container_path":"executor_volume_path","mode":"RW"}},"name":"disk","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"}]'
I0925 01:02:09.780256 29986 master.cpp:3541] Authorizing framework principal 'test-principal' to launch task producer
I0925 01:02:09.780388 29986 master.cpp:3541] Authorizing framework principal 'test-principal' to launch task consumer
I0925 01:02:09.780948 29989 master.cpp:4835] Applying RESERVE operation for resources [{"allocation_info":{"role":"default-role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":0.3},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":96.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"disk","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":96.0},"type":"SCALAR"}] from framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) to agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:09.781265 29989 master.cpp:11353] Sending operation '' (uuid: 2202189b-741c-40ec-a2f4-fdc5ce8d117a) to agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:09.781371 29989 master.cpp:4978] Applying CREATE operation for volumes [{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"executor","principal":"test-principal"},"volume":{"container_path":"executor_volume_path","mode":"RW"}},"name":"disk","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"}] from framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) to agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:09.781491 29989 master.cpp:11353] Sending operation '' (uuid: 2c0bab54-ffb0-4a6b-b02c-fb2789f6354b) to agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:09.782239 29989 master.cpp:12209] Adding task producer with resources cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.1; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32 on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:09.782320 29989 master.cpp:12209] Adding task consumer with resources cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.1; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32 on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:09.782400 29989 master.cpp:5663] Launching task group { consumer, producer } of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) with resources cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.2; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):64; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):64 on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal) on  new executor
I0925 01:02:09.782857 29989 hierarchical.cpp:967] Updated allocation of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 from cpus(allocated: default-role):2; mem(allocated: default-role):1024; disk(allocated: default-role):1024; ports(allocated: default-role):[31000-32000] to cpus(allocated: default-role):1.7; mem(allocated: default-role):928; disk(allocated: default-role):928; ports(allocated: default-role):[31000-32000]; cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.3; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):96; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):95; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1
I0925 01:02:09.782882 29993 slave.cpp:4202] Updated checkpointed resources from {} to cpus(reservations: [(DYNAMIC,default-role,test-principal)]):0.3; mem(reservations: [(DYNAMIC,default-role,test-principal)]):96; disk(reservations: [(DYNAMIC,default-role,test-principal)]):96
I0925 01:02:09.783201 29993 slave.cpp:7990] Updating the state of operation with no ID (uuid: 2202189b-741c-40ec-a2f4-fdc5ce8d117a) for framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0925 01:02:09.783022 29989 hierarchical.cpp:1236] Recovered cpus(allocated: default-role):1.7; mem(allocated: default-role):928; disk(allocated: default-role):928; ports(allocated: default-role):[31000-32000] (total: cpus:1.7; mem:928; disk:928; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,default-role,test-principal)]):0.3; mem(reservations: [(DYNAMIC,default-role,test-principal)]):96; disk(reservations: [(DYNAMIC,default-role,test-principal)]):95; disk(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1, allocated: disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):95; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):96; cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.3) on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 from framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.783454 29989 hierarchical.cpp:1282] Framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 filtered agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 for 5secs
I0925 01:02:09.783421 29990 master.cpp:11103] Updating the state of operation '' (uuid: 2202189b-741c-40ec-a2f4-fdc5ce8d117a) for framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0925 01:02:09.784224 29993 slave.cpp:4202] Updated checkpointed resources from cpus(reservations: [(DYNAMIC,default-role,test-principal)]):0.3; mem(reservations: [(DYNAMIC,default-role,test-principal)]):96; disk(reservations: [(DYNAMIC,default-role,test-principal)]):96 to cpus(reservations: [(DYNAMIC,default-role,test-principal)]):0.3; mem(reservations: [(DYNAMIC,default-role,test-principal)]):96; disk(reservations: [(DYNAMIC,default-role,test-principal)]):95; disk(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1
I0925 01:02:09.784281 29993 slave.cpp:7990] Updating the state of operation with no ID (uuid: 2c0bab54-ffb0-4a6b-b02c-fb2789f6354b) for framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
I0925 01:02:09.784503 29993 slave.cpp:2014] Got assigned task group containing tasks [ producer, consumer ] for framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.784960 29991 master.cpp:11103] Updating the state of operation '' (uuid: 2c0bab54-ffb0-4a6b-b02c-fb2789f6354b) for framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
I0925 01:02:09.785073 29993 slave.cpp:2388] Authorizing task group containing tasks [ producer, consumer ] for framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.785190 29993 slave.cpp:8466] Authorizing framework principal 'test-principal' to launch task producer
I0925 01:02:09.785372 29993 slave.cpp:8466] Authorizing framework principal 'test-principal' to launch task consumer
I0925 01:02:09.786518 29989 slave.cpp:2831] Launching task group containing tasks [ producer, consumer ] for framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.786568 29989 paths.cpp:752] Creating sandbox '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d' for user 'root'
I0925 01:02:09.786859 29989 slave.cpp:8994] Launching executor 'default' of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 with resources [{"allocation_info":{"role":"default-role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"disk","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":31.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"executor","principal":"test-principal"},"volume":{"container_path":"executor_volume_path","mode":"RW"}},"name":"disk","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"}] in work directory '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d'
I0925 01:02:09.787148 29989 slave.cpp:3509] Launching container b430cb65-0720-4793-ae5b-ed23e12f390d for executor 'default' of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.787467 29989 slave.cpp:3028] Queued task group containing tasks [ producer, consumer ] for executor 'default' of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.787612 29989 slave.cpp:988] Successfully attached '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d' to virtual path '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/latest'
I0925 01:02:09.787750 29989 slave.cpp:988] Successfully attached '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d' to virtual path '/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/latest'
I0925 01:02:09.787907 29987 containerizer.cpp:1280] Starting container b430cb65-0720-4793-ae5b-ed23e12f390d
I0925 01:02:09.787959 29989 slave.cpp:988] Successfully attached '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d' to virtual path '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d'
I0925 01:02:09.788810 29987 containerizer.cpp:1446] Checkpointed ContainerConfig at '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/containers/b430cb65-0720-4793-ae5b-ed23e12f390d/config'
I0925 01:02:09.788832 29987 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d from PROVISIONING to PREPARING
I0925 01:02:09.789042 29990 linux.cpp:528] Changing the ownership of the persistent volume at '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/volumes/roles/default-role/executor' with uid 0 and gid 0
I0925 01:02:09.789232 29990 linux.cpp:593] Mounting '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/volumes/roles/default-role/executor' to '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/executor_volume_path' for persistent volume disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1 of container b430cb65-0720-4793-ae5b-ed23e12f390d
I0925 01:02:09.791697 29992 containerizer.cpp:1939] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"clone_namespaces":[131072],"command":{"arguments":["mesos-default-executor","--launcher_dir=/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/Plain/label/mesos-ec2-ubuntu-16.04/mesos/build/src"],"shell":false,"value":"/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/Plain/label/mesos-ec2-ubuntu-16.04/mesos/build/src/mesos-default-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.100:46052"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"default"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(1142)@172.16.10.100:46052"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d"}]},"task_environment":{},"user":"root","working_directory":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d"}" --pipe_read="89" --pipe_write="92" --runtime_directory="/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/containers/b430cb65-0720-4793-ae5b-ed23e12f390d" --unshare_namespace_mnt="false"'
I0925 01:02:09.791883 29988 linux_launcher.cpp:492] Launching container b430cb65-0720-4793-ae5b-ed23e12f390d and cloning with namespaces CLONE_NEWNS
I0925 01:02:09.813344 29992 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d from PREPARING to ISOLATING
I0925 01:02:09.814106 29992 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d from ISOLATING to FETCHING
I0925 01:02:09.814397 29992 fetcher.cpp:369] Starting to fetch URIs for container: b430cb65-0720-4793-ae5b-ed23e12f390d, directory: /tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d
I0925 01:02:09.814828 29992 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d from FETCHING to RUNNING
Marked '/' as rslave
I0925 01:02:09.926293 20114 executor.cpp:201] Version: 1.8.0
I0925 01:02:09.928870 29991 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1/executor'
I0925 01:02:09.929276 29988 http.cpp:1177] HTTP POST for /slave(1142)/api/v1/executor from 172.16.10.100:38906
I0925 01:02:09.929356 29988 slave.cpp:4607] Received Subscribe request for HTTP executor 'default' of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.930279 29991 slave.cpp:3282] Sending queued task group containing tasks [ producer, consumer ] to executor 'default' of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (via HTTP)
I0925 01:02:09.930986 29991 slave.cpp:988] Successfully attached '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/executor_volume_path' to virtual path '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/tasks/producer/task_volume_path'
I0925 01:02:09.931011 29991 slave.cpp:988] Successfully attached '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/executor_volume_path' to virtual path '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/tasks/consumer/task_volume_path'
I0925 01:02:09.931030 20134 default_executor.cpp:204] Received SUBSCRIBED event
I0925 01:02:09.931433 20134 default_executor.cpp:208] Subscribed executor on ip-172-16-10-100.ec2.internal
I0925 01:02:09.932010 20133 default_executor.cpp:204] Received LAUNCH_GROUP event
I0925 01:02:09.932420 20132 default_executor.cpp:428] Setting 'MESOS_CONTAINER_IP' to: 172.16.10.100
I0925 01:02:09.933607 29987 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1/executor'
I0925 01:02:09.933791 29988 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1'
I0925 01:02:09.933883 29988 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1'
I0925 01:02:09.934195 29991 http.cpp:1177] HTTP POST for /slave(1142)/api/v1 from 172.16.10.100:38910
I0925 01:02:09.934279 29991 http.cpp:1177] HTTP POST for /slave(1142)/api/v1 from 172.16.10.100:38910
I0925 01:02:09.934404 29991 http.cpp:2408] Processing LAUNCH_NESTED_CONTAINER call for container 'b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02'
I0925 01:02:09.934543 29991 http.cpp:2408] Processing LAUNCH_NESTED_CONTAINER call for container 'b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f'
I0925 01:02:09.934870 29992 containerizer.cpp:1242] Creating sandbox '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/845040da-48f9-498c-96a2-62e3f83d2f02' for user 'root'
I0925 01:02:09.934984 29991 http.cpp:1177] HTTP POST for /slave(1142)/api/v1/executor from 172.16.10.100:38908
I0925 01:02:09.935042 29991 slave.cpp:5269] Handling status update TASK_STARTING (Status UUID: e182f4b6-8a84-4df9-9c89-a7a3fae81ab1) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.935122 29992 containerizer.cpp:1280] Starting container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02
I0925 01:02:09.935501 29992 containerizer.cpp:1446] Checkpointed ContainerConfig at '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/containers/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/845040da-48f9-498c-96a2-62e3f83d2f02/config'
I0925 01:02:09.935514 29992 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 from PROVISIONING to PREPARING
I0925 01:02:09.935740 29992 containerizer.cpp:1242] Creating sandbox '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/daf69515-caa0-4c26-8956-657efeb52e6f' for user 'root'
I0925 01:02:09.935840 29987 sandbox_path.cpp:374] Mounting SANDBOX_PATH volume from '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/executor_volume_path' to '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/845040da-48f9-498c-96a2-62e3f83d2f02/task_volume_path' for container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02
I0925 01:02:09.935896 29992 containerizer.cpp:1280] Starting container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f
I0925 01:02:09.936252 29992 containerizer.cpp:1446] Checkpointed ContainerConfig at '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/containers/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/daf69515-caa0-4c26-8956-657efeb52e6f/config'
I0925 01:02:09.936270 29992 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f from PROVISIONING to PREPARING
I0925 01:02:09.936635 29992 sandbox_path.cpp:374] Mounting SANDBOX_PATH volume from '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/executor_volume_path' to '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/daf69515-caa0-4c26-8956-657efeb52e6f/task_volume_path' for container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f
I0925 01:02:09.937000 29989 containerizer.cpp:1939] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"clone_namespaces":[131072],"command":{"shell":true,"value":"echo abc > task_volume_path/file"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/845040da-48f9-498c-96a2-62e3f83d2f02"},{"name":"MESOS_CONTAINER_IP","type":"VALUE","value":"172.16.10.100"}]},"mounts":[{"flags":20480,"source":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/executor_volume_path","target":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/845040da-48f9-498c-96a2-62e3f83d2f02/task_volume_path"}],"task_environment":{},"user":"root","working_directory":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/845040da-48f9-498c-96a2-62e3f83d2f02"}" --pipe_read="96" --pipe_write="97" --runtime_directory="/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/containers/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/845040da-48f9-498c-96a2-62e3f83d2f02" --unshare_namespace_mnt="false"'
I0925 01:02:09.937294 29991 linux_launcher.cpp:492] Launching nested container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 and cloning with namespaces CLONE_NEWNS
W0925 01:02:09.937341 29993 containerizer.cpp:2399] Skipping status for container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 because: Container does not exist
I0925 01:02:09.937383 29987 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1/executor'
I0925 01:02:09.942143 29987 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: e182f4b6-8a84-4df9-9c89-a7a3fae81ab1) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.942493 29987 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.942839 29987 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: e182f4b6-8a84-4df9-9c89-a7a3fae81ab1) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to the agent
I0925 01:02:09.943104 29987 slave.cpp:5761] Forwarding the update TASK_STARTING (Status UUID: e182f4b6-8a84-4df9-9c89-a7a3fae81ab1) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to master@172.16.10.100:46052
I0925 01:02:09.943373 29987 slave.cpp:5654] Task status update manager successfully handled status update TASK_STARTING (Status UUID: e182f4b6-8a84-4df9-9c89-a7a3fae81ab1) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.943691 29987 master.cpp:8375] Status update TASK_STARTING (Status UUID: e182f4b6-8a84-4df9-9c89-a7a3fae81ab1) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 from agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:09.944392 20135 default_executor.cpp:204] Received ACKNOWLEDGED event
I0925 01:02:09.944589 29987 master.cpp:8432] Forwarding status update TASK_STARTING (Status UUID: e182f4b6-8a84-4df9-9c89-a7a3fae81ab1) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.945801 29992 scheduler.cpp:845] Enqueuing event UPDATE received from http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:09.946342 29992 scheduler.cpp:248] Sending ACKNOWLEDGE call to http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:09.947451 29987 master.cpp:10932] Updating the state of task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I0925 01:02:09.947677 29987 process.cpp:3569] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 01:02:09.965466 29989 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 from PREPARING to ISOLATING
I0925 01:02:09.966351 29989 containerizer.cpp:1939] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"clone_namespaces":[131072],"command":{"shell":true,"value":"while [ ! -f task_volume_path/file ]; do sleep 1; done\ntrue"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/daf69515-caa0-4c26-8956-657efeb52e6f"},{"name":"MESOS_CONTAINER_IP","type":"VALUE","value":"172.16.10.100"}]},"mounts":[{"flags":20480,"source":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/executor_volume_path","target":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/daf69515-caa0-4c26-8956-657efeb52e6f/task_volume_path"}],"task_environment":{},"user":"root","working_directory":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/daf69515-caa0-4c26-8956-657efeb52e6f"}" --pipe_read="98" --pipe_write="99" --runtime_directory="/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/containers/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/daf69515-caa0-4c26-8956-657efeb52e6f" --unshare_namespace_mnt="false"'
I0925 01:02:09.967350 29991 linux_launcher.cpp:492] Launching nested container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f and cloning with namespaces CLONE_NEWNS
I0925 01:02:09.977674 29992 http.cpp:1177] HTTP POST for /slave(1142)/api/v1/executor from 172.16.10.100:38908
I0925 01:02:09.977779 29992 slave.cpp:5269] Handling status update TASK_STARTING (Status UUID: d3d2b908-da16-450e-91d0-91de107d865d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.985407 29992 http.cpp:1177] HTTP POST for /master/api/v1/scheduler from 172.16.10.100:38902
I0925 01:02:09.985517 29992 master.cpp:6241] Processing ACKNOWLEDGE call for status e182f4b6-8a84-4df9-9c89-a7a3fae81ab1 for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0
I0925 01:02:09.985901 29992 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: e182f4b6-8a84-4df9-9c89-a7a3fae81ab1) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:09.986029 29992 slave.cpp:4505] Task status update manager successfully handled status update acknowledgement (UUID: e182f4b6-8a84-4df9-9c89-a7a3fae81ab1) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.001597 29989 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f from PREPARING to ISOLATING
I0925 01:02:10.001992 29989 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 from ISOLATING to FETCHING
I0925 01:02:10.002414 29989 fetcher.cpp:369] Starting to fetch URIs for container: b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02, directory: /tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/845040da-48f9-498c-96a2-62e3f83d2f02
I0925 01:02:10.002777 29989 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f from ISOLATING to FETCHING
I0925 01:02:10.002831 29989 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 from FETCHING to RUNNING
I0925 01:02:10.003057 29989 fetcher.cpp:369] Starting to fetch URIs for container: b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f, directory: /tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/daf69515-caa0-4c26-8956-657efeb52e6f
I0925 01:02:10.003543 29989 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f from FETCHING to RUNNING
I0925 01:02:10.004250 29990 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: d3d2b908-da16-450e-91d0-91de107d865d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.004294 29990 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.004503 29990 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: d3d2b908-da16-450e-91d0-91de107d865d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to the agent
I0925 01:02:10.004727 29990 slave.cpp:5761] Forwarding the update TASK_STARTING (Status UUID: d3d2b908-da16-450e-91d0-91de107d865d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to master@172.16.10.100:46052
I0925 01:02:10.004815 29990 slave.cpp:5654] Task status update manager successfully handled status update TASK_STARTING (Status UUID: d3d2b908-da16-450e-91d0-91de107d865d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.005018 29992 master.cpp:8375] Status update TASK_STARTING (Status UUID: d3d2b908-da16-450e-91d0-91de107d865d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 from agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:10.005053 29992 master.cpp:8432] Forwarding status update TASK_STARTING (Status UUID: d3d2b908-da16-450e-91d0-91de107d865d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.005221 29992 master.cpp:10932] Updating the state of task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
I0925 01:02:10.005697 29987 scheduler.cpp:845] Enqueuing event UPDATE received from http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:10.006053 29987 scheduler.cpp:248] Sending ACKNOWLEDGE call to http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:10.006901 29986 process.cpp:3569] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 01:02:10.007346 20133 default_executor.cpp:204] Received ACKNOWLEDGED event
I0925 01:02:10.009297 20134 default_executor.cpp:663] Finished launching tasks [ producer, consumer ] in child containers [ b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02, b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f ]
I0925 01:02:10.009330 20134 default_executor.cpp:687] Waiting on child containers of tasks [ producer, consumer ]
I0925 01:02:10.013335 29988 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1/executor'
I0925 01:02:10.020534 20132 default_executor.cpp:748] Waiting for child container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 of task 'producer'
I0925 01:02:10.024971 20132 default_executor.cpp:748] Waiting for child container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f of task 'consumer'
I0925 01:02:10.025357 29991 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1'
I0925 01:02:10.025566 29991 http.cpp:1177] HTTP POST for /slave(1142)/api/v1 from 172.16.10.100:38912
I0925 01:02:10.025862 29989 http.cpp:2643] Processing WAIT_NESTED_CONTAINER call for container 'b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02'
I0925 01:02:10.026609 29987 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1'
I0925 01:02:10.026788 29987 http.cpp:1177] HTTP POST for /slave(1142)/api/v1 from 172.16.10.100:38914
I0925 01:02:10.026895 29987 http.cpp:2643] Processing WAIT_NESTED_CONTAINER call for container 'b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f'
I0925 01:02:10.045330 29987 http.cpp:1177] HTTP POST for /master/api/v1/scheduler from 172.16.10.100:38902
I0925 01:02:10.045413 29987 master.cpp:6241] Processing ACKNOWLEDGE call for status d3d2b908-da16-450e-91d0-91de107d865d for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0
I0925 01:02:10.045687 29987 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: d3d2b908-da16-450e-91d0-91de107d865d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.045780 29987 slave.cpp:4505] Task status update manager successfully handled status update acknowledgement (UUID: d3d2b908-da16-450e-91d0-91de107d865d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.049203 29988 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1/executor'
I0925 01:02:10.049491 29988 http.cpp:1177] HTTP POST for /slave(1142)/api/v1/executor from 172.16.10.100:38908
I0925 01:02:10.049579 29988 slave.cpp:5269] Handling status update TASK_RUNNING (Status UUID: 6334aa31-367d-407f-9084-b0e329d9c5cf) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.049726 29988 http.cpp:1177] HTTP POST for /slave(1142)/api/v1/executor from 172.16.10.100:38908
I0925 01:02:10.049785 29988 slave.cpp:5269] Handling status update TASK_RUNNING (Status UUID: 9f7060a5-450e-4485-a790-e871b294e7fe) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
Marked '/' as rslave
I0925 01:02:10.050681 29988 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 6334aa31-367d-407f-9084-b0e329d9c5cf) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.050750 29988 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 6334aa31-367d-407f-9084-b0e329d9c5cf) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to the agent
I0925 01:02:10.050832 29988 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 9f7060a5-450e-4485-a790-e871b294e7fe) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.050886 29988 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 9f7060a5-450e-4485-a790-e871b294e7fe) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to the agent
I0925 01:02:10.050953 29988 slave.cpp:5761] Forwarding the update TASK_RUNNING (Status UUID: 6334aa31-367d-407f-9084-b0e329d9c5cf) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to master@172.16.10.100:46052
IPrepared mount '0925 01:02:10.051061 29988 slave.cpp:5654] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 6334aa31-367d-407f-9084-b0e329d9c5cf) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.051147 29988 slave.cpp:5761] Forwarding the update TASK_RUNNING (Status UUID: 9f7060a5-450e-4485-a790-e871b294e7fe) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to master@172.16.10.100:46052
I0925 01:02:10.051221 29988 slave.cpp:5654] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 9f7060a5-450e-4485-a790-e871b294e7fe) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
{"flags":20480,"source":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/executor_volume_path","target":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/845040da-48f9-498c-96a2-62e3f83d2f02/task_volume_path"}I0925 01:02:10.051340 29988 master.cpp:8375] Status update TASK_RUNNING (Status UUID: 6334aa31-367d-407f-9084-b0e329d9c5cf) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 from agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:10.051369 29988 master.cpp:8432] Forwarding status update TASK_RUNNING (Status UUID: 6334aa31-367d-407f-9084-b0e329d9c5cf) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
'
I0925 01:02:10.051512 29988 master.cpp:10932] Updating the state of task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0925 01:02:10.051584 29988 master.cpp:8375] Status update TASK_RUNNING (Status UUID: 9f7060a5-450e-4485-a790-e871b294e7fe) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 from agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:10.051622 29988 master.cpp:8432] Forwarding status update TASK_RUNNING (Status UUID: 9f7060a5-450e-4485-a790-e871b294e7fe) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.051717 29988 master.cpp:10932] Updating the state of task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0925 01:02:10.052377 20131 default_executor.cpp:204] Received ACKNOWLEDGED event
I0925 01:02:10.052462 20131 default_executor.cpp:204] Received ACKNOWLEDGED event
I0925 01:02:10.053071 29993 scheduler.cpp:845] Enqueuing event UPDATE received from http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:10.053333 29993 scheduler.cpp:248] Sending ACKNOWLEDGE call to http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:10.053845 29986 process.cpp:3569] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 01:02:10.054056 29987 scheduler.cpp:845] Enqueuing event UPDATE received from http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:10.054270 29987 scheduler.cpp:248] Sending ACKNOWLEDGE call to http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:10.075132 29992 containerizer.cpp:2957] Container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 has exited
I0925 01:02:10.075155 29992 containerizer.cpp:2455] Destroying container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 in RUNNING state
I0925 01:02:10.075165 29992 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 from RUNNING to DESTROYING
I0925 01:02:10.075232 29992 linux_launcher.cpp:580] Asked to destroy container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02
I0925 01:02:10.075276 29992 linux_launcher.cpp:622] Destroying cgroup '/sys/fs/cgroup/freezer/mesos/b430cb65-0720-4793-ae5b-ed23e12f390d/mesos/845040da-48f9-498c-96a2-62e3f83d2f02'
I0925 01:02:10.075484 29992 cgroups.cpp:2838] Freezing cgroup /sys/fs/cgroup/freezer/mesos/b430cb65-0720-4793-ae5b-ed23e12f390d/mesos/845040da-48f9-498c-96a2-62e3f83d2f02
I0925 01:02:10.075603 29992 cgroups.cpp:1229] Successfully froze cgroup /sys/fs/cgroup/freezer/mesos/b430cb65-0720-4793-ae5b-ed23e12f390d/mesos/845040da-48f9-498c-96a2-62e3f83d2f02 after 96256ns
I0925 01:02:10.075717 29992 cgroups.cpp:2856] Thawing cgroup /sys/fs/cgroup/freezer/mesos/b430cb65-0720-4793-ae5b-ed23e12f390d/mesos/845040da-48f9-498c-96a2-62e3f83d2f02
I0925 01:02:10.075801 29992 cgroups.cpp:1258] Successfully thawed cgroup /sys/fs/cgroup/freezer/mesos/b430cb65-0720-4793-ae5b-ed23e12f390d/mesos/845040da-48f9-498c-96a2-62e3f83d2f02 after 62976ns
I0925 01:02:10.077136 29992 provisioner.cpp:597] Ignoring destroy request for unknown container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02
I0925 01:02:10.077342 29992 containerizer.cpp:2747] Checkpointing termination state to nested container's runtime directory '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/containers/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/845040da-48f9-498c-96a2-62e3f83d2f02/termination'
I0925 01:02:10.078702 29986 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1/executor'
I0925 01:02:10.081133 20132 default_executor.cpp:955] Child container b430cb65-0720-4793-ae5b-ed23e12f390d.845040da-48f9-498c-96a2-62e3f83d2f02 of task 'producer' completed in state TASK_FINISHED: Command exited with status 0
I0925 01:02:10.093197 29990 process.cpp:3569] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 01:02:10.093605 29990 http.cpp:1177] HTTP POST for /master/api/v1/scheduler from 172.16.10.100:38902
I0925 01:02:10.093677 29990 master.cpp:6241] Processing ACKNOWLEDGE call for status 6334aa31-367d-407f-9084-b0e329d9c5cf for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0
I0925 01:02:10.093802 29990 http.cpp:1177] HTTP POST for /master/api/v1/scheduler from 172.16.10.100:38902
I0925 01:02:10.093847 29990 master.cpp:6241] Processing ACKNOWLEDGE call for status 9f7060a5-450e-4485-a790-e871b294e7fe for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0
I0925 01:02:10.094156 29990 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 6334aa31-367d-407f-9084-b0e329d9c5cf) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.094244 29990 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 9f7060a5-450e-4485-a790-e871b294e7fe) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.094324 29990 slave.cpp:4505] Task status update manager successfully handled status update acknowledgement (UUID: 6334aa31-367d-407f-9084-b0e329d9c5cf) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.094372 29990 slave.cpp:4505] Task status update manager successfully handled status update acknowledgement (UUID: 9f7060a5-450e-4485-a790-e871b294e7fe) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
Marked '/' as rslave
Prepared mount '{"flags":20480,"source":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/executor_volume_path","target":"/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_aco0Fn/slaves/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0/frameworks/bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000/executors/default/runs/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/daf69515-caa0-4c26-8956-657efeb52e6f/task_volume_path"}'
I0925 01:02:10.117264 29993 http.cpp:1177] HTTP POST for /slave(1142)/api/v1/executor from 172.16.10.100:38908
I0925 01:02:10.117352 29993 slave.cpp:5269] Handling status update TASK_FINISHED (Status UUID: 41ca30de-cdb3-4423-b333-99d3bf684ccd) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.117982 29989 task_status_update_manager.cpp:328] Received task status update TASK_FINISHED (Status UUID: 41ca30de-cdb3-4423-b333-99d3bf684ccd) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.118037 29989 task_status_update_manager.cpp:383] Forwarding task status update TASK_FINISHED (Status UUID: 41ca30de-cdb3-4423-b333-99d3bf684ccd) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to the agent
I0925 01:02:10.118111 29989 slave.cpp:5761] Forwarding the update TASK_FINISHED (Status UUID: 41ca30de-cdb3-4423-b333-99d3bf684ccd) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to master@172.16.10.100:46052
I0925 01:02:10.118261 29986 master.cpp:8375] Status update TASK_FINISHED (Status UUID: 41ca30de-cdb3-4423-b333-99d3bf684ccd) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 from agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:10.118288 29986 master.cpp:8432] Forwarding status update TASK_FINISHED (Status UUID: 41ca30de-cdb3-4423-b333-99d3bf684ccd) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.118402 29986 master.cpp:10932] Updating the state of task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: TASK_FINISHED, status update state: TASK_FINISHED)
I0925 01:02:10.118522 29989 slave.cpp:5654] Task status update manager successfully handled status update TASK_FINISHED (Status UUID: 41ca30de-cdb3-4423-b333-99d3bf684ccd) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.118582 29988 hierarchical.cpp:1236] Recovered cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.1; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32 (total: cpus:1.7; mem:928; disk:928; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,default-role,test-principal)]):0.3; mem(reservations: [(DYNAMIC,default-role,test-principal)]):96; disk(reservations: [(DYNAMIC,default-role,test-principal)]):95; disk(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1, allocated: disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):63; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):64; cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.2) on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 from framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.118860 29990 scheduler.cpp:845] Enqueuing event UPDATE received from http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:10.118990 20135 default_executor.cpp:204] Received ACKNOWLEDGED event
I0925 01:02:10.119097 29993 scheduler.cpp:248] Sending ACKNOWLEDGE call to http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:10.119432 29991 process.cpp:3569] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0925 01:02:10.157290 29989 http.cpp:1177] HTTP POST for /master/api/v1/scheduler from 172.16.10.100:38902
I0925 01:02:10.157359 29989 master.cpp:6241] Processing ACKNOWLEDGE call for status 41ca30de-cdb3-4423-b333-99d3bf684ccd for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0
I0925 01:02:10.157410 29989 master.cpp:11030] Removing task producer with resources cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.1; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32 of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:10.157644 29986 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 41ca30de-cdb3-4423-b333-99d3bf684ccd) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.157694 29986 task_status_update_manager.cpp:538] Cleaning up status update stream for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.157836 29986 slave.cpp:4505] Task status update manager successfully handled status update acknowledgement (UUID: 41ca30de-cdb3-4423-b333-99d3bf684ccd) for task producer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.157860 29986 slave.cpp:9651] Completing task producer
I0925 01:02:10.177611 29992 containerizer.cpp:2957] Container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f has exited
I0925 01:02:10.177635 29992 containerizer.cpp:2455] Destroying container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f in RUNNING state
I0925 01:02:10.177646 29992 containerizer.cpp:3118] Transitioning the state of container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f from RUNNING to DESTROYING
I0925 01:02:10.177721 29992 linux_launcher.cpp:580] Asked to destroy container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f
I0925 01:02:10.177773 29992 linux_launcher.cpp:622] Destroying cgroup '/sys/fs/cgroup/freezer/mesos/b430cb65-0720-4793-ae5b-ed23e12f390d/mesos/daf69515-caa0-4c26-8956-657efeb52e6f'
I0925 01:02:10.177991 29989 cgroups.cpp:2838] Freezing cgroup /sys/fs/cgroup/freezer/mesos/b430cb65-0720-4793-ae5b-ed23e12f390d/mesos/daf69515-caa0-4c26-8956-657efeb52e6f
I0925 01:02:10.178115 29989 cgroups.cpp:1229] Successfully froze cgroup /sys/fs/cgroup/freezer/mesos/b430cb65-0720-4793-ae5b-ed23e12f390d/mesos/daf69515-caa0-4c26-8956-657efeb52e6f after 98816ns
I0925 01:02:10.178267 29989 cgroups.cpp:2856] Thawing cgroup /sys/fs/cgroup/freezer/mesos/b430cb65-0720-4793-ae5b-ed23e12f390d/mesos/daf69515-caa0-4c26-8956-657efeb52e6f
I0925 01:02:10.178359 29989 cgroups.cpp:1258] Successfully thawed cgroup /sys/fs/cgroup/freezer/mesos/b430cb65-0720-4793-ae5b-ed23e12f390d/mesos/daf69515-caa0-4c26-8956-657efeb52e6f after 61952ns
I0925 01:02:10.179339 29986 provisioner.cpp:597] Ignoring destroy request for unknown container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f
I0925 01:02:10.179406 29986 containerizer.cpp:2747] Checkpointing termination state to nested container's runtime directory '/tmp/LauncherAndIsolationParam_PersistentVolumeDefaultExecutor_ROOT_TasksSharingViaSandboxVolumes_2_3Se4n7/containers/b430cb65-0720-4793-ae5b-ed23e12f390d/containers/daf69515-caa0-4c26-8956-657efeb52e6f/termination'
I0925 01:02:10.180907 20130 default_executor.cpp:955] Child container b430cb65-0720-4793-ae5b-ed23e12f390d.daf69515-caa0-4c26-8956-657efeb52e6f of task 'consumer' completed in state TASK_FINISHED: Command exited with status 0
I0925 01:02:10.180977 20130 default_executor.cpp:1077] Terminating after 1secs
I0925 01:02:10.181298 29990 process.cpp:3569] Handling HTTP event for process 'slave(1142)' with path: '/slave(1142)/api/v1/executor'
I0925 01:02:10.221231 29992 http.cpp:1177] HTTP POST for /slave(1142)/api/v1/executor from 172.16.10.100:38908
I0925 01:02:10.221334 29992 slave.cpp:5269] Handling status update TASK_FINISHED (Status UUID: 17396af8-3e82-4a64-a0b0-396f062bf62d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.221937 29991 task_status_update_manager.cpp:328] Received task status update TASK_FINISHED (Status UUID: 17396af8-3e82-4a64-a0b0-396f062bf62d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.221993 29991 task_status_update_manager.cpp:383] Forwarding task status update TASK_FINISHED (Status UUID: 17396af8-3e82-4a64-a0b0-396f062bf62d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to the agent
I0925 01:02:10.222065 29991 slave.cpp:5761] Forwarding the update TASK_FINISHED (Status UUID: 17396af8-3e82-4a64-a0b0-396f062bf62d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 to master@172.16.10.100:46052
I0925 01:02:10.222146 29991 slave.cpp:5654] Task status update manager successfully handled status update TASK_FINISHED (Status UUID: 17396af8-3e82-4a64-a0b0-396f062bf62d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.222263 29991 master.cpp:8375] Status update TASK_FINISHED (Status UUID: 17396af8-3e82-4a64-a0b0-396f062bf62d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 from agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:10.222295 29991 master.cpp:8432] Forwarding status update TASK_FINISHED (Status UUID: 17396af8-3e82-4a64-a0b0-396f062bf62d) for task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.222393 29991 master.cpp:10932] Updating the state of task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: TASK_FINISHED, status update state: TASK_FINISHED)
I0925 01:02:10.222666 29993 hierarchical.cpp:1236] Recovered cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.1; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32 (total: cpus:1.7; mem:928; disk:928; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,default-role,test-principal)]):0.3; mem(reservations: [(DYNAMIC,default-role,test-principal)]):96; disk(reservations: [(DYNAMIC,default-role,test-principal)]):95; disk(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1, allocated: disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):31; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32; cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.1) on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 from framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.222889 29993 scheduler.cpp:845] Enqueuing event UPDATE received from http://172.16.10.100:46052/master/api/v1/scheduler
I0925 01:02:10.224126 29988 master.cpp:1366] Framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) disconnected
I0925 01:02:10.224154 29988 master.cpp:3230] Deactivating framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default)
I0925 01:02:10.224177 29988 master.cpp:3207] Disconnecting framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default)
I0925 01:02:10.224190 29988 master.cpp:1381] Giving framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default) 0ns to failover
I0925 01:02:10.224231 29988 hierarchical.cpp:420] Deactivated framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
*** Aborted at 1537837330 (unix time) try "date -d @1537837330" if you are using GNU date ***
PC: @     0x7f7f6fa73373 mesos::v1::scheduler::Mesos::send()
I0925 01:02:10.227406 29991 master.cpp:9261] Framework failover timeout, removing framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default)
I0925 01:02:10.227430 29991 master.cpp:10197] Removing framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (default)
I0925 01:02:10.227470 29991 master.cpp:10932] Updating the state of task consumer of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (latest state: TASK_FINISHED, status update state: TASK_KILLED)
I0925 01:02:10.227507 29991 master.cpp:11030] Removing task consumer with resources cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.1; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32 of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:10.227695 29991 master.cpp:11061] Removing executor 'default' with resources [{"allocation_info":{"role":"default-role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"mem","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"name":"disk","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":31.0},"type":"SCALAR"},{"allocation_info":{"role":"default-role"},"disk":{"persistence":{"id":"executor","principal":"test-principal"},"volume":{"container_path":"executor_volume_path","mode":"RW"}},"name":"disk","reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"}] of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 at slave(1142)@172.16.10.100:46052 (ip-172-16-10-100.ec2.internal)
I0925 01:02:10.227998 29991 slave.cpp:3896] Asked to shut down framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 by master@172.16.10.100:46052
I0925 01:02:10.228024 29991 slave.cpp:3921] Shutting down framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.228034 29991 slave.cpp:6640] Shutting down executor 'default' of framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000 (via HTTP)
I0925 01:02:10.228205 29991 hierarchical.cpp:1236] Recovered cpus(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):0.1; mem(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):32; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)]):31; disk(allocated: default-role)(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1 (total: cpus:1.7; mem:928; disk:928; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,default-role,test-principal)]):0.3; mem(reservations: [(DYNAMIC,default-role,test-principal)]):96; disk(reservations: [(DYNAMIC,default-role,test-principal)]):95; disk(reservations: [(DYNAMIC,default-role,test-principal)])[executor:executor_volume_path]:1, allocated: {}) on agent bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-S0 from framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
I0925 01:02:10.228339 29991 hierarchical.cpp:359] Removed framework bbb06e8f-11e1-4fcb-aae5-3ffb479df4d3-0000
*** SIGSEGV (@0x0) received by PID 7654 (TID 0x7f7f62fe6700) from PID 0; stack trace: ***
    @     0x7f7f38b6f362 (unknown)
    @     0x7f7f38b738b9 (unknown)
    @     0x7f7f38b66f78 (unknown)
    @     0x7f7f6ca2e390 (unknown)
    @     0x7f7f6fa73373 mesos::v1::scheduler::Mesos::send()
    @     0x55b5fa8a8af6 _ZNK5mesos8internal5tests2v19scheduler23SendAcknowledgeActionP2INS_2v111FrameworkIDENS5_7AgentIDEE10gmock_ImplIFvPNS5_9scheduler5MesosERKNSA_12Event_UpdateEEE17gmock_PerformImplISC_SF_N7testing8internal12ExcessiveArgESL_SL_SL_SL_SL_SL_SL_EEvRKSt5tupleIJSC_SF_EET_T0_T1_T2_T3_T4_T5_T6_T7_T8_
    @     0x55b5fa8a8c70 _ZN5mesos8internal5tests2v19scheduler23SendAcknowledgeActionP2INS_2v111FrameworkIDENS5_7AgentIDEE10gmock_ImplIFvPNS5_9scheduler5MesosERKNSA_12Event_UpdateEEE7PerformERKSt5tupleIJSC_SF_EE
    @     0x55b5fa792fbe _ZN7testing8internal12DoBothActionI17PromiseArgActionPILi1EPN7process7PromiseIN5mesos2v19scheduler12Event_UpdateEEEENS5_8internal5tests2v19scheduler23SendAcknowledgeActionP2INS6_11FrameworkIDENS6_7AgentIDEEEE4ImplIFvPNS7_5MesosERKS8_EE7PerformERKSt5tupleIJSN_SP_EE
    @     0x55b5fa7c7957 testing::internal::FunctionMockerBase<>::UntypedPerformAction()
    @     0x55b5fbc36409 testing::internal::UntypedFunctionMockerBase::UntypedInvokeWith()
    @     0x55b5fa8b6f1a mesos::internal::tests::scheduler::MockHTTPScheduler<>::events()
    @     0x55b5fa828b76 std::_Function_handler<>::_M_invoke()
    @     0x7f7f6fa78358 process::AsyncExecutorProcess::execute<>()
    @     0x7f7f6fa82fdd _ZNO6lambda12CallableOnceIFvPN7process11ProcessBaseEEE10CallableFnINS_8internal7PartialIZNS1_8dispatchI7NothingNS1_20AsyncExecutorProcessERKSt8functionIFvRKSt5queueIN5mesos2v19scheduler5EventESt5dequeISH_SaISH_EEEEESL_SR_RSL_EENS1_6FutureIT_EERKNS1_3PIDIT0_EEMSX_FSU_T1_T2_EOT3_OT4_EUlSt10unique_ptrINS1_7PromiseISA_EESt14default_deleteIS1B_EEOSP_OSL_S3_E_IS1E_SP_SL_St12_PlaceholderILi1EEEEEEclEOS3_
    @     0x7f7f70870ff1 process::ProcessBase::consume()
    @     0x7f7f7089351a process::ProcessManager::resume()
    @     0x7f7f70897256 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
    @     0x7f7f6d211c80 (unknown)
    @     0x7f7f6ca246ba start_thread
    @     0x7f7f6c75a41d (unknown)
timeout: the monitored command dumped core
./mesos-ci/mesos_ci: line 161:  7652 Segmentation fault      (core dumped) $SUDO env GTEST_FILTER="$GTEST_FILTER" GLOG_v=1 PATH="$PATH" $TIMEOUT 60m "$test_binary" --verbose --gtest_output="xml:${xml}"
The test binary has crashed OR the timeout has been exceeded!
~/workspace/mesos/Mesos_CI-build/FLAG/Plain/label/mesos-ec2-ubuntu-16.04
mkswap: /tmp/swapfile: warning: wiping old swap signature.
Setting up swapspace version 1, size = 8 GiB (8589930496 bytes)
no label, UUID=23a14405-c49d-4086-8a2a-c34d73e95fc2
swapon: /tmp/swapfile: insecure file owner 1000, 0 (root) suggested.
gcc (Ubuntu 5.4.0-6ubuntu1~16.04.10) 5.4.0 20160609
Copyright (C) 2015 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
Docker version 18.04.0-ce, build 3d479c0
curl 7.47.0 (x86_64-pc-linux-gnu) libcurl/7.47.0 GnuTLS/3.4.10 zlib/1.2.8 libidn/1.32 librtmp/2.3
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtmp rtsp smb smbs smtp smtps telnet tftp 
Features: AsynchDNS IDN IPv6 Largefile GSS-API Kerberos SPNEGO NTLM NTLM_WB SSL libz TLS-SRP UnixSockets 
I0925 01:02:11.181372 20136 process.cpp:926] Stopped the socket accept loop
[WARNINGS] Parsing warnings in console log with parser GNU Make + GNU C Compiler (gcc)
[WARNINGS] Found 2 warnings after exclusion.
Skipping warnings blame since Git is the only supported SCM up to now.%n
[WARNINGS] Computing warning deltas based on reference build #4484-asf/master-270c4cb6
Archiving artifacts
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Finished: UNSTABLE

Attachments

Issue Links

Blocked

MESOS-8096 Enqueueing events in MockHTTPScheduler can lead to segfaults.

Accepted

Activity

People

Assignee:: Unassigned

Reporter:: Benno Evers

Votes:: 0 Vote for this issue

Watchers:: 1 Start watching this issue

Dates

Created:: 25/Sep/18 10:32

Updated:: 25/Sep/18 13:08

Resolved:: 25/Sep/18 13:08