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 EDB7A200C7D for ; Tue, 16 May 2017 20:22:10 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id EC47D160BC9; Tue, 16 May 2017 18:22:10 +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 BBD46160BA6 for ; Tue, 16 May 2017 20:22:09 +0200 (CEST) Received: (qmail 22313 invoked by uid 500); 16 May 2017 18:22:09 -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 22303 invoked by uid 99); 16 May 2017 18:22:08 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd1-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 16 May 2017 18:22:08 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd1-us-west.apache.org (ASF Mail Server at spamd1-us-west.apache.org) with ESMTP id 8BEBBC6A96 for ; Tue, 16 May 2017 18:22:08 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd1-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -100.001 X-Spam-Level: X-Spam-Status: No, score=-100.001 tagged_above=-999 required=6.31 tests=[NORMAL_HTTP_TO_IP=0.001, RP_MATCHES_RCVD=-0.001, SPF_PASS=-0.001, USER_IN_WHITELIST=-100] autolearn=disabled Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd1-us-west.apache.org [10.40.0.7]) (amavisd-new, port 10024) with ESMTP id NEpK3XXs8WLh for ; Tue, 16 May 2017 18:22:06 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTP id BFE535FC16 for ; Tue, 16 May 2017 18:22:05 +0000 (UTC) Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id E687EE0B4A for ; Tue, 16 May 2017 18:22:04 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id 679EE21942 for ; Tue, 16 May 2017 18:22:04 +0000 (UTC) Date: Tue, 16 May 2017 18:22:04 +0000 (UTC) From: "Neil Conway (JIRA)" To: issues@mesos.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (MESOS-4095) Flaky test: MasterAllocatorTest/1.FrameworkExited MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Tue, 16 May 2017 18:22:11 -0000 [ https://issues.apache.org/jira/browse/MESOS-4095?page=3Dcom.atlassian= .jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=3D1601= 2855#comment-16012855 ]=20 Neil Conway commented on MESOS-4095: ------------------------------------ Another verbose test log, with current code and on a different box: {noformat} [ RUN ] MasterAllocatorTest/1.FrameworkExited I0516 11:20:45.899612 27146 cluster.cpp:162] Creating default 'local' autho= rizer I0516 11:20:45.906642 27166 master.cpp:436] Master 0526e771-e1a3-4bd0-830e-= 6084ff4bc552 (core-dev) started on 10.0.49.2:40918 I0516 11:20:45.906697 27166 master.cpp:438] Flags at startup: --acls=3D"" -= -agent_ping_timeout=3D"15secs" --agent_reregister_timeout=3D"10mins" --allo= cation_interval=3D"50ms" --allocator=3D"HierarchicalDRF" --authenticate_age= nts=3D"true" --authenticate_frameworks=3D"true" --authenticate_http_framewo= rks=3D"true" --authenticate_http_readonly=3D"true" --authenticate_http_read= write=3D"true" --authenticators=3D"crammd5" --authorizers=3D"local" --crede= ntials=3D"/tmp/CnBelc/credentials" --framework_sorter=3D"drf" --help=3D"fal= se" --hostname_lookup=3D"true" --http_authenticators=3D"basic" --http_frame= work_authenticators=3D"basic" --initialize_driver_logging=3D"true" --log_au= to_initialize=3D"true" --logbufsecs=3D"0" --logging_level=3D"INFO" --max_ag= ent_ping_timeouts=3D"5" --max_completed_frameworks=3D"50" --max_completed_t= asks_per_framework=3D"1000" --max_unreachable_tasks_per_framework=3D"1000" = --port=3D"5050" --quiet=3D"false" --recovery_agent_removal_limit=3D"100%" -= -registry=3D"in_memory" --registry_fetch_timeout=3D"1mins" --registry_gc_in= terval=3D"15mins" --registry_max_agent_age=3D"2weeks" --registry_max_agent_= count=3D"102400" --registry_store_timeout=3D"100secs" --registry_strict=3D"= false" --root_submissions=3D"true" --user_sorter=3D"drf" --version=3D"false= " --webui_dir=3D"/usr/local/share/mesos/webui" --work_dir=3D"/tmp/CnBelc/ma= ster" --zk_session_timeout=3D"10secs" I0516 11:20:45.906927 27166 master.cpp:488] Master only allowing authentica= ted frameworks to register I0516 11:20:45.906965 27166 master.cpp:502] Master only allowing authentica= ted agents to register I0516 11:20:45.906991 27166 master.cpp:515] Master only allowing authentica= ted HTTP frameworks to register I0516 11:20:45.907013 27166 credentials.hpp:37] Loading credentials for aut= hentication from '/tmp/CnBelc/credentials' I0516 11:20:45.907254 27166 master.cpp:560] Using default 'crammd5' authent= icator I0516 11:20:45.907379 27166 http.cpp:975] Creating default 'basic' HTTP aut= henticator for realm 'mesos-master-readonly' I0516 11:20:45.907744 27166 http.cpp:975] Creating default 'basic' HTTP aut= henticator for realm 'mesos-master-readwrite' I0516 11:20:45.908084 27166 http.cpp:975] Creating default 'basic' HTTP aut= henticator for realm 'mesos-master-scheduler' I0516 11:20:45.908445 27166 master.cpp:640] Authorization enabled I0516 11:20:45.910624 27187 master.cpp:2161] Elected as the leading master! I0516 11:20:45.910661 27187 master.cpp:1700] Recovering from registrar I0516 11:20:45.913770 27179 registrar.cpp:389] Successfully fetched the reg= istry (0B) in 2.981888ms I0516 11:20:45.913894 27179 registrar.cpp:493] Applied 1 operations in 1604= 7ns; attempting to update the registry I0516 11:20:45.914415 27179 registrar.cpp:550] Successfully updated the reg= istry in 454912ns I0516 11:20:45.914546 27179 registrar.cpp:422] Successfully recovered regis= trar I0516 11:20:45.915236 27207 master.cpp:1799] Recovered 0 agents from the re= gistry (119B); allowing 10mins for agents to re-register I0516 11:20:45.923874 27146 cluster.cpp:448] Creating default 'local' autho= rizer I0516 11:20:45.924935 27182 slave.cpp:225] Mesos agent started on (3)@10.0.= 49.2:40918 I0516 11:20:45.924971 27182 slave.cpp:226] 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"true" --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/MasterAllocatorTest_1_FrameworkExited_cMdy3f/credential" --default_role= =3D"*" --disk_watch_interval=3D"1mins" --docker=3D"docker" --docker_kill_or= phans=3D"true" --docker_registry=3D"https://registry-1.docker.io" --docker_= remove_delay=3D"6hrs" --docker_socket=3D"/var/run/docker.sock" --docker_sto= p_timeout=3D"0ns" --docker_store_dir=3D"/tmp/mesos/store/docker" --docker_v= olume_checkpoint_dir=3D"/var/run/mesos/isolators/docker/volume" --enforce_c= ontainer_disk_quota=3D"false" --executor_registration_timeout=3D"1mins" --e= xecutor_shutdown_grace_period=3D"5secs" --fetcher_cache_dir=3D"/tmp/MasterA= llocatorTest_1_FrameworkExited_cMdy3f/fetch" --fetcher_cache_size=3D"2GB" -= -frameworks_home=3D"" --gc_delay=3D"1weeks" --gc_disk_headroom=3D"0.1" --ha= doop_home=3D"" --help=3D"false" --hostname_lookup=3D"true" --http_command_e= xecutor=3D"false" --http_credentials=3D"/tmp/MasterAllocatorTest_1_Framewor= kExited_cMdy3f/http_credentials" --http_heartbeat_interval=3D"30secs" --ini= tialize_driver_logging=3D"true" --isolation=3D"posix/cpu,posix/mem" --launc= her=3D"posix" --launcher_dir=3D"/home/nrc/build-mesos-default-opts/src" --l= ogbufsecs=3D"0" --logging_level=3D"INFO" --max_completed_executors_per_fram= ework=3D"150" --oversubscribed_resources_interval=3D"15secs" --perf_duratio= n=3D"10secs" --perf_interval=3D"1mins" --port=3D"5051" --qos_correction_int= erval_min=3D"0ns" --quiet=3D"false" --recover=3D"reconnect" --recovery_time= out=3D"15mins" --registration_backoff_factor=3D"10ms" --resources=3D"cpus:3= ;mem:1024" --revocable_cpu_low_priority=3D"true" --runtime_dir=3D"/tmp/Mast= erAllocatorTest_1_FrameworkExited_cMdy3f" --sandbox_directory=3D"/mnt/mesos= /sandbox" --strict=3D"true" --switch_user=3D"true" --systemd_enable_support= =3D"true" --systemd_runtime_directory=3D"/run/systemd/system" --version=3D"= false" --work_dir=3D"/tmp/MasterAllocatorTest_1_FrameworkExited_uwQncJ" I0516 11:20:45.925328 27182 credentials.hpp:86] Loading credential for auth= entication from '/tmp/MasterAllocatorTest_1_FrameworkExited_cMdy3f/credenti= al' I0516 11:20:45.925467 27182 slave.cpp:258] Agent using credential for: test= -principal I0516 11:20:45.925506 27182 credentials.hpp:37] Loading credentials for aut= hentication from '/tmp/MasterAllocatorTest_1_FrameworkExited_cMdy3f/http_cr= edentials' I0516 11:20:45.925808 27182 http.cpp:975] Creating default 'basic' HTTP aut= henticator for realm 'mesos-agent-readonly' I0516 11:20:45.925989 27182 http.cpp:975] Creating default 'basic' HTTP aut= henticator for realm 'mesos-agent-readwrite' I0516 11:20:45.932641 27182 slave.cpp:529] Agent resources: cpus(*):3; mem(= *):1024; disk(*):46053; ports(*):[31000-32000] I0516 11:20:45.932739 27182 slave.cpp:537] Agent attributes: [ ] I0516 11:20:45.932786 27182 slave.cpp:542] Agent hostname: core-dev I0516 11:20:45.932940 27191 status_update_manager.cpp:177] Pausing sending = status updates I0516 11:20:45.934442 27183 state.cpp:62] Recovering state from '/tmp/Maste= rAllocatorTest_1_FrameworkExited_uwQncJ/meta' I0516 11:20:45.934720 27164 status_update_manager.cpp:203] Recovering statu= s update manager I0516 11:20:45.935153 27180 slave.cpp:5974] Finished recovery I0516 11:20:45.935814 27202 status_update_manager.cpp:177] Pausing sending = status updates I0516 11:20:45.935817 27197 slave.cpp:922] New master detected at master@10= .0.49.2:40918 I0516 11:20:45.935984 27197 slave.cpp:957] Detecting new master I0516 11:20:45.942248 27198 slave.cpp:984] Authenticating with master maste= r@10.0.49.2:40918 I0516 11:20:45.942320 27198 slave.cpp:995] Using default CRAM-MD5 authentic= atee I0516 11:20:45.942466 27196 authenticatee.cpp:121] Creating new client SASL= connection I0516 11:20:45.952559 27176 master.cpp:7475] Authenticating slave(3)@10.0.4= 9.2:40918 I0516 11:20:45.952847 27178 authenticator.cpp:98] Creating new server SASL = connection I0516 11:20:45.959229 27146 sched.cpp:232] Version: 1.4.0 I0516 11:20:45.959951 27164 sched.cpp:336] New master detected at master@10= .0.49.2:40918 I0516 11:20:45.960052 27164 sched.cpp:407] Authenticating with master maste= r@10.0.49.2:40918 I0516 11:20:45.960093 27164 sched.cpp:414] Using default CRAM-MD5 authentic= atee I0516 11:20:45.960172 27202 authenticatee.cpp:213] Received SASL authentica= tion mechanisms: CRAM-MD5 I0516 11:20:45.960238 27202 authenticatee.cpp:239] Attempting to authentica= te with mechanism 'CRAM-MD5' I0516 11:20:45.960412 27180 authenticatee.cpp:121] Creating new client SASL= connection I0516 11:20:45.960713 27181 authenticator.cpp:204] Received SASL authentica= tion start I0516 11:20:45.960798 27181 authenticator.cpp:326] Authentication requires = more steps I0516 11:20:45.961197 27206 authenticatee.cpp:259] Received SASL authentica= tion step I0516 11:20:45.961350 27196 authenticator.cpp:232] Received SASL authentica= tion step I0516 11:20:45.961421 27196 authenticator.cpp:318] Authentication success I0516 11:20:45.961501 27206 authenticatee.cpp:299] Authentication success I0516 11:20:45.961863 27173 master.cpp:7505] Successfully authenticated pri= ncipal 'test-principal' at slave(3)@10.0.49.2:40918 I0516 11:20:45.961875 27190 slave.cpp:1079] Successfully authenticated with= master master@10.0.49.2:40918 I0516 11:20:45.962111 27203 master.cpp:5429] Received register agent messag= e from slave(3)@10.0.49.2:40918 (core-dev) I0516 11:20:45.962229 27203 master.cpp:3659] Authorizing agent with princip= al 'test-principal' I0516 11:20:45.962633 27202 master.cpp:5564] Registering agent at slave(3)@= 10.0.49.2:40918 (core-dev) with id 0526e771-e1a3-4bd0-830e-6084ff4bc552-S0 I0516 11:20:45.963028 27195 registrar.cpp:493] Applied 1 operations in 5039= 4ns; attempting to update the registry I0516 11:20:45.965773 27195 registrar.cpp:550] Successfully updated the reg= istry in 2.672896ms I0516 11:20:45.966375 27165 master.cpp:5639] Registered agent 0526e771-e1a3= -4bd0-830e-6084ff4bc552-S0 at slave(3)@10.0.49.2:40918 (core-dev) with cpus= (*):3; mem(*):1024; disk(*):46053; ports(*):[31000-32000] I0516 11:20:45.966478 27201 slave.cpp:1125] Registered with master master@1= 0.0.49.2:40918; given agent ID 0526e771-e1a3-4bd0-830e-6084ff4bc552-S0 I0516 11:20:45.966518 27173 hierarchical.cpp:525] Added agent 0526e771-e1a3= -4bd0-830e-6084ff4bc552-S0 (core-dev) with cpus(*):3; mem(*):1024; disk(*):= 46053; ports(*):[31000-32000] (allocated: {}) I0516 11:20:45.966534 27165 master.cpp:7475] Authenticating scheduler-4d481= 1fa-4e9d-4db2-b1dc-0160a3a97d46@10.0.49.2:40918 I0516 11:20:45.966675 27181 status_update_manager.cpp:184] Resuming sending= status updates I0516 11:20:45.967131 27201 slave.cpp:1191] Forwarding total oversubscribed= resources {} I0516 11:20:45.967241 27188 authenticator.cpp:98] Creating new server SASL = connection I0516 11:20:45.967329 27178 master.cpp:6324] Received update of agent 0526e= 771-e1a3-4bd0-830e-6084ff4bc552-S0 at slave(3)@10.0.49.2:40918 (core-dev) w= ith total oversubscribed resources {} I0516 11:20:45.974470 27187 authenticatee.cpp:213] Received SASL authentica= tion mechanisms: CRAM-MD5 I0516 11:20:45.974520 27187 authenticatee.cpp:239] Attempting to authentica= te with mechanism 'CRAM-MD5' I0516 11:20:45.974653 27190 authenticator.cpp:204] Received SASL authentica= tion start I0516 11:20:45.974771 27190 authenticator.cpp:326] Authentication requires = more steps I0516 11:20:45.974902 27207 authenticatee.cpp:259] Received SASL authentica= tion step I0516 11:20:45.975132 27196 authenticator.cpp:232] Received SASL authentica= tion step I0516 11:20:45.975198 27196 authenticator.cpp:318] Authentication success I0516 11:20:45.975410 27180 authenticatee.cpp:299] Authentication success I0516 11:20:45.975472 27197 master.cpp:7505] Successfully authenticated pri= ncipal 'test-principal' at scheduler-4d4811fa-4e9d-4db2-b1dc-0160a3a97d46@1= 0.0.49.2:40918 I0516 11:20:45.975811 27207 sched.cpp:513] Successfully authenticated with = master master@10.0.49.2:40918 I0516 11:20:45.976063 27188 master.cpp:2813] Received SUBSCRIBE call for fr= amework 'default' at scheduler-4d4811fa-4e9d-4db2-b1dc-0160a3a97d46@10.0.49= .2:40918 I0516 11:20:45.976148 27188 master.cpp:2197] Authorizing framework principa= l 'test-principal' to receive offers for roles '{ * }' I0516 11:20:45.976495 27197 master.cpp:2890] Subscribing framework default = with checkpointing disabled and capabilities [ ] I0516 11:20:45.976966 27188 sched.cpp:759] Framework registered with 0526e7= 71-e1a3-4bd0-830e-6084ff4bc552-0000 I0516 11:20:45.977082 27166 hierarchical.cpp:273] Added framework 0526e771-= e1a3-4bd0-830e-6084ff4bc552-0000 I0516 11:20:45.978278 27195 master.cpp:7305] Sending 1 offers to framework = 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 (default) at scheduler-4d4811fa-4= e9d-4db2-b1dc-0160a3a97d46@10.0.49.2:40918 I0516 11:20:45.979658 27178 master.cpp:3875] Processing ACCEPT call for off= ers: [ 0526e771-e1a3-4bd0-830e-6084ff4bc552-O0 ] on agent 0526e771-e1a3-4bd= 0-830e-6084ff4bc552-S0 at slave(3)@10.0.49.2:40918 (core-dev) for framework= 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 (default) at scheduler-4d4811fa-= 4e9d-4db2-b1dc-0160a3a97d46@10.0.49.2:40918 I0516 11:20:45.979745 27178 master.cpp:3426] Authorizing framework principa= l 'test-principal' to launch task 0 W0516 11:20:45.981372 27186 validation.cpp:1284] Executor 'executor-1' for = task '0' uses less CPUs (None) than the minimum required (0.01). Please upd= ate your executor, as this will be mandatory in future releases. W0516 11:20:45.981426 27186 validation.cpp:1296] Executor 'executor-1' for = task '0' uses less memory (None) than the minimum required (32MB). Please u= pdate your executor, as this will be mandatory in future releases. I0516 11:20:45.981706 27186 master.cpp:9326] Adding task 0 with resources c= pus(*)(allocated: *):2; mem(*)(allocated: *):512 on agent 0526e771-e1a3-4bd= 0-830e-6084ff4bc552-S0 at slave(3)@10.0.49.2:40918 (core-dev) I0516 11:20:45.981864 27186 master.cpp:4531] Launching task 0 of framework = 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 (default) at scheduler-4d4811fa-4= e9d-4db2-b1dc-0160a3a97d46@10.0.49.2:40918 with resources cpus(*)(allocated= : *):2; mem(*)(allocated: *):512 on agent 0526e771-e1a3-4bd0-830e-6084ff4bc= 552-S0 at slave(3)@10.0.49.2:40918 (core-dev) I0516 11:20:45.982285 27183 slave.cpp:1617] Got assigned task '0' for frame= work 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 I0516 11:20:45.982837 27183 slave.cpp:1898] Authorizing task '0' for framew= ork 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 I0516 11:20:45.982906 27183 slave.cpp:6593] Authorizing framework principal= 'test-principal' to launch task 0 I0516 11:20:45.983603 27164 slave.cpp:2085] Launching task '0' for framewor= k 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 I0516 11:20:45.983886 27192 hierarchical.cpp:850] Updated allocation of fra= mework 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 on agent 0526e771-e1a3-4bd= 0-830e-6084ff4bc552-S0 from cpus(*)(allocated: *):3; mem(*)(allocated: *):1= 024; disk(*)(allocated: *):46053; ports(*)(allocated: *):[31000-32000] to c= pus(*)(allocated: *):3; mem(*)(allocated: *):1024; disk(*)(allocated: *):46= 053; ports(*)(allocated: *):[31000-32000] I0516 11:20:45.985476 27164 paths.cpp:573] Trying to chown '/tmp/MasterAllo= catorTest_1_FrameworkExited_uwQncJ/slaves/0526e771-e1a3-4bd0-830e-6084ff4bc= 552-S0/frameworks/0526e771-e1a3-4bd0-830e-6084ff4bc552-0000/executors/execu= tor-1/runs/f4e67839-fc41-459b-a52e-1db363b876dd' to user 'nrc' I0516 11:20:45.985605 27164 slave.cpp:6933] Launching executor 'executor-1'= of framework 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 with resources {} i= n work directory '/tmp/MasterAllocatorTest_1_FrameworkExited_uwQncJ/slaves/= 0526e771-e1a3-4bd0-830e-6084ff4bc552-S0/frameworks/0526e771-e1a3-4bd0-830e-= 6084ff4bc552-0000/executors/executor-1/runs/f4e67839-fc41-459b-a52e-1db363b= 876dd' I0516 11:20:45.985954 27164 slave.cpp:2314] Queued task '0' for executor 'e= xecutor-1' of framework 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 I0516 11:20:45.990473 27180 exec.cpp:162] Version: 1.4.0 I0516 11:20:45.990758 27186 slave.cpp:3788] Got registration for executor '= executor-1' of framework 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 from exe= cutor(5)@10.0.49.2:40918 I0516 11:20:45.991080 27201 exec.cpp:237] Executor registered on agent 0526= e771-e1a3-4bd0-830e-6084ff4bc552-S0 I0516 11:20:45.991627 27186 slave.cpp:2527] Sending queued task '0' to exec= utor 'executor-1' of framework 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 at= executor(5)@10.0.49.2:40918 I0516 11:20:46.001216 27146 sched.cpp:232] Version: 1.4.0 I0516 11:20:46.001626 27176 sched.cpp:336] New master detected at master@10= .0.49.2:40918 I0516 11:20:46.001727 27176 sched.cpp:407] Authenticating with master maste= r@10.0.49.2:40918 I0516 11:20:46.001768 27176 sched.cpp:414] Using default CRAM-MD5 authentic= atee I0516 11:20:46.001927 27180 authenticatee.cpp:121] Creating new client SASL= connection I0516 11:20:46.011135 27167 master.cpp:7475] Authenticating scheduler-be0d7= a23-03fc-493a-96e2-1487729061ec@10.0.49.2:40918 I0516 11:20:46.011405 27167 authenticator.cpp:98] Creating new server SASL = connection W0516 11:20:51.002770 27160 sched.cpp:537] Authentication timed out I0516 11:20:51.003023 27160 sched.cpp:477] Failed to authenticate with mast= er master@10.0.49.2:40918: Authentication discarded W0516 11:20:51.012037 27164 master.cpp:7522] Authentication timed out I0516 11:20:51.029443 27194 master.cpp:7305] Sending 1 offers to framework = 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 (default) at scheduler-4d4811fa-4= e9d-4db2-b1dc-0160a3a97d46@10.0.49.2:40918 I0516 11:20:51.030237 27165 master.cpp:4836] Processing DECLINE call for of= fers: [ 0526e771-e1a3-4bd0-830e-6084ff4bc552-O1 ] for framework 0526e771-e1= a3-4bd0-830e-6084ff4bc552-0000 (default) at scheduler-4d4811fa-4e9d-4db2-b1= dc-0160a3a97d46@10.0.49.2:40918 I0516 11:20:52.559548 27191 sched.cpp:407] Authenticating with master maste= r@10.0.49.2:40918 I0516 11:20:52.559615 27191 sched.cpp:414] Using default CRAM-MD5 authentic= atee I0516 11:20:52.559835 27197 authenticatee.cpp:121] Creating new client SASL= connection I0516 11:20:52.601976 27191 master.cpp:7461] Queuing up authentication requ= est from scheduler-be0d7a23-03fc-493a-96e2-1487729061ec@10.0.49.2:40918 bec= ause authentication is still in progress I0516 11:20:56.050565 27182 master.cpp:7305] Sending 1 offers to framework = 0526e771-e1a3-4bd0-830e-6084ff4bc552-0000 (default) at scheduler-4d4811fa-4= e9d-4db2-b1dc-0160a3a97d46@10.0.49.2:40918 I0516 11:20:56.051501 27174 master.cpp:4836] Processing DECLINE call for of= fers: [ 0526e771-e1a3-4bd0-830e-6084ff4bc552-O2 ] for framework 0526e771-e1= a3-4bd0-830e-6084ff4bc552-0000 (default) at scheduler-4d4811fa-4e9d-4db2-b1= dc-0160a3a97d46@10.0.49.2:40918 ../../mesos/src/tests/master_allocator_tests.cpp:669: Failure Mock function called more times than expected - taking default action speci= fied at: ../../mesos/src/tests/allocator.hpp:327: Function call: recoverResources(@0x7f72f0005cc0 0526e771-e1a3-4bd0-830e= -6084ff4bc552-0000, @0x7f72f00077d0 0526e771-e1a3-4bd0-830e-6084ff4bc552-S0= , @0x7f7368ba52d0 { cpus(*)(allocated: *):1, mem(*)(allocated: *):512, disk= (*)(allocated: *):46053, ports(*)(allocated: *):[31000-32000] }, @0x7f7368b= a52f0 40-byte object <00-00 00-00 73-7F 00-00 F0-39 4D-7D 73-7F 00-00 00-00= 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 14-40>) Expected: to be called once Actual: called twice - over-saturated and active *** Aborted at 1494958856 (unix time) try "date -d @1494958856" if you are = using GNU date *** PC: @ 0x1f872d6 testing::UnitTest::AddTestPartResult() *** SIGSEGV (@0x0) received by PID 27146 (TID 0x7f7368ba6700) from PID 0; s= tack trace: *** @ 0x7f73747b6370 (unknown) @ 0x1f872d6 testing::UnitTest::AddTestPartResult() @ 0x1f7be4d testing::internal::AssertHelper::operator=3D() @ 0x1f9df1c testing::internal::GoogleTestFailureReporter::Repo= rtFailure() @ 0xbc4388 testing::internal::Expect() @ 0x1f9540e testing::internal::UntypedFunctionMockerBase::Unty= pedInvokeWith() @ 0xd542f3 testing::internal::FunctionMockerBase<>::InvokeWit= h() @ 0xd37d7b testing::internal::FunctionMocker<>::Invoke() @ 0x13b252f mesos::internal::tests::TestAllocator<>::recoverRe= sources() @ 0x7f737ac85538 mesos::internal::master::Master::decline() @ 0x7f737ac72b49 mesos::internal::master::Master::receive() @ 0x7f737acf5b62 ProtobufProcess<>::handlerM<>() @ 0x7f737adb3c38 _ZNSt5_BindIFPFvPN5mesos8internal6master6MasterEMS= 3_FvRKN7process4UPIDERKNS0_9scheduler4CallEES8_RKSsES4_SE_St12_PlaceholderI= Li1EESJ_ILi2EEEE6__callIvIS8_SG_EILm0ELm1ELm2ELm3EEEET_OSt5tupleIIDpT0_EESt= 12_Index_tupleIIXspT1_EEE @ 0x7f737ad9276d std::_Bind<>::operator()<>() @ 0x7f737ad677ae std::_Function_handler<>::_M_invoke() @ 0x134ccdd std::function<>::operator()() @ 0x7f737acd6e2d ProtobufProcess<>::visit() @ 0x7f737ac6cacf mesos::internal::master::Master::_visit() @ 0x7f737ac6c0ee mesos::internal::master::Master::visit() @ 0x7f737acb857a process::MessageEvent::visit() @ 0xb0531a process::ProcessBase::serve() @ 0x7f737bfd794f process::ProcessManager::resume() @ 0x7f737bfd4100 _ZZN7process14ProcessManager12init_threadsEvENKUt_= clEv @ 0x7f737bfe636a _ZNSt12_Bind_simpleIFZN7process14ProcessManager12i= nit_threadsEvEUt_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE @ 0x7f737bfe62ae _ZNSt12_Bind_simpleIFZN7process14ProcessManager12i= nit_threadsEvEUt_vEEclEv @ 0x7f737bfe6238 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14P= rocessManager12init_threadsEvEUt_vEEE6_M_runEv @ 0x7f7373f31230 (unknown) @ 0x7f73747aedc5 start_thread @ 0x7f737369a73d __clone zsh: segmentation fault (core dumped) ./src/mesos-tests --gtest_filter=3D"= MasterAllocatorTest/1.FrameworkExited" {noformat} > Flaky test: MasterAllocatorTest/1.FrameworkExited > ------------------------------------------------- > > Key: MESOS-4095 > URL: https://issues.apache.org/jira/browse/MESOS-4095 > Project: Mesos > Issue Type: Bug > Components: allocation, master, test > Reporter: Neil Conway > Labels: flaky, flaky-test, mesosphere > Attachments: wily64_master_allocator_framework_exited-1.log > > > This test fails about ~10% of the time for me on Ubuntu 15.10 (running in= a crappy Virtualbox VM). Passes consistently on Mac OSX 10.10. > Verbose test log attached. -- This message was sent by Atlassian JIRA (v6.3.15#6346)