[ https://issues.apache.org/jira/browse/MESOS-8112?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Alexander Rukletsov updated MESOS-8112: --------------------------------------- Attachment: GetContainers-goodrun.txt GetContainers-badrun.txt > DefaultExecutorTest.ResourceLimitation is flaky > ----------------------------------------------- > > Key: MESOS-8112 > URL: https://issues.apache.org/jira/browse/MESOS-8112 > Project: Mesos > Issue Type: Bug > Components: flaky, test > Reporter: James Peach > Attachments: GetContainers-badrun.txt, GetContainers-goodrun.txt > > > As seen in CI builds, the > {{MesosContainerizer/DefaultExecutorTest.ResourceLimitation/0}} test can be > flaky > {noformat}[ RUN ] > MesosContainerizer/DefaultExecutorTest.ResourceLimitation/0 > I1017 21:37:55.179539 3528 cluster.cpp:162] Creating default 'local' > authorizer > I1017 21:37:55.182804 3529 master.cpp:445] Master > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e (42cd332f4072) started on > 172.17.0.2:33744 > I1017 21:37:55.182847 3529 master.cpp:447] Flags at startup: --acls="" > --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" > --allocation_interval="1secs" --allocator="HierarchicalDRF" > --authenticate_agents="true" --authenticate_frameworks="true" > --authenticate_http_frameworks="true" --authenticate_http_readonly="true" > --authenticate_http_readwrite="true" --authenticators="crammd5" > --authorizers="local" --credentials="/tmp/1FtpuJ/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" --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" > --root_submissions="true" --user_sorter="drf" --version="false" > --webui_dir="/mesos/mesos-1.5.0/_inst/share/mesos/webui" > --work_dir="/tmp/1FtpuJ/master" --zk_session_timeout="10secs" > I1017 21:37:55.183141 3529 master.cpp:496] Master only allowing > authenticated frameworks to register > I1017 21:37:55.183153 3529 master.cpp:502] Master only allowing > authenticated agents to register > I1017 21:37:55.183161 3529 master.cpp:508] Master only allowing > authenticated HTTP frameworks to register > I1017 21:37:55.183167 3529 credentials.hpp:37] Loading credentials for > authentication from '/tmp/1FtpuJ/credentials' > I1017 21:37:55.183472 3529 master.cpp:552] Using default 'crammd5' > authenticator > I1017 21:37:55.183661 3529 http.cpp:1045] Creating default 'basic' HTTP > authenticator for realm 'mesos-master-readonly' > I1017 21:37:55.183862 3529 http.cpp:1045] Creating default 'basic' HTTP > authenticator for realm 'mesos-master-readwrite' > I1017 21:37:55.184082 3529 http.cpp:1045] Creating default 'basic' HTTP > authenticator for realm 'mesos-master-scheduler' > I1017 21:37:55.184257 3529 master.cpp:631] Authorization enabled > I1017 21:37:55.184450 3536 hierarchical.cpp:171] Initialized hierarchical > allocator process > I1017 21:37:55.184551 3536 whitelist_watcher.cpp:77] No whitelist given > I1017 21:37:55.187489 3536 master.cpp:2198] Elected as the leading master! > I1017 21:37:55.187516 3536 master.cpp:1687] Recovering from registrar > I1017 21:37:55.187728 3536 registrar.cpp:347] Recovering registrar > I1017 21:37:55.188508 3536 registrar.cpp:391] Successfully fetched the > registry (0B) in 745984ns > I1017 21:37:55.188616 3536 registrar.cpp:495] Applied 1 operations in > 37290ns; attempting to update the registry > I1017 21:37:55.189162 3536 registrar.cpp:552] Successfully updated the > registry in 491008ns > I1017 21:37:55.189285 3536 registrar.cpp:424] Successfully recovered > registrar > I1017 21:37:55.190011 3531 hierarchical.cpp:209] Skipping recovery of > hierarchical allocator: nothing to recover > I1017 21:37:55.190115 3534 master.cpp:1791] Recovered 0 agents from the > registry (129B); allowing 10mins for agents to re-register > W1017 21:37:55.195062 3528 process.cpp:3194] Attempted to spawn already > running process files@172.17.0.2:33744 > I1017 21:37:55.195956 3528 containerizer.cpp:292] Using isolation { > environment_secret, network/cni, filesystem/posix, disk/du } > W1017 21:37:55.196488 3528 backend.cpp:76] Failed to create 'aufs' backend: > AufsBackend requires root privileges > W1017 21:37:55.196630 3528 backend.cpp:76] Failed to create 'bind' backend: > BindBackend requires root privileges > I1017 21:37:55.196662 3528 provisioner.cpp:255] Using default backend 'copy' > I1017 21:37:55.198724 3528 cluster.cpp:448] Creating default 'local' > authorizer > I1017 21:37:55.200865 3535 slave.cpp:254] Mesos agent started on > (724)@172.17.0.2:33744 > I1017 21:37:55.200907 3535 slave.cpp:255] Flags at startup: --acls="" > --appc_simple_discovery_uri_prefix="http://" > --appc_store_dir="/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5/store/appc" > --authenticate_http_readonly="true" --authenticate_http_readwrite="false" > --authenticatee="crammd5" --authentication_backoff_factor="1secs" > --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" > --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" > --cgroups_limit_swap="false" --cgroups_root="mesos" > --container_disk_watch_interval="1ms" --containerizers="mesos" > --credential="/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5/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/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5/store/docker" > --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" > --enforce_container_disk_quota="true" --executor_registration_timeout="1mins" > --executor_reregistration_timeout="2secs" > --executor_shutdown_grace_period="5secs" > --fetcher_cache_dir="/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5/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_credentials="/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5/http_credentials" > --http_heartbeat_interval="30secs" --initialize_driver_logging="true" > --isolation="disk/du" --launcher="posix" > --launcher_dir="/mesos/mesos-1.5.0/_build/src" --logbufsecs="0" > --logging_level="INFO" --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="10ms" > --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" > --revocable_cpu_low_priority="true" > --runtime_dir="/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5" > --sandbox_directory="/mnt/mesos/sandbox" --strict="true" > --switch_user="true" --systemd_enable_support="true" > --systemd_runtime_directory="/run/systemd/system" --version="false" > --work_dir="/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU" > --zk_session_timeout="10secs" > I1017 21:37:55.201545 3535 credentials.hpp:86] Loading credential for > authentication from > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5/credential' > I1017 21:37:55.201709 3535 slave.cpp:287] Agent using credential for: > test-principal > I1017 21:37:55.201730 3535 credentials.hpp:37] Loading credentials for > authentication from > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5/http_credentials' > I1017 21:37:55.201937 3535 http.cpp:1045] Creating default 'basic' HTTP > authenticator for realm 'mesos-agent-readonly' > I1017 21:37:55.202029 3528 scheduler.cpp:190] Version: 1.5.0 > I1017 21:37:55.202344 3534 scheduler.cpp:313] Using default 'basic' HTTP > authenticatee > I1017 21:37:55.202993 3536 scheduler.cpp:496] New master detected at > master@172.17.0.2:33744 > I1017 21:37:55.203032 3536 scheduler.cpp:505] Waiting for 0ns before > initiating a re-(connection) attempt with the master > I1017 21:37:55.204712 3535 slave.cpp:585] 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"}] > I1017 21:37:55.205080 3535 slave.cpp:593] Agent attributes: [ ] > I1017 21:37:55.205104 3535 slave.cpp:602] Agent hostname: 42cd332f4072 > I1017 21:37:55.206264 3531 status_update_manager.cpp:177] Pausing sending > status updates > I1017 21:37:55.207849 3535 state.cpp:64] Recovering state from > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/meta' > I1017 21:37:55.208111 3532 scheduler.cpp:387] Connected with the master at > http://172.17.0.2:33744/master/api/v1/scheduler > I1017 21:37:55.208317 3531 status_update_manager.cpp:203] Recovering status > update manager > I1017 21:37:55.208547 3533 containerizer.cpp:649] Recovering containerizer > I1017 21:37:55.208860 3532 scheduler.cpp:249] Sending SUBSCRIBE call to > http://172.17.0.2:33744/master/api/v1/scheduler > I1017 21:37:55.210074 3530 provisioner.cpp:416] Provisioner recovery complete > I1017 21:37:55.210355 3533 slave.cpp:6310] Finished recovery > I1017 21:37:55.210883 3533 slave.cpp:6492] Querying resource estimator for > oversubscribable resources > I1017 21:37:55.211053 3535 process.cpp:3929] Handling HTTP event for process > 'master' with path: '/master/api/v1/scheduler' > I1017 21:37:55.211462 3531 status_update_manager.cpp:177] Pausing sending > status updates > I1017 21:37:55.211622 3532 slave.cpp:993] New master detected at > master@172.17.0.2:33744 > I1017 21:37:55.211691 3532 slave.cpp:1028] Detecting new master > I1017 21:37:55.211827 3532 slave.cpp:6506] Received oversubscribable > resources {} from the resource estimator > I1017 21:37:55.213318 3532 http.cpp:1185] HTTP POST for > /master/api/v1/scheduler from 172.17.0.2:59236 > I1017 21:37:55.213582 3532 master.cpp:2580] Received subscription request > for HTTP framework 'default' > I1017 21:37:55.213630 3532 master.cpp:2263] Authorizing framework principal > 'test-principal' to receive offers for roles '{ * }' > I1017 21:37:55.214233 3533 master.cpp:2716] Subscribing framework 'default' > with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ] > I1017 21:37:55.215014 3535 hierarchical.cpp:303] Added framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.215157 3536 master.hpp:349] Sending heartbeat to framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.215317 3535 hierarchical.cpp:1945] No allocations performed > I1017 21:37:55.215373 3535 hierarchical.cpp:2035] No inverse offers to send > out! > I1017 21:37:55.215526 3535 hierarchical.cpp:1488] Performed allocation for 0 > agents in 335061ns > I1017 21:37:55.216519 3529 scheduler.cpp:738] Enqueuing event SUBSCRIBED > received from http://172.17.0.2:33744/master/api/v1/scheduler > I1017 21:37:55.216945 3529 scheduler.cpp:738] Enqueuing event HEARTBEAT > received from http://172.17.0.2:33744/master/api/v1/scheduler > I1017 21:37:55.221559 3535 slave.cpp:1055] Authenticating with master > master@172.17.0.2:33744 > I1017 21:37:55.221652 3535 slave.cpp:1064] Using default CRAM-MD5 > authenticatee > I1017 21:37:55.222021 3536 authenticatee.cpp:121] Creating new client SASL > connection > I1017 21:37:55.222451 3529 master.cpp:7936] Authenticating > slave(724)@172.17.0.2:33744 > I1017 21:37:55.222684 3529 authenticator.cpp:414] Starting authentication > session for crammd5-authenticatee(1363)@172.17.0.2:33744 > I1017 21:37:55.222996 3530 authenticator.cpp:98] Creating new server SASL > connection > I1017 21:37:55.223300 3533 authenticatee.cpp:213] Received SASL > authentication mechanisms: CRAM-MD5 > I1017 21:37:55.223328 3533 authenticatee.cpp:239] Attempting to authenticate > with mechanism 'CRAM-MD5' > I1017 21:37:55.223459 3531 authenticator.cpp:204] Received SASL > authentication start > I1017 21:37:55.223528 3531 authenticator.cpp:326] Authentication requires > more steps > I1017 21:37:55.223623 3531 authenticatee.cpp:259] Received SASL > authentication step > I1017 21:37:55.223747 3531 authenticator.cpp:232] Received SASL > authentication step > I1017 21:37:55.223778 3531 auxprop.cpp:109] Request to lookup properties for > user: 'test-principal' realm: '42cd332f4072' server FQDN: '42cd332f4072' > SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false > SASL_AUXPROP_AUTHZID: false > I1017 21:37:55.223789 3531 auxprop.cpp:181] Looking up auxiliary property > '*userPassword' > I1017 21:37:55.223829 3531 auxprop.cpp:181] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I1017 21:37:55.223852 3531 auxprop.cpp:109] Request to lookup properties for > user: 'test-principal' realm: '42cd332f4072' server FQDN: '42cd332f4072' > SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false > SASL_AUXPROP_AUTHZID: true > I1017 21:37:55.223862 3531 auxprop.cpp:131] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I1017 21:37:55.223870 3531 auxprop.cpp:131] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I1017 21:37:55.223884 3531 authenticator.cpp:318] Authentication success > I1017 21:37:55.223997 3529 authenticatee.cpp:299] Authentication success > I1017 21:37:55.224613 3529 master.cpp:7966] Successfully authenticated > principal 'test-principal' at slave(724)@172.17.0.2:33744 > I1017 21:37:55.224685 3533 authenticator.cpp:432] Authentication session > cleanup for crammd5-authenticatee(1363)@172.17.0.2:33744 > I1017 21:37:55.224956 3531 slave.cpp:1147] Successfully authenticated with > master master@172.17.0.2:33744 > I1017 21:37:55.225222 3531 slave.cpp:1626] Will retry registration in > 19.076909ms if necessary > I1017 21:37:55.225400 3536 master.cpp:5801] Received register agent message > from slave(724)@172.17.0.2:33744 (42cd332f4072) > I1017 21:37:55.225436 3536 master.cpp:3838] Authorizing agent with principal > 'test-principal' > I1017 21:37:55.225952 3530 master.cpp:5861] Authorized registration of agent > at slave(724)@172.17.0.2:33744 (42cd332f4072) > I1017 21:37:55.226116 3530 master.cpp:5954] Registering agent at > slave(724)@172.17.0.2:33744 (42cd332f4072) with id > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 > I1017 21:37:55.226534 3535 registrar.cpp:495] Applied 1 operations in > 82807ns; attempting to update the registry > I1017 21:37:55.227126 3535 registrar.cpp:552] Successfully updated the > registry in 527872ns > I1017 21:37:55.227342 3529 master.cpp:6001] Admitted agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) > I1017 21:37:55.228332 3532 slave.cpp:4966] Received ping from > slave-observer(665)@172.17.0.2:33744 > I1017 21:37:55.227948 3529 master.cpp:6032] Registered agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) with > [{"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"}] > I1017 21:37:55.228945 3532 slave.cpp:1193] Registered with master > master@172.17.0.2:33744; given agent ID > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 > I1017 21:37:55.229113 3535 status_update_manager.cpp:184] Resuming sending > status updates > I1017 21:37:55.229280 3530 hierarchical.cpp:593] Added agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 (42cd332f4072) with cpus:2; mem:1024; > disk:1024; ports:[31000-32000] (allocated: {}) > I1017 21:37:55.229563 3532 slave.cpp:1213] Checkpointing SlaveInfo to > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/meta/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/slave.info' > I1017 21:37:55.230151 3532 slave.cpp:1262] Forwarding total oversubscribed > resources {} > I1017 21:37:55.230377 3534 master.cpp:6817] Received update of agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) with total oversubscribed resources {} > I1017 21:37:55.230751 3534 master.cpp:6828] Ignoring update on agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) as it reports no changes > I1017 21:37:55.231178 3530 hierarchical.cpp:2035] No inverse offers to send > out! > I1017 21:37:55.231250 3530 hierarchical.cpp:1488] Performed allocation for 1 > agents in 1.768449ms > I1017 21:37:55.231683 3533 master.cpp:7766] Sending 1 offers to framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (default) > I1017 21:37:55.233845 3534 scheduler.cpp:738] Enqueuing event OFFERS > received from http://172.17.0.2:33744/master/api/v1/scheduler > I1017 21:37:55.235939 3532 scheduler.cpp:249] Sending ACCEPT call to > http://172.17.0.2:33744/master/api/v1/scheduler > I1017 21:37:55.238193 3531 process.cpp:3929] Handling HTTP event for process > 'master' with path: '/master/api/v1/scheduler' > I1017 21:37:55.239806 3536 http.cpp:1185] HTTP POST for > /master/api/v1/scheduler from 172.17.0.2:59238 > I1017 21:37:55.241052 3536 master.cpp:9389] Removing offer > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-O0 > I1017 21:37:55.241237 3536 master.cpp:4196] Processing ACCEPT call for > offers: [ 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-O0 ] on agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) for framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > (default) > I1017 21:37:55.241349 3536 master.cpp:3565] Authorizing framework principal > 'test-principal' to launch task ffc4604c-a6cb-4ced-a969-fc6b9e6f955d > I1017 21:37:55.244315 3535 master.cpp:10135] Adding task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d with resources > [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":10.0},"type":"SCALAR"}] > on agent 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at > slave(724)@172.17.0.2:33744 (42cd332f4072) > I1017 21:37:55.244639 3535 master.cpp:5083] Launching task group { > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d } of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (default) with resources > cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):10 on agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) > I1017 21:37:55.245133 3536 slave.cpp:1747] Got assigned task group > containing tasks [ ffc4604c-a6cb-4ced-a969-fc6b9e6f955d ] for framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.245731 3533 hierarchical.cpp:1163] Recovered cpus(allocated: > *):1.8; mem(allocated: *):960; disk(allocated: *):1004; ports(allocated: > *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], > allocated: cpus(allocated: *):0.2; mem(allocated: *):64; disk(allocated: > *):20) on agent 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 from framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.245800 3533 hierarchical.cpp:1209] Framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 filtered agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 for 5secs > I1017 21:37:55.245987 3536 slave.cpp:2015] Authorizing task group containing > tasks [ ffc4604c-a6cb-4ced-a969-fc6b9e6f955d ] for framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.246063 3536 slave.cpp:6809] Authorizing framework principal > 'test-principal' to launch task ffc4604c-a6cb-4ced-a969-fc6b9e6f955d > I1017 21:37:55.246987 3535 slave.cpp:2183] Launching task group containing > tasks [ ffc4604c-a6cb-4ced-a969-fc6b9e6f955d ] for framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.247619 3535 paths.cpp:605] Trying to chown > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2' > to user 'mesos' > I1017 21:37:55.247992 3535 slave.cpp:7283] Launching executor 'default' of > framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 with resources > [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":10.0},"type":"SCALAR"}] > in work directory > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2' > I1017 21:37:55.248610 3535 slave.cpp:2874] Launching container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2 for executor 'default' of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.248858 3536 containerizer.cpp:1123] Starting container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2 > I1017 21:37:55.248936 3535 slave.cpp:2411] Queued task group containing > tasks [ ffc4604c-a6cb-4ced-a969-fc6b9e6f955d ] for executor 'default' of > framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.249037 3535 slave.cpp:944] Successfully attached > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2' > to virtual path > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/latest' > I1017 21:37:55.249086 3535 slave.cpp:944] Successfully attached > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2' > to virtual path > '/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/latest' > I1017 21:37:55.249119 3535 slave.cpp:944] Successfully attached > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2' > to virtual path > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2' > I1017 21:37:55.249280 3536 containerizer.cpp:2771] Transitioning the state > of container 4789abbb-04c9-4d6d-b561-f44b34ec47d2 from PROVISIONING to > PREPARING > I1017 21:37:55.252743 3536 containerizer.cpp:1721] Launching > 'mesos-containerizer' with flags '--help="false" > --launch_info="{"command":{"arguments":["mesos-default-executor","--launcher_dir=\/mesos\/mesos-1.5.0\/_build\/src"],"shell":false,"value":"\/mesos\/mesos-1.5.0\/_build\/src\/mesos-default-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.2:33744"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU\/slaves\/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0\/frameworks\/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000\/executors\/default\/runs\/4789abbb-04c9-4d6d-b561-f44b34ec47d2"},{"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":"0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(724)@172.17.0.2:33744"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU\/slaves\/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0\/frameworks\/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000\/executors\/default\/runs\/4789abbb-04c9-4d6d-b561-f44b34ec47d2"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU\/slaves\/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0\/frameworks\/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000\/executors\/default\/runs\/4789abbb-04c9-4d6d-b561-f44b34ec47d2"}" > --pipe_read="30" --pipe_write="31" > --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5/containers/4789abbb-04c9-4d6d-b561-f44b34ec47d2" > --unshare_namespace_mnt="false"' > I1017 21:37:55.257385 3536 launcher.cpp:140] Forked child with pid '8575' > for container '4789abbb-04c9-4d6d-b561-f44b34ec47d2' > I1017 21:37:55.258584 3536 containerizer.cpp:2771] Transitioning the state > of container 4789abbb-04c9-4d6d-b561-f44b34ec47d2 from PREPARING to ISOLATING > I1017 21:37:55.260586 3536 containerizer.cpp:2771] Transitioning the state > of container 4789abbb-04c9-4d6d-b561-f44b34ec47d2 from ISOLATING to FETCHING > I1017 21:37:55.260797 3536 fetcher.cpp:377] Starting to fetch URIs for > container: 4789abbb-04c9-4d6d-b561-f44b34ec47d2, directory: > /tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2 > I1017 21:37:55.261636 3535 containerizer.cpp:2771] Transitioning the state > of container 4789abbb-04c9-4d6d-b561-f44b34ec47d2 from FETCHING to RUNNING > I1017 21:37:55.440201 8576 executor.cpp:192] Version: 1.5.0 > I1017 21:37:55.451673 3533 process.cpp:3929] Handling HTTP event for process > 'slave(724)' with path: '/slave(724)/api/v1/executor' > I1017 21:37:55.453161 3529 http.cpp:1185] HTTP POST for > /slave(724)/api/v1/executor from 172.17.0.2:59240 > I1017 21:37:55.453474 3529 slave.cpp:3743] Received Subscribe request for > HTTP executor 'default' of framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.454911 3529 disk.cpp:208] Updating the disk resources for > container 4789abbb-04c9-4d6d-b561-f44b34ec47d2 to cpus(allocated: *):0.2; > mem(allocated: *):64; disk(allocated: *):20 > I1017 21:37:55.455559 3532 slave.cpp:2654] Sending queued task group task > group containing tasks [ ffc4604c-a6cb-4ced-a969-fc6b9e6f955d ] to executor > 'default' of framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (via HTTP) > I1017 21:37:55.463132 8579 default_executor.cpp:185] Received SUBSCRIBED > event > I1017 21:37:55.465946 8579 default_executor.cpp:189] Subscribed executor on > 42cd332f4072 > I1017 21:37:55.466346 8579 default_executor.cpp:185] Received LAUNCH_GROUP > event > I1017 21:37:55.467268 8581 default_executor.cpp:394] Setting > 'MESOS_CONTAINER_IP' to: 172.17.0.2 > I1017 21:37:55.471292 3531 process.cpp:3929] Handling HTTP event for process > 'slave(724)' with path: '/slave(724)/api/v1' > I1017 21:37:55.472666 3530 http.cpp:1185] HTTP POST for /slave(724)/api/v1 > from 172.17.0.2:59244 > I1017 21:37:55.473181 3530 http.cpp:532] Processing call > LAUNCH_NESTED_CONTAINER > I1017 21:37:55.474130 3536 containerizer.cpp:1094] Trying to chown > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2/containers/b51b7420-1230-487a-a68d-894310a6be10' > to user 'mesos' > I1017 21:37:55.474349 3536 containerizer.cpp:1123] Starting container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 > I1017 21:37:55.474701 3536 containerizer.cpp:2771] Transitioning the state > of container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 > from PROVISIONING to PREPARING > I1017 21:37:55.477772 3532 containerizer.cpp:1721] Launching > 'mesos-containerizer' with flags '--help="false" > --launch_info="{"command":{"shell":true,"value":"dd if=\/dev\/zero of=dd.out > bs=1048576 count=30; sleep > 1000"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU\/slaves\/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0\/frameworks\/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000\/executors\/default\/runs\/4789abbb-04c9-4d6d-b561-f44b34ec47d2\/containers\/b51b7420-1230-487a-a68d-894310a6be10"},{"name":"MESOS_CONTAINER_IP","type":"VALUE","value":"172.17.0.2"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU\/slaves\/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0\/frameworks\/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000\/executors\/default\/runs\/4789abbb-04c9-4d6d-b561-f44b34ec47d2\/containers\/b51b7420-1230-487a-a68d-894310a6be10"}" > --pipe_read="43" --pipe_write="64" > --runtime_directory="/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5/containers/4789abbb-04c9-4d6d-b561-f44b34ec47d2/containers/b51b7420-1230-487a-a68d-894310a6be10" > --unshare_namespace_mnt="false"' > I1017 21:37:55.480569 3532 launcher.cpp:140] Forked child with pid '8588' > for container > '4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10' > I1017 21:37:55.481405 3532 containerizer.cpp:2771] Transitioning the state > of container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 > from PREPARING to ISOLATING > I1017 21:37:55.483858 3532 containerizer.cpp:2771] Transitioning the state > of container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 > from ISOLATING to FETCHING > I1017 21:37:55.484086 3534 fetcher.cpp:377] Starting to fetch URIs for > container: > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10, > directory: > /tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2/containers/b51b7420-1230-487a-a68d-894310a6be10 > I1017 21:37:55.484944 3532 containerizer.cpp:2771] Transitioning the state > of container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 > from FETCHING to RUNNING > I1017 21:37:55.488390 8577 default_executor.cpp:624] Successfully launched > tasks [ ffc4604c-a6cb-4ced-a969-fc6b9e6f955d ] in child containers [ > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 ] > I1017 21:37:55.489305 8577 default_executor.cpp:697] Waiting for child > container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 of > task 'ffc4604c-a6cb-4ced-a969-fc6b9e6f955d' > I1017 21:37:55.492534 3529 process.cpp:3929] Handling HTTP event for process > 'slave(724)' with path: '/slave(724)/api/v1' > I1017 21:37:55.493468 3533 http.cpp:1185] HTTP POST for /slave(724)/api/v1 > from 172.17.0.2:59246 > I1017 21:37:55.493978 3533 http.cpp:532] Processing call > WAIT_NESTED_CONTAINER > I1017 21:37:55.494796 3535 process.cpp:3929] Handling HTTP event for process > 'slave(724)' with path: '/slave(724)/api/v1/executor' > I1017 21:37:55.495892 3529 http.cpp:1185] HTTP POST for > /slave(724)/api/v1/executor from 172.17.0.2:59242 > I1017 21:37:55.496302 3529 slave.cpp:4395] Handling status update > TASK_RUNNING (UUID: 86bb612c-9d48-4e85-a0f1-89820ea65fa1) for task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.498208 3531 status_update_manager.cpp:323] Received status > update TASK_RUNNING (UUID: 86bb612c-9d48-4e85-a0f1-89820ea65fa1) for task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.498260 3531 status_update_manager.cpp:500] Creating > StatusUpdate stream for task ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of > framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.499022 3531 status_update_manager.cpp:377] Forwarding update > TASK_RUNNING (UUID: 86bb612c-9d48-4e85-a0f1-89820ea65fa1) for task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 to the agent > I1017 21:37:55.499274 3533 slave.cpp:4876] Forwarding the update > TASK_RUNNING (UUID: 86bb612c-9d48-4e85-a0f1-89820ea65fa1) for task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 to master@172.17.0.2:33744 > I1017 21:37:55.499537 3533 slave.cpp:4770] Status update manager > successfully handled status update TASK_RUNNING (UUID: > 86bb612c-9d48-4e85-a0f1-89820ea65fa1) for task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.499819 3532 master.cpp:6993] Status update TASK_RUNNING > (UUID: 86bb612c-9d48-4e85-a0f1-89820ea65fa1) for task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 from agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) > I1017 21:37:55.499879 3532 master.cpp:7055] Forwarding status update > TASK_RUNNING (UUID: 86bb612c-9d48-4e85-a0f1-89820ea65fa1) for task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.500429 3532 master.cpp:9157] Updating the state of task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (latest state: TASK_RUNNING, status > update state: TASK_RUNNING) > I1017 21:37:55.501829 3531 scheduler.cpp:738] Enqueuing event UPDATE > received from http://172.17.0.2:33744/master/api/v1/scheduler > I1017 21:37:55.502354 8577 default_executor.cpp:185] Received ACKNOWLEDGED > event > I1017 21:37:55.502974 3532 scheduler.cpp:249] Sending ACKNOWLEDGE call to > http://172.17.0.2:33744/master/api/v1/scheduler > I1017 21:37:55.505254 3533 process.cpp:3929] Handling HTTP event for process > 'master' with path: '/master/api/v1/scheduler' > I1017 21:37:55.549257 3530 http.cpp:1185] HTTP POST for > /master/api/v1/scheduler from 172.17.0.2:59238 > I1017 21:37:55.549644 3530 master.cpp:5566] Processing ACKNOWLEDGE call > 86bb612c-9d48-4e85-a0f1-89820ea65fa1 for task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (default) on agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 > I1017 21:37:55.550588 3530 status_update_manager.cpp:395] Received status > update acknowledgement (UUID: 86bb612c-9d48-4e85-a0f1-89820ea65fa1) for task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:37:55.551023 3530 slave.cpp:3679] Status update manager > successfully handled status update acknowledgement (UUID: > 86bb612c-9d48-4e85-a0f1-89820ea65fa1) for task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I../../src/tests/default_executor_tests.cpp:1460: Failure > 1017 21:37:55.742033 3533 containerizer.cpp:2677] Container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2 has reached its limit for resource > [{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":20.0},"type":"SCALAR"}] > and will be terminated > Failed to wait 15secs for failed > 30+0 records in > 30+0 records out > I1017 21:37:56.186070 3534 hierarchical.cpp:2194] Filtered offer with > cpus:1.8; mem:960; disk:1004; ports:[31000-32000] on agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 for role * of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > 31457280 bytes (31 MB) copied, 87.3544 s, 360 kB/s > I1017 21:39:22.931159 3534 hierarchical.cpp:1945] No allocations performed > I1017 21:38:10.216308 3536 master.hpp:349] Sending heartbeat to framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:39:22.932803 3534 hierarchical.cpp:2035] No inverse offers to send > out! > I1017 21:39:22.929468 3533 containerizer.cpp:2207] Destroying container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2 in RUNNING state > I1017 21:39:22.933064 3533 containerizer.cpp:2771] Transitioning the state > of container 4789abbb-04c9-4d6d-b561-f44b34ec47d2 from RUNNING to DESTROYING > I1017 21:39:22.933130 3533 containerizer.cpp:2207] Destroying container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 in > RUNNING state > I1017 21:39:22.933163 3533 containerizer.cpp:2771] Transitioning the state > of container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 > from RUNNING to DESTROYING > I1017 21:39:22.933696 3534 hierarchical.cpp:1488] Performed allocation for 1 > agents in 1.44580576986667mins > I1017 21:39:22.934236 3533 launcher.cpp:156] Asked to destroy container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 > I1017 21:38:10.213038 3531 slave.cpp:6492] Querying resource estimator for > oversubscribable resources > I1017 21:39:22.939371 3531 slave.cpp:4966] Received ping from > slave-observer(665)@172.17.0.2:33744 > I1017 21:39:22.939764 3531 slave.cpp:4966] Received ping from > slave-observer(665)@172.17.0.2:33744 > I1017 21:39:22.939997 3531 slave.cpp:4966] Received ping from > slave-observer(665)@172.17.0.2:33744 > I1017 21:39:22.940492 3531 slave.cpp:4966] Received ping from > slave-observer(665)@172.17.0.2:33744 > I1017 21:39:22.940925 3531 slave.cpp:4966] Received ping from > slave-observer(665)@172.17.0.2:33744 > I1017 21:39:22.941176 3531 slave.cpp:6506] Received oversubscribable > resources {} from the resource estimator > I1017 21:39:22.941747 3531 slave.cpp:5927] Current disk usage 27.23%. Max > allowed age: 4.393738795125035days > I1017 21:39:22.944377 3535 master.cpp:1417] Framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (default) disconnected > I1017 21:39:22.944420 3535 master.cpp:3299] Deactivating framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (default) > I1017 21:39:22.944555 3535 master.cpp:3276] Disconnecting framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (default) > I1017 21:39:22.944598 3535 master.cpp:1432] Giving framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (default) 0ns to failover > I1017 21:39:22.944836 3536 hierarchical.cpp:412] Deactivated framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:39:22.946259 3529 master.cpp:7598] Framework failover timeout, > removing framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (default) > I1017 21:39:22.946354 3529 master.cpp:8459] Removing framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (default) > I1017 21:39:22.946713 3530 slave.cpp:3211] Asked to shut down framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 by master@172.17.0.2:33744 > I1017 21:39:22.946769 3530 slave.cpp:3236] Shutting down framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:39:22.946825 3530 slave.cpp:5743] Shutting down executor 'default' > of framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (via HTTP) > I1017 21:39:22.946893 3529 master.cpp:9157] Updating the state of task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (latest state: TASK_KILLED, status > update state: TASK_KILLED) > I1017 21:39:22.947825 3529 master.cpp:9251] Removing task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d with resources > [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":10.0},"type":"SCALAR"}] > of framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 on agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) > I1017 21:39:22.948449 3533 hierarchical.cpp:1163] Recovered cpus(allocated: > *):0.1; mem(allocated: *):32; disk(allocated: *):10 (total: cpus:2; mem:1024; > disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):0.1; > mem(allocated: *):32; disk(allocated: *):10) on agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 from framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:39:22.948746 3529 master.cpp:9280] Removing executor 'default' with > resources > [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":10.0},"type":"SCALAR"}] > of framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 on agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) > I1017 21:39:22.950007 3529 hierarchical.cpp:1163] Recovered cpus(allocated: > *):0.1; mem(allocated: *):32; disk(allocated: *):10 (total: cpus:2; mem:1024; > disk:1024; ports:[31000-32000], allocated: {}) on agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 from framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:39:22.950400 3529 hierarchical.cpp:355] Removed framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > ../../src/tests/default_executor_tests.cpp:1427: Failure > Actual function call count doesn't match EXPECT_CALL(*scheduler, update(_, > _))... > Expected: to be called twice > Actual: called once - unsatisfied and active > I1017 21:39:22.953431 8582 default_executor.cpp:185] Received SHUTDOWN event > I1017 21:39:22.953610 8582 default_executor.cpp:937] Shutting down > I1017 21:39:22.953661 8582 default_executor.cpp:1033] Killing task > ffc4604c-a6cb-4ced-a969-fc6b9e6f955d running in child container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 > with SIGTERM signal > I1017 21:39:22.953706 8582 default_executor.cpp:1055] Scheduling escalation > to SIGKILL in 3secs from now > I1017 21:39:22.956368 3533 process.cpp:3929] Handling HTTP event for process > 'slave(724)' with path: '/slave(724)/api/v1' > I1017 21:39:22.957237 3536 http.cpp:1185] HTTP POST for /slave(724)/api/v1 > from 172.17.0.2:59320 > I1017 21:39:22.957690 3536 http.cpp:532] Processing call > KILL_NESTED_CONTAINER > I1017 21:39:22.997555 3536 containerizer.cpp:2658] Container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 has > exited > I1017 21:39:22.999429 3536 provisioner.cpp:490] Ignoring destroy request for > unknown container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 > I1017 21:39:22.999649 3536 containerizer.cpp:2496] Checkpointing termination > state to nested container's runtime directory > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_q49Cv5/containers/4789abbb-04c9-4d6d-b561-f44b34ec47d2/containers/b51b7420-1230-487a-a68d-894310a6be10/termination' > I1017 21:39:23.012559 3533 launcher.cpp:156] Asked to destroy container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2 > I1017 21:39:23.100474 3533 containerizer.cpp:2658] Container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2 has exited > I1017 21:39:23.101578 3535 disk.cpp:320] Checking disk usage at > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2' > for container 4789abbb-04c9-4d6d-b561-f44b34ec47d2 has been cancelled > I1017 21:39:23.102567 3534 provisioner.cpp:490] Ignoring destroy request for > unknown container 4789abbb-04c9-4d6d-b561-f44b34ec47d2 > I1017 21:39:23.105077 3530 slave.cpp:5408] Executor 'default' of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 terminated with signal Killed > I1017 21:39:23.105296 3530 slave.cpp:5512] Cleaning up executor 'default' of > framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 (via HTTP) > W1017 21:39:23.105558 3529 master.cpp:7110] Ignoring unknown exited executor > 'default' of framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 on agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) > I1017 21:39:23.105646 3529 gc.cpp:90] Scheduling > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default/runs/4789abbb-04c9-4d6d-b561-f44b34ec47d2' > for gc 6.99999877965333days in the future > I1017 21:39:23.105700 3530 slave.cpp:5619] Cleaning up framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:39:23.105870 3534 status_update_manager.cpp:285] Closing status > update streams for framework 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:39:23.105942 3534 status_update_manager.cpp:531] Cleaning up status > update stream for task ffc4604c-a6cb-4ced-a969-fc6b9e6f955d of framework > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000 > I1017 21:39:23.105947 3529 gc.cpp:90] Scheduling > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000/executors/default' > for gc 6.99999877745481days in the future > I1017 21:39:23.106046 3529 gc.cpp:90] Scheduling > '/tmp/MesosContainerizer_DefaultExecutorTest_ResourceLimitation_0_9xv0uU/slaves/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0/frameworks/0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-0000' > for gc 6.99999877483852days in the future > W1017 21:39:23.106978 3536 containerizer.cpp:2190] Attempted to destroy > unknown container > 4789abbb-04c9-4d6d-b561-f44b34ec47d2.b51b7420-1230-487a-a68d-894310a6be10 > I1017 21:39:23.110316 3528 slave.cpp:869] Agent terminating > I1017 21:39:23.111014 3532 master.cpp:1303] Agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) disconnected > I1017 21:39:23.111052 3532 master.cpp:3336] Disconnecting agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) > I1017 21:39:23.111115 3532 master.cpp:3355] Deactivating agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 at slave(724)@172.17.0.2:33744 > (42cd332f4072) > I1017 21:39:23.111344 3536 hierarchical.cpp:690] Agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 deactivated > I1017 21:39:23.134323 3528 master.cpp:1145] Master terminating > I1017 21:39:23.135185 3534 hierarchical.cpp:626] Removed agent > 0a7cd77c-8bc0-4fdc-b6c5-918b7ffc392e-S0 > [ FAILED ] MesosContainerizer/DefaultExecutorTest.ResourceLimitation/0, > where GetParam() = "mesos" (87968 ms) > {noformat} -- This message was sent by Atlassian JIRA (v6.4.14#64029)