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 63017200BCB for ; Thu, 10 Nov 2016 02:44:01 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id 616F7160AFA; Thu, 10 Nov 2016 01:44:01 +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 60FC2160AFD for ; Thu, 10 Nov 2016 02:43:59 +0100 (CET) Received: (qmail 46471 invoked by uid 500); 10 Nov 2016 01:43:58 -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 46415 invoked by uid 99); 10 Nov 2016 01:43:58 -0000 Received: from arcas.apache.org (HELO arcas) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 10 Nov 2016 01:43:58 +0000 Received: from arcas.apache.org (localhost [127.0.0.1]) by arcas (Postfix) with ESMTP id 640B22C1F54 for ; Thu, 10 Nov 2016 01:43:58 +0000 (UTC) Date: Thu, 10 Nov 2016 01:43:58 +0000 (UTC) From: "Yan Xu (JIRA)" To: issues@mesos.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Created] (MESOS-6569) MesosContainerizer/DefaultExecutorTest.KillTask/0 failing on ASF CI MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Thu, 10 Nov 2016 01:44:01 -0000 Yan Xu created MESOS-6569: ----------------------------- Summary: MesosContainerizer/DefaultExecutorTest.KillTask/0 fai= ling on ASF CI Key: MESOS-6569 URL: https://issues.apache.org/jira/browse/MESOS-6569 Project: Mesos Issue Type: Bug Affects Versions: 1.1.0 Environment: https://builds.apache.org/job/Mesos/BUILDTOOL=3Dautot= ools,COMPILER=3Dgcc,CONFIGURATION=3D--verbose,ENVIRONMENT=3DGLOG_v=3D1%20ME= SOS_VERBOSE=3D1,OS=3Dubuntu:14.04,label_exp=3D(docker%7C%7CHadoop)&&(!ubunt= u-us1)&&(!ubuntu-6)&&(!ubuntu-eu2)/ Reporter: Yan Xu {noformat:title=3D} [ RUN ] MesosContainerizer/DefaultExecutorTest.KillTask/0 I1110 01:20:11.482097 29700 cluster.cpp:158] Creating default 'local' autho= rizer I1110 01:20:11.485241 29700 leveldb.cpp:174] Opened db in 2.774513ms I1110 01:20:11.486237 29700 leveldb.cpp:181] Compacted db in 953614ns I1110 01:20:11.486299 29700 leveldb.cpp:196] Created db iterator in 24739ns I1110 01:20:11.486325 29700 leveldb.cpp:202] Seeked to beginning of db in 2= 300ns I1110 01:20:11.486344 29700 leveldb.cpp:271] Iterated through 0 keys in the= db in 378ns I1110 01:20:11.486399 29700 replica.cpp:776] Replica recovered with log pos= itions 0 -> 0 with 1 holes and 0 unlearned I1110 01:20:11.486933 29733 recover.cpp:451] Starting replica recovery I1110 01:20:11.487289 29733 recover.cpp:477] Replica is in EMPTY status I1110 01:20:11.488503 29721 replica.cpp:673] Replica in EMPTY status receiv= ed a broadcasted recover request from __req_res__(7318)@172.17.0.3:52462 I1110 01:20:11.488855 29727 recover.cpp:197] Received a recover response fr= om a replica in EMPTY status I1110 01:20:11.489398 29729 recover.cpp:568] Updating replica status to STA= RTING I1110 01:20:11.490223 29723 leveldb.cpp:304] Persisting metadata (8 bytes) = to leveldb took 575135ns I1110 01:20:11.490284 29732 master.cpp:380] Master d28fbae1-c3dc-45fa-8384-= 32ab9395a975 (3a31be8bf679) started on 172.17.0.3:52462 I1110 01:20:11.490317 29732 master.cpp:382] Flags at startup: --acls=3D"" -= -agent_ping_timeout=3D"15secs" --agent_reregister_timeout=3D"10mins" --allo= cation_interval=3D"1secs" --allocator=3D"HierarchicalDRF" --authenticate_ag= ents=3D"true" --authenticate_frameworks=3D"true" --authenticate_http_framew= orks=3D"true" --authenticate_http_readonly=3D"true" --authenticate_http_rea= dwrite=3D"true" --authenticators=3D"crammd5" --authorizers=3D"local" --cred= entials=3D"/tmp/k50x7x/credentials" --framework_sorter=3D"drf" --help=3D"fa= lse" --hostname_lookup=3D"true" --http_authenticators=3D"basic" --http_fram= ework_authenticators=3D"basic" --initialize_driver_logging=3D"true" --log_a= uto_initialize=3D"true" --logbufsecs=3D"0" --logging_level=3D"INFO" --max_a= gent_ping_timeouts=3D"5" --max_completed_frameworks=3D"50" --max_completed_= tasks_per_framework=3D"1000" --quiet=3D"false" --recovery_agent_removal_lim= it=3D"100%" --registry=3D"replicated_log" --registry_fetch_timeout=3D"1mins= " --registry_gc_interval=3D"15mins" --registry_max_agent_age=3D"2weeks" --r= egistry_max_agent_count=3D"102400" --registry_store_timeout=3D"100secs" --r= egistry_strict=3D"false" --root_submissions=3D"true" --user_sorter=3D"drf" = --version=3D"false" --webui_dir=3D"/mesos/mesos-1.2.0/_inst/share/mesos/web= ui" --work_dir=3D"/tmp/k50x7x/master" --zk_session_timeout=3D"10secs" I1110 01:20:11.490696 29732 master.cpp:432] Master only allowing authentica= ted frameworks to register I1110 01:20:11.490712 29732 master.cpp:446] Master only allowing authentica= ted agents to register I1110 01:20:11.490720 29732 master.cpp:459] Master only allowing authentica= ted HTTP frameworks to register I1110 01:20:11.490730 29732 credentials.hpp:37] Loading credentials for aut= hentication from '/tmp/k50x7x/credentials' I1110 01:20:11.490281 29723 replica.cpp:320] Persisted replica status to ST= ARTING I1110 01:20:11.491210 29732 master.cpp:504] Using default 'crammd5' authent= icator I1110 01:20:11.491225 29720 recover.cpp:477] Replica is in STARTING status I1110 01:20:11.491394 29732 http.cpp:895] Using default 'basic' HTTP authen= ticator for realm 'mesos-master-readonly' I1110 01:20:11.491621 29732 http.cpp:895] Using default 'basic' HTTP authen= ticator for realm 'mesos-master-readwrite' I1110 01:20:11.491770 29732 http.cpp:895] Using default 'basic' HTTP authen= ticator for realm 'mesos-master-scheduler' I1110 01:20:11.491937 29732 master.cpp:584] Authorization enabled I1110 01:20:11.492276 29725 whitelist_watcher.cpp:77] No whitelist given I1110 01:20:11.492310 29723 hierarchical.cpp:149] Initialized hierarchical = allocator process I1110 01:20:11.492569 29721 replica.cpp:673] Replica in STARTING status rec= eived a broadcasted recover request from __req_res__(7319)@172.17.0.3:52462 I1110 01:20:11.492830 29719 recover.cpp:197] Received a recover response fr= om a replica in STARTING status I1110 01:20:11.493371 29720 recover.cpp:568] Updating replica status to VOT= ING I1110 01:20:11.494002 29721 leveldb.cpp:304] Persisting metadata (8 bytes) = to leveldb took 367673ns I1110 01:20:11.494032 29721 replica.cpp:320] Persisted replica status to VO= TING I1110 01:20:11.494218 29734 recover.cpp:582] Successfully joined the Paxos = group I1110 01:20:11.494469 29734 recover.cpp:466] Recover process terminated I1110 01:20:11.495633 29733 master.cpp:2033] Elected as the leading master! I1110 01:20:11.495685 29733 master.cpp:1560] Recovering from registrar I1110 01:20:11.495880 29720 registrar.cpp:329] Recovering registrar I1110 01:20:11.496842 29730 log.cpp:553] Attempting to start the writer I1110 01:20:11.498610 29725 replica.cpp:493] Replica received implicit prom= ise request from __req_res__(7320)@172.17.0.3:52462 with proposal 1 I1110 01:20:11.499179 29725 leveldb.cpp:304] Persisting metadata (8 bytes) = to leveldb took 524192ns I1110 01:20:11.499213 29725 replica.cpp:342] Persisted promised to 1 I1110 01:20:11.500258 29726 coordinator.cpp:238] Coordinator attempting to = fill missing positions I1110 01:20:11.501874 29731 replica.cpp:388] Replica received explicit prom= ise request from __req_res__(7321)@172.17.0.3:52462 for position 0 with pro= posal 2 I1110 01:20:11.502413 29731 leveldb.cpp:341] Persisting action (8 bytes) to= leveldb took 484138ns I1110 01:20:11.502457 29731 replica.cpp:708] Persisted action NOP at positi= on 0 I1110 01:20:11.503885 29720 replica.cpp:537] Replica received write request= for position 0 from __req_res__(7322)@172.17.0.3:52462 I1110 01:20:11.503985 29720 leveldb.cpp:436] Reading position from leveldb = took 56800ns I1110 01:20:11.504534 29720 leveldb.cpp:341] Persisting action (14 bytes) t= o leveldb took 467426ns I1110 01:20:11.504566 29720 replica.cpp:708] Persisted action NOP at positi= on 0 I1110 01:20:11.505470 29721 replica.cpp:691] Replica received learned notic= e for position 0 from @0.0.0.0:0 I1110 01:20:11.505988 29721 leveldb.cpp:341] Persisting action (16 bytes) t= o leveldb took 479078ns I1110 01:20:11.506021 29721 replica.cpp:708] Persisted action NOP at positi= on 0 I1110 01:20:11.506706 29732 log.cpp:569] Writer started with ending positio= n 0 I1110 01:20:11.508041 29734 leveldb.cpp:436] Reading position from leveldb = took 50010ns I1110 01:20:11.509210 29733 registrar.cpp:362] Successfully fetched the reg= istry (0B) in 13.068032ms I1110 01:20:11.509356 29733 registrar.cpp:461] Applied 1 operations in 2712= 4ns; attempting to update the registry I1110 01:20:11.510251 29732 log.cpp:577] Attempting to append 168 bytes to = the log I1110 01:20:11.510457 29724 coordinator.cpp:348] Coordinator attempting to = write APPEND action at position 1 I1110 01:20:11.511355 29728 replica.cpp:537] Replica received write request= for position 1 from __req_res__(7323)@172.17.0.3:52462 I1110 01:20:11.511828 29728 leveldb.cpp:341] Persisting action (187 bytes) = to leveldb took 423890ns I1110 01:20:11.511859 29728 replica.cpp:708] Persisted action APPEND at pos= ition 1 I1110 01:20:11.512572 29734 replica.cpp:691] Replica received learned notic= e for position 1 from @0.0.0.0:0 I1110 01:20:11.513051 29734 leveldb.cpp:341] Persisting action (189 bytes) = to leveldb took 368122ns I1110 01:20:11.513087 29734 replica.cpp:708] Persisted action APPEND at pos= ition 1 I1110 01:20:11.514302 29726 registrar.cpp:506] Successfully updated the reg= istry in 4.862976ms I1110 01:20:11.514503 29726 registrar.cpp:392] Successfully recovered regis= trar I1110 01:20:11.514593 29728 log.cpp:596] Attempting to truncate the log to = 1 I1110 01:20:11.514760 29730 coordinator.cpp:348] Coordinator attempting to = write TRUNCATE action at position 2 I1110 01:20:11.515249 29723 master.cpp:1676] Recovered 0 agents from the re= gistry (129B); allowing 10mins for agents to re-register I1110 01:20:11.515534 29722 hierarchical.cpp:176] Skipping recovery of hier= archical allocator: nothing to recover I1110 01:20:11.516068 29722 replica.cpp:537] Replica received write request= for position 2 from __req_res__(7324)@172.17.0.3:52462 I1110 01:20:11.516619 29722 leveldb.cpp:341] Persisting action (16 bytes) t= o leveldb took 497823ns I1110 01:20:11.516652 29722 replica.cpp:708] Persisted action TRUNCATE at p= osition 2 I1110 01:20:11.517526 29734 replica.cpp:691] Replica received learned notic= e for position 2 from @0.0.0.0:0 I1110 01:20:11.518040 29734 leveldb.cpp:341] Persisting action (18 bytes) t= o leveldb took 384129ns I1110 01:20:11.518111 29734 leveldb.cpp:399] Deleting ~1 keys from leveldb = took 39398ns I1110 01:20:11.518138 29734 replica.cpp:708] Persisted action TRUNCATE at p= osition 2 I1110 01:20:11.525027 29700 containerizer.cpp:201] Using isolation: posix/c= pu,posix/mem,filesystem/posix,network/cni W1110 01:20:11.525806 29700 backend.cpp:76] Failed to create 'aufs' backend= : AufsBackend requires root privileges, but is running as user mesos W1110 01:20:11.526018 29700 backend.cpp:76] Failed to create 'bind' backend= : BindBackend requires root privileges I1110 01:20:11.527331 29700 cluster.cpp:435] Creating default 'local' autho= rizer I1110 01:20:11.528741 29725 slave.cpp:208] Mesos agent started on (571)@172= .17.0.3:52462 I1110 01:20:11.528789 29725 slave.cpp:209] Flags at startup: --acls=3D"" --= appc_simple_discovery_uri_prefix=3D"http://" --appc_store_dir=3D"/tmp/mesos= /store/appc" --authenticate_http_readonly=3D"true" --authenticate_http_read= write=3D"false" --authenticatee=3D"crammd5" --authentication_backoff_factor= =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/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/credential" --d= efault_role=3D"*" --disk_watch_interval=3D"1mins" --docker=3D"docker" --doc= ker_kill_orphans=3D"true" --docker_registry=3D"https://registry-1.docker.io= " --docker_remove_delay=3D"6hrs" --docker_socket=3D"/var/run/docker.sock" -= -docker_stop_timeout=3D"0ns" --docker_store_dir=3D"/tmp/mesos/store/docker"= --docker_volume_checkpoint_dir=3D"/var/run/mesos/isolators/docker/volume" = --enforce_container_disk_quota=3D"false" --executor_registration_timeout=3D= "1mins" --executor_shutdown_grace_period=3D"5secs" --fetcher_cache_dir=3D"/= tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ/fetch" --fetch= er_cache_size=3D"2GB" --frameworks_home=3D"" --gc_delay=3D"1weeks" --gc_dis= k_headroom=3D"0.1" --hadoop_home=3D"" --help=3D"false" --hostname_lookup=3D= "true" --http_authenticators=3D"basic" --http_command_executor=3D"false" --= http_credentials=3D"/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_= wVf7JJ/http_credentials" --image_provisioner_backend=3D"copy" --initialize_= driver_logging=3D"true" --isolation=3D"posix/cpu,posix/mem" --launcher=3D"p= osix" --launcher_dir=3D"/mesos/mesos-1.2.0/_build/src" --logbufsecs=3D"0" -= -logging_level=3D"INFO" --max_completed_executors_per_framework=3D"150" --o= versubscribed_resources_interval=3D"15secs" --perf_duration=3D"10secs" --pe= rf_interval=3D"1mins" --qos_correction_interval_min=3D"0ns" --quiet=3D"fals= e" --recover=3D"reconnect" --recovery_timeout=3D"15mins" --registration_bac= koff_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/= MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf7JJ" --sandbox_directo= ry=3D"/mnt/mesos/sandbox" --strict=3D"true" --switch_user=3D"true" --system= d_enable_support=3D"true" --systemd_runtime_directory=3D"/run/systemd/syste= m" --version=3D"false" --work_dir=3D"/tmp/MesosContainerizer_DefaultExecuto= rTest_KillTask_0_8sXOVD" I1110 01:20:11.529228 29725 credentials.hpp:86] Loading credential for auth= entication from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf= 7JJ/credential' I1110 01:20:11.529305 29700 scheduler.cpp:176] Version: 1.2.0 I1110 01:20:11.529436 29725 slave.cpp:346] Agent using credential for: test= -principal I1110 01:20:11.529464 29725 credentials.hpp:37] Loading credentials for aut= hentication from '/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wV= f7JJ/http_credentials' I1110 01:20:11.529747 29725 http.cpp:895] Using default 'basic' HTTP authen= ticator for realm 'mesos-agent-readonly' I1110 01:20:11.529855 29729 scheduler.cpp:469] New master detected at maste= r@172.17.0.3:52462 I1110 01:20:11.529884 29729 scheduler.cpp:478] Waiting for 0ns before initi= ating a re-(connection) attempt with the master I1110 01:20:11.531039 29725 slave.cpp:533] Agent resources: cpus(*):2; mem(= *):1024; disk(*):1024; ports(*):[31000-32000] I1110 01:20:11.531113 29725 slave.cpp:541] Agent attributes: [ ] I1110 01:20:11.531126 29725 slave.cpp:546] Agent hostname: 3a31be8bf679 I1110 01:20:11.532897 29723 state.cpp:57] Recovering state from '/tmp/Mesos= Containerizer_DefaultExecutorTest_KillTask_0_8sXOVD/meta' I1110 01:20:11.533222 29727 status_update_manager.cpp:203] Recovering statu= s update manager I1110 01:20:11.533269 29721 scheduler.cpp:353] Connected with the master at= http://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.533627 29734 containerizer.cpp:557] Recovering containerizer I1110 01:20:11.534519 29725 scheduler.cpp:235] Sending SUBSCRIBE call to ht= tp://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.535482 29732 provisioner.cpp:253] Provisioner recovery compl= ete I1110 01:20:11.535652 29734 process.cpp:3570] Handling HTTP event for proce= ss 'master' with path: '/master/api/v1/scheduler' I1110 01:20:11.535815 29724 slave.cpp:5411] Finished recovery I1110 01:20:11.536440 29724 slave.cpp:5585] Querying resource estimator for= oversubscribable resources I1110 01:20:11.536898 29721 slave.cpp:915] New master detected at master@17= 2.17.0.3:52462 I1110 01:20:11.536906 29731 status_update_manager.cpp:177] Pausing sending = status updates I1110 01:20:11.536941 29721 slave.cpp:974] Authenticating with master maste= r@172.17.0.3:52462 I1110 01:20:11.537076 29721 slave.cpp:985] Using default CRAM-MD5 authentic= atee I1110 01:20:11.537214 29733 http.cpp:391] HTTP POST for /master/api/v1/sche= duler from 172.17.0.3:54635 I1110 01:20:11.537353 29719 authenticatee.cpp:121] Creating new client SASL= connection I1110 01:20:11.537256 29721 slave.cpp:947] Detecting new master I1110 01:20:11.537591 29733 master.cpp:2329] Received subscription request = for HTTP framework 'default' I1110 01:20:11.537611 29721 slave.cpp:5599] Received oversubscribable resou= rces {} from the resource estimator I1110 01:20:11.537701 29733 master.cpp:2069] Authorizing framework principa= l 'test-principal' to receive offers for role '*' I1110 01:20:11.538077 29733 master.cpp:6745] Authenticating slave(571)@172.= 17.0.3:52462 I1110 01:20:11.538208 29732 authenticator.cpp:414] Starting authentication = session for crammd5-authenticatee(1121)@172.17.0.3:52462 I1110 01:20:11.538291 29733 master.cpp:2427] Subscribing framework 'default= ' with checkpointing disabled and capabilities [ ] I1110 01:20:11.538508 29731 authenticator.cpp:98] Creating new server SASL = connection I1110 01:20:11.538782 29720 authenticatee.cpp:213] Received SASL authentica= tion mechanisms: CRAM-MD5 I1110 01:20:11.538823 29720 authenticatee.cpp:239] Attempting to authentica= te with mechanism 'CRAM-MD5' I1110 01:20:11.539227 29730 hierarchical.cpp:275] Added framework d28fbae1-= c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.539317 29722 master.hpp:2161] Sending heartbeat to d28fbae1-= c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.539331 29730 hierarchical.cpp:1694] No allocations performed I1110 01:20:11.539696 29730 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:11.539818 29730 hierarchical.cpp:1286] Performed allocation for= 0 agents in 554795ns I1110 01:20:11.540354 29720 authenticator.cpp:204] Received SASL authentica= tion start I1110 01:20:11.540361 29719 scheduler.cpp:675] Enqueuing event SUBSCRIBED r= eceived from http://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.540438 29720 authenticator.cpp:326] Authentication requires = more steps I1110 01:20:11.540750 29720 authenticatee.cpp:259] Received SASL authentica= tion step I1110 01:20:11.541038 29721 authenticator.cpp:232] Received SASL authentica= tion step I1110 01:20:11.541081 29721 auxprop.cpp:109] Request to lookup properties f= or user: 'test-principal' realm: '3a31be8bf679' server FQDN: '3a31be8bf679'= SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_= AUXPROP_AUTHZID: false=20 I1110 01:20:11.541112 29721 auxprop.cpp:181] Looking up auxiliary property = '*userPassword' I1110 01:20:11.541147 29719 scheduler.cpp:675] Enqueuing event HEARTBEAT re= ceived from http://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.541178 29721 auxprop.cpp:181] Looking up auxiliary property = '*cmusaslsecretCRAM-MD5' I1110 01:20:11.541260 29721 auxprop.cpp:109] Request to lookup properties f= or user: 'test-principal' realm: '3a31be8bf679' server FQDN: '3a31be8bf679'= SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_= AUXPROP_AUTHZID: true=20 I1110 01:20:11.541285 29721 auxprop.cpp:131] Skipping auxiliary property '*= userPassword' since SASL_AUXPROP_AUTHZID =3D=3D true I1110 01:20:11.541307 29721 auxprop.cpp:131] Skipping auxiliary property '*= cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID =3D=3D true I1110 01:20:11.541342 29721 authenticator.cpp:318] Authentication success I1110 01:20:11.541517 29733 authenticatee.cpp:299] Authentication success I1110 01:20:11.541586 29720 master.cpp:6775] Successfully authenticated pri= ncipal 'test-principal' at slave(571)@172.17.0.3:52462 I1110 01:20:11.541826 29721 authenticator.cpp:432] Authentication session c= leanup for crammd5-authenticatee(1121)@172.17.0.3:52462 I1110 01:20:11.542129 29730 slave.cpp:1069] Successfully authenticated with= master master@172.17.0.3:52462 I1110 01:20:11.542362 29730 slave.cpp:1483] Will retry registration in 9.53= 2818ms if necessary I1110 01:20:11.542577 29733 master.cpp:5154] Registering agent at slave(571= )@172.17.0.3:52462 (3a31be8bf679) with id d28fbae1-c3dc-45fa-8384-32ab9395a= 975-S0 I1110 01:20:11.543083 29731 registrar.cpp:461] Applied 1 operations in 6047= 6ns; attempting to update the registry I1110 01:20:11.543926 29729 log.cpp:577] Attempting to append 337 bytes to = the log I1110 01:20:11.544077 29723 coordinator.cpp:348] Coordinator attempting to = write APPEND action at position 3 I1110 01:20:11.545238 29731 replica.cpp:537] Replica received write request= for position 3 from __req_res__(7325)@172.17.0.3:52462 I1110 01:20:11.546116 29731 leveldb.cpp:341] Persisting action (356 bytes) = to leveldb took 825474ns I1110 01:20:11.546169 29731 replica.cpp:708] Persisted action APPEND at pos= ition 3 I1110 01:20:11.547427 29725 replica.cpp:691] Replica received learned notic= e for position 3 from @0.0.0.0:0 I1110 01:20:11.547969 29725 leveldb.cpp:341] Persisting action (358 bytes) = to leveldb took 483290ns I1110 01:20:11.548005 29725 replica.cpp:708] Persisted action APPEND at pos= ition 3 I1110 01:20:11.550129 29732 registrar.cpp:506] Successfully updated the reg= istry in 6.962944ms I1110 01:20:11.550396 29726 log.cpp:596] Attempting to truncate the log to = 3 I1110 01:20:11.550614 29720 coordinator.cpp:348] Coordinator attempting to = write TRUNCATE action at position 4 I1110 01:20:11.551375 29723 slave.cpp:4263] Received ping from slave-observ= er(531)@172.17.0.3:52462 I1110 01:20:11.551326 29734 master.cpp:5225] Registered agent d28fbae1-c3dc= -45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) wi= th cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1110 01:20:11.551720 29730 replica.cpp:537] Replica received write request= for position 4 from __req_res__(7326)@172.17.0.3:52462 I1110 01:20:11.551892 29723 slave.cpp:1115] Registered with master master@1= 72.17.0.3:52462; given agent ID d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 I1110 01:20:11.551975 29723 fetcher.cpp:86] Clearing fetcher cache I1110 01:20:11.552170 29732 hierarchical.cpp:485] Added agent d28fbae1-c3dc= -45fa-8384-32ab9395a975-S0 (3a31be8bf679) with cpus(*):2; mem(*):1024; disk= (*):1024; ports(*):[31000-32000] (allocated: {}) I1110 01:20:11.552338 29721 status_update_manager.cpp:184] Resuming sending= status updates I1110 01:20:11.552486 29730 leveldb.cpp:341] Persisting action (16 bytes) t= o leveldb took 709727ns I1110 01:20:11.552655 29723 slave.cpp:1138] Checkpointing SlaveInfo to '/tm= p/MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/meta/slaves/d28f= bae1-c3dc-45fa-8384-32ab9395a975-S0/slave.info' I1110 01:20:11.552609 29730 replica.cpp:708] Persisted action TRUNCATE at p= osition 4 I1110 01:20:11.553383 29731 replica.cpp:691] Replica received learned notic= e for position 4 from @0.0.0.0:0 I1110 01:20:11.553409 29723 slave.cpp:1175] Forwarding total oversubscribed= resources {} I1110 01:20:11.553653 29732 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:11.553671 29727 master.cpp:5624] Received update of agent d28fb= ae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8b= f679) with total oversubscribed resources {} I1110 01:20:11.553755 29732 hierarchical.cpp:1309] Performed allocation for= agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 in 1.528714ms I1110 01:20:11.553975 29731 leveldb.cpp:341] Persisting action (18 bytes) t= o leveldb took 525057ns I1110 01:20:11.554072 29731 leveldb.cpp:399] Deleting ~2 keys from leveldb = took 59750ns I1110 01:20:11.554065 29732 hierarchical.cpp:555] Agent d28fbae1-c3dc-45fa-= 8384-32ab9395a975-S0 (3a31be8bf679) updated with oversubscribed resources {= } (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], all= ocated: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) I1110 01:20:11.554105 29731 replica.cpp:708] Persisted action TRUNCATE at p= osition 4 I1110 01:20:11.554260 29732 hierarchical.cpp:1694] No allocations performed I1110 01:20:11.554314 29732 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:11.554345 29727 master.cpp:6574] Sending 1 offers to framework = d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) I1110 01:20:11.554379 29732 hierarchical.cpp:1309] Performed allocation for= agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 in 239597ns I1110 01:20:11.556370 29724 scheduler.cpp:675] Enqueuing event OFFERS recei= ved from http://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.559177 29730 scheduler.cpp:235] Sending ACCEPT call to http:= //172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.560282 29734 process.cpp:3570] Handling HTTP event for proce= ss 'master' with path: '/master/api/v1/scheduler' I1110 01:20:11.561323 29733 http.cpp:391] HTTP POST for /master/api/v1/sche= duler from 172.17.0.3:54634 I1110 01:20:11.562417 29733 master.cpp:3581] Processing ACCEPT call for off= ers: [ d28fbae1-c3dc-45fa-8384-32ab9395a975-O0 ] on agent d28fbae1-c3dc-45f= a-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) for fr= amework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) I1110 01:20:11.562584 29733 master.cpp:3173] Authorizing framework principa= l 'test-principal' to launch task c96eb523-0365-49b2-8b3b-78976ff28797 I1110 01:20:11.563097 29733 master.cpp:3173] Authorizing framework principa= l 'test-principal' to launch task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba I1110 01:20:11.567248 29733 master.cpp:8337] Adding task c96eb523-0365-49b2= -8b3b-78976ff28797 with resources cpus(*):0.1; mem(*):32; disk(*):32 on age= nt d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679) I1110 01:20:11.567651 29733 master.cpp:8337] Adding task 08848440-4c0e-4ad6= -a0a9-b5947c5d21ba with resources cpus(*):0.1; mem(*):32; disk(*):32 on age= nt d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 (3a31be8bf679) I1110 01:20:11.567845 29733 master.cpp:4438] Launching task group { 0884844= 0-4c0e-4ad6-a0a9-b5947c5d21ba, c96eb523-0365-49b2-8b3b-78976ff28797 } of fr= amework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) with resources = cpus(*):0.2; mem(*):64; disk(*):64 on agent d28fbae1-c3dc-45fa-8384-32ab939= 5a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) I1110 01:20:11.568495 29724 slave.cpp:1547] Got assigned task group contain= ing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b= 5947c5d21ba ] for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.569128 29729 hierarchical.cpp:1018] Recovered cpus(*):1.7; m= em(*):928; disk(*):928; ports(*):[31000-32000] (total: cpus(*):2; mem(*):10= 24; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*):0.3; mem(*):96= ; disk(*):96) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framewo= rk d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.569211 29729 hierarchical.cpp:1055] Framework d28fbae1-c3dc-= 45fa-8384-32ab9395a975-0000 filtered agent d28fbae1-c3dc-45fa-8384-32ab9395= a975-S0 for 5secs I1110 01:20:11.570461 29724 slave.cpp:1709] Launching task group containing= tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b594= 7c5d21ba ] for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.571297 29724 paths.cpp:530] Trying to chown '/tmp/MesosConta= inerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-83= 84-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/exe= cutors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06' to user 'mesos' I1110 01:20:11.580168 29724 slave.cpp:6319] Launching executor 'default' of= framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 with resources cpus(*)= :0.1; mem(*):32; disk(*):32 in work directory '/tmp/MesosContainerizer_Defa= ultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a9= 75-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/defaul= t/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06' I1110 01:20:11.580930 29734 containerizer.cpp:940] Starting container a2830= 35b-25d3-4b48-b59a-964e5a4dfa06 for executor 'default' of framework d28fbae= 1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.581110 29724 slave.cpp:2031] Queued task group containing ta= sks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0e-4ad6-a0a9-b5947c5= d21ba ] for executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab939= 5a975-0000 I1110 01:20:11.581214 29724 slave.cpp:868] Successfully attached file '/tmp= /MesosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c= 3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a9= 75-0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06' I1110 01:20:11.585572 29722 containerizer.cpp:1480] Launching 'mesos-contai= nerizer' with flags '--command=3D"{"arguments":["mesos-default-executor","-= -launcher_dir=3D\/mesos\/mesos-1.2.0\/_build\/src"],"shell":false,"value":"= \/mesos\/mesos-1.2.0\/_build\/src\/mesos-default-executor"}" --help=3D"fals= e" --pipe_read=3D"60" --pipe_write=3D"61" --pre_exec_commands=3D"[]" --runt= ime_directory=3D"/tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_wVf= 7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06" --unshare_namespace_mn= t=3D"false" --user=3D"mesos" --working_directory=3D"/tmp/MesosContainerizer= _DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9= 395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/d= efault/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06"' I1110 01:20:11.588587 29722 launcher.cpp:127] Forked child with pid '10191'= for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06' I1110 01:20:11.592996 29734 fetcher.cpp:345] Starting to fetch URIs for con= tainer: a283035b-25d3-4b48-b59a-964e5a4dfa06, directory: /tmp/MesosContaine= rizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-= 32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/execut= ors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06 I1110 01:20:11.777189 10229 executor.cpp:189] Version: 1.2.0 I1110 01:20:11.786099 29719 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1/executor' I1110 01:20:11.787382 29722 http.cpp:277] HTTP POST for /slave(571)/api/v1/= executor from 172.17.0.3:54638 I1110 01:20:11.787693 29722 slave.cpp:3086] Received Subscribe request for = HTTP executor 'default' of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0= 000 I1110 01:20:11.790436 29730 slave.cpp:2276] Sending queued task group task = group containing tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 08848440-4c0= e-4ad6-a0a9-b5947c5d21ba ] to executor 'default' of framework d28fbae1-c3dc= -45fa-8384-32ab9395a975-0000 (via HTTP) I1110 01:20:11.795663 10221 default_executor.cpp:130] Received SUBSCRIBED e= vent I1110 01:20:11.797111 10221 default_executor.cpp:134] Subscribed executor o= n 3a31be8bf679 I1110 01:20:11.797611 10221 default_executor.cpp:130] Received LAUNCH_GROUP= event I1110 01:20:11.801981 29729 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1' I1110 01:20:11.802435 29729 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1' I1110 01:20:11.803306 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 = from 172.17.0.3:54640 I1110 01:20:11.803452 29723 http.cpp:353] Processing call LAUNCH_NESTED_CON= TAINER I1110 01:20:11.803827 29727 containerizer.cpp:1685] Starting nested contain= er a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6= d I1110 01:20:11.803865 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 = from 172.17.0.3:54640 I1110 01:20:11.803978 29723 http.cpp:353] Processing call LAUNCH_NESTED_CON= TAINER I1110 01:20:11.804236 29727 containerizer.cpp:1709] Trying to chown '/tmp/M= esosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3d= c-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975= -0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/container= s/afdfa733-0ffd-4290-a69f-700b7d13cf6d' to user 'mesos' I1110 01:20:11.814858 29727 containerizer.cpp:1685] Starting nested contain= er a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b6661= 1 I1110 01:20:11.815129 29727 containerizer.cpp:1709] Trying to chown '/tmp/M= esosContainerizer_DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3d= c-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975= -0000/executors/default/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06/container= s/969c8095-ccfc-46d1-802d-4c55f0b66611' to user 'mesos' I1110 01:20:11.824666 29727 containerizer.cpp:1480] Launching 'mesos-contai= nerizer' with flags '--command=3D"{"shell":true,"value":"sleep 1000"}" --he= lp=3D"false" --pipe_read=3D"63" --pipe_write=3D"64" --pre_exec_commands=3D"= []" --runtime_directory=3D"/tmp/MesosContainerizer_DefaultExecutorTest_Kill= Task_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/af= dfa733-0ffd-4290-a69f-700b7d13cf6d" --unshare_namespace_mnt=3D"false" --use= r=3D"mesos" --working_directory=3D"/tmp/MesosContainerizer_DefaultExecutorT= est_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/framew= orks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a2830= 35b-25d3-4b48-b59a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13= cf6d"' I1110 01:20:11.826855 29727 launcher.cpp:127] Forked child with pid '10240'= for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69= f-700b7d13cf6d' I1110 01:20:11.828918 29727 containerizer.cpp:1480] Launching 'mesos-contai= nerizer' with flags '--command=3D"{"shell":true,"value":"sleep 1000"}" --he= lp=3D"false" --pipe_read=3D"65" --pipe_write=3D"66" --pre_exec_commands=3D"= []" --runtime_directory=3D"/tmp/MesosContainerizer_DefaultExecutorTest_Kill= Task_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964e5a4dfa06/containers/96= 9c8095-ccfc-46d1-802d-4c55f0b66611" --unshare_namespace_mnt=3D"false" --use= r=3D"mesos" --working_directory=3D"/tmp/MesosContainerizer_DefaultExecutorT= est_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/framew= orks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a2830= 35b-25d3-4b48-b59a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b6= 6611"' I1110 01:20:11.831428 29727 launcher.cpp:127] Forked child with pid '10241'= for container 'a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802= d-4c55f0b66611' I1110 01:20:11.834421 29731 fetcher.cpp:345] Starting to fetch URIs for con= tainer: a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d= 13cf6d, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8= sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3= dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b5= 9a-964e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d I1110 01:20:11.837882 29731 fetcher.cpp:345] Starting to fetch URIs for con= tainer: a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0= b66611, directory: /tmp/MesosContainerizer_DefaultExecutorTest_KillTask_0_8= sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab9395a975-S0/frameworks/d28fbae1-c3= dc-45fa-8384-32ab9395a975-0000/executors/default/runs/a283035b-25d3-4b48-b5= 9a-964e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611 I1110 01:20:11.847651 10227 default_executor.cpp:470] Successfully launched= child containers [ a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290= -a69f-700b7d13cf6d, a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1= -802d-4c55f0b66611 ] for tasks [ c96eb523-0365-49b2-8b3b-78976ff28797, 0884= 8440-4c0e-4ad6-a0a9-b5947c5d21ba ] I1110 01:20:11.849225 29728 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1/executor' I1110 01:20:11.850085 10226 default_executor.cpp:546] Waiting for child con= tainer a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d1= 3cf6d of task 'c96eb523-0365-49b2-8b3b-78976ff28797' I1110 01:20:11.850145 29734 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1/executor' I1110 01:20:11.850405 10226 default_executor.cpp:546] Waiting for child con= tainer a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b= 66611 of task '08848440-4c0e-4ad6-a0a9-b5947c5d21ba' I1110 01:20:11.850746 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1/= executor from 172.17.0.3:54639 I1110 01:20:11.851114 29726 slave.cpp:3740] Handling status update TASK_RUN= NING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49= b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.851552 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1/= executor from 172.17.0.3:54639 I1110 01:20:11.851727 29726 slave.cpp:3740] Handling status update TASK_RUN= NING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4a= d6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.852295 29726 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1' I1110 01:20:11.852826 29726 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1' I1110 01:20:11.853938 29724 status_update_manager.cpp:323] Received status = update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 0= 8848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32= ab9395a975-0000 I1110 01:20:11.854076 29724 status_update_manager.cpp:500] Creating StatusU= pdate stream for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28= fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.854460 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1 = from 172.17.0.3:54641 I1110 01:20:11.854559 29726 http.cpp:353] Processing call WAIT_NESTED_CONTA= INER I1110 01:20:11.854610 29724 status_update_manager.cpp:377] Forwarding updat= e TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 088484= 40-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab939= 5a975-0000 to the agent I1110 01:20:11.855126 29724 status_update_manager.cpp:323] Received status = update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c= 96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32= ab9395a975-0000 I1110 01:20:11.855190 29724 status_update_manager.cpp:500] Creating StatusU= pdate stream for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28= fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.855200 29726 http.cpp:277] HTTP POST for /slave(571)/api/v1 = from 172.17.0.3:54642 I1110 01:20:11.855409 29726 http.cpp:353] Processing call WAIT_NESTED_CONTA= INER I1110 01:20:11.855608 29724 status_update_manager.cpp:377] Forwarding updat= e TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb5= 23-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab939= 5a975-0000 to the agent I1110 01:20:11.855803 29726 slave.cpp:4181] Forwarding the update TASK_RUNN= ING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad= 6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 = to master@172.17.0.3:52462 I1110 01:20:11.856199 29726 slave.cpp:4075] Status update manager successfu= lly handled status update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c9= 5fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae= 1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.856346 29725 master.cpp:5760] Status update TASK_RUNNING (UU= ID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-= b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from ag= ent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 = (3a31be8bf679) I1110 01:20:11.856439 29725 master.cpp:5822] Forwarding status update TASK_= RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e= -4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0= 000 I1110 01:20:11.856598 29726 slave.cpp:4181] Forwarding the update TASK_RUNN= ING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b= 2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 = to master@172.17.0.3:52462 I1110 01:20:11.856828 29726 slave.cpp:4075] Status update manager successfu= lly handled status update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a= 256e8d2) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae= 1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.856998 29725 master.cpp:7715] Updating the state of task 088= 48440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab= 9395a975-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNIN= G) I1110 01:20:11.857322 29725 master.cpp:5760] Status update TASK_RUNNING (UU= ID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-= 78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from ag= ent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 = (3a31be8bf679) I1110 01:20:11.857386 29725 master.cpp:5822] Forwarding status update TASK_= RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365= -49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0= 000 I1110 01:20:11.857787 29725 master.cpp:7715] Updating the state of task c96= eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab= 9395a975-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNIN= G) I1110 01:20:11.858124 10226 default_executor.cpp:130] Received ACKNOWLEDGED= event I1110 01:20:11.858530 29725 scheduler.cpp:675] Enqueuing event UPDATE recei= ved from http://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.859519 29732 scheduler.cpp:675] Enqueuing event UPDATE recei= ved from http://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.859676 10233 default_executor.cpp:130] Received ACKNOWLEDGED= event ../../src/tests/default_executor_tests.cpp:338: Failure Value of: runningUpdate1->status().task_id() Actual: 08848440-4c0e-4ad6-a0a9-b5947c5d21ba Expected: taskInfo1.task_id() Which is: c96eb523-0365-49b2-8b3b-78976ff28797 ../../src/tests/default_executor_tests.cpp:342: Failure Value of: runningUpdate2->status().task_id() Actual: c96eb523-0365-49b2-8b3b-78976ff28797 Expected: taskInfo2.task_id() Which is: 08848440-4c0e-4ad6-a0a9-b5947c5d21ba I1110 01:20:11.861587 29733 scheduler.cpp:235] Sending ACKNOWLEDGE call to = http://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.861948 29733 scheduler.cpp:235] Sending ACKNOWLEDGE call to = http://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.862280 29733 scheduler.cpp:235] Sending KILL call to http://= 172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:11.862632 29721 process.cpp:3570] Handling HTTP event for proce= ss 'master' with path: '/master/api/v1/scheduler' I1110 01:20:11.863528 29719 http.cpp:391] HTTP POST for /master/api/v1/sche= duler from 172.17.0.3:54634 I1110 01:20:11.863664 29719 master.cpp:4870] Processing ACKNOWLEDGE call 3b= 6a6ffd-d27d-4558-820e-fb9c95fa9f87 for task c96eb523-0365-49b2-8b3b-78976ff= 28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) on a= gent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 I1110 01:20:11.864003 29732 status_update_manager.cpp:395] Received status = update acknowledgement (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for tas= k c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384= -32ab9395a975-0000 W1110 01:20:11.864294 29732 status_update_manager.cpp:769] Unexpected statu= s update acknowledgement (received 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87, ex= pecting d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for update TASK_RUNNING (UUID= : d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-78= 976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 E1110 01:20:11.864575 29726 slave.cpp:3015] Failed to handle status update = acknowledgement (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task c96eb= 523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab93= 95a975-0000: Duplicate acknowledgement I1110 01:20:11.864804 29723 process.cpp:3570] Handling HTTP event for proce= ss 'master' with path: '/master/api/v1/scheduler' I1110 01:20:11.865231 29723 process.cpp:3570] Handling HTTP event for proce= ss 'master' with path: '/master/api/v1/scheduler' I1110 01:20:11.866297 29722 http.cpp:391] HTTP POST for /master/api/v1/sche= duler from 172.17.0.3:54634 I1110 01:20:11.866420 29722 master.cpp:4870] Processing ACKNOWLEDGE call d9= 1c7deb-4646-4b4e-ba1a-5650a256e8d2 for task 08848440-4c0e-4ad6-a0a9-b5947c5= d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) on a= gent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 I1110 01:20:11.867036 29726 status_update_manager.cpp:395] Received status = update acknowledgement (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for tas= k 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384= -32ab9395a975-0000 I1110 01:20:11.867076 29722 http.cpp:391] HTTP POST for /master/api/v1/sche= duler from 172.17.0.3:54634 I1110 01:20:11.867291 29722 master.cpp:4762] Telling agent d28fbae1-c3dc-45= fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) to ki= ll task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45f= a-8384-32ab9395a975-0000 (default) W1110 01:20:11.867297 29726 status_update_manager.cpp:769] Unexpected statu= s update acknowledgement (received d91c7deb-4646-4b4e-ba1a-5650a256e8d2, ex= pecting 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for update TASK_RUNNING (UUID= : 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-b5= 947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.867449 29733 slave.cpp:2344] Asked to kill task c96eb523-036= 5-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-= 0000 E1110 01:20:11.867710 29733 slave.cpp:3015] Failed to handle status update = acknowledgement (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task 08848= 440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab93= 95a975-0000: Duplicate acknowledgement I1110 01:20:11.869391 10228 default_executor.cpp:130] Received KILL event I1110 01:20:11.869498 10228 default_executor.cpp:810] Received kill for tas= k 'c96eb523-0365-49b2-8b3b-78976ff28797' I1110 01:20:11.869544 10228 default_executor.cpp:694] Shutting down I1110 01:20:11.870112 10221 default_executor.cpp:782] Killing child contain= er a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6= d I1110 01:20:11.870338 10221 default_executor.cpp:782] Killing child contain= er a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b6661= 1 I1110 01:20:11.870965 29729 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1' I1110 01:20:11.871399 29730 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1' I1110 01:20:11.871984 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 = from 172.17.0.3:54643 I1110 01:20:11.872088 29723 http.cpp:353] Processing call KILL_NESTED_CONTA= INER I1110 01:20:11.872284 29726 containerizer.cpp:1973] Destroying container a2= 83035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d in = RUNNING state I1110 01:20:11.872340 29723 http.cpp:277] HTTP POST for /slave(571)/api/v1 = from 172.17.0.3:54643 I1110 01:20:11.872416 29723 http.cpp:353] Processing call KILL_NESTED_CONTA= INER I1110 01:20:11.872597 29726 launcher.cpp:143] Asked to destroy container a2= 83035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d I1110 01:20:11.877090 29726 containerizer.cpp:1973] Destroying container a2= 83035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 in = RUNNING state I1110 01:20:11.877320 29726 launcher.cpp:143] Asked to destroy container a2= 83035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 I1110 01:20:11.962539 29729 containerizer.cpp:2336] Container a283035b-25d3= -4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-a69f-700b7d13cf6d has exited I1110 01:20:11.963811 29733 provisioner.cpp:324] Ignoring destroy request f= or unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-429= 0-a69f-700b7d13cf6d I1110 01:20:11.963851 29729 containerizer.cpp:2336] Container a283035b-25d3= -4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-802d-4c55f0b66611 has exited I1110 01:20:11.964437 29729 containerizer.cpp:2252] Checkpointing terminati= on state to nested container's runtime directory '/tmp/MesosContainerizer_D= efaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964= e5a4dfa06/containers/afdfa733-0ffd-4290-a69f-700b7d13cf6d/termination' I1110 01:20:11.965940 29728 provisioner.cpp:324] Ignoring destroy request f= or unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d= 1-802d-4c55f0b66611 I1110 01:20:11.966202 29732 containerizer.cpp:2252] Checkpointing terminati= on state to nested container's runtime directory '/tmp/MesosContainerizer_D= efaultExecutorTest_KillTask_0_wVf7JJ/containers/a283035b-25d3-4b48-b59a-964= e5a4dfa06/containers/969c8095-ccfc-46d1-802d-4c55f0b66611/termination' I1110 01:20:11.970046 10231 default_executor.cpp:663] Successfully waited f= or child container a283035b-25d3-4b48-b59a-964e5a4dfa06.afdfa733-0ffd-4290-= a69f-700b7d13cf6d of task 'c96eb523-0365-49b2-8b3b-78976ff28797' in state T= ASK_KILLED I1110 01:20:11.970501 10231 default_executor.cpp:663] Successfully waited f= or child container a283035b-25d3-4b48-b59a-964e5a4dfa06.969c8095-ccfc-46d1-= 802d-4c55f0b66611 of task '08848440-4c0e-4ad6-a0a9-b5947c5d21ba' in state T= ASK_KILLED I1110 01:20:11.970559 10231 default_executor.cpp:768] Terminating after 1se= cs I1110 01:20:11.971288 29723 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1/executor' I1110 01:20:11.972218 29728 http.cpp:277] HTTP POST for /slave(571)/api/v1/= executor from 172.17.0.3:54639 I1110 01:20:11.972488 29728 slave.cpp:3740] Handling status update TASK_KIL= LED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c96eb523-0365-49b= 2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.974179 29719 process.cpp:3570] Handling HTTP event for proce= ss 'slave(571)' with path: '/slave(571)/api/v1/executor' I1110 01:20:11.975229 29726 status_update_manager.cpp:323] Received status = update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b1048fc89) for task c9= 6eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32a= b9395a975-0000 I1110 01:20:11.975278 29729 http.cpp:277] HTTP POST for /slave(571)/api/v1/= executor from 172.17.0.3:54639 I1110 01:20:11.975517 29729 slave.cpp:3740] Handling status update TASK_KIL= LED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08848440-4c0e-4ad= 6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.976048 29729 slave.cpp:4075] Status update manager successfu= lly handled status update TASK_KILLED (UUID: 48f76bc6-3855-40fc-b22b-e26b10= 48fc89) for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1= -c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:11.978132 29720 status_update_manager.cpp:323] Received status = update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbafde1029) for task 08= 848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32a= b9395a975-0000 I1110 01:20:11.978482 29725 slave.cpp:4075] Status update manager successfu= lly handled status update TASK_KILLED (UUID: a3be1364-0830-4dd3-8be5-2bbbaf= de1029) for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1= -c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:12.494274 29725 hierarchical.cpp:1880] Filtered offer with cpus= (*):1.7; mem(*):928; disk(*):928; ports(*):[31000-32000] on agent d28fbae1-= c3dc-45fa-8384-32ab9395a975-S0 for framework d28fbae1-c3dc-45fa-8384-32ab93= 95a975-0000 I1110 01:20:12.494357 29725 hierarchical.cpp:1694] No allocations performed I1110 01:20:12.494402 29725 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:12.494491 29725 hierarchical.cpp:1286] Performed allocation for= 1 agents in 915780ns I1110 01:20:13.071280 29734 containerizer.cpp:2336] Container a283035b-25d3= -4b48-b59a-964e5a4dfa06 has exited I1110 01:20:13.071339 29734 containerizer.cpp:1973] Destroying container a2= 83035b-25d3-4b48-b59a-964e5a4dfa06 in RUNNING state I1110 01:20:13.071746 29734 launcher.cpp:143] Asked to destroy container a2= 83035b-25d3-4b48-b59a-964e5a4dfa06 I1110 01:20:13.076637 29723 provisioner.cpp:324] Ignoring destroy request f= or unknown container a283035b-25d3-4b48-b59a-964e5a4dfa06 I1110 01:20:13.077929 29721 slave.cpp:4672] Executor 'default' of framework= d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 exited with status 0 I1110 01:20:13.078433 29732 master.cpp:5884] Executor 'default' of framewor= k d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-838= 4-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679): exited wit= h status 0 I1110 01:20:13.078538 29732 master.cpp:7840] Removing executor 'default' wi= th resources cpus(*):0.1; mem(*):32; disk(*):32 of framework d28fbae1-c3dc-= 45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S= 0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) I1110 01:20:13.079448 29730 hierarchical.cpp:1018] Recovered cpus(*):0.1; m= em(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*)= :[31000-32000], allocated: cpus(*):0.2; mem(*):64; disk(*):64) on agent d28= fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384= -32ab9395a975-0000 I1110 01:20:13.081049 29723 scheduler.cpp:675] Enqueuing event FAILURE rece= ived from http://172.17.0.3:52462/master/api/v1/scheduler GMOCK WARNING: Uninteresting mock function call - returning directly. Function call: failure(0x7fff1aa9a950, @0x2ab91c02dd10 48-byte object <= 90-62 27-EC B8-2A 00-00 00-00 00-00 00-00 00-00 07-00 00-00 00-00 00-00 10-= CE 01-1C B9-2A 00-00 70-CE 02-1C B9-2A 00-00 00-00 00-00 B8-2A 00-00>) Stack trace: I1110 01:20:13.496551 29730 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:13.496680 29730 hierarchical.cpp:1286] Performed allocation for= 1 agents in 1.498625ms I1110 01:20:13.497339 29729 master.cpp:6574] Sending 1 offers to framework = d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) I1110 01:20:13.499797 29721 scheduler.cpp:675] Enqueuing event OFFERS recei= ved from http://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:14.497707 29732 hierarchical.cpp:1694] No allocations performed I1110 01:20:14.497795 29732 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:14.497895 29732 hierarchical.cpp:1286] Performed allocation for= 1 agents in 410313ns I1110 01:20:15.499423 29728 hierarchical.cpp:1694] No allocations performed I1110 01:20:15.499526 29728 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:15.499658 29728 hierarchical.cpp:1286] Performed allocation for= 1 agents in 547651ns I1110 01:20:16.500463 29729 hierarchical.cpp:1694] No allocations performed I1110 01:20:16.500581 29729 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:16.500699 29729 hierarchical.cpp:1286] Performed allocation for= 1 agents in 505442ns I1110 01:20:17.502176 29727 hierarchical.cpp:1694] No allocations performed I1110 01:20:17.502262 29727 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:17.502367 29727 hierarchical.cpp:1286] Performed allocation for= 1 agents in 464526ns I1110 01:20:18.503680 29723 hierarchical.cpp:1694] No allocations performed I1110 01:20:18.503762 29723 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:18.503851 29723 hierarchical.cpp:1286] Performed allocation for= 1 agents in 425163ns I1110 01:20:19.505476 29723 hierarchical.cpp:1694] No allocations performed I1110 01:20:19.505586 29723 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:19.505705 29723 hierarchical.cpp:1286] Performed allocation for= 1 agents in 590762ns I1110 01:20:20.507310 29724 hierarchical.cpp:1694] No allocations performed I1110 01:20:20.507390 29724 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:20.507477 29724 hierarchical.cpp:1286] Performed allocation for= 1 agents in 411721ns I1110 01:20:21.508368 29729 hierarchical.cpp:1694] No allocations performed I1110 01:20:21.508458 29729 hierarchical.cpp:1789] No inverse offers to sen= d out! I1110 01:20:21.508564 29729 hierarchical.cpp:1286] Performed allocation for= 1 agents in 432440ns W1110 01:20:21.855908 29728 status_update_manager.cpp:478] Resending status= update TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task = 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-3= 2ab9395a975-0000 I1110 01:20:21.856066 29728 status_update_manager.cpp:377] Forwarding updat= e TASK_RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 088484= 40-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab939= 5a975-0000 to the agent I1110 01:20:21.856652 29734 slave.cpp:4181] Forwarding the update TASK_RUNN= ING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad= 6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 = to master@172.17.0.3:52462 W1110 01:20:21.857002 29727 status_update_manager.cpp:478] Resending status= update TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task = c96eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-3= 2ab9395a975-0000 I1110 01:20:21.857069 29727 status_update_manager.cpp:377] Forwarding updat= e TASK_RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb5= 23-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab939= 5a975-0000 to the agent I1110 01:20:21.857378 29733 master.cpp:5760] Status update TASK_RUNNING (UU= ID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e-4ad6-a0a9-= b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from ag= ent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 = (3a31be8bf679) I1110 01:20:21.857475 29733 master.cpp:5822] Forwarding status update TASK_= RUNNING (UUID: 3b6a6ffd-d27d-4558-820e-fb9c95fa9f87) for task 08848440-4c0e= -4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0= 000 I1110 01:20:21.857662 29722 slave.cpp:4181] Forwarding the update TASK_RUNN= ING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b= 2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 = to master@172.17.0.3:52462 I1110 01:20:21.858206 29733 master.cpp:7715] Updating the state of task 088= 48440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab= 9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_RUNNING= ) I1110 01:20:21.858988 29733 master.cpp:5760] Status update TASK_RUNNING (UU= ID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365-49b2-8b3b-= 78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 from ag= ent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 = (3a31be8bf679) I1110 01:20:21.859259 29733 master.cpp:5822] Forwarding status update TASK_= RUNNING (UUID: d91c7deb-4646-4b4e-ba1a-5650a256e8d2) for task c96eb523-0365= -49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0= 000 I1110 01:20:21.859647 29725 hierarchical.cpp:1018] Recovered cpus(*):0.1; m= em(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*)= :[31000-32000], allocated: cpus(*):1.9; mem(*):992; disk(*):992; ports(*):[= 31000-32000]) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framewo= rk d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:21.859845 29725 scheduler.cpp:675] Enqueuing event UPDATE recei= ved from http://172.17.0.3:52462/master/api/v1/scheduler I1110 01:20:21.859979 29733 master.cpp:7715] Updating the state of task c96= eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab= 9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_RUNNING= ) I1110 01:20:21.860970 29729 hierarchical.cpp:1018] Recovered cpus(*):0.1; m= em(*):32; disk(*):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*)= :[31000-32000], allocated: cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[= 31000-32000]) on agent d28fbae1-c3dc-45fa-8384-32ab9395a975-S0 from framewo= rk d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:21.861687 29725 scheduler.cpp:675] Enqueuing event UPDATE recei= ved from http://172.17.0.3:52462/master/api/v1/scheduler ../../src/tests/default_executor_tests.cpp:400: Failure Value of: killedUpdate1->status().state() Actual: TASK_RUNNING Expected: TASK_KILLED I1110 01:20:21.864666 29721 master.cpp:1297] Framework d28fbae1-c3dc-45fa-8= 384-32ab9395a975-0000 (default) disconnected I1110 01:20:21.864765 29721 master.cpp:2918] Disconnecting framework d28fba= e1-c3dc-45fa-8384-32ab9395a975-0000 (default) I1110 01:20:21.864820 29721 master.cpp:2942] Deactivating framework d28fbae= 1-c3dc-45fa-8384-32ab9395a975-0000 (default) I1110 01:20:21.865016 29732 hierarchical.cpp:386] Deactivated framework d28= fbae1-c3dc-45fa-8384-32ab9395a975-0000 W1110 01:20:21.865586 29721 master.hpp:2264] Master attempted to send messa= ge to disconnected framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (def= ault) W1110 01:20:21.865691 29721 master.hpp:2270] Unable to send event to framew= ork d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default): connection closed I1110 01:20:21.865777 29721 master.cpp:1310] Giving framework d28fbae1-c3dc= -45fa-8384-32ab9395a975-0000 (default) 0ns to failover I1110 01:20:21.866277 29728 hierarchical.cpp:1018] Recovered cpus(*):1.8; m= em(*):960; disk(*):960; ports(*):[31000-32000] (total: cpus(*):2; mem(*):10= 24; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent d28fbae1-= c3dc-45fa-8384-32ab9395a975-S0 from framework d28fbae1-c3dc-45fa-8384-32ab9= 395a975-0000 I1110 01:20:21.867295 29733 master.cpp:6426] Framework failover timeout, re= moving framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (default) I1110 01:20:21.867328 29733 master.cpp:7170] Removing framework d28fbae1-c3= dc-45fa-8384-32ab9395a975-0000 (default) I1110 01:20:21.867539 29733 master.cpp:7715] Updating the state of task 088= 48440-4c0e-4ad6-a0a9-b5947c5d21ba of framework d28fbae1-c3dc-45fa-8384-32ab= 9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED) I1110 01:20:21.867559 29731 slave.cpp:2575] Asked to shut down framework d2= 8fbae1-c3dc-45fa-8384-32ab9395a975-0000 by master@172.17.0.3:52462 I1110 01:20:21.867617 29731 slave.cpp:2600] Shutting down framework d28fbae= 1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:21.867585 29733 master.cpp:7811] Removing task 08848440-4c0e-4a= d6-a0a9-b5947c5d21ba with resources cpus(*):0.1; mem(*):32; disk(*):32 of f= ramework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-4= 5fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) I1110 01:20:21.867707 29731 slave.cpp:4776] Cleaning up executor 'default' = of framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 (via HTTP) I1110 01:20:21.867904 29733 master.cpp:7715] Updating the state of task c96= eb523-0365-49b2-8b3b-78976ff28797 of framework d28fbae1-c3dc-45fa-8384-32ab= 9395a975-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED) I1110 01:20:21.868042 29729 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_= DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab93= 95a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/de= fault/runs/a283035b-25d3-4b48-b59a-964e5a4dfa06' for gc 6.99998999732444day= s in the future I1110 01:20:21.867939 29733 master.cpp:7811] Removing task c96eb523-0365-49= b2-8b3b-78976ff28797 with resources cpus(*):0.1; mem(*):32; disk(*):32 of f= ramework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 on agent d28fbae1-c3dc-4= 5fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) I1110 01:20:21.868232 29731 slave.cpp:4864] Cleaning up framework d28fbae1-= c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:21.868252 29729 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_= DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab93= 95a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000/executors/de= fault' for gc 6.99998999732444days in the future I1110 01:20:21.868422 29725 status_update_manager.cpp:285] Closing status u= pdate streams for framework d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:21.868484 29725 status_update_manager.cpp:531] Cleaning up stat= us update stream for task c96eb523-0365-49b2-8b3b-78976ff28797 of framework= d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:21.868777 29721 gc.cpp:55] Scheduling '/tmp/MesosContainerizer_= DefaultExecutorTest_KillTask_0_8sXOVD/slaves/d28fbae1-c3dc-45fa-8384-32ab93= 95a975-S0/frameworks/d28fbae1-c3dc-45fa-8384-32ab9395a975-0000' for gc 6.99= 998999732444days in the future I1110 01:20:21.868926 29720 hierarchical.cpp:337] Removed framework d28fbae= 1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:21.869235 29725 status_update_manager.cpp:531] Cleaning up stat= us update stream for task 08848440-4c0e-4ad6-a0a9-b5947c5d21ba of framework= d28fbae1-c3dc-45fa-8384-32ab9395a975-0000 I1110 01:20:21.870568 29730 slave.cpp:787] Agent terminating I1110 01:20:21.870795 29732 master.cpp:1258] Agent d28fbae1-c3dc-45fa-8384-= 32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) disconnected I1110 01:20:21.870825 29732 master.cpp:2977] Disconnecting agent d28fbae1-c= 3dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) I1110 01:20:21.870930 29732 master.cpp:2996] Deactivating agent d28fbae1-c3= dc-45fa-8384-32ab9395a975-S0 at slave(571)@172.17.0.3:52462 (3a31be8bf679) I1110 01:20:21.871158 29726 hierarchical.cpp:584] Agent d28fbae1-c3dc-45fa-= 8384-32ab9395a975-S0 deactivated I1110 01:20:21.876986 29733 master.cpp:1097] Master terminating I1110 01:20:21.877754 29724 hierarchical.cpp:517] Removed agent d28fbae1-c3= dc-45fa-8384-32ab9395a975-S0 [ FAILED ] MesosContainerizer/DefaultExecutorTest.KillTask/0, where GetPa= ram() =3D "mesos" (10406 ms) {noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332)