You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Till Toenshoff (JIRA)" <ji...@apache.org> on 2018/07/04 12:52:00 UTC

[jira] [Commented] (MESOS-8305) DefaultExecutorTest.ROOT_MultiTaskgroupSharePidNamespace is flaky.

    [ https://issues.apache.org/jira/browse/MESOS-8305?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16532716#comment-16532716 ] 

Till Toenshoff commented on MESOS-8305:
---------------------------------------

Just seen this test being flaky on 1.4.x. The errors however are not identical to what is described above.

 
{noformat}
08:36:56 [ RUN ] ROOT_DOCKER_DockerAndMesosContainerizers/DefaultExecutorTest.ROOT_MultiTaskgroupSharePidNamespace/0
08:36:56 I0702 08:36:56.885752 28719 cluster.cpp:162] Creating default 'local' authorizer
08:36:56 I0702 08:36:56.886807 18346 master.cpp:442] Master 1b41a301-e70a-4aec-830f-7850032b28c3 (ip-172-16-10-112.ec2.internal) started on 172.16.10.112:35906
08:36:56 I0702 08:36:56.886837 18346 master.cpp:444] 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" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/f7z9P0/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" --role_sorter="drf" --root_submissions="true" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/f7z9P0/master" --zk_session_timeout="10secs"
08:36:56 I0702 08:36:56.886965 18346 master.cpp:494] Master only allowing authenticated frameworks to register
08:36:56 I0702 08:36:56.886974 18346 master.cpp:508] Master only allowing authenticated agents to register
08:36:56 I0702 08:36:56.886981 18346 master.cpp:521] Master only allowing authenticated HTTP frameworks to register
08:36:56 I0702 08:36:56.886986 18346 credentials.hpp:37] Loading credentials for authentication from '/tmp/f7z9P0/credentials'
08:36:56 I0702 08:36:56.887074 18346 master.cpp:566] Using default 'crammd5' authenticator
08:36:56 I0702 08:36:56.887127 18346 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
08:36:56 I0702 08:36:56.887168 18346 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
08:36:56 I0702 08:36:56.887195 18346 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
08:36:56 I0702 08:36:56.887310 18346 master.cpp:646] Authorization enabled
08:36:56 I0702 08:36:56.887361 18348 hierarchical.cpp:171] Initialized hierarchical allocator process
08:36:56 I0702 08:36:56.887409 18348 whitelist_watcher.cpp:77] No whitelist given
08:36:56 I0702 08:36:56.888077 18349 master.cpp:2163] Elected as the leading master!
08:36:56 I0702 08:36:56.888098 18349 master.cpp:1702] Recovering from registrar
08:36:56 I0702 08:36:56.888209 18349 registrar.cpp:347] Recovering registrar
08:36:56 I0702 08:36:56.888391 18349 registrar.cpp:391] Successfully fetched the registry (0B) in 159232ns
08:36:56 I0702 08:36:56.888428 18349 registrar.cpp:495] Applied 1 operations in 13259ns; attempting to update the registry
08:36:56 I0702 08:36:56.888618 18347 registrar.cpp:552] Successfully updated the registry in 174080ns
08:36:56 I0702 08:36:56.888662 18347 registrar.cpp:424] Successfully recovered registrar
08:36:56 I0702 08:36:56.888756 18347 master.cpp:1801] Recovered 0 agents from the registry (172B); allowing 10mins for agents to re-register
08:36:56 I0702 08:36:56.888878 18349 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
08:36:56 W0702 08:36:56.890381 28719 process.cpp:3196] Attempted to spawn already running process files@172.16.10.112:35906
08:36:56 I0702 08:36:56.978411 28719 containerizer.cpp:246] Using isolation: cgroups/cpu,filesystem/linux,namespaces/pid,network/cni,volume/image,environment_secret
08:36:56 I0702 08:36:56.982765 28719 linux_launcher.cpp:150] Using /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
08:36:56 I0702 08:36:56.983234 28719 provisioner.cpp:255] Using default backend 'overlay'
08:36:56 I0702 08:36:56.990206 28719 cluster.cpp:448] Creating default 'local' authorizer
08:36:56 I0702 08:36:56.990712 18348 slave.cpp:250] Mesos agent started on (820)@172.16.10.112:35906
08:36:56 I0702 08:36:56.990886 18348 slave.cpp:251] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_U0uIz8/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="docker,mesos" --credential="/tmp/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_U0uIz8/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/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_U0uIz8/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/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_U0uIz8/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/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_U0uIz8/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="cgroups/cpu,filesystem/linux,namespaces/pid" --launcher="linux" --launcher_dir="/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/Clang/label/mesos-ec2-ubuntu-16.04/mesos/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/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_U0uIz8" --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/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_0fWVH4"
08:36:56 I0702 08:36:56.991469 18348 credentials.hpp:86] Loading credential for authentication from '/tmp/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_U0uIz8/credential'
08:36:56 I0702 08:36:56.991209 28719 scheduler.cpp:184] Version: 1.4.2
08:36:56 I0702 08:36:56.991696 18348 slave.cpp:283] Agent using credential for: test-principal
08:36:56 I0702 08:36:56.991720 18348 credentials.hpp:37] Loading credentials for authentication from '/tmp/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_U0uIz8/http_credentials'
08:36:56 I0702 08:36:56.991875 18348 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
08:36:56 I0702 08:36:56.992400 18349 scheduler.cpp:470] New master detected at master@172.16.10.112:35906
08:36:56 I0702 08:36:56.992429 18349 scheduler.cpp:479] Waiting for 0ns before initiating a re-(connection) attempt with the master
08:36:56 I0702 08:36:56.992621 18348 slave.cpp:565] 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"}]
08:36:56 I0702 08:36:56.992702 18348 slave.cpp:573] Agent attributes: [ ]
08:36:56 I0702 08:36:56.992710 18348 slave.cpp:582] Agent hostname: ip-172-16-10-112.ec2.internal
08:36:56 I0702 08:36:56.992854 18350 status_update_manager.cpp:177] Pausing sending status updates
08:36:56 I0702 08:36:56.993185 18348 state.cpp:64] Recovering state from '/tmp/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_0fWVH4/meta'
08:36:56 I0702 08:36:56.993363 18348 status_update_manager.cpp:203] Recovering status update manager
08:36:56 I0702 08:36:56.993469 18348 containerizer.cpp:609] Recovering containerizer
08:36:56 I0702 08:36:56.993595 18347 docker.cpp:890] Recovering Docker containers
08:36:56 I0702 08:36:56.993783 18347 docker.cpp:1397] Running docker -H unix:///var/run/docker.sock ps -a
08:36:57 I0702 08:36:56.999671 18351 scheduler.cpp:361] Connected with the master at http://172.16.10.112:35906/master/api/v1/scheduler
08:36:57 I0702 08:36:57.000233 18350 scheduler.cpp:243] Sending SUBSCRIBE call to http://172.16.10.112:35906/master/api/v1/scheduler
08:36:57 I0702 08:36:57.002498 18348 provisioner.cpp:416] Provisioner recovery complete
08:36:57 I0702 08:36:57.003031 18352 process.cpp:3938] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
08:36:57 I0702 08:36:57.003875 18352 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.16.10.112:38732
08:36:57 I0702 08:36:57.004159 18352 master.cpp:2552] Received subscription request for HTTP framework 'default'
08:36:57 I0702 08:36:57.004354 18352 master.cpp:2235] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
08:36:57 I0702 08:36:57.004715 18352 master.cpp:2688] Subscribing framework 'default' with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
08:36:57 I0702 08:36:57.005127 18352 hierarchical.cpp:295] Added framework 1b41a301-e70a-4aec-830f-7850032b28c3-0000
08:36:57 I0702 08:36:57.005954 18352 hierarchical.cpp:2100] No allocations performed
08:36:57 I0702 08:36:57.006136 18352 hierarchical.cpp:2190] No inverse offers to send out!
08:36:57 I0702 08:36:57.006312 18352 hierarchical.cpp:1438] Performed allocation for 0 agents in 379164ns
08:36:57 I0702 08:36:57.005762 18351 scheduler.cpp:676] Enqueuing event SUBSCRIBED received from http://172.16.10.112:35906/master/api/v1/scheduler
08:36:57 
08:36:57 I0702 08:36:57.005344 18346 master.hpp:2217] Sending heartbeat to 1b41a301-e70a-4aec-830f-7850032b28c3-0000
08:36:57 GMOCK WARNING:
08:36:57 Uninteresting mock function call - returning directly.
08:36:57 Function call: subscribed(0x7ffcfade4888, @0x7f49c000b980 48-byte object <40-EB 8F-ED 49-7F 00-00 00-00 00-00 00-00 00-00 07-00 00-00 00-00 00-00 40-0F 02-C0 49-7F 00-00 80-72 03-C0 49-7F 00-00 00-00 00-00 00-00 2E-40>)
08:36:57 NOTE: You can safely ignore the above warning unless this call should not happen. Do not suppress it by blindly adding an EXPECT_CALL() if you don't mean to enforce the call. See https://github.com/google/googletest/blob/master/googlemock/docs/CookBook.md#knowing-when-to-expect for details.
08:36:57 I0702 08:36:57.007515 18351 scheduler.cpp:676] Enqueuing event HEARTBEAT received from http://172.16.10.112:35906/master/api/v1/scheduler
08:36:57 
08:36:57 GMOCK WARNING:
08:36:57 Uninteresting mock function call - returning directly.
08:36:57 Function call: heartbeat(0x7ffcfade4888)
08:36:57 NOTE: You can safely ignore the above warning unless this call should not happen. Do not suppress it by blindly adding an EXPECT_CALL() if you don't mean to enforce the call. See https://github.com/google/googletest/blob/master/googlemock/docs/CookBook.md#knowing-when-to-expect for details.
08:36:57 I0702 08:36:57.079345 18348 slave.cpp:6325] Finished recovery
08:36:57 I0702 08:36:57.079663 18348 slave.cpp:6507] Querying resource estimator for oversubscribable resources
08:36:57 I0702 08:36:57.079736 18348 slave.cpp:6521] Received oversubscribable resources {} from the resource estimator
08:36:57 I0702 08:36:57.079915 18350 status_update_manager.cpp:177] Pausing sending status updates
08:36:57 I0702 08:36:57.079912 18349 slave.cpp:971] New master detected at master@172.16.10.112:35906
08:36:57 I0702 08:36:57.080047 18349 slave.cpp:1006] Detecting new master
08:36:57 I0702 08:36:57.081328 18351 slave.cpp:1033] Authenticating with master master@172.16.10.112:35906
08:36:57 I0702 08:36:57.081519 18351 slave.cpp:1044] Using default CRAM-MD5 authenticatee
08:36:57 I0702 08:36:57.081629 18351 authenticatee.cpp:121] Creating new client SASL connection
08:36:57 I0702 08:36:57.082093 18351 master.cpp:7867] Authenticating slave(820)@172.16.10.112:35906
08:36:57 I0702 08:36:57.082156 18351 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1527)@172.16.10.112:35906
08:36:57 I0702 08:36:57.082257 18351 authenticator.cpp:98] Creating new server SASL connection
08:36:57 I0702 08:36:57.082566 18351 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
08:36:57 I0702 08:36:57.082587 18351 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
08:36:57 I0702 08:36:57.082617 18351 authenticator.cpp:204] Received SASL authentication start
08:36:57 I0702 08:36:57.082653 18351 authenticator.cpp:326] Authentication requires more steps
08:36:57 I0702 08:36:57.082720 18351 authenticatee.cpp:259] Received SASL authentication step
08:36:57 I0702 08:36:57.082895 18351 authenticator.cpp:232] Received SASL authentication step
08:36:57 I0702 08:36:57.082924 18351 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-112.ec2.internal' server FQDN: 'ip-172-16-10-112.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
08:36:57 I0702 08:36:57.082934 18351 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
08:36:57 I0702 08:36:57.082947 18351 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
08:36:57 I0702 08:36:57.082957 18351 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-112.ec2.internal' server FQDN: 'ip-172-16-10-112.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
08:36:57 I0702 08:36:57.082964 18351 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
08:36:57 I0702 08:36:57.082970 18351 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
08:36:57 I0702 08:36:57.082983 18351 authenticator.cpp:318] Authentication success
08:36:57 I0702 08:36:57.083117 18352 master.cpp:7897] Successfully authenticated principal 'test-principal' at slave(820)@172.16.10.112:35906
08:36:57 I0702 08:36:57.083082 18351 authenticatee.cpp:299] Authentication success
08:36:57 I0702 08:36:57.083359 18351 slave.cpp:1128] Successfully authenticated with master master@172.16.10.112:35906
08:36:57 I0702 08:36:57.083448 18351 slave.cpp:1600] Will retry registration in 8.852079ms if necessary
08:36:57 I0702 08:36:57.083689 18347 master.cpp:5721] Received register agent message from slave(820)@172.16.10.112:35906 (ip-172-16-10-112.ec2.internal)
08:36:57 I0702 08:36:57.083724 18347 master.cpp:3810] Authorizing agent with principal 'test-principal'
08:36:57 I0702 08:36:57.083247 18346 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1527)@172.16.10.112:35906
08:36:57 I0702 08:36:57.083999 18347 master.cpp:5781] Authorized registration of agent at slave(820)@172.16.10.112:35906 (ip-172-16-10-112.ec2.internal)
08:36:57 I0702 08:36:57.084048 18347 master.cpp:5874] Registering agent at slave(820)@172.16.10.112:35906 (ip-172-16-10-112.ec2.internal) with id 1b41a301-e70a-4aec-830f-7850032b28c3-S0
08:36:57 I0702 08:36:57.084358 18347 registrar.cpp:495] Applied 1 operations in 23525ns; attempting to update the registry
08:36:57 I0702 08:36:57.084637 18347 registrar.cpp:552] Successfully updated the registry in 244992ns
08:36:57 I0702 08:36:57.084738 18347 master.cpp:5921] Admitted agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0 at slave(820)@172.16.10.112:35906 (ip-172-16-10-112.ec2.internal)
08:36:57 I0702 08:36:57.084888 18350 slave.cpp:5000] Received ping from slave-observer(748)@172.16.10.112:35906
08:36:57 I0702 08:36:57.085072 18352 hierarchical.cpp:570] Added agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0 (ip-172-16-10-112.ec2.internal) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
08:36:57 I0702 08:36:57.084885 18347 master.cpp:5952] Registered agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0 at slave(820)@172.16.10.112:35906 (ip-172-16-10-112.ec2.internal) 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"}]
08:36:57 I0702 08:36:57.085233 18350 slave.cpp:1174] Registered with master master@172.16.10.112:35906; given agent ID 1b41a301-e70a-4aec-830f-7850032b28c3-S0
08:36:57 I0702 08:36:57.085477 18352 hierarchical.cpp:2190] No inverse offers to send out!
08:36:57 I0702 08:36:57.085506 18352 hierarchical.cpp:1438] Performed allocation for 1 agents in 236577ns
08:36:57 I0702 08:36:57.085530 18352 status_update_manager.cpp:184] Resuming sending status updates
08:36:57 I0702 08:36:57.085664 18352 master.cpp:7697] Sending 1 offers to framework 1b41a301-e70a-4aec-830f-7850032b28c3-0000 (default)
08:36:57 I0702 08:36:57.085849 18350 slave.cpp:1194] Checkpointing SlaveInfo to '/tmp/ROOT_DOCKER_DockerAndMesosContainerizers_DefaultExecutorTest_ROOT_MultiTaskgroupSharePidNamespace_0_0fWVH4/meta/slaves/1b41a301-e70a-4aec-830f-7850032b28c3-S0/slave.info'
08:36:57 I0702 08:36:57.086319 18352 scheduler.cpp:676] Enqueuing event OFFERS received from http://172.16.10.112:35906/master/api/v1/scheduler
08:36:57 I0702 08:36:57.086596 18350 slave.cpp:1243] Forwarding total oversubscribed resources {}
08:36:57 I0702 08:36:57.086660 18350 master.cpp:6701] Received update of agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0 at slave(820)@172.16.10.112:35906 (ip-172-16-10-112.ec2.internal) with total oversubscribed resources {}
08:36:57 I0702 08:36:57.086768 18350 hierarchical.cpp:639] Agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0 (ip-172-16-10-112.ec2.internal) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
08:36:57 I0702 08:36:57.888594 18348 hierarchical.cpp:2100] No allocations performed
08:36:57 I0702 08:36:57.888639 18348 hierarchical.cpp:2190] No inverse offers to send out!
08:36:57 I0702 08:36:57.888651 18348 hierarchical.cpp:1438] Performed allocation for 1 agents in 150902ns
08:36:58 I0702 08:36:58.889405 18350 hierarchical.cpp:2100] No allocations performed
08:36:58 I0702 08:36:58.889448 18350 hierarchical.cpp:2190] No inverse offers to send out!
08:36:58 I0702 08:36:58.889461 18350 hierarchical.cpp:1438] Performed allocation for 1 agents in 149977ns
08:36:59 I0702 08:36:59.890436 18346 hierarchical.cpp:2100] No allocations performed
08:36:59 I0702 08:36:59.890481 18346 hierarchical.cpp:2190] No inverse offers to send out!
08:36:59 I0702 08:36:59.890494 18346 hierarchical.cpp:1438] Performed allocation for 1 agents in 145043ns
08:37:00 I0702 08:37:00.891070 18345 hierarchical.cpp:2100] No allocations performed
08:37:00 I0702 08:37:00.891116 18345 hierarchical.cpp:2190] No inverse offers to send out!
08:37:00 I0702 08:37:00.891129 18345 hierarchical.cpp:1438] Performed allocation for 1 agents in 153807ns
08:37:01 I0702 08:37:01.891387 18352 hierarchical.cpp:2100] No allocations performed
08:37:01 I0702 08:37:01.891433 18352 hierarchical.cpp:2190] No inverse offers to send out!
08:37:01 I0702 08:37:01.891445 18352 hierarchical.cpp:1438] Performed allocation for 1 agents in 160601ns
08:37:02 I0702 08:37:02.892103 18350 hierarchical.cpp:2100] No allocations performed
08:37:02 I0702 08:37:02.892149 18350 hierarchical.cpp:2190] No inverse offers to send out!
08:37:02 I0702 08:37:02.892163 18350 hierarchical.cpp:1438] Performed allocation for 1 agents in 151446ns
08:37:06 I0702 08:37:03.892902 18352 hierarchical.cpp:2100] No allocations performed
08:37:06 I0702 08:37:03.892947 18352 hierarchical.cpp:2190] No inverse offers to send out!
08:37:06 I0702 08:37:03.892961 18352 hierarchical.cpp:1438] Performed allocation for 1 agents in 143224ns
08:37:06 I0702 08:37:04.894285 18345 hierarchical.cpp:2100] No allocations performed
08:37:06 I0702 08:37:04.894331 18345 hierarchical.cpp:2190] No inverse offers to send out!
08:37:06 I0702 08:37:04.894345 18345 hierarchical.cpp:1438] Performed allocation for 1 agents in 149776ns
08:37:06 I0702 08:37:05.895040 18349 hierarchical.cpp:2100] No allocations performed
08:37:06 I0702 08:37:05.895088 18349 hierarchical.cpp:2190] No inverse offers to send out!
08:37:06 I0702 08:37:05.895102 18349 hierarchical.cpp:1438] Performed allocation for 1 agents in 178089ns
08:37:06 I0702 08:37:06.895756 18346 hierarchical.cpp:2100] No allocations performed
08:37:06 I0702 08:37:06.895802 18346 hierarchical.cpp:2190] No inverse offers to send out!
08:37:06 I0702 08:37:06.895814 18346 hierarchical.cpp:1438] Performed allocation for 1 agents in 149783ns
08:37:07 I0702 08:37:07.896450 18347 hierarchical.cpp:2100] No allocations performed
08:37:07 I0702 08:37:07.896497 18347 hierarchical.cpp:2190] No inverse offers to send out!
08:37:07 I0702 08:37:07.896509 18347 hierarchical.cpp:1438] Performed allocation for 1 agents in 154240ns
08:37:08 I0702 08:37:08.897680 18351 hierarchical.cpp:2100] No allocations performed
08:37:08 I0702 08:37:08.897725 18351 hierarchical.cpp:2190] No inverse offers to send out!
08:37:08 I0702 08:37:08.897739 18351 hierarchical.cpp:1438] Performed allocation for 1 agents in 161949ns
08:37:09 I0702 08:37:09.898281 18348 hierarchical.cpp:2100] No allocations performed
08:37:09 I0702 08:37:09.898326 18348 hierarchical.cpp:2190] No inverse offers to send out!
08:37:09 I0702 08:37:09.898339 18348 hierarchical.cpp:1438] Performed allocation for 1 agents in 152873ns
08:37:10 I0702 08:37:10.898883 18350 hierarchical.cpp:2100] No allocations performed
08:37:10 I0702 08:37:10.898931 18350 hierarchical.cpp:2190] No inverse offers to send out!
08:37:10 I0702 08:37:10.898944 18350 hierarchical.cpp:1438] Performed allocation for 1 agents in 152239ns
08:37:11 I0702 08:37:11.899273 18352 hierarchical.cpp:2100] No allocations performed
08:37:11 I0702 08:37:11.899319 18352 hierarchical.cpp:2190] No inverse offers to send out!
08:37:11 I0702 08:37:11.899333 18352 hierarchical.cpp:1438] Performed allocation for 1 agents in 148464ns
08:37:12 I0702 08:37:12.008049 18348 master.hpp:2217] Sending heartbeat to 1b41a301-e70a-4aec-830f-7850032b28c3-0000
08:37:12 I0702 08:37:12.008471 18347 scheduler.cpp:676] Enqueuing event HEARTBEAT received from http://172.16.10.112:35906/master/api/v1/scheduler
08:37:12 ../../src/tests/default_executor_tests.cpp:1420: Failure
08:37:12 Failed to wait 15secs for subscribed
08:37:12 ../../src/tests/default_executor_tests.cpp:1410: Failure
08:37:12 Actual function call count doesn't match EXPECT_CALL(*scheduler, subscribed(_, _))...
08:37:12 Expected: to be called once
08:37:12 Actual: never called - unsatisfied and active
08:37:12 I0702 08:37:12.009460 28719 slave.cpp:843] Agent terminating
08:37:12 I0702 08:37:12.009508 18352 master.cpp:1432] Framework 1b41a301-e70a-4aec-830f-7850032b28c3-0000 (default) disconnected
08:37:12 I0702 08:37:12.009521 18352 master.cpp:3271] Deactivating framework 1b41a301-e70a-4aec-830f-7850032b28c3-0000 (default)
08:37:12 W0702 08:37:12.009644 18352 master.hpp:2378] Unable to send event to framework 1b41a301-e70a-4aec-830f-7850032b28c3-0000 (default): connection closed
08:37:12 I0702 08:37:12.009656 18352 master.cpp:9201] Removing offer 1b41a301-e70a-4aec-830f-7850032b28c3-O0
08:37:12 I0702 08:37:12.009672 18352 master.cpp:3248] Disconnecting framework 1b41a301-e70a-4aec-830f-7850032b28c3-0000 (default)
08:37:12 I0702 08:37:12.009682 18352 master.cpp:1447] Giving framework 1b41a301-e70a-4aec-830f-7850032b28c3-0000 (default) 0ns to failover
08:37:12 I0702 08:37:12.009723 18352 hierarchical.cpp:399] Deactivated framework 1b41a301-e70a-4aec-830f-7850032b28c3-0000
08:37:12 I0702 08:37:12.009850 18352 hierarchical.cpp:1122] Recovered cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0 from framework 1b41a301-e70a-4aec-830f-7850032b28c3-0000
08:37:12 I0702 08:37:12.010066 18352 master.cpp:1318] Agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0 at slave(820)@172.16.10.112:35906 (ip-172-16-10-112.ec2.internal) disconnected
08:37:12 I0702 08:37:12.010089 18352 master.cpp:3308] Disconnecting agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0 at slave(820)@172.16.10.112:35906 (ip-172-16-10-112.ec2.internal)
08:37:12 I0702 08:37:12.010110 18352 master.cpp:3327] Deactivating agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0 at slave(820)@172.16.10.112:35906 (ip-172-16-10-112.ec2.internal)
08:37:12 I0702 08:37:12.010140 18347 hierarchical.cpp:669] Agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0 deactivated
08:37:12 I0702 08:37:12.012230 18345 master.cpp:1160] Master terminating
08:37:12 I0702 08:37:12.012362 18348 hierarchical.cpp:605] Removed agent 1b41a301-e70a-4aec-830f-7850032b28c3-S0
08:37:12 I0702 08:37:12.012493 18348 hierarchical.cpp:342] Removed framework 1b41a301-e70a-4aec-830f-7850032b28c3-0000
08:37:12 [ FAILED ] ROOT_DOCKER_DockerAndMesosContainerizers/DefaultExecutorTest.ROOT_MultiTaskgroupSharePidNamespace/0, where GetParam() = "docker,mesos" (15135 ms){noformat}

