Till Toenshoff created MESOS-9401:
-------------------------------------
Summary: AgentAPITest.GetFrameworks is flaky
Key: MESOS-9401
URL: https://issues.apache.org/jira/browse/MESOS-9401
Project: Mesos
Issue Type: Bug
Components: test
Affects Versions: 1.8.0
Reporter: Till Toenshoff
The following I saw in a macOS run:
{noformat}
14:39:11 [ RUN ] ContentType/AgentAPITest.GetFrameworks/1
14:39:11 I1119 06:39:15.264891 2668864320 cluster.cpp:173] Creating default
'local' authorizer
14:39:11 I1119 06:39:15.266228 170434560 master.cpp:413] Master
be3714c6-f7ac-4dce-8791-7bddc37889d4 (Jenkinss-Mac-mini.local) started on
10.0.49.4:61227
14:39:11 I1119 06:39:15.266257 170434560 master.cpp:416] Flags at startup:
--acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1000secs" --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="/private/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/dFgHko/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"
--publish_per_framework_metrics="true" --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="/private/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/dFgHko/master"
--zk_session_timeout="10secs"
14:39:11 I1119 06:39:15.266446 170434560 master.cpp:465] Master only allowing
authenticated frameworks to register
14:39:11 I1119 06:39:15.266455 170434560 master.cpp:471] Master only allowing
authenticated agents to register
14:39:11 I1119 06:39:15.266460 170434560 master.cpp:477] Master only allowing
authenticated HTTP frameworks to register
14:39:11 I1119 06:39:15.266484 170434560 credentials.hpp:37] Loading
credentials for authentication from
'/private/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/dFgHko/credentials'
14:39:11 I1119 06:39:15.266654 170434560 master.cpp:521] Using default
'crammd5' authenticator
14:39:11 I1119 06:39:15.266732 170434560 http.cpp:1042] Creating default
'basic' HTTP authenticator for realm 'mesos-master-readonly'
14:39:11 I1119 06:39:15.266801 170434560 http.cpp:1042] Creating default
'basic' HTTP authenticator for realm 'mesos-master-readwrite'
14:39:11 I1119 06:39:15.266851 170434560 http.cpp:1042] Creating default
'basic' HTTP authenticator for realm 'mesos-master-scheduler'
14:39:11 I1119 06:39:15.266904 170434560 master.cpp:602] Authorization enabled
14:39:11 I1119 06:39:15.267139 169361408 hierarchical.cpp:175] Initialized
hierarchical allocator process
14:39:11 I1119 06:39:15.267357 170971136 whitelist_watcher.cpp:77] No
whitelist given
14:39:11 I1119 06:39:15.268975 170971136 master.cpp:2105] Elected as the
leading master!
14:39:11 I1119 06:39:15.269001 170971136 master.cpp:1660] Recovering from
registrar
14:39:11 I1119 06:39:15.269045 169897984 registrar.cpp:339] Recovering
registrar
14:39:11 I1119 06:39:15.269253 169361408 registrar.cpp:383] Successfully
fetched the registry (0B) in 187136ns
14:39:11 I1119 06:39:15.269342 169361408 registrar.cpp:487] Applied 1
operations in 22753ns; attempting to update the registry
14:39:11 I1119 06:39:15.269572 168288256 registrar.cpp:544] Successfully
updated the registry in 187136ns
14:39:11 I1119 06:39:15.269637 168288256 registrar.cpp:416] Successfully
recovered registrar
14:39:11 I1119 06:39:15.269793 170434560 master.cpp:1774] Recovered 0 agents
from the registry (155B); allowing 10mins for agents to reregister
14:39:11 I1119 06:39:15.269825 167215104 hierarchical.cpp:215] Skipping
recovery of hierarchical allocator: nothing to recover
14:39:11 W1119 06:39:15.272145 2668864320 process.cpp:2829] Attempted to spawn
already running process [email protected]:61227
14:39:11 I1119 06:39:15.272856 2668864320 containerizer.cpp:305] Using
isolation { environment_secret, filesystem/posix, posix/mem, posix/cpu }
14:39:11 I1119 06:39:15.273074 2668864320 provisioner.cpp:298] Using default
backend 'copy'
14:39:11 I1119 06:39:15.273936 2668864320 cluster.cpp:485] Creating default
'local' authorizer
14:39:11 I1119 06:39:15.275010 169361408 slave.cpp:267] Mesos agent started on
(828)@10.0.49.4:61227
14:39:11 I1119 06:39:15.275039 169361408 slave.cpp:268] Flags at startup:
--acls="" --appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/store/appc"
--authenticate_http_executors="true" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authenticatee="crammd5"
--authentication_backoff_factor="1secs" --authentication_timeout_max="1mins"
--authentication_timeout_min="5secs" --authorizer="local"
--container_disk_watch_interval="15secs" --containerizers="mesos"
--credential="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/credential"
--default_role="*" --disk_watch_interval="1mins" --docker="docker"
--docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io";
--docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock"
--docker_stop_timeout="0ns"
--docker_store_dir="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/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="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/fetch"
--fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins"
--frameworks_home="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/frameworks"
--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="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem"
--jwt_secret_key="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/jwt_secret_key"
--launcher="posix"
--launcher_dir="/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/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"
--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]"
--runtime_dir="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW"
--sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true"
--version="false"
--work_dir="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73"
--zk_session_timeout="10secs"
14:39:11 I1119 06:39:15.275311 169361408 credentials.hpp:86] Loading
credential for authentication from
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/credential'
14:39:11 W1119 06:39:15.275388 2668864320 process.cpp:2829] Attempted to spawn
already running process [email protected]:61227
14:39:11 I1119 06:39:15.275434 169361408 slave.cpp:300] Agent using credential
for: test-principal
14:39:11 I1119 06:39:15.275447 169361408 credentials.hpp:37] Loading
credentials for authentication from
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/http_credentials'
14:39:11 I1119 06:39:15.275643 169361408 http.cpp:1042] Creating default
'basic' HTTP authenticator for realm 'mesos-agent-executor'
14:39:11 I1119 06:39:15.275707 169361408 http.cpp:1063] Creating default 'jwt'
HTTP authenticator for realm 'mesos-agent-executor'
14:39:11 I1119 06:39:15.275797 169361408 http.cpp:1042] Creating default
'basic' HTTP authenticator for realm 'mesos-agent-readonly'
14:39:11 I1119 06:39:15.275840 169361408 http.cpp:1063] Creating default 'jwt'
HTTP authenticator for realm 'mesos-agent-readonly'
14:39:11 I1119 06:39:15.275915 169361408 http.cpp:1042] Creating default
'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
14:39:11 I1119 06:39:15.275976 169361408 http.cpp:1063] Creating default 'jwt'
HTTP authenticator for realm 'mesos-agent-readwrite'
14:39:11 I1119 06:39:15.276202 169361408 disk_profile_adaptor.cpp:80] Creating
default disk profile adaptor module
14:39:11 I1119 06:39:15.276495 169361408 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"}]
14:39:11 I1119 06:39:15.276616 169361408 slave.cpp:623] Agent attributes: [ ]
14:39:11 I1119 06:39:15.276629 169361408 slave.cpp:632] Agent hostname:
Jenkinss-Mac-mini.local
14:39:11 I1119 06:39:15.276681 2668864320 sched.cpp:232] Version: 1.8.0
14:39:11 I1119 06:39:15.276784 167751680 task_status_update_manager.cpp:181]
Pausing sending task status updates
14:39:11 I1119 06:39:15.276967 168824832 sched.cpp:336] New master detected at
[email protected]:61227
14:39:11 I1119 06:39:15.277015 168824832 sched.cpp:401] Authenticating with
master [email protected]:61227
14:39:11 I1119 06:39:15.277029 168824832 sched.cpp:408] Using default CRAM-MD5
authenticatee
14:39:11 I1119 06:39:15.277178 167751680 authenticatee.cpp:121] Creating new
client SASL connection
14:39:11 I1119 06:39:15.277346 169897984 master.cpp:9699] Authenticating
[email protected]:61227
14:39:11 I1119 06:39:15.277380 170434560 state.cpp:66] Recovering state from
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/meta'
14:39:11 I1119 06:39:15.277441 168824832 authenticator.cpp:414] Starting
authentication session for crammd5-authenticatee(1512)@10.0.49.4:61227
14:39:11 I1119 06:39:15.277501 168288256 slave.cpp:6915] Finished recovering
checkpointed state from
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/meta',
beginning agent recovery
14:39:11 I1119 06:39:15.277590 167751680 authenticator.cpp:98] Creating new
server SASL connection
14:39:11 I1119 06:39:15.277578 169361408 task_status_update_manager.cpp:207]
Recovering task status update manager
14:39:11 I1119 06:39:15.277705 170971136 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
14:39:11 I1119 06:39:15.277731 170971136 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
14:39:11 I1119 06:39:15.277789 170434560 authenticator.cpp:204] Received SASL
authentication start
14:39:11 I1119 06:39:15.277865 170434560 authenticator.cpp:326] Authentication
requires more steps
14:39:11 I1119 06:39:15.277918 168288256 containerizer.cpp:727] Recovering
Mesos containers
14:39:11 I1119 06:39:15.278023 167751680 authenticatee.cpp:259] Received SASL
authentication step
14:39:11 I1119 06:39:15.278050 168288256 containerizer.cpp:1053] Recovering
isolators
14:39:11 I1119 06:39:15.278092 169361408 authenticator.cpp:232] Received SASL
authentication step
14:39:11 I1119 06:39:15.278115 169361408 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'Jenkinss-Mac-mini.local' server
FQDN: 'Jenkinss-Mac-mini.local' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
14:39:11 I1119 06:39:15.278144 169361408 auxprop.cpp:181] Looking up auxiliary
property '*userPassword'
14:39:11 I1119 06:39:15.278185 169361408 auxprop.cpp:181] Looking up auxiliary
property '*cmusaslsecretCRAM-MD5'
14:39:11 I1119 06:39:15.278205 169361408 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'Jenkinss-Mac-mini.local' server
FQDN: 'Jenkinss-Mac-mini.local' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
14:39:11 I1119 06:39:15.278218 169361408 auxprop.cpp:131] Skipping auxiliary
property '*userPassword' since SASL_AUXPROP_AUTHZID == true
14:39:11 I1119 06:39:15.278228 169361408 auxprop.cpp:131] Skipping auxiliary
property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
14:39:11 I1119 06:39:15.278241 169361408 authenticator.cpp:318] Authentication
success
14:39:11 I1119 06:39:15.278412 169897984 authenticatee.cpp:299] Authentication
success
14:39:11 I1119 06:39:15.278461 168288256 master.cpp:9731] Successfully
authenticated principal 'test-principal' at
[email protected]:61227
14:39:11 I1119 06:39:15.278484 170971136 authenticator.cpp:432] Authentication
session cleanup for crammd5-authenticatee(1512)@10.0.49.4:61227
14:39:11 I1119 06:39:15.278705 169361408 sched.cpp:513] Successfully
authenticated with master [email protected]:61227
14:39:11 I1119 06:39:15.278726 169361408 sched.cpp:817] Sending SUBSCRIBE call
to [email protected]:61227
14:39:11 I1119 06:39:15.278820 169361408 sched.cpp:850] Will retry
registration in 180.347158ms if necessary
14:39:11 I1119 06:39:15.278838 169897984 containerizer.cpp:1092] Recovering
provisioner
14:39:11 I1119 06:39:15.278961 167215104 master.cpp:2876] Received SUBSCRIBE
call for framework 'default' at
[email protected]:61227
14:39:11 I1119 06:39:15.278980 167215104 master.cpp:2177] Authorizing
framework principal 'test-principal' to receive offers for roles '{ * }'
14:39:11 I1119 06:39:15.279155 168288256 provisioner.cpp:494] Provisioner
recovery complete
14:39:11 I1119 06:39:15.279166 167751680 master.cpp:2957] Subscribing
framework default with checkpointing disabled and capabilities [ MULTI_ROLE,
RESERVATION_REFINEMENT ]
14:39:11 I1119 06:39:15.279510 168824832 composing.cpp:339] Finished
recovering all containerizers
14:39:11 I1119 06:39:15.279649 169361408 slave.cpp:7144] Recovering executors
14:39:11 I1119 06:39:15.279739 169361408 slave.cpp:7297] Finished recovery
14:39:11 I1119 06:39:15.280234 167751680 master.cpp:9929] Adding framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at
[email protected]:61227 with roles { }
suppressed
14:39:11 I1119 06:39:15.280364 169361408 slave.cpp:1260] New master detected
at [email protected]:61227
14:39:11 I1119 06:39:15.280418 169361408 slave.cpp:1325] Detecting new master
14:39:11 I1119 06:39:15.280503 170434560 task_status_update_manager.cpp:181]
Pausing sending task status updates
14:39:11 I1119 06:39:15.280575 168824832 sched.cpp:744] Framework registered
with be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.280624 169897984 hierarchical.cpp:304] Added framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.280637 168824832 sched.cpp:758] Scheduler::registered
took 41698ns
14:39:11 I1119 06:39:15.280748 169897984 hierarchical.cpp:1566] Performed
allocation for 0 agents in 39282ns
14:39:11 I1119 06:39:15.291321 170971136 slave.cpp:1352] Authenticating with
master [email protected]:61227
14:39:11 I1119 06:39:15.291391 170971136 slave.cpp:1361] Using default
CRAM-MD5 authenticatee
14:39:11 I1119 06:39:15.291515 167751680 authenticatee.cpp:121] Creating new
client SASL connection
14:39:11 I1119 06:39:15.291652 170434560 master.cpp:9699] Authenticating
slave(828)@10.0.49.4:61227
14:39:11 I1119 06:39:15.291715 168288256 authenticator.cpp:414] Starting
authentication session for crammd5-authenticatee(1513)@10.0.49.4:61227
14:39:11 I1119 06:39:15.291827 168824832 authenticator.cpp:98] Creating new
server SASL connection
14:39:11 I1119 06:39:15.291947 169897984 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
14:39:11 I1119 06:39:15.291980 169897984 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
14:39:11 I1119 06:39:15.292027 167215104 authenticator.cpp:204] Received SASL
authentication start
14:39:11 I1119 06:39:15.292095 167215104 authenticator.cpp:326] Authentication
requires more steps
14:39:11 I1119 06:39:15.292170 169361408 authenticatee.cpp:259] Received SASL
authentication step
14:39:11 I1119 06:39:15.292229 170971136 authenticator.cpp:232] Received SASL
authentication step
14:39:11 I1119 06:39:15.292248 170971136 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'Jenkinss-Mac-mini.local' server
FQDN: 'Jenkinss-Mac-mini.local' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
14:39:11 I1119 06:39:15.292261 170971136 auxprop.cpp:181] Looking up auxiliary
property '*userPassword'
14:39:11 I1119 06:39:15.292274 170971136 auxprop.cpp:181] Looking up auxiliary
property '*cmusaslsecretCRAM-MD5'
14:39:11 I1119 06:39:15.292284 170971136 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'Jenkinss-Mac-mini.local' server
FQDN: 'Jenkinss-Mac-mini.local' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
14:39:11 I1119 06:39:15.292294 170971136 auxprop.cpp:131] Skipping auxiliary
property '*userPassword' since SASL_AUXPROP_AUTHZID == true
14:39:11 I1119 06:39:15.292302 170971136 auxprop.cpp:131] Skipping auxiliary
property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
14:39:11 I1119 06:39:15.292312 170971136 authenticator.cpp:318] Authentication
success
14:39:11 I1119 06:39:15.292369 167751680 authenticatee.cpp:299] Authentication
success
14:39:11 I1119 06:39:15.292409 170434560 master.cpp:9731] Successfully
authenticated principal 'test-principal' at slave(828)@10.0.49.4:61227
14:39:11 I1119 06:39:15.292420 168288256 authenticator.cpp:432] Authentication
session cleanup for crammd5-authenticatee(1513)@10.0.49.4:61227
14:39:11 I1119 06:39:15.292557 168824832 slave.cpp:1452] Successfully
authenticated with master [email protected]:61227
14:39:11 I1119 06:39:15.292769 168824832 slave.cpp:1883] Will retry
registration in 1.614395ms if necessary
14:39:11 I1119 06:39:15.292850 170971136 master.cpp:6650] Received register
agent message from slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local)
14:39:11 I1119 06:39:15.292981 170971136 master.cpp:3986] Authorizing agent
providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with
principal 'test-principal'
14:39:11 I1119 06:39:15.293256 169897984 master.cpp:6717] Authorized
registration of agent at slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local)
14:39:11 I1119 06:39:15.293342 169897984 master.cpp:6832] Registering agent at
slave(828)@10.0.49.4:61227 (Jenkinss-Mac-mini.local) with id
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0
14:39:11 I1119 06:39:15.293634 167215104 registrar.cpp:487] Applied 1
operations in 140802ns; attempting to update the registry
14:39:11 I1119 06:39:15.293885 167215104 registrar.cpp:544] Successfully
updated the registry in 221952ns
14:39:11 I1119 06:39:15.293956 168288256 master.cpp:6880] Admitted agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local)
14:39:11 I1119 06:39:15.294142 168288256 master.cpp:6925] Registered agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
14:39:11 I1119 06:39:15.294226 169897984 slave.cpp:1485] Registered with
master [email protected]:61227; given agent ID
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0
14:39:11 I1119 06:39:15.294286 170971136 task_status_update_manager.cpp:188]
Resuming sending task status updates
14:39:11 I1119 06:39:15.294329 169361408 hierarchical.cpp:603] Added agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 (Jenkinss-Mac-mini.local) with cpus:2;
mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
14:39:11 I1119 06:39:15.294559 169897984 slave.cpp:1505] Checkpointing
SlaveInfo to
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/meta/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/slave.info'
14:39:11 I1119 06:39:15.294680 169361408 hierarchical.cpp:1566] Performed
allocation for 1 agents in 268880ns
14:39:11 I1119 06:39:15.294847 170434560 master.cpp:9514] Sending offers [
be3714c6-f7ac-4dce-8791-7bddc37889d4-O0 ] to framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at
[email protected]:61227
14:39:11 I1119 06:39:15.295161 167215104 sched.cpp:914]
Scheduler::resourceOffers took 101264ns
14:39:11 I1119 06:39:15.295339 169897984 slave.cpp:1554] Forwarding agent
update
{"operations":{},"resource_version_uuid":{"value":"pIFlAHOPSGSAkO4feS0sAw=="},"slave_id":{"value":"be3714c6-f7ac-4dce-8791-7bddc37889d4-S0"},"update_oversubscribed_resources":false}
14:39:11 I1119 06:39:15.295725 168288256 master.cpp:7984] Ignoring update on
agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local) as it reports no changes
14:39:11 I1119 06:39:15.296494 169897984 process.cpp:3588] Handling HTTP event
for process 'slave(828)' with path: '/slave(828)/api/v1'
14:39:11 I1119 06:39:15.297157 170434560 http.cpp:1182] HTTP POST for
/slave(828)/api/v1 from 10.0.49.4:63781
14:39:11 I1119 06:39:15.297356 170434560 http.cpp:1454] Processing
GET_FRAMEWORKS call
14:39:11 I1119 06:39:15.298992 168824832 master.cpp:11513] Removing offer
be3714c6-f7ac-4dce-8791-7bddc37889d4-O0
14:39:11 I1119 06:39:15.299257 168824832 master.cpp:4511] Processing ACCEPT
call for offers: [ be3714c6-f7ac-4dce-8791-7bddc37889d4-O0 ] on agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local) for framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at
[email protected]:61227
14:39:11 I1119 06:39:15.299327 168824832 master.cpp:3563] Authorizing
framework principal 'test-principal' to launch task 1
14:39:11 I1119 06:39:15.300367 170434560 master.cpp:4088] Adding task 1 with
resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated:
*):1024; ports(allocated: *):[31000-32000] of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at
[email protected]:61227 on agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local)
14:39:11 I1119 06:39:15.300609 170434560 master.cpp:5483] Launching task 1 of
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at
[email protected]:61227 with resources
[{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
on agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local) on new executor
14:39:11 I1119 06:39:15.301375 167215104 slave.cpp:2020] Got assigned task '1'
for framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.302006 167215104 slave.cpp:2394] Authorizing task '1'
for framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.302045 167215104 slave.cpp:8472] Authorizing framework
principal 'test-principal' to launch task 1
14:39:11 I1119 06:39:15.302819 167215104 slave.cpp:2837] Launching task '1'
for framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.302872 167215104 paths.cpp:752] Creating sandbox
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10'
for user 'jenkins'
14:39:11 I1119 06:39:15.303869 167215104 slave.cpp:9000] Launching executor
'1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-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"}]
in work directory
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10'
14:39:11 I1119 06:39:15.304333 167215104 slave.cpp:3034] Queued task '1' for
executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.304420 167215104 slave.cpp:994] Successfully attached
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10'
to virtual path
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/latest'
14:39:11 I1119 06:39:15.304605 167215104 slave.cpp:3515] Launching container
28632eb3-e3fb-41cf-8698-1353f9ccfa10 for executor '1' of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.304941 167215104 slave.cpp:994] Successfully attached
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10'
to virtual path
'/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/latest'
14:39:11 I1119 06:39:15.304965 167215104 slave.cpp:994] Successfully attached
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10'
to virtual path
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10'
14:39:11 I1119 06:39:15.305202 169361408 containerizer.cpp:1288] Starting
container 28632eb3-e3fb-41cf-8698-1353f9ccfa10
14:39:11 I1119 06:39:15.306092 169361408 containerizer.cpp:1454] Checkpointed
ContainerConfig at
'/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/containers/28632eb3-e3fb-41cf-8698-1353f9ccfa10/config'
14:39:11 I1119 06:39:15.306118 169361408 containerizer.cpp:3130] Transitioning
the state of container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 from PROVISIONING
to PREPARING
14:39:11 I1119 06:39:15.307767 169897984 containerizer.cpp:1947] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/mesos/build/src"],"shell":false,"value":"/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/mesos/build/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"10.0.49.4:61227"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiIyODYzMmViMy1lM2ZiLTQxY2YtODY5OC0xMzUzZjljY2ZhMTAiLCJlaWQiOiIxIiwiZmlkIjoiYmUzNzE0YzYtZjdhYy00ZGNlLTg3OTEtN2JkZGMzNzg4OWQ0LTAwMDAifQ.OoSLOnlVGd8hsijTazWpBeFFobk0XKOq8-LuL4l2s2c"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"1"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"be3714c6-f7ac-4dce-8791-7bddc37889d4-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"be3714c6-f7ac-4dce-8791-7bddc37889d4-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(828)@10.0.49.4:61227"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"}]},"task_environment":{},"user":"jenkins","working_directory":"/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"}"
--pipe_read="24" --pipe_write="28"
--runtime_directory="/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_Rt51JW/containers/28632eb3-e3fb-41cf-8698-1353f9ccfa10"'
14:39:11 I1119 06:39:15.309439 169897984 launcher.cpp:145] Forked child with
pid '71895' for container '28632eb3-e3fb-41cf-8698-1353f9ccfa10'
14:39:11 I1119 06:39:15.310206 169897984 containerizer.cpp:3130] Transitioning
the state of container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 from PREPARING to
ISOLATING
14:39:11 I1119 06:39:15.312588 169897984 containerizer.cpp:3130] Transitioning
the state of container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 from ISOLATING to
FETCHING
14:39:11 I1119 06:39:15.312872 170434560 fetcher.cpp:369] Starting to fetch
URIs for container: 28632eb3-e3fb-41cf-8698-1353f9ccfa10, directory:
/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10
14:39:11 I1119 06:39:15.313565 167751680 containerizer.cpp:3130] Transitioning
the state of container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 from FETCHING to
RUNNING
14:39:11 [warn] kq_init: detected broken kqueue; not using.: Undefined error: 0
14:39:11 I1119 06:39:15.474073 151658496 exec.cpp:162] Version: 1.8.0
14:39:11 I1119 06:39:15.477310 167751680 slave.cpp:4809] Got registration for
executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from
executor(1)@10.0.49.4:63782
14:39:11 I1119 06:39:15.478510 168288256 slave.cpp:3247] Sending queued task
'1' to executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 at
executor(1)@10.0.49.4:63782
14:39:11 I1119 06:39:15.478849 149512192 exec.cpp:236] Executor registered on
agent be3714c6-f7ac-4dce-8791-7bddc37889d4-S0
14:39:11 I1119 06:39:15.485213 148975616 executor.cpp:184] Received SUBSCRIBED
event
14:39:11 I1119 06:39:15.485697 148975616 executor.cpp:188] Subscribed executor
on Jenkinss-Mac-mini.local
14:39:11 I1119 06:39:15.485786 148975616 executor.cpp:184] Received LAUNCH
event
14:39:11 I1119 06:39:15.491688 148975616 executor.cpp:687] Starting task 1
14:39:11 I1119 06:39:15.497985 167215104 slave.cpp:5275] Handling status
update TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for
task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from
executor(1)@10.0.49.4:63782
14:39:11 I1119 06:39:15.498713 148975616 executor.cpp:502] Running
'/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/mesos/build/src/mesos-containerizer
launch <POSSIBLY-SENSITIVE-DATA>'
14:39:11 I1119 06:39:15.498822 167751680 task_status_update_manager.cpp:328]
Received task status update TASK_STARTING (Status UUID:
aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.498853 167751680 task_status_update_manager.cpp:507]
Creating StatusUpdate stream for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.499197 167751680 task_status_update_manager.cpp:383]
Forwarding task status update TASK_STARTING (Status UUID:
aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to the agent
14:39:11 I1119 06:39:15.499266 169897984 slave.cpp:5767] Forwarding the update
TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to [email protected]:61227
14:39:11 I1119 06:39:15.499434 169897984 slave.cpp:5660] Task status update
manager successfully handled status update TASK_STARTING (Status UUID:
aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.499503 169897984 slave.cpp:5676] Sending
acknowledgement for status update TASK_STARTING (Status UUID:
aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to executor(1)@10.0.49.4:63782
14:39:11 I1119 06:39:15.499511 168288256 master.cpp:8420] Status update
TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local)
14:39:11 I1119 06:39:15.499544 168288256 master.cpp:8477] Forwarding status
update TASK_STARTING (Status UUID: aca86396-e493-4a95-9bd3-d723058e9da7) for
task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.499650 168288256 master.cpp:10978] Updating the state
of task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (latest state:
TASK_STARTING, status update state: TASK_STARTING)
14:39:11 I1119 06:39:15.499884 167215104 sched.cpp:1022]
Scheduler::statusUpdate took 108414ns
14:39:11 I1119 06:39:15.500064 170434560 master.cpp:6286] Processing
ACKNOWLEDGE call for status aca86396-e493-4a95-9bd3-d723058e9da7 for task 1 of
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at
[email protected]:61227 on agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0
14:39:11 I1119 06:39:15.500166 148975616 executor.cpp:702] Forked command at
71923
14:39:11 I1119 06:39:15.500257 169897984 task_status_update_manager.cpp:401]
Received task status update acknowledgement (UUID:
aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.500407 170971136 slave.cpp:4511] Task status update
manager successfully handled status update acknowledgement (UUID:
aca86396-e493-4a95-9bd3-d723058e9da7) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.507848 168824832 slave.cpp:5275] Handling status
update TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for
task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from
executor(1)@10.0.49.4:63782
14:39:11 I1119 06:39:15.508744 169897984 task_status_update_manager.cpp:328]
Received task status update TASK_RUNNING (Status UUID:
a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.508831 169897984 task_status_update_manager.cpp:383]
Forwarding task status update TASK_RUNNING (Status UUID:
a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to the agent
14:39:11 I1119 06:39:15.509007 168288256 slave.cpp:5767] Forwarding the update
TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to [email protected]:61227
14:39:11 I1119 06:39:15.509145 168288256 slave.cpp:5660] Task status update
manager successfully handled status update TASK_RUNNING (Status UUID:
a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.509188 168288256 slave.cpp:5676] Sending
acknowledgement for status update TASK_RUNNING (Status UUID:
a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 to executor(1)@10.0.49.4:63782
14:39:11 I1119 06:39:15.509207 170971136 master.cpp:8420] Status update
TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local)
14:39:11 I1119 06:39:15.509243 170971136 master.cpp:8477] Forwarding status
update TASK_RUNNING (Status UUID: a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for
task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.509382 170971136 master.cpp:10978] Updating the state
of task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (latest state:
TASK_RUNNING, status update state: TASK_RUNNING)
14:39:11 I1119 06:39:15.509624 168824832 sched.cpp:1022]
Scheduler::statusUpdate took 107500ns
14:39:11 I1119 06:39:15.509821 169361408 master.cpp:6286] Processing
ACKNOWLEDGE call for status a49a359c-1cb8-4551-8df3-bc28ac2b7a2a for task 1 of
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at
[email protected]:61227 on agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0
14:39:11 I1119 06:39:15.510013 168288256 task_status_update_manager.cpp:401]
Received task status update acknowledgement (UUID:
a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.510170 167751680 slave.cpp:4511] Task status update
manager successfully handled status update acknowledgement (UUID:
a49a359c-1cb8-4551-8df3-bc28ac2b7a2a) for task 1 of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.511095 169897984 process.cpp:3588] Handling HTTP event
for process 'slave(828)' with path: '/slave(828)/api/v1'
14:39:11 I1119 06:39:15.511780 168288256 http.cpp:1182] HTTP POST for
/slave(828)/api/v1 from 10.0.49.4:63785
14:39:11 I1119 06:39:15.511982 168288256 http.cpp:1454] Processing
GET_FRAMEWORKS call
14:39:11 I1119 06:39:15.513320 2668864320 sched.cpp:2008] Asked to stop the
driver
14:39:11 I1119 06:39:15.513387 170434560 sched.cpp:1184] Stopping framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.513556 167215104 master.cpp:10231] Processing TEARDOWN
call for framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at
[email protected]:61227
14:39:11 I1119 06:39:15.513588 167215104 master.cpp:10243] Removing framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at
[email protected]:61227
14:39:11 I1119 06:39:15.513605 167215104 master.cpp:3252] Deactivating
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (default) at
[email protected]:61227
14:39:11 I1119 06:39:15.513739 167215104 master.cpp:10978] Updating the state
of task 1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 (latest state:
TASK_KILLED, status update state: TASK_KILLED)
14:39:11 I1119 06:39:15.513789 167751680 hierarchical.cpp:418] Deactivated
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.513829 168824832 slave.cpp:3902] Asked to shut down
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 by [email protected]:61227
14:39:11 I1119 06:39:15.513851 168824832 slave.cpp:3927] Shutting down
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.513883 168824832 slave.cpp:6646] Shutting down
executor '1' of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 at
executor(1)@10.0.49.4:63782
14:39:11 I1119 06:39:15.514106 167215104 master.cpp:11076] Removing task 1
with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated:
*):1024; ports(allocated: *):[31000-32000] of framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 on agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local)
14:39:11 I1119 06:39:15.514303 169361408 hierarchical.cpp:1238] 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
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 from framework
be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.514572 169897984 hierarchical.cpp:357] Removed
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:11 I1119 06:39:15.514663 147902464 exec.cpp:445] Executor asked to
shutdown
14:39:11 I1119 06:39:15.514859 149512192 executor.cpp:184] Received SHUTDOWN
event
14:39:11 I1119 06:39:15.514885 149512192 executor.cpp:805] Shutting down
14:39:11 I1119 06:39:15.514914 149512192 executor.cpp:918] Sending SIGTERM to
process tree at pid 71923
14:39:11 I1119 06:39:15.552628 149512192 executor.cpp:931] Sent SIGTERM to the
following process trees:
14:39:11 [
14:39:11 -+- 71923 /bin/sh
/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/mesos/build/src/mesos-containerizer
launch --help=false --launch_info={"command":{"shell":true,"value":"sleep
1000"},"environment":{"variables":[{"name":"PATH","type":"VALUE","value":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"},{"name":"PWD","type":"VALUE","value":"/private/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(828)@10.0.49.4:61227"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"be3714c6-f7ac-4dce-8791-7bddc37889d4-0000"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"1"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiIyODYzMmViMy1lM2ZiLTQxY2YtODY5OC0xMzUzZjljY2ZhMTAiLCJlaWQiOiIxIiwiZmlkIjoiYmUzNzE0YzYtZjdhYy00ZGNlLTg3OTEtN2JkZGMzNzg4OWQ0LTAwMDAifQ.OoSLOnlVGd8hsijTazWpBeFFobk0XKOq8-LuL4l2s2c"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"be3714c6-f7ac-4dce-8791-7bddc37889d4-S0"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"SHLVL","type":"VALUE","value":"0"},{"name":"DUALCASE","type":"VALUE","value":"1"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"10.0.49.4:61227"},{"name":"DYLD_LIBRARY_PATH","type":"VALUE","value":"/Users/jenkins/workspace/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mac/mesos/build/src/.libs"},{"name":"__CF_USER_TEXT_ENCODING","type":"VALUE","value":"0x1F5:0x0:0x0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/var/folders/6w/rw03zh013y38ys6cyn8qppf80000gn/T/ContentType_AgentAPITest_GetFrameworks_1_6fUr73/slaves/be3714c6-f7ac-4dce-8791-7bddc37889d4-S0/frameworks/be3714c6-f7ac-4dce-8791-7bddc37889d4-0000/executors/1/runs/28632eb3-e3fb-41cf-8698-1353f9ccfa10"},{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"BIN_SH","type":"VALUE","value":"xpg4"}]}}
14:39:11 \--- 71934 (sh)
14:39:11 ]
14:39:11 I1119 06:39:15.552690 149512192 executor.cpp:935] Scheduling
escalation to SIGKILL in 3secs from now
14:39:11 I1119 06:39:15.570111 151121920 executor.cpp:1003] Command terminated
with signal Terminated: 15 (pid: 71923)
14:39:11 I1119 06:39:15.576234 168824832 slave.cpp:5275] Handling status
update TASK_KILLED (Status UUID: c5d92cee-03c1-45ce-8cb0-81d0dfc968d8) for task
1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 from
executor(1)@10.0.49.4:63782
14:39:11 W1119 06:39:15.576290 168824832 slave.cpp:5344] Ignoring status
update TASK_KILLED (Status UUID: c5d92cee-03c1-45ce-8cb0-81d0dfc968d8) for task
1 of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 for terminating
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000
14:39:51 I1119 06:39:51.104415 167215104 slave.cpp:6719] Killing executor '1'
of framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 at
executor(1)@10.0.49.4:63782
14:39:51 I1119 06:39:51.106272 168288256 slave.cpp:5899] Got exited event for
executor(1)@10.0.49.4:63782
14:39:51 ../../src/tests/api_tests.cpp:5500: Failure
14:39:51 Failed to wait 15secs for executorTerminated
14:39:51 I1119 06:39:51.106459 170434560 containerizer.cpp:2463] Destroying
container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 in RUNNING state
14:39:51 I1119 06:39:51.106482 170434560 containerizer.cpp:3130] Transitioning
the state of container 28632eb3-e3fb-41cf-8698-1353f9ccfa10 from RUNNING to
DESTROYING
14:39:51 I1119 06:39:51.106822 170434560 launcher.cpp:161] Asked to destroy
container 28632eb3-e3fb-41cf-8698-1353f9ccfa10
14:39:51 I1119 06:39:51.107393 2668864320 slave.cpp:915] Agent terminating
14:39:51 I1119 06:39:51.107439 2668864320 slave.cpp:3902] Asked to shut down
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 by @0.0.0.0:0
14:39:51 W1119 06:39:51.107461 2668864320 slave.cpp:3923] Ignoring shutdown
framework be3714c6-f7ac-4dce-8791-7bddc37889d4-0000 because it is terminating
14:39:51 I1119 06:39:51.165649 168824832 master.cpp:1273] Agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local) disconnected
14:39:51 I1119 06:39:51.165710 168824832 master.cpp:3289] Disconnecting agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local)
14:39:51 I1119 06:39:51.165760 168824832 master.cpp:3308] Deactivating agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 at slave(828)@10.0.49.4:61227
(Jenkinss-Mac-mini.local)
14:39:51 I1119 06:39:51.165907 169361408 hierarchical.cpp:801] Agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0 deactivated
14:39:51 I1119 06:39:51.205538 167751680 containerizer.cpp:2969] Container
28632eb3-e3fb-41cf-8698-1353f9ccfa10 has exited
14:39:51 I1119 06:39:51.206760 168824832 provisioner.cpp:597] Ignoring destroy
request for unknown container 28632eb3-e3fb-41cf-8698-1353f9ccfa10
14:39:51 I1119 06:39:51.214574 2668864320 master.cpp:1115] Master terminating
14:39:51 I1119 06:39:51.215334 168288256 hierarchical.cpp:643] Removed agent
be3714c6-f7ac-4dce-8791-7bddc37889d4-S0
14:39:51 ../../3rdparty/libprocess/include/process/gmock.hpp:545: Failure
14:39:51 Actual function call count doesn't match EXPECT_CALL(filter->mock,
filter(pid, testing::A<const DispatchEvent&>()))...
14:39:51 Expected args: dispatch matcher 16-byte object <59-00 00-00 00-00
00-00 00-00 00-00 00-00 00-00>
14:39:51 Expected: to be called once
14:39:51 Actual: never called - unsatisfied and active
14:39:51 [ FAILED ] ContentType/AgentAPITest.GetFrameworks/1, where
GetParam() = application/json (35956 ms)
{noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
