Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 13D29200C08 for ; Thu, 12 Jan 2017 01:39:19 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id 124DD160B50; Thu, 12 Jan 2017 00:39:19 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id B577F160B4E for ; Thu, 12 Jan 2017 01:39:17 +0100 (CET) Received: (qmail 75522 invoked by uid 500); 12 Jan 2017 00:39:16 -0000 Mailing-List: contact issues-help@mesos.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@mesos.apache.org Delivered-To: mailing list issues@mesos.apache.org Received: (qmail 75488 invoked by uid 99); 12 Jan 2017 00:39:16 -0000 Received: from arcas.apache.org (HELO arcas) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 12 Jan 2017 00:39:16 +0000 Received: from arcas.apache.org (localhost [127.0.0.1]) by arcas (Postfix) with ESMTP id 93BB32C0298 for ; Thu, 12 Jan 2017 00:39:16 +0000 (UTC) Date: Thu, 12 Jan 2017 00:39:16 +0000 (UTC) From: "Neil Conway (JIRA)" To: issues@mesos.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Updated] (MESOS-6911) SlaveRecoveryTest/0.RegisterDisconnectedSlave test is flaky MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Thu, 12 Jan 2017 00:39:19 -0000 [ https://issues.apache.org/jira/browse/MESOS-6911?page=3Dcom.atlassia= n.jira.plugin.system.issuetabpanels:all-tabpanel ] Neil Conway updated MESOS-6911: ------------------------------- Shepherd: Vinod Kone > SlaveRecoveryTest/0.RegisterDisconnectedSlave test is flaky > ----------------------------------------------------------- > > Key: MESOS-6911 > URL: https://issues.apache.org/jira/browse/MESOS-6911 > Project: Mesos > Issue Type: Bug > Environment: ASF CI > Reporter: Vinod Kone > Assignee: Neil Conway > > Observed this on ASF CI: > {code} > [ RUN ] SlaveRecoveryTest/0.RegisterDisconnectedSlave > I0111 18:52:55.691341 27071 cluster.cpp:160] Creating default 'local' aut= horizer > I0111 18:52:55.693492 27076 master.cpp:383] Master f193ab26-63f6-4284-9de= 0-cd89bb73adb4 (b09aa0a37318) started on 172.17.0.3:42061 > I0111 18:52:55.693522 27076 master.cpp:385] Flags at startup: --acls=3D""= --agent_ping_timeout=3D"15secs" --agent_reregister_timeout=3D"10mins" --al= location_interval=3D"1secs" --allocat > or=3D"HierarchicalDRF" --authenticate_agents=3D"false" --authenticate_fra= meworks=3D"true" --authenticate_http_frameworks=3D"true" --authenticate_htt= p_readonly=3D"true" --authenticate_http > _readwrite=3D"true" --authenticators=3D"crammd5" --authorizers=3D"local" = --credentials=3D"/tmp/e83N9C/credentials" --framework_sorter=3D"drf" --help= =3D"false" --hostname_lookup=3D"true" --htt > p_authenticators=3D"basic" --http_framework_authenticators=3D"basic" --in= itialize_driver_logging=3D"true" --log_auto_initialize=3D"true" --logbufsec= s=3D"0" --logging_level=3D"INFO" --max_ag > ent_ping_timeouts=3D"5" --max_completed_frameworks=3D"50" --max_completed= _tasks_per_framework=3D"1000" --quiet=3D"false" --recovery_agent_removal_li= mit=3D"100%" --registry=3D"in_memory" --r > egistry_fetch_timeout=3D"1mins" --registry_gc_interval=3D"15mins" --regis= try_max_agent_age=3D"2weeks" --registry_max_agent_count=3D"102400" --regist= ry_store_timeout=3D"100secs" --registry > _strict=3D"false" --root_submissions=3D"true" --user_sorter=3D"drf" --ver= sion=3D"false" --webui_dir=3D"/usr/local/share/mesos/webui" --work_dir=3D"/= tmp/e83N9C/master" --zk_session_timeout=3D" > 10secs" > I0111 18:52:55.693800 27076 master.cpp:435] Master only allowing authenti= cated frameworks to register > I0111 18:52:55.693811 27076 master.cpp:451] Master allowing unauthenticat= ed agents to register > I0111 18:52:55.693819 27076 master.cpp:462] Master only allowing authenti= cated HTTP frameworks to register > I0111 18:52:55.693825 27076 credentials.hpp:37] Loading credentials for a= uthentication from '/tmp/e83N9C/credentials' > I0111 18:52:55.693991 27076 master.cpp:507] Using default 'crammd5' authe= nticator > I0111 18:52:55.694067 27076 http.cpp:922] Using default 'basic' HTTP auth= enticator for realm 'mesos-master-readonly' > I0111 18:52:55.694119 27076 http.cpp:922] Using default 'basic' HTTP auth= enticator for realm 'mesos-master-readwrite' > I0111 18:52:55.694142 27076 http.cpp:922] Using default 'basic' HTTP auth= enticator for realm 'mesos-master-scheduler' > I0111 18:52:55.694156 27076 master.cpp:587] Authorization enabled > I0111 18:52:55.694834 27083 hierarchical.cpp:149] Initialized hierarchica= l allocator process > I0111 18:52:55.694885 27083 whitelist_watcher.cpp:77] No whitelist given > I0111 18:52:55.695083 27076 master.cpp:2119] Elected as the leading maste= r! > I0111 18:52:55.695096 27076 master.cpp:1641] Recovering from registrar > I0111 18:52:55.695166 27076 registrar.cpp:329] Recovering registrar > I0111 18:52:55.695739 27076 registrar.cpp:362] Successfully fetched the r= egistry (0B) in 551936ns > I0111 18:52:55.695775 27076 registrar.cpp:461] Applied 1 operations in 49= 72ns; attempting to update the registry > I0111 18:52:55.696069 27076 registrar.cpp:506] Successfully updated the r= egistry in 273920ns > I0111 18:52:55.696121 27076 registrar.cpp:392] Successfully recovered reg= istrar > I0111 18:52:55.696553 27079 hierarchical.cpp:176] Skipping recovery of hi= erarchical allocator: nothing to recover > I0111 18:52:55.696570 27073 master.cpp:1757] Recovered 0 agents from the = registry (129B); allowing 10mins for agents to re-register > I0111 18:52:55.698655 27071 containerizer.cpp:220] Using isolation: posix= /cpu,posix/mem,filesystem/posix,network/cni > W0111 18:52:55.699059 27071 backend.cpp:76] Failed to create 'aufs' backe= nd: AufsBackend requires root privileges, but is running as user mesos > W0111 18:52:55.699148 27071 backend.cpp:76] Failed to create 'bind' backe= nd: BindBackend requires root privileges > I0111 18:52:55.701257 27071 cluster.cpp:446] Creating default 'local' aut= horizer > I0111 18:52:55.702049 27077 slave.cpp:209] Mesos agent started on (485)@1= 72.17.0.3:42061 > I0111 18:52:55.702069 27077 slave.cpp:210] Flags at startup: --acls=3D"" = --appc_simple_discovery_uri_prefix=3D"http://" --appc_store_dir=3D"/tmp/mes= os/store/appc" --authenticate_http_readonly=3D"true" --authenticate_http_re= adwrite=3D"true" --authenticatee=3D"crammd5" --authentication_backoff_facto= r=3D"1secs" --authorizer=3D"local" --cgroups_cpu_enable_pids_and_tids_count= =3D"false" --cgroups_enable_cfs=3D"false" --cgroups_hierarchy=3D"/sys/fs/cg= roup" --cgroups_limit_swap=3D"false" --cgroups_root=3D"mesos" --container_d= isk_watch_interval=3D"15secs" --containerizers=3D"mesos" --credential=3D"/t= mp/SlaveRecoveryTest_0_RegisterDisconnectedSlave_IX53a9/credential" --defau= lt_role=3D"*" --disk_watch_interval=3D"1mins" --docker=3D"docker" --docker_= kill_orphans=3D"true" --docker_registry=3D"https://registry-1.docker.io" --= docker_remove_delay=3D"6hrs" --docker_socket=3D"/var/run/docker.sock" --doc= ker_stop_timeout=3D"0ns" --docker_store_dir=3D"/tmp/mesos/store/docker" --d= ocker_volume_checkpoint_dir=3D"/var/run/mesos/isolators/docker/volume" --en= force_container_disk_quota=3D"false" --executor_registration_timeout=3D"1mi= ns" --executor_shutdown_grace_period=3D"5secs" --fetcher_cache_dir=3D"/tmp/= SlaveRecoveryTest_0_RegisterDisconnectedSlave_IX53a9/fetch" --fetcher_cache= _size=3D"2GB" --frameworks_home=3D"" --gc_delay=3D"1weeks" --gc_disk_headro= om=3D"0.1" --hadoop_home=3D"" --help=3D"false" --hostname_lookup=3D"true" -= -http_authenticators=3D"basic" --http_command_executor=3D"false" --http_cre= dentials=3D"/tmp/SlaveRecoveryTest_0_RegisterDisconnectedSlave_IX53a9/http_= credentials" --http_heartbeat_interval=3D"30secs" --image_provisioner_backe= nd=3D"copy" --initialize_driver_logging=3D"true" --isolation=3D"posix/cpu,p= osix/mem" --launcher=3D"posix" --launcher_dir=3D"/mesos/build/src" --logbuf= secs=3D"0" --logging_level=3D"INFO" --max_completed_executors_per_framework= =3D"150" --oversubscribed_resources_interval=3D"15secs" --perf_duration=3D"= 10secs" --perf_interval=3D"1mins" --qos_correction_interval_min=3D"0ns" --q= uiet=3D"false" --recover=3D"reconnect" --recovery_timeout=3D"15mins" --regi= stration_backoff_factor=3D"10ms" --resources=3D"cpus:2;gpus:0;mem:1024;disk= :1024;ports:[31000-32000]" --revocable_cpu_low_priority=3D"true" --runtime_= dir=3D"/tmp/SlaveRecoveryTest_0_RegisterDisconnectedSlave_IX53a9" --sandbox= _directory=3D"/mnt/mesos/sandbox" --strict=3D"true" --switch_user=3D"true" = --systemd_enable_support=3D"true" --systemd_runtime_directory=3D"/run/syste= md/system" --version=3D"false" --work_dir=3D"/tmp/SlaveRecoveryTest_0_Regis= terDisconnectedSlave_XwgqaT" > I0111 18:52:55.702533 27077 credentials.hpp:86] Loading credential for au= thentication from '/tmp/SlaveRecoveryTest_0_RegisterDisconnectedSlave_IX53a= 9/credential' > I0111 18:52:55.702687 27077 slave.cpp:352] Agent using credential for: te= st-principal > I0111 18:52:55.702721 27077 credentials.hpp:37] Loading credentials for a= uthentication from '/tmp/SlaveRecoveryTest_0_RegisterDisconnectedSlave_IX53= a9/http_credentials' > I0111 18:52:55.702865 27077 http.cpp:922] Using default 'basic' HTTP auth= enticator for realm 'mesos-agent-readonly' > I0111 18:52:55.703058 27077 http.cpp:922] Using default 'basic' HTTP auth= enticator for realm 'mesos-agent-readwrite' > I0111 18:52:55.703541 27077 slave.cpp:539] Agent resources: cpus(*):2; me= m(*):1024; disk(*):1024; ports(*):[31000-32000] > I0111 18:52:55.703575 27077 slave.cpp:547] Agent attributes: [ ] > I0111 18:52:55.703583 27077 slave.cpp:552] Agent hostname: b09aa0a37318 > I0111 18:52:55.704030 27086 state.cpp:60] Recovering state from '/tmp/Sla= veRecoveryTest_0_RegisterDisconnectedSlave_XwgqaT/meta' > I0111 18:52:55.704193 27086 status_update_manager.cpp:203] Recovering sta= tus update manager > I0111 18:52:55.704581 27086 containerizer.cpp:599] Recovering containeriz= er > I0111 18:52:55.705227 27080 provisioner.cpp:251] Provisioner recovery com= plete > I0111 18:52:55.705379 27086 slave.cpp:5421] Finished recovery > I0111 18:52:55.705912 27086 slave.cpp:5595] Querying resource estimator f= or oversubscribable resources > I0111 18:52:55.706006 27086 slave.cpp:5609] Received oversubscribable res= ources {} from the resource estimator > I0111 18:52:55.706210 27081 status_update_manager.cpp:177] Pausing sendin= g status updates > I0111 18:52:55.706233 27078 slave.cpp:924] New master detected at master@= 172.17.0.3:42061 > I0111 18:52:55.706285 27078 slave.cpp:959] Detecting new master > I0111 18:52:55.715513 27078 slave.cpp:986] Authenticating with master mas= ter@172.17.0.3:42061 > I0111 18:52:55.715556 27078 slave.cpp:997] Using default CRAM-MD5 authent= icatee > I0111 18:52:55.715667 27077 authenticatee.cpp:121] Creating new client SA= SL connection > I0111 18:52:55.715894 27081 master.cpp:6835] Authenticating slave(485)@17= 2.17.0.3:42061 > I0111 18:52:55.715944 27077 authenticator.cpp:414] Starting authenticatio= n session for crammd5-authenticatee(986)@172.17.0.3:42061 > I0111 18:52:55.716037 27075 authenticator.cpp:98] Creating new server SAS= L connection > I0111 18:52:55.716234 27080 authenticatee.cpp:213] Received SASL authenti= cation mechanisms: CRAM-MD5 > I0111 18:52:55.716277 27080 authenticatee.cpp:239] Attempting to authenti= cate with mechanism 'CRAM-MD5' > I0111 18:52:55.716333 27080 authenticator.cpp:204] Received SASL authenti= cation start > I0111 18:52:55.716477 27080 authenticator.cpp:326] Authentication require= s more steps > I0111 18:52:55.716605 27080 authenticatee.cpp:259] Received SASL authenti= cation step > I0111 18:52:55.716790 27080 authenticator.cpp:232] Received SASL authenti= cation step > I0111 18:52:55.716907 27080 auxprop.cpp:109] Request to lookup properties= for user: 'test-principal' realm: 'b09aa0a37318' server FQDN: 'b09aa0a3731= 8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SAS= L_AUXPROP_AUTHZID: false=20 > I0111 18:52:55.717041 27080 auxprop.cpp:181] Looking up auxiliary propert= y '*userPassword' > I0111 18:52:55.717185 27080 auxprop.cpp:181] Looking up auxiliary propert= y '*cmusaslsecretCRAM-MD5' > I0111 18:52:55.717207 27080 auxprop.cpp:109] Request to lookup properties= for user: 'test-principal' realm: 'b09aa0a37318' server FQDN: 'b09aa0a3731= 8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SAS= L_AUXPROP_AUTHZID: true=20 > I0111 18:52:55.717247 27080 auxprop.cpp:131] Skipping auxiliary property = '*userPassword' since SASL_AUXPROP_AUTHZID =3D=3D true > I0111 18:52:55.717257 27080 auxprop.cpp:131] Skipping auxiliary property = '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID =3D=3D true > I0111 18:52:55.717296 27080 authenticator.cpp:318] Authentication success > I0111 18:52:55.717373 27080 authenticatee.cpp:299] Authentication success > I0111 18:52:55.717404 27086 master.cpp:6865] Successfully authenticated p= rincipal 'test-principal' at slave(485)@172.17.0.3:42061 > I0111 18:52:55.717432 27081 authenticator.cpp:432] Authentication session= cleanup for crammd5-authenticatee(986)@172.17.0.3:42061 > I0111 18:52:55.717664 27080 slave.cpp:1081] Successfully authenticated wi= th master master@172.17.0.3:42061 > I0111 18:52:55.717756 27080 slave.cpp:1503] Will retry registration in 17= .356946ms if necessary > I0111 18:52:55.717931 27081 master.cpp:5234] Registering agent at slave(4= 85)@172.17.0.3:42061 (b09aa0a37318) with id f193ab26-63f6-4284-9de0-cd89bb7= 3adb4-S0 > I0111 18:52:55.718101 27077 registrar.cpp:461] Applied 1 operations in 20= 803ns; attempting to update the registry > I0111 18:52:55.718472 27076 registrar.cpp:506] Successfully updated the r= egistry in 338176ns > I0111 18:52:55.719049 27081 slave.cpp:4285] Received ping from slave-obse= rver(462)@172.17.0.3:42061 > I0111 18:52:55.719120 27081 slave.cpp:1127] Registered with master master= @172.17.0.3:42061; given agent ID f193ab26-63f6-4284-9de0-cd89bb73adb4-S0 > I0111 18:52:55.719139 27081 fetcher.cpp:90] Clearing fetcher cache > I0111 18:52:55.719128 27084 master.cpp:5305] Registered agent f193ab26-63= f6-4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:42061 (b09aa0a37318) = with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] > I0111 18:52:55.719342 27084 hierarchical.cpp:491] Added agent f193ab26-63= f6-4284-9de0-cd89bb73adb4-S0 (b09aa0a37318) with cpus(*):2; mem(*):1024; di= sk(*):1024; ports(*):[31000-32000] (allocated: {}) > I0111 18:52:55.719408 27084 hierarchical.cpp:1690] No allocations perform= ed > I0111 18:52:55.719430 27084 hierarchical.cpp:1315] Performed allocation f= or agent f193ab26-63f6-4284-9de0-cd89bb73adb4-S0 in 61136ns > I0111 18:52:55.719466 27081 slave.cpp:1155] Checkpointing SlaveInfo to '/= tmp/SlaveRecoveryTest_0_RegisterDisconnectedSlave_XwgqaT/meta/slaves/f193ab= 26-63f6-4284-9de0-cd89bb73adb4-S0/slave.info' > I0111 18:52:55.719480 27084 status_update_manager.cpp:184] Resuming sendi= ng status updates > I0111 18:52:55.719810 27081 slave.cpp:1193] Forwarding total oversubscrib= ed resources {} > I0111 18:52:55.719862 27081 master.cpp:5712] Received update of agent f19= 3ab26-63f6-4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:42061 (b09aa0= a37318) with total oversubscribed resources {} > I0111 18:52:55.720095 27087 hierarchical.cpp:561] Agent f193ab26-63f6-428= 4-9de0-cd89bb73adb4-S0 (b09aa0a37318) updated with oversubscribed resources= {} (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], a= llocated: {}) > I0111 18:52:55.720407 27087 hierarchical.cpp:1690] No allocations perform= ed > I0111 18:52:55.720433 27087 hierarchical.cpp:1315] Performed allocation f= or agent f193ab26-63f6-4284-9de0-cd89bb73adb4-S0 in 161873ns > I0111 18:52:55.721096 27071 sched.cpp:232] Version: 1.2.0 > I0111 18:52:55.721359 27079 sched.cpp:336] New master detected at master@= 172.17.0.3:42061 > I0111 18:52:55.721395 27079 sched.cpp:407] Authenticating with master mas= ter@172.17.0.3:42061 > I0111 18:52:55.721410 27079 sched.cpp:414] Using default CRAM-MD5 authent= icatee > I0111 18:52:55.721606 27072 authenticatee.cpp:121] Creating new client SA= SL connection > I0111 18:52:55.721803 27072 master.cpp:6835] Authenticating scheduler-491= fec7d-d55e-48e3-9ca3-fce068ce2dce@172.17.0.3:42061 > I0111 18:52:55.722048 27072 authenticator.cpp:414] Starting authenticatio= n session for crammd5-authenticatee(987)@172.17.0.3:42061 > I0111 18:52:55.722317 27072 authenticator.cpp:98] Creating new server SAS= L connection > I0111 18:52:55.722518 27072 authenticatee.cpp:213] Received SASL authenti= cation mechanisms: CRAM-MD5 > I0111 18:52:55.722548 27072 authenticatee.cpp:239] Attempting to authenti= cate with mechanism 'CRAM-MD5' > I0111 18:52:55.722594 27072 authenticator.cpp:204] Received SASL authenti= cation start > I0111 18:52:55.722645 27072 authenticator.cpp:326] Authentication require= s more steps > I0111 18:52:55.722689 27072 authenticatee.cpp:259] Received SASL authenti= cation step > I0111 18:52:55.722745 27072 authenticator.cpp:232] Received SASL authenti= cation step > I0111 18:52:55.722771 27072 auxprop.cpp:109] Request to lookup properties= for user: 'test-principal' realm: 'b09aa0a37318' server FQDN: 'b09aa0a3731= 8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SAS= L_AUXPROP_AUTHZID: false=20 > I0111 18:52:55.722784 27072 auxprop.cpp:181] Looking up auxiliary propert= y '*userPassword' > I0111 18:52:55.722797 27072 auxprop.cpp:181] Looking up auxiliary propert= y '*cmusaslsecretCRAM-MD5' > I0111 18:52:55.722815 27072 auxprop.cpp:109] Request to lookup properties= for user: 'test-principal' realm: 'b09aa0a37318' server FQDN: 'b09aa0a3731= 8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SAS= L_AUXPROP_AUTHZID: true=20 > I0111 18:52:55.722826 27072 auxprop.cpp:131] Skipping auxiliary property = '*userPassword' since SASL_AUXPROP_AUTHZID =3D=3D true > I0111 18:52:55.722832 27072 auxprop.cpp:131] Skipping auxiliary property = '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID =3D=3D true > I0111 18:52:55.722847 27072 authenticator.cpp:318] Authentication success > I0111 18:52:55.722895 27072 authenticatee.cpp:299] Authentication success > I0111 18:52:55.722937 27072 master.cpp:6865] Successfully authenticated p= rincipal 'test-principal' at scheduler-491fec7d-d55e-48e3-9ca3-fce068ce2dce= @172.17.0.3:42061 > I0111 18:52:55.722971 27072 authenticator.cpp:432] Authentication session= cleanup for crammd5-authenticatee(987)@172.17.0.3:42061 > I0111 18:52:55.723062 27072 sched.cpp:513] Successfully authenticated wit= h master master@172.17.0.3:42061 > I0111 18:52:55.723081 27072 sched.cpp:836] Sending SUBSCRIBE call to mast= er@172.17.0.3:42061 > I0111 18:52:55.723125 27072 sched.cpp:869] Will retry registration in 1.6= 30125153secs if necessary > I0111 18:52:55.723235 27072 master.cpp:2707] Received SUBSCRIBE call for = framework 'default' at scheduler-491fec7d-d55e-48e3-9ca3-fce068ce2dce@172.1= 7.0.3:42061 > I0111 18:52:55.723264 27072 master.cpp:2155] Authorizing framework princi= pal 'test-principal' to receive offers for role '*' > I0111 18:52:55.723398 27072 master.cpp:2783] Subscribing framework defaul= t with checkpointing enabled and capabilities [ ] > I0111 18:52:55.723603 27072 hierarchical.cpp:277] Added framework f193ab2= 6-63f6-4284-9de0-cd89bb73adb4-0000 > I0111 18:52:55.723865 27072 hierarchical.cpp:1785] No inverse offers to s= end out! > I0111 18:52:55.723897 27072 hierarchical.cpp:1292] Performed allocation f= or 1 agents in 273576ns > I0111 18:52:55.724014 27072 sched.cpp:759] Framework registered with f193= ab26-63f6-4284-9de0-cd89bb73adb4-0000 > I0111 18:52:55.724050 27072 sched.cpp:773] Scheduler::registered took 157= 50ns > I0111 18:52:55.724215 27072 master.cpp:6664] Sending 1 offers to framewor= k f193ab26-63f6-4284-9de0-cd89bb73adb4-0000 (default) at scheduler-491fec7d= -d55e-48e3-9ca3-fce068ce2dce@172.17.0.3:42061 > I0111 18:52:55.724386 27072 sched.cpp:933] Scheduler::resourceOffers took= 36299ns > I0111 18:52:55.725075 27085 master.cpp:3662] Processing ACCEPT call for o= ffers: [ f193ab26-63f6-4284-9de0-cd89bb73adb4-O0 ] on agent f193ab26-63f6-4= 284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:42061 (b09aa0a37318) for = framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0000 (default) at scheduler-= 491fec7d-d55e-48e3-9ca3-fce068ce2dce@172.17.0.3:42061 > I0111 18:52:55.725113 27085 master.cpp:3249] Authorizing framework princi= pal 'test-principal' to launch task b969d109-e0fb-4308-9290-92b22ae8c4b7 > I0111 18:52:55.725637 27085 master.cpp:8581] Adding task b969d109-e0fb-43= 08-9290-92b22ae8c4b7 with resources cpus(*):2; mem(*):1024; disk(*):1024; p= orts(*):[31000-32000] on agent f193ab26-63f6-4284-9de0-cd89bb73adb4-S0 at s= lave(485)@172.17.0.3:42061 (b09aa0a37318) > I0111 18:52:55.725724 27085 master.cpp:4313] Launching task b969d109-e0fb= -4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0= 000 (default) at scheduler-491fec7d-d55e-48e3-9ca3-fce068ce2dce@172.17.0.3:= 42061 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-= 32000] on agent f193ab26-63f6-4284-9de0-cd89bb73adb4-S0 at slave(485)@172.1= 7.0.3:42061 (b09aa0a37318) > I0111 18:52:55.726084 27085 slave.cpp:1571] Got assigned task 'b969d109-e= 0fb-4308-9290-92b22ae8c4b7' for framework f193ab26-63f6-4284-9de0-cd89bb73a= db4-0000 > I0111 18:52:55.726239 27085 slave.cpp:6262] Checkpointing FrameworkInfo t= o '/tmp/SlaveRecoveryTest_0_RegisterDisconnectedSlave_XwgqaT/meta/slaves/f1= 93ab26-63f6-4284-9de0-cd89bb73adb4-S0/frameworks/f193ab26-63f6-4284-9de0-cd= 89bb73adb4-0000/framework.info' > I0111 18:52:55.726835 27085 slave.cpp:6273] Checkpointing framework pid '= scheduler-491fec7d-d55e-48e3-9ca3-fce068ce2dce@172.17.0.3:42061' to '/tmp/S= laveRecoveryTest_0_RegisterDisconnectedSlave_XwgqaT/meta/slaves/f193ab26-63= f6-4284-9de0-cd89bb73adb4-S0/frameworks/f193ab26-63f6-4284-9de0-cd89bb73adb= 4-0000/framework.pid' > I0111 18:52:55.727361 27085 slave.cpp:1731] Launching task 'b969d109-e0fb= -4308-9290-92b22ae8c4b7' for framework f193ab26-63f6-4284-9de0-cd89bb73adb4= -0000 > I0111 18:52:55.727908 27085 paths.cpp:530] Trying to chown '/tmp/SlaveRec= overyTest_0_RegisterDisconnectedSlave_XwgqaT/slaves/f193ab26-63f6-4284-9de0= -cd89bb73adb4-S0/frameworks/f193ab26-63f6-4284-9de0-cd89bb73adb4-0000/execu= tors/b969d109-e0fb-4308-9290-92b22ae8c4b7/runs/5ca261a9-7655-4473-ad23-4638= c856c858' to user 'mesos' > I0111 18:52:55.732523 27085 slave.cpp:6739] Checkpointing ExecutorInfo to= '/tmp/SlaveRecoveryTest_0_RegisterDisconnectedSlave_XwgqaT/meta/slaves/f19= 3ab26-63f6-4284-9de0-cd89bb73adb4-S0/frameworks/f193ab26-63f6-4284-9de0-cd8= 9bb73adb4-0000/executors/b969d109-e0fb-4308-9290-92b22ae8c4b7/executor.info= ' > I0111 18:52:55.733202 27085 slave.cpp:6348] Launching executor 'b969d109-= e0fb-4308-9290-92b22ae8c4b7' of framework f193ab26-63f6-4284-9de0-cd89bb73a= db4-0000 with resources cpus(*):0.1; mem(*):32 in work directory '/tmp/Slav= eRecoveryTest_0_RegisterDisconnectedSlave_XwgqaT/slaves/f193ab26-63f6-4284-= 9de0-cd89bb73adb4-S0/frameworks/f193ab26-63f6-4284-9de0-cd89bb73adb4-0000/e= xecutors/b969d109-e0fb-4308-9290-92b22ae8c4b7/runs/5ca261a9-7655-4473-ad23-= 4638c856c858' > I0111 18:52:55.733749 27077 containerizer.cpp:991] Starting container 5ca= 261a9-7655-4473-ad23-4638c856c858 for executor 'b969d109-e0fb-4308-9290-92b= 22ae8c4b7' of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0000 > I0111 18:52:55.733780 27085 slave.cpp:6762] Checkpointing TaskInfo to '/t= mp/SlaveRecoveryTest_0_RegisterDisconnectedSlave_XwgqaT/meta/slaves/f193ab2= 6-63f6-4284-9de0-cd89bb73adb4-S0/frameworks/f193ab26-63f6-4284-9de0-cd89bb7= 3adb4-0000/executors/b969d109-e0fb-4308-9290-92b22ae8c4b7/runs/5ca261a9-765= 5-4473-ad23-4638c856c858/tasks/b969d109-e0fb-4308-9290-92b22ae8c4b7/task.in= fo' > I0111 18:52:55.734252 27085 slave.cpp:2053] Queued task 'b969d109-e0fb-43= 08-9290-92b22ae8c4b7' for executor 'b969d109-e0fb-4308-9290-92b22ae8c4b7' o= f framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0000 > I0111 18:52:55.734329 27085 slave.cpp:877] Successfully attached file '/t= mp/SlaveRecoveryTest_0_RegisterDisconnectedSlave_XwgqaT/slaves/f193ab26-63f= 6-4284-9de0-cd89bb73adb4-S0/frameworks/f193ab26-63f6-4284-9de0-cd89bb73adb4= -0000/executors/b969d109-e0fb-4308-9290-92b22ae8c4b7/runs/5ca261a9-7655-447= 3-ad23-4638c856c858' > I0111 18:52:55.735308 27081 containerizer.cpp:1540] Launching 'mesos-cont= ainerizer' with flags '--help=3D"false" --launch_info=3D"{"command":{"argum= ents":["mesos-executor","--launcher_dir=3D\/mesos\/build\/src"],"shell":fal= se,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables= ":[{"name":"LIBPROCESS_PORT","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","v= alue":"172.17.0.3:42061"},{"name":"MESOS_CHECKPOINT","value":"1"},{"name":"= MESOS_DIRECTORY","value":"\/tmp\/SlaveRecoveryTest_0_RegisterDisconnectedSl= ave_XwgqaT\/slaves\/f193ab26-63f6-4284-9de0-cd89bb73adb4-S0\/frameworks\/f1= 93ab26-63f6-4284-9de0-cd89bb73adb4-0000\/executors\/b969d109-e0fb-4308-9290= -92b22ae8c4b7\/runs\/5ca261a9-7655-4473-ad23-4638c856c858"},{"name":"MESOS_= EXECUTOR_ID","value":"b969d109-e0fb-4308-9290-92b22ae8c4b7"},{"name":"MESOS= _EXECUTOR_SHUTDOWN_GRACE_PERIOD","value":"5secs"},{"name":"MESOS_FRAMEWORK_= ID","value":"f193ab26-63f6-4284-9de0-cd89bb73adb4-0000"},{"name":"MESOS_HTT= P_COMMAND_EXECUTOR","value":"0"},{"name":"MESOS_RECOVERY_TIMEOUT","value":"= 15mins"},{"name":"MESOS_SLAVE_ID","value":"f193ab26-63f6-4284-9de0-cd89bb73= adb4-S0"},{"name":"MESOS_SLAVE_PID","value":"slave(485)@172.17.0.3:42061"},= {"name":"MESOS_SUBSCRIPTION_BACKOFF_MAX","value":"2secs"},{"name":"MESOS_SA= NDBOX","value":"\/tmp\/SlaveRecoveryTest_0_RegisterDisconnectedSlave_XwgqaT= \/slaves\/f193ab26-63f6-4284-9de0-cd89bb73adb4-S0\/frameworks\/f193ab26-63f= 6-4284-9de0-cd89bb73adb4-0000\/executors\/b969d109-e0fb-4308-9290-92b22ae8c= 4b7\/runs\/5ca261a9-7655-4473-ad23-4638c856c858"}]},"user":"mesos","working= _directory":"\/tmp\/SlaveRecoveryTest_0_RegisterDisconnectedSlave_XwgqaT\/s= laves\/f193ab26-63f6-4284-9de0-cd89bb73adb4-S0\/frameworks\/f193ab26-63f6-4= 284-9de0-cd89bb73adb4-0000\/executors\/b969d109-e0fb-4308-9290-92b22ae8c4b7= \/runs\/5ca261a9-7655-4473-ad23-4638c856c858"}" --pipe_read=3D"7" --pipe_wr= ite=3D"8" --runtime_directory=3D"/tmp/SlaveRecoveryTest_0_RegisterDisconnec= tedSlave_IX53a9/containers/5ca261a9-7655-4473-ad23-4638c856c858" --unshare_= namespace_mnt=3D"false"' > I0111 18:52:55.736647 27081 launcher.cpp:133] Forked child with pid '3091= 4' for container '5ca261a9-7655-4473-ad23-4638c856c858' > I0111 18:52:55.736830 27081 containerizer.cpp:1639] Checkpointing contain= er's forked pid 30914 to '/tmp/SlaveRecoveryTest_0_RegisterDisconnectedSlav= e_XwgqaT/meta/slaves/f193ab26-63f6-4284-9de0-cd89bb73adb4-S0/frameworks/f19= 3ab26-63f6-4284-9de0-cd89bb73adb4-0000/executors/b969d109-e0fb-4308-9290-92= b22ae8c4b7/runs/5ca261a9-7655-4473-ad23-4638c856c858/pids/forked.pid' > I0111 18:52:55.738760 27080 fetcher.cpp:349] Starting to fetch URIs for c= ontainer: 5ca261a9-7655-4473-ad23-4638c856c858, directory: /tmp/SlaveRecove= ryTest_0_RegisterDisconnectedSlave_XwgqaT/slaves/f193ab26-63f6-4284-9de0-cd= 89bb73adb4-S0/frameworks/f193ab26-63f6-4284-9de0-cd89bb73adb4-0000/executor= s/b969d109-e0fb-4308-9290-92b22ae8c4b7/runs/5ca261a9-7655-4473-ad23-4638c85= 6c858 > I0111 18:52:55.828845 30921 exec.cpp:162] Version: 1.2.0 > I0111 18:52:55.833731 27078 slave.cpp:3322] Got registration for executor= 'b969d109-e0fb-4308-9290-92b22ae8c4b7' of framework f193ab26-63f6-4284-9de= 0-cd89bb73adb4-0000 from executor(1)@172.17.0.3:44874 > I0111 18:52:55.833977 27078 slave.cpp:3408] Checkpointing executor pid 'e= xecutor(1)@172.17.0.3:44874' to '/tmp/SlaveRecoveryTest_0_RegisterDisconnec= tedSlave_XwgqaT/meta/slaves/f193ab26-63f6-4284-9de0-cd89bb73adb4-S0/framewo= rks/f193ab26-63f6-4284-9de0-cd89bb73adb4-0000/executors/b969d109-e0fb-4308-= 9290-92b22ae8c4b7/runs/5ca261a9-7655-4473-ad23-4638c856c858/pids/libprocess= .pid' > I0111 18:52:55.835109 30923 exec.cpp:237] Executor registered on agent f1= 93ab26-63f6-4284-9de0-cd89bb73adb4-S0 > I0111 18:52:55.835211 27078 slave.cpp:2267] Sending queued task 'b969d109= -e0fb-4308-9290-92b22ae8c4b7' to executor 'b969d109-e0fb-4308-9290-92b22ae8= c4b7' of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0000 at executor(1)= @172.17.0.3:44874 > Received SUBSCRIBED event > Subscribed executor on b09aa0a37318 > Received LAUNCH event > Starting task b969d109-e0fb-4308-9290-92b22ae8c4b7 > /mesos/build/src/mesos-containerizer launch --help=3D"false" --launch_inf= o=3D"{"command":{"shell":true,"value":"sleep 1000"}}" --unshare_namespace_m= nt=3D"false" > Forked command at 30933 > I0111 18:52:55.842718 27082 slave.cpp:3754] Handling status update TASK_R= UNNING (UUID: 6fbee882-8439-4c01-91b5-49b7955349f8) for task b969d109-e0fb-= 4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-00= 00 from executor(1)@172.17.0.3:44874 > I0111 18:52:55.843504 27073 status_update_manager.cpp:323] Received statu= s update TASK_RUNNING (UUID: 6fbee882-8439-4c01-91b5-49b7955349f8) for task= b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-= cd89bb73adb4-0000 > I0111 18:52:55.843534 27073 status_update_manager.cpp:500] Creating Statu= sUpdate stream for task b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f= 193ab26-63f6-4284-9de0-cd89bb73adb4-0000 > I0111 18:52:55.843977 27073 status_update_manager.cpp:832] Checkpointing = UPDATE for status update TASK_RUNNING (UUID: 6fbee882-8439-4c01-91b5-49b795= 5349f8) for task b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26= -63f6-4284-9de0-cd89bb73adb4-0000 > I0111 18:52:55.844115 27073 status_update_manager.cpp:377] Forwarding upd= ate TASK_RUNNING (UUID: 6fbee882-8439-4c01-91b5-49b7955349f8) for task b969= d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89b= b73adb4-0000 to the agent > I0111 18:52:55.844358 27073 slave.cpp:4195] Forwarding the update TASK_RU= NNING (UUID: 6fbee882-8439-4c01-91b5-49b7955349f8) for task b969d109-e0fb-4= 308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-000= 0 to master@172.17.0.3:42061 > I0111 18:52:55.844611 27073 slave.cpp:4089] Status update manager success= fully handled status update TASK_RUNNING (UUID: 6fbee882-8439-4c01-91b5-49b= 7955349f8) for task b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193a= b26-63f6-4284-9de0-cd89bb73adb4-0000 > I0111 18:52:55.844825 27073 slave.cpp:4105] Sending acknowledgement for s= tatus update TASK_RUNNING (UUID: 6fbee882-8439-4c01-91b5-49b7955349f8) for = task b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9= de0-cd89bb73adb4-0000 to executor(1)@172.17.0.3:44874 > I0111 18:52:55.844782 27086 master.cpp:5848] Status update TASK_RUNNING (= UUID: 6fbee882-8439-4c01-91b5-49b7955349f8) for task b969d109-e0fb-4308-929= 0-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0000 from = agent f193ab26-63f6-4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:4206= 1 (b09aa0a37318) > I0111 18:52:55.844988 27086 master.cpp:5910] Forwarding status update TAS= K_RUNNING (UUID: 6fbee882-8439-4c01-91b5-49b7955349f8) for task b969d109-e0= fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4= -0000 > I0111 18:52:55.845077 27086 master.cpp:7953] Updating the state of task b= 969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd= 89bb73adb4-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNN= ING) > I0111 18:52:55.845196 27086 sched.cpp:1041] Scheduler::statusUpdate took = 24432ns > I0111 18:52:55.845324 27086 master.cpp:4950] Processing ACKNOWLEDGE call = 6fbee882-8439-4c01-91b5-49b7955349f8 for task b969d109-e0fb-4308-9290-92b22= ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0000 (default) at= scheduler-491fec7d-d55e-48e3-9ca3-fce068ce2dce@172.17.0.3:42061 on agent f= 193ab26-63f6-4284-9de0-cd89bb73adb4-S0 > I0111 18:52:55.845535 27086 status_update_manager.cpp:395] Received statu= s update acknowledgement (UUID: 6fbee882-8439-4c01-91b5-49b7955349f8) for t= ask b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9d= e0-cd89bb73adb4-0000 > I0111 18:52:55.845602 27086 status_update_manager.cpp:832] Checkpointing = ACK for status update TASK_RUNNING (UUID: 6fbee882-8439-4c01-91b5-49b795534= 9f8) for task b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63= f6-4284-9de0-cd89bb73adb4-0000 > I0111 18:52:55.845835 27086 slave.cpp:3042] Status update manager success= fully handled status update acknowledgement (UUID: 6fbee882-8439-4c01-91b5-= 49b7955349f8) for task b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f1= 93ab26-63f6-4284-9de0-cd89bb73adb4-0000 > I0111 18:52:55.846096 27075 containerizer.cpp:2118] Destroying container = 5ca261a9-7655-4473-ad23-4638c856c858 in RUNNING state > I0111 18:52:55.846189 27075 launcher.cpp:149] Asked to destroy container = 5ca261a9-7655-4473-ad23-4638c856c858 > I0111 18:52:55.853996 27075 slave.cpp:4327] Got exited event for executor= (1)@172.17.0.3:44874 > I0111 18:52:55.882633 27079 containerizer.cpp:2481] Container 5ca261a9-76= 55-4473-ad23-4638c856c858 has exited > I0111 18:52:55.883587 27079 provisioner.cpp:322] Ignoring destroy request= for unknown container 5ca261a9-7655-4473-ad23-4638c856c858 > I0111 18:52:55.884263 27080 slave.cpp:4690] Executor 'b969d109-e0fb-4308-= 9290-92b22ae8c4b7' of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0000 t= erminated with signal Killed > I0111 18:52:55.884340 27080 slave.cpp:3754] Handling status update TASK_F= AILED (UUID: a641ba05-c0cc-4d51-9bc7-5d8dae71afce) for task b969d109-e0fb-4= 308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-000= 0 from @0.0.0.0:0 > W0111 18:52:55.884745 27083 containerizer.cpp:1933] Ignoring update for u= nknown container 5ca261a9-7655-4473-ad23-4638c856c858 > I0111 18:52:55.885037 27074 status_update_manager.cpp:323] Received statu= s update TASK_FAILED (UUID: a641ba05-c0cc-4d51-9bc7-5d8dae71afce) for task = b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-c= d89bb73adb4-0000 > I0111 18:52:55.885092 27074 status_update_manager.cpp:832] Checkpointing = UPDATE for status update TASK_FAILED (UUID: a641ba05-c0cc-4d51-9bc7-5d8dae7= 1afce) for task b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-= 63f6-4284-9de0-cd89bb73adb4-0000 > I0111 18:52:55.885257 27074 status_update_manager.cpp:377] Forwarding upd= ate TASK_FAILED (UUID: a641ba05-c0cc-4d51-9bc7-5d8dae71afce) for task b969d= 109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb= 73adb4-0000 to the agent > I0111 18:52:55.885406 27082 slave.cpp:4195] Forwarding the update TASK_FA= ILED (UUID: a641ba05-c0cc-4d51-9bc7-5d8dae71afce) for task b969d109-e0fb-43= 08-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0000= to master@172.17.0.3:42061 > I0111 18:52:55.885622 27082 slave.cpp:796] Agent terminating > I0111 18:52:55.885812 27074 master.cpp:5848] Status update TASK_FAILED (U= UID: a641ba05-c0cc-4d51-9bc7-5d8dae71afce) for task b969d109-e0fb-4308-9290= -92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0000 from a= gent f193ab26-63f6-4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:42061= (b09aa0a37318) > I0111 18:52:55.885972 27074 master.cpp:5910] Forwarding status update TAS= K_FAILED (UUID: a641ba05-c0cc-4d51-9bc7-5d8dae71afce) for task b969d109-e0f= b-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-= 0000 > I0111 18:52:55.886055 27074 master.cpp:7953] Updating the state of task b= 969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd= 89bb73adb4-0000 (latest state: TASK_FAILED, status update state: TASK_FAILE= D) > /mesos/src/tests/slave_recovery_tests.cpp:2799: Failure > Mock function called more times than expected - returning directly. > Function call: statusUpdate(0x7ffc45655d90, @0x2ac116c60810 120-byte = object <50-6B 53-0D C1-2A 00-00 00-00 00-00 00-00 00-00 DF-13 00-00 00-00 0= 0-00 00-55 00-34 C1-2A 00-00 70-23 00-34 C1-2A 00-00 03-00 00-00 01-00 00-0= 0 D0-C1 73-02 00-00 00-00 B0-6D 01-34 C1-2A 00-00 30-4A 02-34 C1-2A 00-00 0= 1-00 00-00 00-2A 00-00 D3-A0 D4-CE 87-2B D6-41 10-12 00-34 C1-2A 00-00 00-0= 0 00-00 00-00 00-00 D0-ED 00-34 C1-2A 00-00 00-00 00-00 00-00 00-00>) > Expected: to be called once > Actual: called twice - over-saturated and active > I0111 18:52:55.886711 27082 hierarchical.cpp:1024] Recovered cpus(*):2; m= em(*):1024; disk(*):1024; ports(*):[31000-32000] (total: cpus(*):2; mem(*):= 1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent f193ab2= 6-63f6-4284-9de0-cd89bb73adb4-S0 from framework f193ab26-63f6-4284-9de0-cd8= 9bb73adb4-0000 > I0111 18:52:55.886860 27074 sched.cpp:1041] Scheduler::statusUpdate took = 505379ns > I0111 18:52:55.886862 27085 master.cpp:1261] Agent f193ab26-63f6-4284-9de= 0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:42061 (b09aa0a37318) disconnecte= d > I0111 18:52:55.887459 27085 master.cpp:3051] Disconnecting agent f193ab26= -63f6-4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:42061 (b09aa0a3731= 8) > I0111 18:52:55.887506 27085 master.cpp:3070] Deactivating agent f193ab26-= 63f6-4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:42061 (b09aa0a37318= ) > W0111 18:52:55.887595 27085 master.cpp:4942] Cannot send status update ac= knowledgement a641ba05-c0cc-4d51-9bc7-5d8dae71afce for task b969d109-e0fb-4= 308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-000= 0 (default) at scheduler-491fec7d-d55e-48e3-9ca3-fce068ce2dce@172.17.0.3:42= 061 to agent f193ab26-63f6-4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0= .3:42061 (b09aa0a37318) because agent is disconnected > I0111 18:52:55.887657 27085 hierarchical.cpp:590] Agent f193ab26-63f6-428= 4-9de0-cd89bb73adb4-S0 deactivated > I0111 18:52:55.888365 27085 master.cpp:5195] Removing old disconnected ag= ent f193ab26-63f6-4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:42061 = (b09aa0a37318) because a registration attempt occurred > I0111 18:52:55.888388 27085 master.cpp:7736] Removing agent f193ab26-63f6= -4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:42061 (b09aa0a37318): a= new agent registered at the same address > I0111 18:52:55.888535 27085 master.cpp:5234] Registering agent at slave(4= 85)@172.17.0.3:42061 (b09aa0a37318) with id f193ab26-63f6-4284-9de0-cd89bb7= 3adb4-S1 > I0111 18:52:55.888734 27085 registrar.cpp:461] Applied 1 operations in 30= 248ns; attempting to update the registry > I0111 18:52:55.889088 27085 registrar.cpp:506] Successfully updated the r= egistry in 321024ns > I0111 18:52:55.889161 27085 registrar.cpp:461] Applied 1 operations in 10= 441ns; attempting to update the registry > I0111 18:52:55.889709 27085 registrar.cpp:506] Successfully updated the r= egistry in 393984ns > I0111 18:52:55.889269 27076 master.cpp:7778] Removed agent f193ab26-63f6-= 4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0.3:42061 (b09aa0a37318): a = new agent registered at the same address > I0111 18:52:55.889883 27076 master.cpp:7953] Updating the state of task b= 969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f6-4284-9de0-cd= 89bb73adb4-0000 (latest state: TASK_FAILED, status update state: TASK_LOST) > I0111 18:52:55.889982 27076 master.cpp:8049] Removing task b969d109-e0fb-= 4308-9290-92b22ae8c4b7 with resources cpus(*):2; mem(*):1024; disk(*):1024;= ports(*):[31000-32000] of framework f193ab26-63f6-4284-9de0-cd89bb73adb4-0= 000 on agent f193ab26-63f6-4284-9de0-cd89bb73adb4-S0 at slave(485)@172.17.0= .3:42061 (b09aa0a37318) > I0111 18:52:55.890242 27076 master.cpp:5905] Sending status update TASK_L= OST for task b969d109-e0fb-4308-9290-92b22ae8c4b7 of framework f193ab26-63f= 6-4284-9de0-cd89bb73adb4-0000 'Agent b09aa0a37318 removed: a new agent regi= stered at the same address' > I0111 18:52:55.890367 27076 master.cpp:2036] Notifying framework f193ab26= -63f6-4284-9de0-cd89bb73adb4-0000 (default) at scheduler-491fec7d-d55e-48e3= -9ca3-fce068ce2dce@172.17.0.3:42061 of lost agent f193ab26-63f6-4284-9de0-c= d89bb73adb4-S0 (b09aa0a37318) > I0111 18:52:55.890631 27076 master.cpp:5305] Registered agent f193ab26-63= f6-4284-9de0-cd89bb73adb4-S1 at slave(485)@172.17.0.3:42061 (b09aa0a37318) = with cpus(*):2; mem(*):1024; : > {code} -- This message was sent by Atlassian JIRA (v6.3.4#6332)