From nobody Fri May 17 09:38:19 2024 Delivered-To: importer@patchew.org Received-SPF: pass (zoho.com: domain of gnu.org designates 208.118.235.17 as permitted sender) client-ip=208.118.235.17; envelope-from=qemu-devel-bounces+importer=patchew.org@nongnu.org; helo=lists.gnu.org; Authentication-Results: mx.zohomail.com; spf=pass (zoho.com: domain of gnu.org designates 208.118.235.17 as permitted sender) smtp.mailfrom=qemu-devel-bounces+importer=patchew.org@nongnu.org; dmarc=fail(p=none dis=none) header.from=redhat.com Return-Path: Received: from lists.gnu.org (lists.gnu.org [208.118.235.17]) by mx.zohomail.com with SMTPS id 1545173946256380.3536614259466; Tue, 18 Dec 2018 14:59:06 -0800 (PST) Received: from localhost ([::1]:56624 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gZOKO-0005UI-Vd for importer@patchew.org; Tue, 18 Dec 2018 17:59:05 -0500 Received: from eggs.gnu.org ([2001:4830:134:3::10]:36617) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gZOIr-0004h6-2Z for qemu-devel@nongnu.org; Tue, 18 Dec 2018 17:57:32 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1gZOIl-00072b-E6 for qemu-devel@nongnu.org; Tue, 18 Dec 2018 17:57:25 -0500 Received: from mx1.redhat.com ([209.132.183.28]:32772) by eggs.gnu.org with esmtps (TLS1.0:DHE_RSA_AES_256_CBC_SHA1:32) (Exim 4.71) (envelope-from ) id 1gZOIh-0006yU-DB; Tue, 18 Dec 2018 17:57:19 -0500 Received: from smtp.corp.redhat.com (int-mx01.intmail.prod.int.phx2.redhat.com [10.5.11.11]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id 9ED88C04959E; Tue, 18 Dec 2018 22:57:18 +0000 (UTC) Received: from red.redhat.com (ovpn-122-76.rdu2.redhat.com [10.10.122.76]) by smtp.corp.redhat.com (Postfix) with ESMTP id 91A6D600C9; Tue, 18 Dec 2018 22:57:17 +0000 (UTC) From: Eric Blake To: qemu-devel@nongnu.org Date: Tue, 18 Dec 2018 16:57:12 -0600 Message-Id: <20181218225714.284495-2-eblake@redhat.com> In-Reply-To: <20181218225714.284495-1-eblake@redhat.com> References: <20181218225714.284495-1-eblake@redhat.com> X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.31]); Tue, 18 Dec 2018 22:57:18 +0000 (UTC) X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] [fuzzy] X-Received-From: 209.132.183.28 Subject: [Qemu-devel] [PATCH v2 1/3] nbd: publish _lookup functions X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: Kevin Wolf , vsementsov@virtuozzo.com, "open list:Network Block Dev..." , Max Reitz Errors-To: qemu-devel-bounces+importer=patchew.org@nongnu.org Sender: "Qemu-devel" Content-Transfer-Encoding: quoted-printable MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" From: Vladimir Sementsov-Ogievskiy These functions are used for formatting pretty trace points. We are going to add some in block/nbd-client, so, let's publish all these functions at once. Note, that nbd_reply_type_lookup is already published, and constants, "named" by these functions live in include/block/nbd.h too. Signed-off-by: Vladimir Sementsov-Ogievskiy Message-Id: <20181102151152.288399-3-vsementsov@virtuozzo.com> Reviewed-by: Eric Blake Signed-off-by: Eric Blake --- include/block/nbd.h | 5 +++++ nbd/nbd-internal.h | 5 ----- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/include/block/nbd.h b/include/block/nbd.h index 6a5bfe5d559..65402d33964 100644 --- a/include/block/nbd.h +++ b/include/block/nbd.h @@ -343,5 +343,10 @@ static inline bool nbd_reply_is_structured(NBDReply *r= eply) } const char *nbd_reply_type_lookup(uint16_t type); +const char *nbd_opt_lookup(uint32_t opt); +const char *nbd_rep_lookup(uint32_t rep); +const char *nbd_info_lookup(uint16_t info); +const char *nbd_cmd_lookup(uint16_t info); +const char *nbd_err_lookup(int err); #endif diff --git a/nbd/nbd-internal.h b/nbd/nbd-internal.h index eeff78d3c98..f38be9ebaaf 100644 --- a/nbd/nbd-internal.h +++ b/nbd/nbd-internal.h @@ -100,11 +100,6 @@ struct NBDTLSHandshakeData { void nbd_tls_handshake(QIOTask *task, void *opaque); -const char *nbd_opt_lookup(uint32_t opt); -const char *nbd_rep_lookup(uint32_t rep); -const char *nbd_info_lookup(uint16_t info); -const char *nbd_cmd_lookup(uint16_t info); -const char *nbd_err_lookup(int err); int nbd_drop(QIOChannel *ioc, size_t size, Error **errp); --=20 2.17.2 From nobody Fri May 17 09:38:19 2024 Delivered-To: importer@patchew.org Received-SPF: pass (zoho.com: domain of gnu.org designates 208.118.235.17 as permitted sender) client-ip=208.118.235.17; envelope-from=qemu-devel-bounces+importer=patchew.org@nongnu.org; helo=lists.gnu.org; Authentication-Results: mx.zohomail.com; spf=pass (zoho.com: domain of gnu.org designates 208.118.235.17 as permitted sender) smtp.mailfrom=qemu-devel-bounces+importer=patchew.org@nongnu.org; dmarc=fail(p=none dis=none) header.from=redhat.com Return-Path: Received: from lists.gnu.org (lists.gnu.org [208.118.235.17]) by mx.zohomail.com with SMTPS id 1545174032425697.1664947965525; Tue, 18 Dec 2018 15:00:32 -0800 (PST) Received: from localhost ([::1]:56631 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gZOLj-0006OU-IC for importer@patchew.org; Tue, 18 Dec 2018 18:00:27 -0500 Received: from eggs.gnu.org ([2001:4830:134:3::10]:36674) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gZOJ1-0004pq-LA for qemu-devel@nongnu.org; Tue, 18 Dec 2018 17:57:44 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1gZOIx-0007Cw-R4 for qemu-devel@nongnu.org; Tue, 18 Dec 2018 17:57:37 -0500 Received: from mx1.redhat.com ([209.132.183.28]:47550) by eggs.gnu.org with esmtps (TLS1.0:DHE_RSA_AES_256_CBC_SHA1:32) (Exim 4.71) (envelope-from ) id 1gZOIj-00070K-5J; Tue, 18 Dec 2018 17:57:21 -0500 Received: from smtp.corp.redhat.com (int-mx01.intmail.prod.int.phx2.redhat.com [10.5.11.11]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id 3776F80470; Tue, 18 Dec 2018 22:57:20 +0000 (UTC) Received: from red.redhat.com (ovpn-122-76.rdu2.redhat.com [10.10.122.76]) by smtp.corp.redhat.com (Postfix) with ESMTP id E268F600CC; Tue, 18 Dec 2018 22:57:18 +0000 (UTC) From: Eric Blake To: qemu-devel@nongnu.org Date: Tue, 18 Dec 2018 16:57:13 -0600 Message-Id: <20181218225714.284495-3-eblake@redhat.com> In-Reply-To: <20181218225714.284495-1-eblake@redhat.com> References: <20181218225714.284495-1-eblake@redhat.com> X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.28]); Tue, 18 Dec 2018 22:57:20 +0000 (UTC) X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] [fuzzy] X-Received-From: 209.132.183.28 Subject: [Qemu-devel] [PATCH v2 2/3] nbd/client: Trace all server option error messages X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: vsementsov@virtuozzo.com, "open list:Network Block Dev..." Errors-To: qemu-devel-bounces+importer=patchew.org@nongnu.org Sender: "Qemu-devel" Content-Transfer-Encoding: quoted-printable MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Not all servers send free-form text alongside option error replies, but for servers that do (such as qemu), we pass the server's message as a hint alongside our own error reporting. However, it would also be useful to trace such server messages, since we can't guarantee how the hint may be consumed. Signed-off-by: Eric Blake Reviewed-by: Vladimir Sementsov-Ogievskiy --- nbd/client.c | 2 ++ nbd/trace-events | 1 + 2 files changed, 3 insertions(+) diff --git a/nbd/client.c b/nbd/client.c index b4d457a19ad..0ad7147ed95 100644 --- a/nbd/client.c +++ b/nbd/client.c @@ -171,6 +171,8 @@ static int nbd_handle_reply_err(QIOChannel *ioc, NBDOpt= ionReply *reply, goto cleanup; } msg[reply->length] =3D '\0'; + trace_nbd_server_error_msg(reply->type, + nbd_reply_type_lookup(reply->type), msg= ); } switch (reply->type) { diff --git a/nbd/trace-events b/nbd/trace-events index 5e1d4afe8e6..5492042acbf 100644 --- a/nbd/trace-events +++ b/nbd/trace-events @@ -1,6 +1,7 @@ # nbd/client.c nbd_send_option_request(uint32_t opt, const char *name, uint32_t len) "Sen= ding option request %" PRIu32" (%s), len %" PRIu32 nbd_receive_option_reply(uint32_t option, const char *optname, uint32_t ty= pe, const char *typename, uint32_t length) "Received option reply %" PRIu32= " (%s), type %" PRIu32" (%s), len %" PRIu32 +nbd_server_error_msg(uint32_t err, const char *type, const char *msg) "ser= ver reported error 0x%" PRIx32 " (%s) with additional message: %s" nbd_reply_err_unsup(uint32_t option, const char *name) "server doesn't und= erstand request %" PRIu32 " (%s), attempting fallback" nbd_opt_go_start(const char *name) "Attempting NBD_OPT_GO for export '%s'" nbd_opt_go_success(void) "Export is good to go" --=20 2.17.2 From nobody Fri May 17 09:38:19 2024 Delivered-To: importer@patchew.org Received-SPF: pass (zoho.com: domain of gnu.org designates 208.118.235.17 as permitted sender) client-ip=208.118.235.17; envelope-from=qemu-devel-bounces+importer=patchew.org@nongnu.org; helo=lists.gnu.org; Authentication-Results: mx.zohomail.com; spf=pass (zoho.com: domain of gnu.org designates 208.118.235.17 as permitted sender) smtp.mailfrom=qemu-devel-bounces+importer=patchew.org@nongnu.org; dmarc=fail(p=none dis=none) header.from=redhat.com Return-Path: Received: from lists.gnu.org (lists.gnu.org [208.118.235.17]) by mx.zohomail.com with SMTPS id 1545174115834819.9081438249066; Tue, 18 Dec 2018 15:01:55 -0800 (PST) Received: from localhost ([::1]:56643 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gZON8-0007Cf-KK for importer@patchew.org; Tue, 18 Dec 2018 18:01:54 -0500 Received: from eggs.gnu.org ([2001:4830:134:3::10]:36717) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1gZOJB-0004u2-Mq for qemu-devel@nongnu.org; Tue, 18 Dec 2018 17:57:52 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1gZOJ2-0007FS-QG for qemu-devel@nongnu.org; Tue, 18 Dec 2018 17:57:45 -0500 Received: from mx1.redhat.com ([209.132.183.28]:52278) by eggs.gnu.org with esmtps (TLS1.0:DHE_RSA_AES_256_CBC_SHA1:32) (Exim 4.71) (envelope-from ) id 1gZOIl-00071s-Di; Tue, 18 Dec 2018 17:57:25 -0500 Received: from smtp.corp.redhat.com (int-mx01.intmail.prod.int.phx2.redhat.com [10.5.11.11]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id 1946F89AC8; Tue, 18 Dec 2018 22:57:22 +0000 (UTC) Received: from red.redhat.com (ovpn-122-76.rdu2.redhat.com [10.10.122.76]) by smtp.corp.redhat.com (Postfix) with ESMTP id 9799B600C9; Tue, 18 Dec 2018 22:57:20 +0000 (UTC) From: Eric Blake To: qemu-devel@nongnu.org Date: Tue, 18 Dec 2018 16:57:14 -0600 Message-Id: <20181218225714.284495-4-eblake@redhat.com> In-Reply-To: <20181218225714.284495-1-eblake@redhat.com> References: <20181218225714.284495-1-eblake@redhat.com> X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.26]); Tue, 18 Dec 2018 22:57:22 +0000 (UTC) X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] [fuzzy] X-Received-From: 209.132.183.28 Subject: [Qemu-devel] [PATCH v2 3/3] block/nbd-client: use traces instead of noisy error_report_err X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: Kevin Wolf , vsementsov@virtuozzo.com, "open list:Network Block Dev..." , Max Reitz Errors-To: qemu-devel-bounces+importer=patchew.org@nongnu.org Sender: "Qemu-devel" Content-Transfer-Encoding: quoted-printable MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" From: Vladimir Sementsov-Ogievskiy Reduce extra noise of nbd-client, change 083 correspondingly. In various commits (be41c100 in 2.10, f140e300 in 2.11, 78a33ab in 2.12), we added spots where qemu as an NBD client would report problems communicating with the server to stderr, because there was no where else to send the error to. However, this is racy, particularly since the most common source of these errors is when either the client or the server abruptly hangs up, leaving one coroutine to report the error only if it wins (or loses) the race as attempting the read from the server before another thread completes its cleanup of a protocol error that caused the disconnect in the first place. The race is also apparent in the fact that differences in the flush behavior of the server can alter the frequency of encountering the race in the client (see commit 6d39db96). Rather than polluting stderr, it's better to just trace these situations, for use by developers debugging a flaky connection, particularly since the real error that either triggers the abrupt disconnection in the first place, or that results from the EIO when a request can't receive a reply, DOES make it back to the user in the normal Error propagation channels. Signed-off-by: Vladimir Sementsov-Ogievskiy Message-Id: <20181102151152.288399-4-vsementsov@virtuozzo.com> [eblake: drop depedence on error hint, enhance commit message] Signed-off-by: Eric Blake --- block/nbd-client.c | 23 +++++++++++++++++++---- block/trace-events | 4 ++++ tests/qemu-iotests/083.out | 28 ---------------------------- 3 files changed, 23 insertions(+), 32 deletions(-) diff --git a/block/nbd-client.c b/block/nbd-client.c index fc5b7eda8ee..ef320759716 100644 --- a/block/nbd-client.c +++ b/block/nbd-client.c @@ -28,6 +28,8 @@ */ #include "qemu/osdep.h" + +#include "trace.h" #include "qapi/error.h" #include "nbd-client.h" @@ -79,7 +81,8 @@ static coroutine_fn void nbd_read_reply_entry(void *opaqu= e) assert(s->reply.handle =3D=3D 0); ret =3D nbd_receive_reply(s->ioc, &s->reply, &local_err); if (local_err) { - error_report_err(local_err); + trace_nbd_read_reply_entry_fail(ret, error_get_pretty(local_er= r)); + error_free(local_err); } if (ret <=3D 0) { break; @@ -771,7 +774,11 @@ static int nbd_co_request(BlockDriverState *bs, NBDReq= uest *request, ret =3D nbd_co_receive_return_code(client, request->handle, &local_err= ); if (local_err) { - error_report_err(local_err); + trace_nbd_co_request_fail(request->from, request->len, request->ha= ndle, + request->flags, request->type, + nbd_cmd_lookup(request->type), + ret, error_get_pretty(local_err)); + error_free(local_err); } return ret; } @@ -802,7 +809,11 @@ int nbd_client_co_preadv(BlockDriverState *bs, uint64_= t offset, ret =3D nbd_co_receive_cmdread_reply(client, request.handle, offset, q= iov, &local_err); if (local_err) { - error_report_err(local_err); + trace_nbd_co_request_fail(request.from, request.len, request.handl= e, + request.flags, request.type, + nbd_cmd_lookup(request.type), + ret, error_get_pretty(local_err)); + error_free(local_err); } return ret; } @@ -925,7 +936,11 @@ int coroutine_fn nbd_client_co_block_status(BlockDrive= rState *bs, ret =3D nbd_co_receive_blockstatus_reply(client, request.handle, bytes, &extent, &local_err); if (local_err) { - error_report_err(local_err); + trace_nbd_co_request_fail(request.from, request.len, request.handl= e, + request.flags, request.type, + nbd_cmd_lookup(request.type), + ret, error_get_pretty(local_err)); + error_free(local_err); } if (ret < 0) { return ret; diff --git a/block/trace-events b/block/trace-events index 3e8c47bb243..693c14c4435 100644 --- a/block/trace-events +++ b/block/trace-events @@ -156,3 +156,7 @@ nvme_cmd_map_qiov_iov(void *s, int i, void *page, int p= ages) "s %p iov[%d] %p pa # block/iscsi.c iscsi_xcopy(void *src_lun, uint64_t src_off, void *dst_lun, uint64_t dst_o= ff, uint64_t bytes, int ret) "src_lun %p offset %"PRIu64" dst_lun %p offset= %"PRIu64" bytes %"PRIu64" ret %d" + +# block/nbd-client.c +nbd_read_reply_entry_fail(int ret, const char *err) "ret =3D %d, err: %s" +nbd_co_request_fail(uint64_t from, uint32_t len, uint64_t handle, uint16_t= flags, uint16_t type, const char *name, int ret, const char *err) "Request= failed { .from =3D %" PRIu64", .len =3D %" PRIu32 ", .handle =3D %" PRIu64= ", .flags =3D 0x%" PRIx16 ", .type =3D %" PRIu16 " (%s) } ret =3D %d, err:= %s" diff --git a/tests/qemu-iotests/083.out b/tests/qemu-iotests/083.out index f9af8bb6918..7419722cd7a 100644 --- a/tests/qemu-iotests/083.out +++ b/tests/qemu-iotests/083.out @@ -41,8 +41,6 @@ can't open device nbd+tcp://127.0.0.1:PORT/foo =3D=3D=3D Check disconnect after neg2 =3D=3D=3D -Unable to read from socket: Connection reset by peer -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect 8 neg2 =3D=3D=3D @@ -55,40 +53,30 @@ can't open device nbd+tcp://127.0.0.1:PORT/foo =3D=3D=3D Check disconnect before request =3D=3D=3D -Unable to read from socket: Connection reset by peer -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect after request =3D=3D=3D -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect before reply =3D=3D=3D -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect after reply =3D=3D=3D -Unexpected end-of-file before all bytes were read read failed: Input/output error =3D=3D=3D Check disconnect 4 reply =3D=3D=3D -Unexpected end-of-file before all bytes were read -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect 8 reply =3D=3D=3D -Unexpected end-of-file before all bytes were read -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect before data =3D=3D=3D -Unexpected end-of-file before all bytes were read read failed: Input/output error =3D=3D=3D Check disconnect after data =3D=3D=3D @@ -118,8 +106,6 @@ can't open device nbd+tcp://127.0.0.1:PORT/ =3D=3D=3D Check disconnect after neg-classic =3D=3D=3D -Unable to read from socket: Connection reset by peer -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect before neg1 =3D=3D=3D @@ -164,8 +150,6 @@ can't open device nbd+unix:///foo?socket=3DTEST_DIR/nbd= .sock =3D=3D=3D Check disconnect after neg2 =3D=3D=3D -Unable to read from socket: Connection reset by peer -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect 8 neg2 =3D=3D=3D @@ -178,40 +162,30 @@ can't open device nbd+unix:///foo?socket=3DTEST_DIR/n= bd.sock =3D=3D=3D Check disconnect before request =3D=3D=3D -Unable to read from socket: Connection reset by peer -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect after request =3D=3D=3D -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect before reply =3D=3D=3D -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect after reply =3D=3D=3D -Unexpected end-of-file before all bytes were read read failed: Input/output error =3D=3D=3D Check disconnect 4 reply =3D=3D=3D -Unexpected end-of-file before all bytes were read -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect 8 reply =3D=3D=3D -Unexpected end-of-file before all bytes were read -Connection closed read failed: Input/output error =3D=3D=3D Check disconnect before data =3D=3D=3D -Unexpected end-of-file before all bytes were read read failed: Input/output error =3D=3D=3D Check disconnect after data =3D=3D=3D @@ -241,8 +215,6 @@ can't open device nbd+unix:///?socket=3DTEST_DIR/nbd.so= ck =3D=3D=3D Check disconnect after neg-classic =3D=3D=3D -Unable to read from socket: Connection reset by peer -Connection closed read failed: Input/output error *** done --=20 2.17.2