> DefaultExecutorTest.ROOT_MultiTaskgroupSharePidNamespace is flaky.
> ------------------------------------------------------------------
>
>                 Key: MESOS-8305
>                 URL: https://issues.apache.org/jira/browse/MESOS-8305
>             Project: Mesos
>          Issue Type: Bug
>    Affects Versions: 1.4.1
>         Environment: Ubuntu 16.04
> Fedora 23
>            Reporter: Alexander Rukletsov
>            Assignee: Qian Zhang
>            Priority: Major
>              Labels: flaky-test
>             Fix For: 1.6.0
>
>         Attachments: ROOT_MultiTaskgroupSharePidNamespace-badrun.txt
>
>
> On Ubuntu 16.04:
> {noformat}
> ../../src/tests/default_executor_tests.cpp:1877
>       Expected: strings::trim(pidNamespace1.get())
>       Which is: "4026532250"
> To be equal to: strings::trim(pidNamespace2.get())
>       Which is: ""
> {noformat}
> Full log attached.
> On Fedora 23:
> {noformat}
> ../../src/tests/default_executor_tests.cpp:1878
>       Expected: strings::trim(pidNamespace1.get())
>       Which is: "4026532233"
> To be equal to: strings::trim(pidNamespace2.get())
>       Which is: ""
> {noformat}
> The test became flaky shortly after MESOS-7306 has been committed and likely related to it.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)