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 131A2200BC2 for ; Thu, 17 Nov 2016 22:49:00 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id 1144E160B0B; Thu, 17 Nov 2016 21:49:00 +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 59AE6160AD8 for ; Thu, 17 Nov 2016 22:48:59 +0100 (CET) Received: (qmail 61104 invoked by uid 500); 17 Nov 2016 21:48:58 -0000 Mailing-List: contact commits-help@cassandra.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cassandra.apache.org Delivered-To: mailing list commits@cassandra.apache.org Received: (qmail 61092 invoked by uid 99); 17 Nov 2016 21:48:58 -0000 Received: from arcas.apache.org (HELO arcas) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 17 Nov 2016 21:48:58 +0000 Received: from arcas.apache.org (localhost [127.0.0.1]) by arcas (Postfix) with ESMTP id 666CF2C4C73 for ; Thu, 17 Nov 2016 21:48:58 +0000 (UTC) Date: Thu, 17 Nov 2016 21:48:58 +0000 (UTC) From: "Ariel Weisberg (JIRA)" To: commits@cassandra.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (CASSANDRA-12920) Possible messaging latency caused by not flushing in time MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Thu, 17 Nov 2016 21:49:00 -0000 [ https://issues.apache.org/jira/browse/CASSANDRA-12920?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15674914#comment-15674914 ] Ariel Weisberg commented on CASSANDRA-12920: -------------------------------------------- Is this on every request or just some? If I am reading this correctly it is approximately 150 to 200 milliseconds? That's roughly G1 GC pause time. Is this happening on every request or just some of them? I have to confess I haven't read a trace before. Is that a single request or 3 requests? > Possible messaging latency caused by not flushing in time > --------------------------------------------------------- > > Key: CASSANDRA-12920 > URL: https://issues.apache.org/jira/browse/CASSANDRA-12920 > Project: Cassandra > Issue Type: Bug > Reporter: Simon Zhou > Assignee: Simon Zhou > Priority: Minor > Fix For: 2.2.5 > > > Not sure if this can be improved. We're using Cassandra 2.2.5. Cassandra considers messages whose payload size <= 64KB as small messages. For response for such as digest request, it's very likely a small message. Even quite a few such responses cannot fill in the output buffer and thus trigger a flush. > One possible issue is that, we use conditions count == 1 && backlog.isEmpty() to decide whether to flush the output stream. That means if the backlog is empty, we won't flush the output stream even we drained, say, 10 messages whose sizes sum < 64K. This may cause delay for small messages. Shouldn't we flush after writing the last drained message if backlog is empty? Of course if backlog is not empty, we can continue draining more messages and very likely trigger a flush very soon. > Here are some tracing events that show the latency. Be noted that the involved nodes are in the same data center whose round trip network latency is well below 1ms. Alao we have disabled message coalescing due to CASSANDRA-12676. > {noformat} > 126571b0-aaa6-11e6-ab2b-77eb6f529c59 | 127c7c28-aaa6-11e6-941f-f3a2e2759bd2 | Enqueuing response to /*******32.28 | *******29.3 | 1199 | SharedPool-Worker-4 > 126571b0-aaa6-11e6-ab2b-77eb6f529c59 | 127cca45-aaa6-11e6-941f-f3a2e2759bd2 | Sending REQUEST_RESPONSE message to /*******32.28 | *******29.3 | 2667 | MessagingService-Outgoing-/*******32.28 > 126571b0-aaa6-11e6-ab2b-77eb6f529c59 | 127cca40-aaa6-11e6-ab2b-77eb6f529c59 | REQUEST_RESPONSE message received from /*******29.3 | *******32.28 | 152635 | MessagingService-Incoming-/*******29.3 > 126571b0-aaa6-11e6-ab2b-77eb6f529c59 | 127cca41-aaa6-11e6-ab2b-77eb6f529c59 | Processing response from /*******29.3 | *******32.28 | 152665 | SharedPool-Worker-45 > 1af31490-aaa6-11e6-ab2b-77eb6f529c59 | 1b08e68a-aaa6-11e6-8dce-951d39203586 | Enqueuing response to /*******32.28 | *******29.5 | 532 | SharedPool-Worker-178 > 1af31490-aaa6-11e6-ab2b-77eb6f529c59 | 1b090d90-aaa6-11e6-8dce-951d39203586 | Sending REQUEST_RESPONSE message to /*******32.28 | *******29.5 | 579 | MessagingService-Outgoing-/*******32.28 > 1af31490-aaa6-11e6-ab2b-77eb6f529c59 | 1b090d90-aaa6-11e6-ab2b-77eb6f529c59 | REQUEST_RESPONSE message received from /*******29.5 | *******32.28 | 143865 | MessagingService-Incoming-/*******29.5 > 1af31490-aaa6-11e6-ab2b-77eb6f529c59 | 1b090d91-aaa6-11e6-ab2b-77eb6f529c59 | Processing response from /*******29.5 | *******32.28 | 143908 | > SharedPool-Worker-41 > 1af58590-aaa6-11e6-ab2b-77eb6f529c59 | 1b0934a8-aaa6-11e6-8dce-951d39203586 | Enqueuing response to /*******32.28 | *******29.5 | 1632 | > SharedPool-Worker-159 1af58590-aaa6-11e6-ab2b-77eb6f529c59 | 1b0934a9-aaa6-11e6-8dce-951d39203586 | Sending REQUEST_RESPONSE message to /*******32.28 | *******29.5 | 1660 | MessagingService > -Outgoing-/*******32.28 1af58590-aaa6-11e6-ab2b-77eb6f529c59 | 1b095bb0-aaa6-11e6-ab2b-77eb6f529c59 | REQUEST_RESPONSE message received from /*******29.5 | *******32.28 | 129813 | MessagingServic > e-Incoming-/*******29.5 1af58590-aaa6-11e6-ab2b-77eb6f529c59 | 1b095bb1-aaa6-11e6-ab2b-77eb6f529c59 | Processing response from /*******29.5 | *******32.28 | 129835 | > SharedPool-Worker-3 > 3010cfc0-aaa6-11e6-ab2b-77eb6f529c59 | 3029fd17-aaa6-11e6-a5cc-8b24438aa927 | Enqueuing response to /*******32.28 | *******30.8 | 1686 | SharedPool-Worker-271 > 3010cfc0-aaa6-11e6-ab2b-77eb6f529c59 | 302ae770-aaa6-11e6-a5cc-8b24438aa927 | Sending REQUEST_RESPONSE message to /*******32.28 | *******30.8 | 6938 | MessagingService-Outgoing-/*******32.28 > 3010cfc0-aaa6-11e6-ab2b-77eb6f529c59 | 302ae770-aaa6-11e6-ab2b-77eb6f529c59 | REQUEST_RESPONSE message received from /*******30.8 | *******32.28 | 171380 | MessagingService-Incoming-/*******30.8 > 3010cfc0-aaa6-11e6-ab2b-77eb6f529c59 | 302ae771-aaa6-11e6-ab2b-77eb6f529c59 | Processing response from /*******30.8 | *******32.28 | 171472 | SharedPool-Worker-55 > {noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332)