From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752130AbbCZBx6 (ORCPT ); Wed, 25 Mar 2015 21:53:58 -0400 Received: from linuxhacker.ru ([217.76.32.60]:39153 "EHLO fiona.linuxhacker.ru" rhost-flags-OK-FAIL-OK-OK) by vger.kernel.org with ESMTP id S1750910AbbCZBxu (ORCPT ); Wed, 25 Mar 2015 21:53:50 -0400 From: green@linuxhacker.ru To: Greg Kroah-Hartman , devel@driverdev.osuosl.org, Andreas Dilger Cc: Linux Kernel Mailing List , Liang Zhen , Oleg Drokin Subject: [PATCH 03/10] staging/lustre/ptlrpc: false alarm in AT network latency measuring Date: Wed, 25 Mar 2015 21:53:19 -0400 Message-Id: <1427334806-31466-4-git-send-email-green@linuxhacker.ru> X-Mailer: git-send-email 2.1.0 In-Reply-To: <1427334806-31466-1-git-send-email-green@linuxhacker.ru> References: <1427334806-31466-1-git-send-email-green@linuxhacker.ru> Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org From: Liang Zhen If early reply of client RPC is lost and client RPC is expired and resent, server will drop the resent RPC because it's already in processing, server may also send reply or early reply to client, which can still match reply buffer of the original request. In this case, client is measuring time from resent time, but server is reporting service time of original RPC, which is longer than the time measured by client. Signed-off-by: Liang Zhen Reviewed-on: http://review.whamcloud.com/12855 Intel-bug-id: https://jira.hpdd.intel.com/browse/LU-5545 Reviewed-by: Li Wei Reviewed-by: Johann Lombardi Signed-off-by: Oleg Drokin --- drivers/staging/lustre/lustre/ptlrpc/client.c | 25 +++++++++++++++++++------ 1 file changed, 19 insertions(+), 6 deletions(-) diff --git a/drivers/staging/lustre/lustre/ptlrpc/client.c b/drivers/staging/lustre/lustre/ptlrpc/client.c index 0fe6a64..0357f1d 100644 --- a/drivers/staging/lustre/lustre/ptlrpc/client.c +++ b/drivers/staging/lustre/lustre/ptlrpc/client.c @@ -285,14 +285,27 @@ static void ptlrpc_at_adj_net_latency(struct ptlrpc_request *req, time_t now = get_seconds(); LASSERT(req->rq_import); - at = &req->rq_import->imp_at; + + if (service_time > now - req->rq_sent + 3) { + /* bz16408, however, this can also happen if early reply + * is lost and client RPC is expired and resent, early reply + * or reply of original RPC can still be fit in reply buffer + * of resent RPC, now client is measuring time from the + * resent time, but server sent back service time of original + * RPC. + */ + CDEBUG((lustre_msg_get_flags(req->rq_reqmsg) & MSG_RESENT) ? + D_ADAPTTO : D_WARNING, + "Reported service time %u > total measured time " + CFS_DURATION_T"\n", service_time, + cfs_time_sub(now, req->rq_sent)); + return; + } /* Network latency is total time less server processing time */ - nl = max_t(int, now - req->rq_sent - service_time, 0) + 1/*st rounding*/; - if (service_time > now - req->rq_sent + 3 /* bz16408 */) - CWARN("Reported service time %u > total measured time " - CFS_DURATION_T"\n", service_time, - cfs_time_sub(now, req->rq_sent)); + nl = max_t(int, now - req->rq_sent - + service_time, 0) + 1; /* st rounding */ + at = &req->rq_import->imp_at; oldnl = at_measured(&at->iat_net_latency, nl); if (oldnl != 0) -- 2.1.0