From patchwork Thu Dec 23 08:36:53 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Maxime Coquelin X-Patchwork-Id: 105358 X-Patchwork-Delegate: maxime.coquelin@redhat.com Return-Path: X-Original-To: patchwork@inbox.dpdk.org Delivered-To: patchwork@inbox.dpdk.org Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id 11199A0350; Thu, 23 Dec 2021 09:37:40 +0100 (CET) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id D124A4114D; Thu, 23 Dec 2021 09:37:36 +0100 (CET) Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.129.124]) by mails.dpdk.org (Postfix) with ESMTP id 7A400410F1 for ; Thu, 23 Dec 2021 09:37:34 +0100 (CET) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1640248654; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=fplIkD8anLTw8NFD4lK3SKZi3NSH189BmPk7Zq/mF00=; b=P+W7reITW1XALR1GDRPLr0v6a9pAbjn96EDtHgC7V4hvWc57Rzzbrb0jz0btD5p9ZYcOyb 1oTg9GNSIxQZXNhVFkEpXh9rHNZkt7FrJxrqPl67eT6lJx7MXNvPT1zYCfmSggvhZzeuFv 8sNunLzYT/AGoec+pIPb5R/zfrZ6Yoo= Received: from mimecast-mx01.redhat.com (mimecast-mx01.redhat.com [209.132.183.4]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-435-MPVheFg8PASUwf04KzVtBg-1; Thu, 23 Dec 2021 03:37:30 -0500 X-MC-Unique: MPVheFg8PASUwf04KzVtBg-1 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 mimecast-mx01.redhat.com (Postfix) with ESMTPS id 91E28100C623; Thu, 23 Dec 2021 08:37:29 +0000 (UTC) Received: from max-t490s.redhat.com (unknown [10.39.208.14]) by smtp.corp.redhat.com (Postfix) with ESMTP id CC5ED5BD14; Thu, 23 Dec 2021 08:37:19 +0000 (UTC) From: Maxime Coquelin To: dev@dpdk.org, chenbo.xia@intel.com, david.marchand@redhat.com Cc: Maxime Coquelin Subject: [PATCH 1/7] vhost: improve IOTLB logs Date: Thu, 23 Dec 2021 09:36:53 +0100 Message-Id: <20211223083659.245766-2-maxime.coquelin@redhat.com> In-Reply-To: <20211223083659.245766-1-maxime.coquelin@redhat.com> References: <20211223083659.245766-1-maxime.coquelin@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=maxime.coquelin@redhat.com X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org This patch adds IOTLB mempool name when logging debug or error messages, and also prepends the socket path. to all the logs. Signed-off-by: Maxime Coquelin --- lib/vhost/iotlb.c | 26 +++++++++++++++----------- lib/vhost/iotlb.h | 10 +++++----- lib/vhost/vhost.c | 2 +- lib/vhost/vhost_user.c | 2 +- 4 files changed, 22 insertions(+), 18 deletions(-) diff --git a/lib/vhost/iotlb.c b/lib/vhost/iotlb.c index 82bdb84526..e9e1ede7a4 100644 --- a/lib/vhost/iotlb.c +++ b/lib/vhost/iotlb.c @@ -62,7 +62,7 @@ vhost_user_iotlb_pending_miss(struct vhost_virtqueue *vq, uint64_t iova, } void -vhost_user_iotlb_pending_insert(struct vhost_virtqueue *vq, +vhost_user_iotlb_pending_insert(struct virtio_net *dev, struct vhost_virtqueue *vq, uint64_t iova, uint8_t perm) { struct vhost_iotlb_entry *node; @@ -70,14 +70,16 @@ vhost_user_iotlb_pending_insert(struct vhost_virtqueue *vq, ret = rte_mempool_get(vq->iotlb_pool, (void **)&node); if (ret) { - VHOST_LOG_CONFIG(DEBUG, "IOTLB pool empty, clear entries\n"); + VHOST_LOG_CONFIG(DEBUG, "(%s) IOTLB pool %s empty, clear entries\n", + dev->ifname, vq->iotlb_pool->name); if (!TAILQ_EMPTY(&vq->iotlb_pending_list)) vhost_user_iotlb_pending_remove_all(vq); else vhost_user_iotlb_cache_random_evict(vq); ret = rte_mempool_get(vq->iotlb_pool, (void **)&node); if (ret) { - VHOST_LOG_CONFIG(ERR, "IOTLB pool still empty, failure\n"); + VHOST_LOG_CONFIG(ERR, "(%s) IOTLB pool %s still empty, failure\n", + dev->ifname, vq->iotlb_pool->name); return; } } @@ -156,22 +158,25 @@ vhost_user_iotlb_cache_random_evict(struct vhost_virtqueue *vq) } void -vhost_user_iotlb_cache_insert(struct vhost_virtqueue *vq, uint64_t iova, - uint64_t uaddr, uint64_t size, uint8_t perm) +vhost_user_iotlb_cache_insert(struct virtio_net *dev, struct vhost_virtqueue *vq, + uint64_t iova, uint64_t uaddr, + uint64_t size, uint8_t perm) { struct vhost_iotlb_entry *node, *new_node; int ret; ret = rte_mempool_get(vq->iotlb_pool, (void **)&new_node); if (ret) { - VHOST_LOG_CONFIG(DEBUG, "IOTLB pool empty, clear entries\n"); + VHOST_LOG_CONFIG(DEBUG, "(%s) IOTLB pool %s empty, clear entries\n", + dev->ifname, vq->iotlb_pool->name); if (!TAILQ_EMPTY(&vq->iotlb_list)) vhost_user_iotlb_cache_random_evict(vq); else vhost_user_iotlb_pending_remove_all(vq); ret = rte_mempool_get(vq->iotlb_pool, (void **)&new_node); if (ret) { - VHOST_LOG_CONFIG(ERR, "IOTLB pool still empty, failure\n"); + VHOST_LOG_CONFIG(ERR, "(%s) IOTLB pool %s still empty, failure\n", + dev->ifname, vq->iotlb_pool->name); return; } } @@ -311,7 +316,7 @@ vhost_user_iotlb_init(struct virtio_net *dev, int vq_index) snprintf(pool_name, sizeof(pool_name), "iotlb_%u_%d_%d", getpid(), dev->vid, vq_index); - VHOST_LOG_CONFIG(DEBUG, "IOTLB cache name: %s\n", pool_name); + VHOST_LOG_CONFIG(DEBUG, "(%s) IOTLB cache name: %s\n", dev->ifname, pool_name); /* If already created, free it and recreate */ vq->iotlb_pool = rte_mempool_lookup(pool_name); @@ -324,9 +329,8 @@ vhost_user_iotlb_init(struct virtio_net *dev, int vq_index) RTE_MEMPOOL_F_NO_CACHE_ALIGN | RTE_MEMPOOL_F_SP_PUT); if (!vq->iotlb_pool) { - VHOST_LOG_CONFIG(ERR, - "Failed to create IOTLB cache pool (%s)\n", - pool_name); + VHOST_LOG_CONFIG(ERR, "(%s) Failed to create IOTLB cache pool (%s)\n", + dev->ifname, pool_name); return -1; } diff --git a/lib/vhost/iotlb.h b/lib/vhost/iotlb.h index b6e0757ad6..8d0ff7473b 100644 --- a/lib/vhost/iotlb.h +++ b/lib/vhost/iotlb.h @@ -33,17 +33,17 @@ vhost_user_iotlb_wr_unlock(struct vhost_virtqueue *vq) rte_rwlock_write_unlock(&vq->iotlb_lock); } -void vhost_user_iotlb_cache_insert(struct vhost_virtqueue *vq, uint64_t iova, - uint64_t uaddr, uint64_t size, - uint8_t perm); +void vhost_user_iotlb_cache_insert(struct virtio_net *dev, struct vhost_virtqueue *vq, + uint64_t iova, uint64_t uaddr, + uint64_t size, uint8_t perm); void vhost_user_iotlb_cache_remove(struct vhost_virtqueue *vq, uint64_t iova, uint64_t size); uint64_t vhost_user_iotlb_cache_find(struct vhost_virtqueue *vq, uint64_t iova, uint64_t *size, uint8_t perm); bool vhost_user_iotlb_pending_miss(struct vhost_virtqueue *vq, uint64_t iova, uint8_t perm); -void vhost_user_iotlb_pending_insert(struct vhost_virtqueue *vq, uint64_t iova, - uint8_t perm); +void vhost_user_iotlb_pending_insert(struct virtio_net *dev, struct vhost_virtqueue *vq, + uint64_t iova, uint8_t perm); void vhost_user_iotlb_pending_remove(struct vhost_virtqueue *vq, uint64_t iova, uint64_t size, uint8_t perm); void vhost_user_iotlb_flush_all(struct vhost_virtqueue *vq); diff --git a/lib/vhost/vhost.c b/lib/vhost/vhost.c index 13a9bb9dd1..e52d7f7bb6 100644 --- a/lib/vhost/vhost.c +++ b/lib/vhost/vhost.c @@ -56,7 +56,7 @@ __vhost_iova_to_vva(struct virtio_net *dev, struct vhost_virtqueue *vq, */ vhost_user_iotlb_rd_unlock(vq); - vhost_user_iotlb_pending_insert(vq, iova, perm); + vhost_user_iotlb_pending_insert(dev, vq, iova, perm); if (vhost_user_iotlb_miss(dev, iova, perm)) { VHOST_LOG_CONFIG(ERR, "IOTLB miss req failed for IOVA 0x%" PRIx64 "\n", diff --git a/lib/vhost/vhost_user.c b/lib/vhost/vhost_user.c index a781346c4d..67934be12c 100644 --- a/lib/vhost/vhost_user.c +++ b/lib/vhost/vhost_user.c @@ -2563,7 +2563,7 @@ vhost_user_iotlb_msg(struct virtio_net **pdev, struct VhostUserMsg *msg, if (!vq) continue; - vhost_user_iotlb_cache_insert(vq, imsg->iova, vva, + vhost_user_iotlb_cache_insert(dev, vq, imsg->iova, vva, len, imsg->perm); if (is_vring_iotlb(dev, vq, imsg)) From patchwork Thu Dec 23 08:36:54 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Maxime Coquelin X-Patchwork-Id: 105357 X-Patchwork-Delegate: maxime.coquelin@redhat.com Return-Path: X-Original-To: patchwork@inbox.dpdk.org Delivered-To: patchwork@inbox.dpdk.org Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id 9C020A0350; Thu, 23 Dec 2021 09:37:34 +0100 (CET) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 8671A410FC; Thu, 23 Dec 2021 09:37:34 +0100 (CET) Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.129.124]) by mails.dpdk.org (Postfix) with ESMTP id 9F5DD410F1 for ; Thu, 23 Dec 2021 09:37:33 +0100 (CET) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1640248653; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=7kUdPOZ7SLkszbtcJcUQGeQwXSEhrx+/udL0sHKDRJ4=; b=Rt1SXIzqYkh4S78QaYgF6i150QVVM1xU4VcWon3KpeEfdSNh0qj5kDnBuPfxhtNV951OAA Z/WqdDYsF3o0LSQw2QQ9QFUlZwWvJmaraq6E4iIYzs5EOeKcybiZf/oL0LXynq7Nzl2ZZj A5Z+cW7F8ERcPDD4KdrSQxEOHI6HcE0= Received: from mimecast-mx01.redhat.com (mimecast-mx01.redhat.com [209.132.183.4]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-307-ZWdfVlXyNquJYNhhVkpJdg-1; Thu, 23 Dec 2021 03:37:32 -0500 X-MC-Unique: ZWdfVlXyNquJYNhhVkpJdg-1 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 mimecast-mx01.redhat.com (Postfix) with ESMTPS id 0EFFF1923E29; Thu, 23 Dec 2021 08:37:31 +0000 (UTC) Received: from max-t490s.redhat.com (unknown [10.39.208.14]) by smtp.corp.redhat.com (Postfix) with ESMTP id E8CB55BD14; Thu, 23 Dec 2021 08:37:29 +0000 (UTC) From: Maxime Coquelin To: dev@dpdk.org, chenbo.xia@intel.com, david.marchand@redhat.com Cc: Maxime Coquelin Subject: [PATCH 2/7] vhost: improve vDPA registration failure log Date: Thu, 23 Dec 2021 09:36:54 +0100 Message-Id: <20211223083659.245766-3-maxime.coquelin@redhat.com> In-Reply-To: <20211223083659.245766-1-maxime.coquelin@redhat.com> References: <20211223083659.245766-1-maxime.coquelin@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=maxime.coquelin@redhat.com X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org This patchs adds name of the device failing vDPA registration. Signed-off-by: Maxime Coquelin --- lib/vhost/vdpa.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/lib/vhost/vdpa.c b/lib/vhost/vdpa.c index 09ad5d866e..6df2230a67 100644 --- a/lib/vhost/vdpa.c +++ b/lib/vhost/vdpa.c @@ -82,8 +82,8 @@ rte_vdpa_register_device(struct rte_device *rte_dev, !ops->get_protocol_features || !ops->dev_conf || !ops->dev_close || !ops->set_vring_state || !ops->set_features) { - VHOST_LOG_CONFIG(ERR, - "Some mandatory vDPA ops aren't implemented\n"); + VHOST_LOG_CONFIG(ERR, "(%s) Some mandatory vDPA ops aren't implemented\n", + rte_dev->name); return NULL; } From patchwork Thu Dec 23 08:36:55 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Maxime Coquelin X-Patchwork-Id: 105359 X-Patchwork-Delegate: maxime.coquelin@redhat.com Return-Path: X-Original-To: patchwork@inbox.dpdk.org Delivered-To: patchwork@inbox.dpdk.org Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id C5F1CA0350; Thu, 23 Dec 2021 09:37:44 +0100 (CET) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id B799E41152; Thu, 23 Dec 2021 09:37:37 +0100 (CET) Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.133.124]) by mails.dpdk.org (Postfix) with ESMTP id D888841142 for ; Thu, 23 Dec 2021 09:37:35 +0100 (CET) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1640248655; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=ScOTJKSy5HnU+4Eq0/8FGmCWp3zPURtjfjI0dwg0yj8=; b=iVkPTxL2bJAlY3J+VkQzydvPCnue0quRLQWuMijdRrMWEDfdfWPtukHRqorgKfrEit7a+n AbThO5W3+QDjVZcABPrg8X9NjOUe7u0XAR/yizS4bac4oth9C+HONjyxuLc6jtvI7fPqYU sX51vBbBEjMNuuQKjcGaiJDxZrVkMMM= Received: from mimecast-mx01.redhat.com (mimecast-mx01.redhat.com [209.132.183.4]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-486-reaFOoaOP1a0FO5uNNNLYw-1; Thu, 23 Dec 2021 03:37:33 -0500 X-MC-Unique: reaFOoaOP1a0FO5uNNNLYw-1 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 mimecast-mx01.redhat.com (Postfix) with ESMTPS id 9A17E344AF; Thu, 23 Dec 2021 08:37:32 +0000 (UTC) Received: from max-t490s.redhat.com (unknown [10.39.208.14]) by smtp.corp.redhat.com (Postfix) with ESMTP id 698A660BD8; Thu, 23 Dec 2021 08:37:31 +0000 (UTC) From: Maxime Coquelin To: dev@dpdk.org, chenbo.xia@intel.com, david.marchand@redhat.com Cc: Maxime Coquelin Subject: [PATCH 3/7] vhost: improve socket layer logs Date: Thu, 23 Dec 2021 09:36:55 +0100 Message-Id: <20211223083659.245766-4-maxime.coquelin@redhat.com> In-Reply-To: <20211223083659.245766-1-maxime.coquelin@redhat.com> References: <20211223083659.245766-1-maxime.coquelin@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=maxime.coquelin@redhat.com X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org This patch adds the Vhost socket path whenever possible in order to make debugging possible when multiple Vhost devices are in use. Signed-off-by: Maxime Coquelin --- lib/vhost/socket.c | 129 ++++++++++++++++++--------------------------- 1 file changed, 51 insertions(+), 78 deletions(-) diff --git a/lib/vhost/socket.c b/lib/vhost/socket.c index 82963c1e6d..fd6b3a3ee4 100644 --- a/lib/vhost/socket.c +++ b/lib/vhost/socket.c @@ -124,12 +124,12 @@ read_fd_message(int sockfd, char *buf, int buflen, int *fds, int max_fds, ret = recvmsg(sockfd, &msgh, 0); if (ret <= 0) { if (ret) - VHOST_LOG_CONFIG(ERR, "recvmsg failed\n"); + VHOST_LOG_CONFIG(ERR, "recvmsg failed (fd %d)\n", sockfd); return ret; } if (msgh.msg_flags & (MSG_TRUNC | MSG_CTRUNC)) { - VHOST_LOG_CONFIG(ERR, "truncated msg\n"); + VHOST_LOG_CONFIG(ERR, "truncated msg (fd %d)\n", sockfd); return -1; } @@ -192,7 +192,7 @@ send_fd_message(int sockfd, char *buf, int buflen, int *fds, int fd_num) } while (ret < 0 && errno == EINTR); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, "sendmsg error\n"); + VHOST_LOG_CONFIG(ERR, "sendmsg error (fd %d)\n", sockfd); return ret; } @@ -243,14 +243,14 @@ vhost_user_add_connection(int fd, struct vhost_user_socket *vsocket) dev->async_copy = 1; } - VHOST_LOG_CONFIG(INFO, "new device, handle is %d, path is %s\n", vid, vsocket->path); + VHOST_LOG_CONFIG(INFO, "(%s) new device, handle is %d\n", vsocket->path, vid); if (vsocket->notify_ops->new_connection) { ret = vsocket->notify_ops->new_connection(vid); if (ret < 0) { VHOST_LOG_CONFIG(ERR, - "failed to add vhost user connection with fd %d\n", - fd); + "(%s) failed to add vhost user connection with fd %d\n", + vsocket->path, fd); goto err_cleanup; } } @@ -261,9 +261,8 @@ vhost_user_add_connection(int fd, struct vhost_user_socket *vsocket) ret = fdset_add(&vhost_user.fdset, fd, vhost_user_read_cb, NULL, conn); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, - "failed to add fd %d into vhost server fdset\n", - fd); + VHOST_LOG_CONFIG(ERR, "(%s) failed to add fd %d into vhost server fdset\n", + vsocket->path, fd); if (vsocket->notify_ops->destroy_connection) vsocket->notify_ops->destroy_connection(conn->vid); @@ -295,7 +294,8 @@ vhost_user_server_new_connection(int fd, void *dat, int *remove __rte_unused) if (fd < 0) return; - VHOST_LOG_CONFIG(INFO, "new vhost user connection is %d\n", fd); + VHOST_LOG_CONFIG(INFO, "(%s) new vhost user connection is %d\n", + vsocket->path, fd); vhost_user_add_connection(fd, vsocket); } @@ -343,13 +343,13 @@ create_unix_socket(struct vhost_user_socket *vsocket) fd = socket(AF_UNIX, SOCK_STREAM, 0); if (fd < 0) return -1; - VHOST_LOG_CONFIG(INFO, "vhost-user %s: socket created, fd: %d\n", - vsocket->is_server ? "server" : "client", fd); + VHOST_LOG_CONFIG(INFO, "(%s) vhost-user %s: socket created, fd: %d\n", + vsocket->path, vsocket->is_server ? "server" : "client", fd); if (!vsocket->is_server && fcntl(fd, F_SETFL, O_NONBLOCK)) { VHOST_LOG_CONFIG(ERR, - "vhost-user: can't set nonblocking mode for socket, fd: " - "%d (%s)\n", fd, strerror(errno)); + "(%s) vhost-user: can't set nonblocking mode for socket, fd: %d (%s)\n", + vsocket->path, fd, strerror(errno)); close(fd); return -1; } @@ -382,12 +382,11 @@ vhost_user_start_server(struct vhost_user_socket *vsocket) */ ret = bind(fd, (struct sockaddr *)&vsocket->un, sizeof(vsocket->un)); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, - "failed to bind to %s: %s; remove it and try again\n", + VHOST_LOG_CONFIG(ERR, "(%s) failed to bind: %s; remove it and try again\n", path, strerror(errno)); goto err; } - VHOST_LOG_CONFIG(INFO, "bind to %s\n", path); + VHOST_LOG_CONFIG(INFO, "(%s) binding succeeded\n", path); ret = listen(fd, MAX_VIRTIO_BACKLOG); if (ret < 0) @@ -397,8 +396,8 @@ vhost_user_start_server(struct vhost_user_socket *vsocket) NULL, vsocket); if (ret < 0) { VHOST_LOG_CONFIG(ERR, - "failed to add listen fd %d to vhost server fdset\n", - fd); + "(%s) failed to add listen fd %d to vhost server fdset\n", + path, fd); goto err; } @@ -437,13 +436,11 @@ vhost_user_connect_nonblock(int fd, struct sockaddr *un, size_t sz) flags = fcntl(fd, F_GETFL, 0); if (flags < 0) { - VHOST_LOG_CONFIG(ERR, - "can't get flags for connfd %d\n", fd); + VHOST_LOG_CONFIG(ERR, "can't get flags for connfd %d\n", fd); return -2; } if ((flags & O_NONBLOCK) && fcntl(fd, F_SETFL, flags & ~O_NONBLOCK)) { - VHOST_LOG_CONFIG(ERR, - "can't disable nonblocking on fd %d\n", fd); + VHOST_LOG_CONFIG(ERR, "can't disable nonblocking on fd %d\n", fd); return -2; } return 0; @@ -471,16 +468,14 @@ vhost_user_client_reconnect(void *arg __rte_unused) sizeof(reconn->un)); if (ret == -2) { close(reconn->fd); - VHOST_LOG_CONFIG(ERR, - "reconnection for fd %d failed\n", - reconn->fd); + VHOST_LOG_CONFIG(ERR, "(%s) reconnection for fd %d failed\n", + reconn->vsocket->path, reconn->fd); goto remove_fd; } if (ret == -1) continue; - VHOST_LOG_CONFIG(INFO, - "%s: connected\n", reconn->vsocket->path); + VHOST_LOG_CONFIG(INFO, "%s: connected\n", reconn->vsocket->path); vhost_user_add_connection(reconn->fd, reconn->vsocket); remove_fd: TAILQ_REMOVE(&reconn_list.head, reconn, next); @@ -510,10 +505,8 @@ vhost_user_reconnect_init(void) vhost_user_client_reconnect, NULL); if (ret != 0) { VHOST_LOG_CONFIG(ERR, "failed to create reconnect thread"); - if (pthread_mutex_destroy(&reconn_list.mutex)) { - VHOST_LOG_CONFIG(ERR, - "failed to destroy reconnect mutex"); - } + if (pthread_mutex_destroy(&reconn_list.mutex)) + VHOST_LOG_CONFIG(ERR, "failed to destroy reconnect mutex"); } return ret; @@ -534,20 +527,17 @@ vhost_user_start_client(struct vhost_user_socket *vsocket) return 0; } - VHOST_LOG_CONFIG(WARNING, - "failed to connect to %s: %s\n", - path, strerror(errno)); + VHOST_LOG_CONFIG(WARNING, "(%s) failed to connect: %s\n", path, strerror(errno)); if (ret == -2 || !vsocket->reconnect) { close(fd); return -1; } - VHOST_LOG_CONFIG(INFO, "%s: reconnecting...\n", path); + VHOST_LOG_CONFIG(INFO, "(%s) reconnecting...\n", path); reconn = malloc(sizeof(*reconn)); if (reconn == NULL) { - VHOST_LOG_CONFIG(ERR, - "failed to allocate memory for reconnect\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate memory for reconnect\n", path); close(fd); return -1; } @@ -701,8 +691,7 @@ rte_vhost_driver_get_features(const char *path, uint64_t *features) pthread_mutex_lock(&vhost_user.mutex); vsocket = find_vhost_user_socket(path); if (!vsocket) { - VHOST_LOG_CONFIG(ERR, - "socket file %s is not registered yet.\n", path); + VHOST_LOG_CONFIG(ERR, "(%s) socket file is not registered yet.\n", path); ret = -1; goto unlock_exit; } @@ -714,9 +703,7 @@ rte_vhost_driver_get_features(const char *path, uint64_t *features) } if (vdpa_dev->ops->get_features(vdpa_dev, &vdpa_features) < 0) { - VHOST_LOG_CONFIG(ERR, - "failed to get vdpa features " - "for socket file %s.\n", path); + VHOST_LOG_CONFIG(ERR, "(%s) failed to get vdpa features for socket file.\n", path); ret = -1; goto unlock_exit; } @@ -754,8 +741,7 @@ rte_vhost_driver_get_protocol_features(const char *path, pthread_mutex_lock(&vhost_user.mutex); vsocket = find_vhost_user_socket(path); if (!vsocket) { - VHOST_LOG_CONFIG(ERR, - "socket file %s is not registered yet.\n", path); + VHOST_LOG_CONFIG(ERR, "(%s) socket file is not registered yet.\n", path); ret = -1; goto unlock_exit; } @@ -768,9 +754,8 @@ rte_vhost_driver_get_protocol_features(const char *path, if (vdpa_dev->ops->get_protocol_features(vdpa_dev, &vdpa_protocol_features) < 0) { - VHOST_LOG_CONFIG(ERR, - "failed to get vdpa protocol features " - "for socket file %s.\n", path); + VHOST_LOG_CONFIG(ERR, "(%s) failed to get vdpa protocol features.\n", + path); ret = -1; goto unlock_exit; } @@ -794,8 +779,7 @@ rte_vhost_driver_get_queue_num(const char *path, uint32_t *queue_num) pthread_mutex_lock(&vhost_user.mutex); vsocket = find_vhost_user_socket(path); if (!vsocket) { - VHOST_LOG_CONFIG(ERR, - "socket file %s is not registered yet.\n", path); + VHOST_LOG_CONFIG(ERR, "(%s) socket file is not registered yet.\n", path); ret = -1; goto unlock_exit; } @@ -807,9 +791,8 @@ rte_vhost_driver_get_queue_num(const char *path, uint32_t *queue_num) } if (vdpa_dev->ops->get_queue_num(vdpa_dev, &vdpa_queue_num) < 0) { - VHOST_LOG_CONFIG(ERR, - "failed to get vdpa queue number " - "for socket file %s.\n", path); + VHOST_LOG_CONFIG(ERR, "(%s) failed to get vdpa queue number.\n", + path); ret = -1; goto unlock_exit; } @@ -852,8 +835,8 @@ rte_vhost_driver_register(const char *path, uint64_t flags) pthread_mutex_lock(&vhost_user.mutex); if (vhost_user.vsocket_cnt == MAX_VHOST_SOCKET) { - VHOST_LOG_CONFIG(ERR, - "error: the number of vhost sockets reaches maximum\n"); + VHOST_LOG_CONFIG(ERR, "(%s) the number of vhost sockets reaches maximum\n", + path); goto out; } @@ -863,16 +846,14 @@ rte_vhost_driver_register(const char *path, uint64_t flags) memset(vsocket, 0, sizeof(struct vhost_user_socket)); vsocket->path = strdup(path); if (vsocket->path == NULL) { - VHOST_LOG_CONFIG(ERR, - "error: failed to copy socket path string\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to copy socket path string\n", path); vhost_user_socket_mem_free(vsocket); goto out; } TAILQ_INIT(&vsocket->conn_list); ret = pthread_mutex_init(&vsocket->conn_mutex, NULL); if (ret) { - VHOST_LOG_CONFIG(ERR, - "error: failed to init connection mutex\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to init connection mutex\n", path); goto out_free; } vsocket->vdpa_dev = NULL; @@ -884,9 +865,8 @@ rte_vhost_driver_register(const char *path, uint64_t flags) if (vsocket->async_copy && (flags & (RTE_VHOST_USER_IOMMU_SUPPORT | RTE_VHOST_USER_POSTCOPY_SUPPORT))) { - VHOST_LOG_CONFIG(ERR, "error: enabling async copy and IOMMU " - "or post-copy feature simultaneously is not " - "supported\n"); + VHOST_LOG_CONFIG(ERR, "(%s) enabling async copy and IOMMU " + "or post-copy feature simultaneously is not supported\n", path); goto out_mutex; } @@ -910,8 +890,8 @@ rte_vhost_driver_register(const char *path, uint64_t flags) if (vsocket->async_copy) { vsocket->supported_features &= ~(1ULL << VHOST_F_LOG_ALL); vsocket->features &= ~(1ULL << VHOST_F_LOG_ALL); - VHOST_LOG_CONFIG(INFO, - "Logging feature is disabled in async copy mode\n"); + VHOST_LOG_CONFIG(INFO, "(%s) logging feature is disabled in async copy mode\n", + path); } /* @@ -925,9 +905,8 @@ rte_vhost_driver_register(const char *path, uint64_t flags) (1ULL << VIRTIO_NET_F_HOST_TSO6) | (1ULL << VIRTIO_NET_F_HOST_UFO); - VHOST_LOG_CONFIG(INFO, - "Linear buffers requested without external buffers, " - "disabling host segmentation offloading support\n"); + VHOST_LOG_CONFIG(INFO, "(%s) Linear buffers requested without external buffers, " + "disabling host segmentation offloading support\n", path); vsocket->supported_features &= ~seg_offload_features; vsocket->features &= ~seg_offload_features; } @@ -942,8 +921,7 @@ rte_vhost_driver_register(const char *path, uint64_t flags) ~(1ULL << VHOST_USER_PROTOCOL_F_PAGEFAULT); } else { #ifndef RTE_LIBRTE_VHOST_POSTCOPY - VHOST_LOG_CONFIG(ERR, - "Postcopy requested but not compiled\n"); + VHOST_LOG_CONFIG(ERR, "(%s) Postcopy requested but not compiled\n", path); ret = -1; goto out_mutex; #endif @@ -970,8 +948,7 @@ rte_vhost_driver_register(const char *path, uint64_t flags) out_mutex: if (pthread_mutex_destroy(&vsocket->conn_mutex)) { - VHOST_LOG_CONFIG(ERR, - "error: failed to destroy connection mutex\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to destroy connection mutex\n", path); } out_free: vhost_user_socket_mem_free(vsocket); @@ -1059,9 +1036,7 @@ rte_vhost_driver_unregister(const char *path) goto again; } - VHOST_LOG_CONFIG(INFO, - "free connfd = %d for device '%s'\n", - conn->connfd, path); + VHOST_LOG_CONFIG(INFO, "(%s) free connfd %d\n", path, conn->connfd); close(conn->connfd); vhost_destroy_device(conn->vid); TAILQ_REMOVE(&vsocket->conn_list, conn, next); @@ -1137,8 +1112,7 @@ rte_vhost_driver_start(const char *path) * rebuild the wait list of poll. */ if (fdset_pipe_init(&vhost_user.fdset) < 0) { - VHOST_LOG_CONFIG(ERR, - "failed to create pipe for vhost fdset\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to create pipe for vhost fdset\n", path); return -1; } @@ -1146,8 +1120,7 @@ rte_vhost_driver_start(const char *path) "vhost-events", NULL, fdset_event_dispatch, &vhost_user.fdset); if (ret != 0) { - VHOST_LOG_CONFIG(ERR, - "failed to create fdset handling thread"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to create fdset handling thread", path); fdset_pipe_uninit(&vhost_user.fdset); return -1; From patchwork Thu Dec 23 08:36:56 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Maxime Coquelin X-Patchwork-Id: 105360 X-Patchwork-Delegate: maxime.coquelin@redhat.com Return-Path: X-Original-To: patchwork@inbox.dpdk.org Delivered-To: patchwork@inbox.dpdk.org Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id 5B2C3A0350; Thu, 23 Dec 2021 09:37:50 +0100 (CET) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id B695041157; Thu, 23 Dec 2021 09:37:39 +0100 (CET) Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.129.124]) by mails.dpdk.org (Postfix) with ESMTP id 9135941155 for ; Thu, 23 Dec 2021 09:37:38 +0100 (CET) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1640248658; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=MwIUU9AkyrAAk3mlArJaYbTVD+rN/2oEbG7O3VclWZQ=; b=UEYbg35VcAJFr8FmOugCZV276j3o6SsLd0wRw2DAlFpmZ2D4FQswj+hcPaKrMv7cA6JuTt IpS9xQ08f1Y3uO7w3YcDgxI+l9RxkZPv2yW/Zb2K7w3De9tQdr3LKUi3WN2FLCu2xLIhP7 wmWuDWVfOAg8tiTBgId88CR7s99bAq4= Received: from mimecast-mx01.redhat.com (mimecast-mx01.redhat.com [209.132.183.4]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-423-QEyuuk7cOs23Sf04JEnPsg-1; Thu, 23 Dec 2021 03:37:35 -0500 X-MC-Unique: QEyuuk7cOs23Sf04JEnPsg-1 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 mimecast-mx01.redhat.com (Postfix) with ESMTPS id 15D8A1023F4D; Thu, 23 Dec 2021 08:37:34 +0000 (UTC) Received: from max-t490s.redhat.com (unknown [10.39.208.14]) by smtp.corp.redhat.com (Postfix) with ESMTP id ED49F5BD14; Thu, 23 Dec 2021 08:37:32 +0000 (UTC) From: Maxime Coquelin To: dev@dpdk.org, chenbo.xia@intel.com, david.marchand@redhat.com Cc: Maxime Coquelin Subject: [PATCH 4/7] vhost: improve Vhost layer logs Date: Thu, 23 Dec 2021 09:36:56 +0100 Message-Id: <20211223083659.245766-5-maxime.coquelin@redhat.com> In-Reply-To: <20211223083659.245766-1-maxime.coquelin@redhat.com> References: <20211223083659.245766-1-maxime.coquelin@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=maxime.coquelin@redhat.com X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org This patch prepends Vhost logs with the Vhost-user socket patch when available to ease filtering logs for a given port. Signed-off-by: Maxime Coquelin --- lib/vhost/vhost.c | 104 +++++++++++++++++++++++----------------------- 1 file changed, 51 insertions(+), 53 deletions(-) diff --git a/lib/vhost/vhost.c b/lib/vhost/vhost.c index e52d7f7bb6..dac0915ac0 100644 --- a/lib/vhost/vhost.c +++ b/lib/vhost/vhost.c @@ -58,9 +58,8 @@ __vhost_iova_to_vva(struct virtio_net *dev, struct vhost_virtqueue *vq, vhost_user_iotlb_pending_insert(dev, vq, iova, perm); if (vhost_user_iotlb_miss(dev, iova, perm)) { - VHOST_LOG_CONFIG(ERR, - "IOTLB miss req failed for IOVA 0x%" PRIx64 "\n", - iova); + VHOST_LOG_DATA(ERR, "(%s) IOTLB miss req failed for IOVA 0x%" PRIx64 "\n", + dev->ifname, iova); vhost_user_iotlb_pending_remove(vq, iova, 1, perm); } @@ -126,8 +125,8 @@ __vhost_log_write_iova(struct virtio_net *dev, struct vhost_virtqueue *vq, hva = __vhost_iova_to_vva(dev, vq, iova, &map_len, VHOST_ACCESS_RW); if (map_len != len) { VHOST_LOG_DATA(ERR, - "Failed to write log for IOVA 0x%" PRIx64 ". No IOTLB entry found\n", - iova); + "(%s) failed to write log for IOVA 0x%" PRIx64 ". No IOTLB entry found\n", + dev->ifname, iova); return; } @@ -243,8 +242,8 @@ __vhost_log_cache_write_iova(struct virtio_net *dev, struct vhost_virtqueue *vq, hva = __vhost_iova_to_vva(dev, vq, iova, &map_len, VHOST_ACCESS_RW); if (map_len != len) { VHOST_LOG_DATA(ERR, - "Failed to write log for IOVA 0x%" PRIx64 ". No IOTLB entry found\n", - iova); + "(%s) failed to write log for IOVA 0x%" PRIx64 ". No IOTLB entry found\n", + dev->ifname, iova); return; } @@ -422,9 +421,9 @@ translate_log_addr(struct virtio_net *dev, struct vhost_virtqueue *vq, gpa = hva_to_gpa(dev, hva, exp_size); if (!gpa) { VHOST_LOG_CONFIG(ERR, - "VQ: Failed to find GPA for log_addr: 0x%" + "(%s) failed to find GPA for log_addr: 0x%" PRIx64 " hva: 0x%" PRIx64 "\n", - log_addr, hva); + dev->ifname, log_addr, hva); return 0; } return gpa; @@ -551,16 +550,15 @@ init_vring_queue(struct virtio_net *dev, uint32_t vring_idx) int numa_node = SOCKET_ID_ANY; if (vring_idx >= VHOST_MAX_VRING) { - VHOST_LOG_CONFIG(ERR, - "Failed not init vring, out of bound (%d)\n", - vring_idx); + VHOST_LOG_CONFIG(ERR, "(%s) failed not init vring, out of bound (%d)\n", + dev->ifname, vring_idx); return; } vq = dev->virtqueue[vring_idx]; if (!vq) { - VHOST_LOG_CONFIG(ERR, "Virtqueue not allocated (%d)\n", - vring_idx); + VHOST_LOG_CONFIG(ERR, "(%s) virtqueue not allocated (%d)\n", + dev->ifname, vring_idx); return; } @@ -572,8 +570,8 @@ init_vring_queue(struct virtio_net *dev, uint32_t vring_idx) #ifdef RTE_LIBRTE_VHOST_NUMA if (get_mempolicy(&numa_node, NULL, 0, vq, MPOL_F_NODE | MPOL_F_ADDR)) { - VHOST_LOG_CONFIG(ERR, "(%d) failed to query numa node: %s\n", - dev->vid, rte_strerror(errno)); + VHOST_LOG_CONFIG(ERR, "(%s) failed to query numa node: %s\n", + dev->ifname, rte_strerror(errno)); numa_node = SOCKET_ID_ANY; } #endif @@ -590,15 +588,15 @@ reset_vring_queue(struct virtio_net *dev, uint32_t vring_idx) if (vring_idx >= VHOST_MAX_VRING) { VHOST_LOG_CONFIG(ERR, - "Failed not init vring, out of bound (%d)\n", - vring_idx); + "(%s) failed to reset vring, out of bound (%d)\n", + dev->ifname, vring_idx); return; } vq = dev->virtqueue[vring_idx]; if (!vq) { - VHOST_LOG_CONFIG(ERR, "Virtqueue not allocated (%d)\n", - vring_idx); + VHOST_LOG_CONFIG(ERR, "(%s) failed to reset vring, virtqueue not allocated (%d)\n", + dev->ifname, vring_idx); return; } @@ -620,8 +618,8 @@ alloc_vring_queue(struct virtio_net *dev, uint32_t vring_idx) vq = rte_zmalloc(NULL, sizeof(struct vhost_virtqueue), 0); if (vq == NULL) { - VHOST_LOG_CONFIG(ERR, - "Failed to allocate memory for vring:%u.\n", i); + VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate memory for vring %u.\n", + dev->ifname, i); return -1; } @@ -673,16 +671,14 @@ vhost_new_device(void) } if (i == MAX_VHOST_DEVICE) { - VHOST_LOG_CONFIG(ERR, - "Failed to find a free slot for new device.\n"); + VHOST_LOG_CONFIG(ERR, "failed to find a free slot for new device.\n"); pthread_mutex_unlock(&vhost_dev_lock); return -1; } dev = rte_zmalloc(NULL, sizeof(struct virtio_net), 0); if (dev == NULL) { - VHOST_LOG_CONFIG(ERR, - "Failed to allocate memory for new dev.\n"); + VHOST_LOG_CONFIG(ERR, "failed to allocate memory for new device.\n"); pthread_mutex_unlock(&vhost_dev_lock); return -1; } @@ -834,9 +830,8 @@ rte_vhost_get_numa_node(int vid) ret = get_mempolicy(&numa_node, NULL, 0, dev, MPOL_F_NODE | MPOL_F_ADDR); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, - "(%d) failed to query numa node: %s\n", - vid, rte_strerror(errno)); + VHOST_LOG_CONFIG(ERR, "(%s) failed to query numa node: %s\n", + dev->ifname, rte_strerror(errno)); return -1; } @@ -1470,8 +1465,8 @@ rte_vhost_rx_queue_count(int vid, uint16_t qid) return 0; if (unlikely(qid >= dev->nr_vring || (qid & 1) == 0)) { - VHOST_LOG_DATA(ERR, "(%d) %s: invalid virtqueue idx %d.\n", - dev->vid, __func__, qid); + VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", + dev->ifname, __func__, qid); return 0; } @@ -1636,23 +1631,23 @@ async_channel_register(int vid, uint16_t queue_id, if (unlikely(vq->async)) { VHOST_LOG_CONFIG(ERR, - "async register failed: already registered (vid %d, qid: %d)\n", - vid, queue_id); + "(%s) async register failed: already registered (qid: %d)\n", + dev->ifname, queue_id); return -1; } async = rte_zmalloc_socket(NULL, sizeof(struct vhost_async), 0, node); if (!async) { - VHOST_LOG_CONFIG(ERR, "failed to allocate async metadata (vid %d, qid: %d)\n", - vid, queue_id); + VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate async metadata (qid: %d)\n", + dev->ifname, queue_id); return -1; } async->pkts_info = rte_malloc_socket(NULL, vq->size * sizeof(struct async_inflight_info), RTE_CACHE_LINE_SIZE, node); if (!async->pkts_info) { - VHOST_LOG_CONFIG(ERR, "failed to allocate async_pkts_info (vid %d, qid: %d)\n", - vid, queue_id); + VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate async_pkts_info (qid: %d)\n", + dev->ifname, queue_id); goto out_free_async; } @@ -1661,8 +1656,8 @@ async_channel_register(int vid, uint16_t queue_id, vq->size * sizeof(struct vring_used_elem_packed), RTE_CACHE_LINE_SIZE, node); if (!async->buffers_packed) { - VHOST_LOG_CONFIG(ERR, "failed to allocate async buffers (vid %d, qid: %d)\n", - vid, queue_id); + VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate async buffers (qid: %d)\n", + dev->ifname, queue_id); goto out_free_inflight; } } else { @@ -1670,8 +1665,8 @@ async_channel_register(int vid, uint16_t queue_id, vq->size * sizeof(struct vring_used_elem), RTE_CACHE_LINE_SIZE, node); if (!async->descs_split) { - VHOST_LOG_CONFIG(ERR, "failed to allocate async descs (vid %d, qid: %d)\n", - vid, queue_id); + VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate async descs (qid: %d)\n", + dev->ifname, queue_id); goto out_free_inflight; } } @@ -1712,8 +1707,8 @@ rte_vhost_async_channel_register(int vid, uint16_t queue_id, if (unlikely(!(config.features & RTE_VHOST_ASYNC_INORDER))) { VHOST_LOG_CONFIG(ERR, - "async copy is not supported on non-inorder mode " - "(vid %d, qid: %d)\n", vid, queue_id); + "(%s) async copy is not supported on non-inorder mode (qid: %d)\n", + dev->ifname, queue_id); return -1; } @@ -1749,8 +1744,8 @@ rte_vhost_async_channel_register_thread_unsafe(int vid, uint16_t queue_id, if (unlikely(!(config.features & RTE_VHOST_ASYNC_INORDER))) { VHOST_LOG_CONFIG(ERR, - "async copy is not supported on non-inorder mode " - "(vid %d, qid: %d)\n", vid, queue_id); + "(%s) async copy is not supported on non-inorder mode (qid: %d)\n", + dev->ifname, queue_id); return -1; } @@ -1785,14 +1780,15 @@ rte_vhost_async_channel_unregister(int vid, uint16_t queue_id) return ret; if (!rte_spinlock_trylock(&vq->access_lock)) { - VHOST_LOG_CONFIG(ERR, "Failed to unregister async channel. " - "virt queue busy.\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to unregister async channel, virtqueue busy.\n", + dev->ifname); return -1; } if (vq->async->pkts_inflight_n) { - VHOST_LOG_CONFIG(ERR, "Failed to unregister async channel. " - "async inflight packets must be completed before unregistration.\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to unregister async channel. " + "async inflight packets must be completed before unregistration.\n", + dev->ifname); ret = -1; goto out; } @@ -1825,8 +1821,9 @@ rte_vhost_async_channel_unregister_thread_unsafe(int vid, uint16_t queue_id) return 0; if (vq->async->pkts_inflight_n) { - VHOST_LOG_CONFIG(ERR, "Failed to unregister async channel. " - "async inflight packets must be completed before unregistration.\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to unregister async channel. " + "async inflight packets must be completed before unregistration.\n", + dev->ifname); return -1; } @@ -1857,8 +1854,9 @@ rte_vhost_async_get_inflight(int vid, uint16_t queue_id) return ret; if (!rte_spinlock_trylock(&vq->access_lock)) { - VHOST_LOG_CONFIG(DEBUG, "Failed to check in-flight packets. " - "virt queue busy.\n"); + VHOST_LOG_CONFIG(DEBUG, + "(%s) failed to check in-flight packets. virtqueue busy.\n", + dev->ifname); return ret; } From patchwork Thu Dec 23 08:36:57 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Maxime Coquelin X-Patchwork-Id: 105362 X-Patchwork-Delegate: maxime.coquelin@redhat.com Return-Path: X-Original-To: patchwork@inbox.dpdk.org Delivered-To: patchwork@inbox.dpdk.org Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id 39D4FA0350; Thu, 23 Dec 2021 09:38:19 +0100 (CET) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 29D91410E0; Thu, 23 Dec 2021 09:38:19 +0100 (CET) Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.129.124]) by mails.dpdk.org (Postfix) with ESMTP id B2FB041163 for ; Thu, 23 Dec 2021 09:37:42 +0100 (CET) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1640248662; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=j+8nDr/xKrteHZobw9ft46pZGJBK9y05Se13Gzt3zgg=; b=Ih2ZHxtld0zwh7z2WFFZ0Nw0gqTG+0EzywSGfCHTmf1YBtjxVd0wexqvjQVzohkdGS0nCe YqUQzGAV65w809x9KkcgCgbGKYy/hKIXgWvD6UWLSGXFtUM3LgQ9uIa9rZGbHdOchYt0b6 EhoUen4xfHfTcOZmRuz/j6WOeBqyfew= Received: from mimecast-mx01.redhat.com (mimecast-mx01.redhat.com [209.132.183.4]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-333-BuyGYUowO-Ojdkngb8Tv2w-1; Thu, 23 Dec 2021 03:37:40 -0500 X-MC-Unique: BuyGYUowO-Ojdkngb8Tv2w-1 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 mimecast-mx01.redhat.com (Postfix) with ESMTPS id B6ED581EE60; Thu, 23 Dec 2021 08:37:39 +0000 (UTC) Received: from max-t490s.redhat.com (unknown [10.39.208.14]) by smtp.corp.redhat.com (Postfix) with ESMTP id 7397360BD8; Thu, 23 Dec 2021 08:37:34 +0000 (UTC) From: Maxime Coquelin To: dev@dpdk.org, chenbo.xia@intel.com, david.marchand@redhat.com Cc: Maxime Coquelin Subject: [PATCH 5/7] vhost: improve Vhost-user layer logs Date: Thu, 23 Dec 2021 09:36:57 +0100 Message-Id: <20211223083659.245766-6-maxime.coquelin@redhat.com> In-Reply-To: <20211223083659.245766-1-maxime.coquelin@redhat.com> References: <20211223083659.245766-1-maxime.coquelin@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=maxime.coquelin@redhat.com X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org This patch adds the Vhost-user socket path to Vhost-user layer logs in order to ease logs filtering. Signed-off-by: Maxime Coquelin --- lib/vhost/vhost_user.c | 573 ++++++++++++++++++++--------------------- 1 file changed, 275 insertions(+), 298 deletions(-) diff --git a/lib/vhost/vhost_user.c b/lib/vhost/vhost_user.c index 67934be12c..923d619213 100644 --- a/lib/vhost/vhost_user.c +++ b/lib/vhost/vhost_user.c @@ -94,7 +94,7 @@ static const char *vhost_message_str[VHOST_USER_MAX] = { }; static int send_vhost_reply(int sockfd, struct VhostUserMsg *msg); -static int read_vhost_message(int sockfd, struct VhostUserMsg *msg); +static int read_vhost_message(struct virtio_net *dev, int sockfd, struct VhostUserMsg *msg); static void close_msg_fds(struct VhostUserMsg *msg) @@ -117,14 +117,13 @@ close_msg_fds(struct VhostUserMsg *msg) * close all FDs and return an error if this is not the case. */ static int -validate_msg_fds(struct VhostUserMsg *msg, int expected_fds) +validate_msg_fds(struct virtio_net *dev, struct VhostUserMsg *msg, int expected_fds) { if (msg->fd_num == expected_fds) return 0; - VHOST_LOG_CONFIG(ERR, - " Expect %d FDs for request %s, received %d\n", - expected_fds, + VHOST_LOG_CONFIG(ERR, "(%s) expect %d FDs for request %s, received %d\n", + dev->ifname, expected_fds, vhost_message_str[msg->request.master], msg->fd_num); @@ -144,7 +143,7 @@ get_blk_size(int fd) } static int -async_dma_map(struct rte_vhost_mem_region *region, bool do_map) +async_dma_map(struct virtio_net *dev, struct rte_vhost_mem_region *region, bool do_map) { uint64_t host_iova; int ret = 0; @@ -172,7 +171,7 @@ async_dma_map(struct rte_vhost_mem_region *region, bool do_map) if (rte_errno == ENODEV || rte_errno == ENOTSUP) return 0; - VHOST_LOG_CONFIG(ERR, "DMA engine map failed\n"); + VHOST_LOG_CONFIG(ERR, "(%s) DMA engine map failed\n", dev->ifname); /* DMA mapping errors won't stop VHST_USER_SET_MEM_TABLE. */ return 0; } @@ -188,7 +187,7 @@ async_dma_map(struct rte_vhost_mem_region *region, bool do_map) if (rte_errno == EINVAL) return 0; - VHOST_LOG_CONFIG(ERR, "DMA engine unmap failed\n"); + VHOST_LOG_CONFIG(ERR, "(%s) DMA engine unmap failed\n", dev->ifname); return ret; } } @@ -209,7 +208,7 @@ free_mem_region(struct virtio_net *dev) reg = &dev->mem->regions[i]; if (reg->host_user_addr) { if (dev->async_copy && rte_vfio_is_enabled("vfio")) - async_dma_map(reg, false); + async_dma_map(dev, reg, false); munmap(reg->mmap_addr, reg->mmap_size); close(reg->fd); @@ -287,11 +286,13 @@ vhost_user_notify_queue_state(struct virtio_net *dev, uint16_t index, * the device hasn't been initialised. */ static int -vhost_user_set_owner(struct virtio_net **pdev __rte_unused, +vhost_user_set_owner(struct virtio_net **pdev, struct VhostUserMsg *msg, int main_fd __rte_unused) { - if (validate_msg_fds(msg, 0) != 0) + struct virtio_net *dev = *pdev; + + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; return RTE_VHOST_MSG_RESULT_OK; @@ -304,7 +305,7 @@ vhost_user_reset_owner(struct virtio_net **pdev, { struct virtio_net *dev = *pdev; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; vhost_destroy_device_notify(dev); @@ -324,7 +325,7 @@ vhost_user_get_features(struct virtio_net **pdev, struct VhostUserMsg *msg, struct virtio_net *dev = *pdev; uint64_t features = 0; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; rte_vhost_driver_get_features(dev->ifname, &features); @@ -346,7 +347,7 @@ vhost_user_get_queue_num(struct virtio_net **pdev, struct VhostUserMsg *msg, struct virtio_net *dev = *pdev; uint32_t queue_num = 0; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; rte_vhost_driver_get_queue_num(dev->ifname, &queue_num); @@ -370,14 +371,13 @@ vhost_user_set_features(struct virtio_net **pdev, struct VhostUserMsg *msg, uint64_t vhost_features = 0; struct rte_vdpa_device *vdpa_dev; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; rte_vhost_driver_get_features(dev->ifname, &vhost_features); if (features & ~vhost_features) { - VHOST_LOG_CONFIG(ERR, - "(%d) received invalid negotiated features.\n", - dev->vid); + VHOST_LOG_CONFIG(ERR, "(%s) received invalid negotiated features.\n", + dev->ifname); dev->flags |= VIRTIO_DEV_FEATURES_FAILED; dev->status &= ~VIRTIO_DEVICE_STATUS_FEATURES_OK; @@ -394,9 +394,8 @@ vhost_user_set_features(struct virtio_net **pdev, struct VhostUserMsg *msg, * is enabled when the live-migration starts. */ if ((dev->features ^ features) & ~(1ULL << VHOST_F_LOG_ALL)) { - VHOST_LOG_CONFIG(ERR, - "(%d) features changed while device is running.\n", - dev->vid); + VHOST_LOG_CONFIG(ERR, "(%s) features changed while device is running.\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } @@ -413,11 +412,10 @@ vhost_user_set_features(struct virtio_net **pdev, struct VhostUserMsg *msg, } else { dev->vhost_hlen = sizeof(struct virtio_net_hdr); } - VHOST_LOG_CONFIG(INFO, - "negotiated Virtio features: 0x%" PRIx64 "\n", dev->features); - VHOST_LOG_CONFIG(DEBUG, - "(%d) mergeable RX buffers %s, virtio 1 %s\n", - dev->vid, + VHOST_LOG_CONFIG(INFO, "(%s) negotiated Virtio features: 0x%" PRIx64 "\n", + dev->ifname, dev->features); + VHOST_LOG_CONFIG(DEBUG, "(%s) mergeable RX buffers %s, virtio 1 %s\n", + dev->ifname, (dev->features & (1 << VIRTIO_NET_F_MRG_RXBUF)) ? "on" : "off", (dev->features & (1ULL << VIRTIO_F_VERSION_1)) ? "on" : "off"); @@ -461,11 +459,12 @@ vhost_user_set_vring_num(struct virtio_net **pdev, struct virtio_net *dev = *pdev; struct vhost_virtqueue *vq = dev->virtqueue[msg->payload.state.index]; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; if (msg->payload.state.num > 32768) { - VHOST_LOG_CONFIG(ERR, "invalid virtqueue size %u\n", msg->payload.state.num); + VHOST_LOG_CONFIG(ERR, "(%s) invalid virtqueue size %u\n", + dev->ifname, msg->payload.state.num); return RTE_VHOST_MSG_RESULT_ERR; } @@ -482,8 +481,8 @@ vhost_user_set_vring_num(struct virtio_net **pdev, */ if (!vq_is_packed(dev)) { if (vq->size & (vq->size - 1)) { - VHOST_LOG_CONFIG(ERR, - "invalid virtqueue size %u\n", vq->size); + VHOST_LOG_CONFIG(ERR, "(%s) invalid virtqueue size %u\n", + dev->ifname, vq->size); return RTE_VHOST_MSG_RESULT_ERR; } } @@ -497,7 +496,8 @@ vhost_user_set_vring_num(struct virtio_net **pdev, RTE_CACHE_LINE_SIZE, vq->numa_node); if (!vq->shadow_used_packed) { VHOST_LOG_CONFIG(ERR, - "failed to allocate memory for shadow used ring.\n"); + "(%s) failed to allocate memory for shadow used ring.\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } @@ -511,7 +511,8 @@ vhost_user_set_vring_num(struct virtio_net **pdev, if (!vq->shadow_used_split) { VHOST_LOG_CONFIG(ERR, - "failed to allocate memory for vq internal data.\n"); + "(%s) failed to allocate memory for vq internal data.\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } } @@ -522,8 +523,8 @@ vhost_user_set_vring_num(struct virtio_net **pdev, vq->size * sizeof(struct batch_copy_elem), RTE_CACHE_LINE_SIZE, vq->numa_node); if (!vq->batch_copy_elems) { - VHOST_LOG_CONFIG(ERR, - "failed to allocate memory for batching copy.\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate memory for batching copy.\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } @@ -559,7 +560,8 @@ numa_realloc(struct virtio_net *dev, int index) ret = get_mempolicy(&node, NULL, 0, vq->desc, MPOL_F_NODE | MPOL_F_ADDR); if (ret) { - VHOST_LOG_CONFIG(ERR, "Unable to get virtqueue %d numa information.\n", index); + VHOST_LOG_CONFIG(ERR, "(%s) unable to get virtqueue %d numa information.\n", + dev->ifname, index); return dev; } @@ -568,13 +570,14 @@ numa_realloc(struct virtio_net *dev, int index) vq = rte_realloc_socket(vq, sizeof(*vq), 0, node); if (!vq) { - VHOST_LOG_CONFIG(ERR, "Failed to realloc virtqueue %d on node %d\n", - index, node); + VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc virtqueue %d on node %d\n", + dev->ifname, index, node); return dev; } if (vq != dev->virtqueue[index]) { - VHOST_LOG_CONFIG(INFO, "reallocated virtqueue on node %d\n", node); + VHOST_LOG_CONFIG(INFO, "(%s) reallocated virtqueue on node %d\n", + dev->ifname, node); dev->virtqueue[index] = vq; vhost_user_iotlb_init(dev, index); } @@ -585,7 +588,8 @@ numa_realloc(struct virtio_net *dev, int index) sup = rte_realloc_socket(vq->shadow_used_packed, vq->size * sizeof(*sup), RTE_CACHE_LINE_SIZE, node); if (!sup) { - VHOST_LOG_CONFIG(ERR, "Failed to realloc shadow packed on node %d\n", node); + VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc shadow packed on node %d\n", + dev->ifname, node); return dev; } vq->shadow_used_packed = sup; @@ -595,7 +599,8 @@ numa_realloc(struct virtio_net *dev, int index) sus = rte_realloc_socket(vq->shadow_used_split, vq->size * sizeof(*sus), RTE_CACHE_LINE_SIZE, node); if (!sus) { - VHOST_LOG_CONFIG(ERR, "Failed to realloc shadow split on node %d\n", node); + VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc shadow split on node %d\n", + dev->ifname, node); return dev; } vq->shadow_used_split = sus; @@ -604,7 +609,8 @@ numa_realloc(struct virtio_net *dev, int index) bce = rte_realloc_socket(vq->batch_copy_elems, vq->size * sizeof(*bce), RTE_CACHE_LINE_SIZE, node); if (!bce) { - VHOST_LOG_CONFIG(ERR, "Failed to realloc batch copy elem on node %d\n", node); + VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc batch copy elem on node %d\n", + dev->ifname, node); return dev; } vq->batch_copy_elems = bce; @@ -614,7 +620,8 @@ numa_realloc(struct virtio_net *dev, int index) lc = rte_realloc_socket(vq->log_cache, sizeof(*lc) * VHOST_LOG_CACHE_NR, 0, node); if (!lc) { - VHOST_LOG_CONFIG(ERR, "Failed to realloc log cache on node %d\n", node); + VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc log cache on node %d\n", + dev->ifname, node); return dev; } vq->log_cache = lc; @@ -625,8 +632,8 @@ numa_realloc(struct virtio_net *dev, int index) ri = rte_realloc_socket(vq->resubmit_inflight, sizeof(*ri), 0, node); if (!ri) { - VHOST_LOG_CONFIG(ERR, "Failed to realloc resubmit inflight on node %d\n", - node); + VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc resubmit inflight on node %d\n", + dev->ifname, node); return dev; } vq->resubmit_inflight = ri; @@ -637,8 +644,8 @@ numa_realloc(struct virtio_net *dev, int index) rd = rte_realloc_socket(ri->resubmit_list, sizeof(*rd) * ri->resubmit_num, 0, node); if (!rd) { - VHOST_LOG_CONFIG(ERR, "Failed to realloc resubmit list on node %d\n", - node); + VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc resubmit list on node %d\n", + dev->ifname, node); return dev; } ri->resubmit_list = rd; @@ -654,7 +661,7 @@ numa_realloc(struct virtio_net *dev, int index) ret = get_mempolicy(&dev_node, NULL, 0, dev, MPOL_F_NODE | MPOL_F_ADDR); if (ret) { - VHOST_LOG_CONFIG(ERR, "Unable to get Virtio dev %d numa information.\n", dev->vid); + VHOST_LOG_CONFIG(ERR, "(%s) unable to get numa information.\n", dev->ifname); return dev; } @@ -663,18 +670,20 @@ numa_realloc(struct virtio_net *dev, int index) dev = rte_realloc_socket(old_dev, sizeof(*dev), 0, node); if (!dev) { - VHOST_LOG_CONFIG(ERR, "Failed to realloc dev on node %d\n", node); + VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc dev on node %d\n", + dev->ifname, node); return old_dev; } - VHOST_LOG_CONFIG(INFO, "reallocated device on node %d\n", node); + VHOST_LOG_CONFIG(INFO, "(%s) reallocated device on node %d\n", dev->ifname, node); vhost_devices[dev->vid] = dev; mem_size = sizeof(struct rte_vhost_memory) + sizeof(struct rte_vhost_mem_region) * dev->mem->nregions; mem = rte_realloc_socket(dev->mem, mem_size, 0, node); if (!mem) { - VHOST_LOG_CONFIG(ERR, "Failed to realloc mem table on node %d\n", node); + VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc mem table on node %d\n", + dev->ifname, node); return dev; } dev->mem = mem; @@ -682,7 +691,8 @@ numa_realloc(struct virtio_net *dev, int index) gp = rte_realloc_socket(dev->guest_pages, dev->max_guest_pages * sizeof(*gp), RTE_CACHE_LINE_SIZE, node); if (!gp) { - VHOST_LOG_CONFIG(ERR, "Failed to realloc guest pages on node %d\n", node); + VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc guest pages on node %d\n", + dev->ifname, node); return dev; } dev->guest_pages = gp; @@ -774,9 +784,8 @@ translate_ring_addresses(struct virtio_net *dev, int vq_index) vq->log_guest_addr = log_addr_to_gpa(dev, vq); if (vq->log_guest_addr == 0) { - VHOST_LOG_CONFIG(DEBUG, - "(%d) failed to map log_guest_addr.\n", - dev->vid); + VHOST_LOG_CONFIG(DEBUG, "(%s) failed to map log_guest_addr.\n", + dev->ifname); return dev; } } @@ -788,9 +797,8 @@ translate_ring_addresses(struct virtio_net *dev, int vq_index) if (vq->desc_packed == NULL || len != sizeof(struct vring_packed_desc) * vq->size) { - VHOST_LOG_CONFIG(DEBUG, - "(%d) failed to map desc_packed ring.\n", - dev->vid); + VHOST_LOG_CONFIG(DEBUG, "(%s) failed to map desc_packed ring.\n", + dev->ifname); return dev; } @@ -804,9 +812,8 @@ translate_ring_addresses(struct virtio_net *dev, int vq_index) vq, addr->avail_user_addr, &len); if (vq->driver_event == NULL || len != sizeof(struct vring_packed_desc_event)) { - VHOST_LOG_CONFIG(DEBUG, - "(%d) failed to find driver area address.\n", - dev->vid); + VHOST_LOG_CONFIG(DEBUG, "(%s) failed to find driver area address.\n", + dev->ifname); return dev; } @@ -816,9 +823,8 @@ translate_ring_addresses(struct virtio_net *dev, int vq_index) vq, addr->used_user_addr, &len); if (vq->device_event == NULL || len != sizeof(struct vring_packed_desc_event)) { - VHOST_LOG_CONFIG(DEBUG, - "(%d) failed to find device area address.\n", - dev->vid); + VHOST_LOG_CONFIG(DEBUG, "(%s) failed to find device area address.\n", + dev->ifname); return dev; } @@ -834,9 +840,7 @@ translate_ring_addresses(struct virtio_net *dev, int vq_index) vq->desc = (struct vring_desc *)(uintptr_t)ring_addr_to_vva(dev, vq, addr->desc_user_addr, &len); if (vq->desc == 0 || len != sizeof(struct vring_desc) * vq->size) { - VHOST_LOG_CONFIG(DEBUG, - "(%d) failed to map desc ring.\n", - dev->vid); + VHOST_LOG_CONFIG(DEBUG, "(%s) failed to map desc ring.\n", dev->ifname); return dev; } @@ -851,9 +855,7 @@ translate_ring_addresses(struct virtio_net *dev, int vq_index) vq->avail = (struct vring_avail *)(uintptr_t)ring_addr_to_vva(dev, vq, addr->avail_user_addr, &len); if (vq->avail == 0 || len != expected_len) { - VHOST_LOG_CONFIG(DEBUG, - "(%d) failed to map avail ring.\n", - dev->vid); + VHOST_LOG_CONFIG(DEBUG, "(%s) failed to map avail ring.\n", dev->ifname); return dev; } @@ -865,16 +867,15 @@ translate_ring_addresses(struct virtio_net *dev, int vq_index) vq->used = (struct vring_used *)(uintptr_t)ring_addr_to_vva(dev, vq, addr->used_user_addr, &len); if (vq->used == 0 || len != expected_len) { - VHOST_LOG_CONFIG(DEBUG, - "(%d) failed to map used ring.\n", - dev->vid); + VHOST_LOG_CONFIG(DEBUG, "(%s) failed to map used ring.\n", dev->ifname); return dev; } if (vq->last_used_idx != vq->used->idx) { VHOST_LOG_CONFIG(WARNING, - "last_used_idx (%u) and vq->used->idx (%u) mismatches; " + "(%s) last_used_idx (%u) and vq->used->idx (%u) mismatches; " "some packets maybe resent for Tx and dropped for Rx\n", + dev->ifname, vq->last_used_idx, vq->used->idx); vq->last_used_idx = vq->used->idx; vq->last_avail_idx = vq->used->idx; @@ -882,14 +883,11 @@ translate_ring_addresses(struct virtio_net *dev, int vq_index) vq->access_ok = true; - VHOST_LOG_CONFIG(DEBUG, "(%d) mapped address desc: %p\n", - dev->vid, vq->desc); - VHOST_LOG_CONFIG(DEBUG, "(%d) mapped address avail: %p\n", - dev->vid, vq->avail); - VHOST_LOG_CONFIG(DEBUG, "(%d) mapped address used: %p\n", - dev->vid, vq->used); - VHOST_LOG_CONFIG(DEBUG, "(%d) log_guest_addr: %" PRIx64 "\n", - dev->vid, vq->log_guest_addr); + VHOST_LOG_CONFIG(DEBUG, "(%s) mapped address desc: %p\n", dev->ifname, vq->desc); + VHOST_LOG_CONFIG(DEBUG, "(%s) mapped address avail: %p\n", dev->ifname, vq->avail); + VHOST_LOG_CONFIG(DEBUG, "(%s) mapped address used: %p\n", dev->ifname, vq->used); + VHOST_LOG_CONFIG(DEBUG, "(%s) log_guest_addr: %" PRIx64 "\n", + dev->ifname, vq->log_guest_addr); return dev; } @@ -907,7 +905,7 @@ vhost_user_set_vring_addr(struct virtio_net **pdev, struct VhostUserMsg *msg, struct vhost_vring_addr *addr = &msg->payload.addr; bool access_ok; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; if (dev->mem == NULL) @@ -951,7 +949,7 @@ vhost_user_set_vring_base(struct virtio_net **pdev, struct vhost_virtqueue *vq = dev->virtqueue[msg->payload.state.index]; uint64_t val = msg->payload.state.num; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; if (vq_is_packed(dev)) { @@ -990,7 +988,7 @@ add_one_guest_page(struct virtio_net *dev, uint64_t guest_phys_addr, dev->max_guest_pages * sizeof(*page), RTE_CACHE_LINE_SIZE); if (dev->guest_pages == NULL) { - VHOST_LOG_CONFIG(ERR, "cannot realloc guest_pages\n"); + VHOST_LOG_CONFIG(ERR, "(%s) cannot realloc guest_pages\n", dev->ifname); rte_free(old_pages); return -1; } @@ -1069,11 +1067,11 @@ dump_guest_pages(struct virtio_net *dev) page = &dev->guest_pages[i]; VHOST_LOG_CONFIG(INFO, - "guest physical page region %u\n" + "(%s) guest physical page region %u\n" "\t guest_phys_addr: %" PRIx64 "\n" "\t host_phys_addr : %" PRIx64 "\n" "\t size : %" PRIx64 "\n", - i, + dev->ifname, i, page->guest_phys_addr, page->host_phys_addr, page->size); @@ -1124,8 +1122,9 @@ vhost_user_postcopy_region_register(struct virtio_net *dev, if (ioctl(dev->postcopy_ufd, UFFDIO_REGISTER, ®_struct)) { - VHOST_LOG_CONFIG(ERR, "Failed to register ufd for region " + VHOST_LOG_CONFIG(ERR, "(%s) failed to register ufd for region " "%" PRIx64 " - %" PRIx64 " (ufd = %d) %s\n", + dev->ifname, (uint64_t)reg_struct.range.start, (uint64_t)reg_struct.range.start + (uint64_t)reg_struct.range.len - 1, @@ -1134,7 +1133,8 @@ vhost_user_postcopy_region_register(struct virtio_net *dev, return -1; } - VHOST_LOG_CONFIG(INFO, "\t userfaultfd registered for range : %" PRIx64 " - %" PRIx64 "\n", + VHOST_LOG_CONFIG(INFO, "(%s)\t userfaultfd registered for range : %" PRIx64 " - %" PRIx64 "\n", + dev->ifname, (uint64_t)reg_struct.range.start, (uint64_t)reg_struct.range.start + (uint64_t)reg_struct.range.len - 1); @@ -1180,19 +1180,18 @@ vhost_user_postcopy_register(struct virtio_net *dev, int main_fd, /* Wait for qemu to acknolwedge it's got the addresses * we've got to wait before we're allowed to generate faults. */ - if (read_vhost_message(main_fd, &ack_msg) <= 0) { - VHOST_LOG_CONFIG(ERR, - "Failed to read qemu ack on postcopy set-mem-table\n"); + if (read_vhost_message(dev, main_fd, &ack_msg) <= 0) { + VHOST_LOG_CONFIG(ERR, "(%s) failed to read qemu ack on postcopy set-mem-table\n", + dev->ifname); return -1; } - if (validate_msg_fds(&ack_msg, 0) != 0) + if (validate_msg_fds(dev, &ack_msg, 0) != 0) return -1; if (ack_msg.request.master != VHOST_USER_SET_MEM_TABLE) { - VHOST_LOG_CONFIG(ERR, - "Bad qemu ack on postcopy set-mem-table (%d)\n", - ack_msg.request.master); + VHOST_LOG_CONFIG(ERR, "(%s) bad qemu ack on postcopy set-mem-table (%d)\n", + dev->ifname, ack_msg.request.master); return -1; } @@ -1219,10 +1218,9 @@ vhost_user_mmap_region(struct virtio_net *dev, /* Check for memory_size + mmap_offset overflow */ if (mmap_offset >= -region->size) { - VHOST_LOG_CONFIG(ERR, - "mmap_offset (%#"PRIx64") and memory_size " + VHOST_LOG_CONFIG(ERR, "(%s) mmap_offset (%#"PRIx64") and memory_size " "(%#"PRIx64") overflow\n", - mmap_offset, region->size); + dev->ifname, mmap_offset, region->size); return -1; } @@ -1236,8 +1234,8 @@ vhost_user_mmap_region(struct virtio_net *dev, */ alignment = get_blk_size(region->fd); if (alignment == (uint64_t)-1) { - VHOST_LOG_CONFIG(ERR, - "couldn't get hugepage size through fstat\n"); + VHOST_LOG_CONFIG(ERR, "(%s) couldn't get hugepage size through fstat\n", + dev->ifname); return -1; } mmap_size = RTE_ALIGN_CEIL(mmap_size, alignment); @@ -1250,9 +1248,9 @@ vhost_user_mmap_region(struct virtio_net *dev, * mmap() kernel implementation would return an error, but * better catch it before and provide useful info in the logs. */ - VHOST_LOG_CONFIG(ERR, "mmap size (0x%" PRIx64 ") " + VHOST_LOG_CONFIG(ERR, "(%s) mmap size (0x%" PRIx64 ") " "or alignment (0x%" PRIx64 ") is invalid\n", - region->size + mmap_offset, alignment); + dev->ifname, region->size + mmap_offset, alignment); return -1; } @@ -1261,7 +1259,7 @@ vhost_user_mmap_region(struct virtio_net *dev, MAP_SHARED | populate, region->fd, 0); if (mmap_addr == MAP_FAILED) { - VHOST_LOG_CONFIG(ERR, "mmap failed (%s).\n", strerror(errno)); + VHOST_LOG_CONFIG(ERR, "(%s) mmap failed (%s).\n", dev->ifname, strerror(errno)); return -1; } @@ -1271,21 +1269,24 @@ vhost_user_mmap_region(struct virtio_net *dev, if (dev->async_copy) { if (add_guest_pages(dev, region, alignment) < 0) { - VHOST_LOG_CONFIG(ERR, "adding guest pages to region failed.\n"); + VHOST_LOG_CONFIG(ERR, "(%s) adding guest pages to region failed.\n", + dev->ifname); return -1; } if (rte_vfio_is_enabled("vfio")) { - ret = async_dma_map(region, true); + ret = async_dma_map(dev, region, true); if (ret) { - VHOST_LOG_CONFIG(ERR, "Configure IOMMU for DMA engine failed\n"); + VHOST_LOG_CONFIG(ERR, + "(%s) configure IOMMU for DMA engine failed\n", + dev->ifname); return -1; } } } VHOST_LOG_CONFIG(INFO, - "guest memory region size: 0x%" PRIx64 "\n" + "(%s) guest memory region size: 0x%" PRIx64 "\n" "\t guest physical addr: 0x%" PRIx64 "\n" "\t guest virtual addr: 0x%" PRIx64 "\n" "\t host virtual addr: 0x%" PRIx64 "\n" @@ -1293,6 +1294,7 @@ vhost_user_mmap_region(struct virtio_net *dev, "\t mmap size : 0x%" PRIx64 "\n" "\t mmap align: 0x%" PRIx64 "\n" "\t mmap off : 0x%" PRIx64 "\n", + dev->ifname, region->size, region->guest_phys_addr, region->guest_user_addr, @@ -1317,18 +1319,17 @@ vhost_user_set_mem_table(struct virtio_net **pdev, struct VhostUserMsg *msg, uint32_t i; bool async_notify = false; - if (validate_msg_fds(msg, memory->nregions) != 0) + if (validate_msg_fds(dev, msg, memory->nregions) != 0) return RTE_VHOST_MSG_RESULT_ERR; if (memory->nregions > VHOST_MEMORY_MAX_NREGIONS) { - VHOST_LOG_CONFIG(ERR, - "too many memory regions (%u)\n", memory->nregions); + VHOST_LOG_CONFIG(ERR, "(%s) too many memory regions (%u)\n", + dev->ifname, memory->nregions); goto close_msg_fds; } if (dev->mem && !vhost_memory_changed(memory, dev->mem)) { - VHOST_LOG_CONFIG(INFO, - "(%d) memory regions not changed\n", dev->vid); + VHOST_LOG_CONFIG(INFO, "(%s) memory regions not changed\n", dev->ifname); close_msg_fds(msg); @@ -1380,9 +1381,8 @@ vhost_user_set_mem_table(struct virtio_net **pdev, struct VhostUserMsg *msg, numa_node); if (dev->guest_pages == NULL) { VHOST_LOG_CONFIG(ERR, - "(%d) failed to allocate memory " - "for dev->guest_pages\n", - dev->vid); + "(%s) failed to allocate memory for dev->guest_pages\n", + dev->ifname); goto close_msg_fds; } } @@ -1391,8 +1391,8 @@ vhost_user_set_mem_table(struct virtio_net **pdev, struct VhostUserMsg *msg, sizeof(struct rte_vhost_mem_region) * memory->nregions, 0, numa_node); if (dev->mem == NULL) { VHOST_LOG_CONFIG(ERR, - "(%d) failed to allocate memory for dev->mem\n", - dev->vid); + "(%s) failed to allocate memory for dev->mem\n", + dev->ifname); goto free_guest_pages; } @@ -1413,7 +1413,7 @@ vhost_user_set_mem_table(struct virtio_net **pdev, struct VhostUserMsg *msg, mmap_offset = memory->regions[i].mmap_offset; if (vhost_user_mmap_region(dev, reg, mmap_offset) < 0) { - VHOST_LOG_CONFIG(ERR, "Failed to mmap region %u\n", i); + VHOST_LOG_CONFIG(ERR, "(%s) failed to mmap region %u\n", dev->ifname, i); goto free_mem_table; } @@ -1525,13 +1525,12 @@ virtio_is_ready(struct virtio_net *dev) dev->flags |= VIRTIO_DEV_READY; if (!(dev->flags & VIRTIO_DEV_RUNNING)) - VHOST_LOG_CONFIG(INFO, - "virtio is now ready for processing.\n"); + VHOST_LOG_CONFIG(INFO, "(%s) virtio is now ready for processing.\n", dev->ifname); return 1; } static void * -inflight_mem_alloc(const char *name, size_t size, int *fd) +inflight_mem_alloc(struct virtio_net *dev, const char *name, size_t size, int *fd) { void *ptr; int mfd = -1; @@ -1546,8 +1545,8 @@ inflight_mem_alloc(const char *name, size_t size, int *fd) if (mfd == -1) { mfd = mkstemp(fname); if (mfd == -1) { - VHOST_LOG_CONFIG(ERR, - "failed to get inflight buffer fd\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to get inflight buffer fd\n", + dev->ifname); return NULL; } @@ -1555,16 +1554,14 @@ inflight_mem_alloc(const char *name, size_t size, int *fd) } if (ftruncate(mfd, size) == -1) { - VHOST_LOG_CONFIG(ERR, - "failed to alloc inflight buffer\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to alloc inflight buffer\n", dev->ifname); close(mfd); return NULL; } ptr = mmap(0, size, PROT_READ | PROT_WRITE, MAP_SHARED, mfd, 0); if (ptr == MAP_FAILED) { - VHOST_LOG_CONFIG(ERR, - "failed to mmap inflight buffer\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to mmap inflight buffer\n", dev->ifname); close(mfd); return NULL; } @@ -1604,9 +1601,8 @@ vhost_user_get_inflight_fd(struct virtio_net **pdev, void *addr; if (msg->size != sizeof(msg->payload.inflight)) { - VHOST_LOG_CONFIG(ERR, - "invalid get_inflight_fd message size is %d\n", - msg->size); + VHOST_LOG_CONFIG(ERR, "(%s) invalid get_inflight_fd message size is %d\n", + dev->ifname, msg->size); return RTE_VHOST_MSG_RESULT_ERR; } @@ -1621,8 +1617,8 @@ vhost_user_get_inflight_fd(struct virtio_net **pdev, dev->inflight_info = rte_zmalloc_socket("inflight_info", sizeof(struct inflight_mem_info), 0, numa_node); if (!dev->inflight_info) { - VHOST_LOG_CONFIG(ERR, - "failed to alloc dev inflight area\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to alloc dev inflight area\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } dev->inflight_info->fd = -1; @@ -1631,10 +1627,10 @@ vhost_user_get_inflight_fd(struct virtio_net **pdev, num_queues = msg->payload.inflight.num_queues; queue_size = msg->payload.inflight.queue_size; - VHOST_LOG_CONFIG(INFO, "get_inflight_fd num_queues: %u\n", - msg->payload.inflight.num_queues); - VHOST_LOG_CONFIG(INFO, "get_inflight_fd queue_size: %u\n", - msg->payload.inflight.queue_size); + VHOST_LOG_CONFIG(INFO, "(%s) get_inflight_fd num_queues: %u\n", + dev->ifname, msg->payload.inflight.num_queues); + VHOST_LOG_CONFIG(INFO, "(%s) get_inflight_fd queue_size: %u\n", + dev->ifname, msg->payload.inflight.queue_size); if (vq_is_packed(dev)) pervq_inflight_size = get_pervq_shm_size_packed(queue_size); @@ -1642,10 +1638,9 @@ vhost_user_get_inflight_fd(struct virtio_net **pdev, pervq_inflight_size = get_pervq_shm_size_split(queue_size); mmap_size = num_queues * pervq_inflight_size; - addr = inflight_mem_alloc("vhost-inflight", mmap_size, &fd); + addr = inflight_mem_alloc(dev, "vhost-inflight", mmap_size, &fd); if (!addr) { - VHOST_LOG_CONFIG(ERR, - "failed to alloc vhost inflight area\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to alloc vhost inflight area\n", dev->ifname); msg->payload.inflight.mmap_size = 0; return RTE_VHOST_MSG_RESULT_ERR; } @@ -1679,14 +1674,11 @@ vhost_user_get_inflight_fd(struct virtio_net **pdev, } } - VHOST_LOG_CONFIG(INFO, - "send inflight mmap_size: %"PRIu64"\n", - msg->payload.inflight.mmap_size); - VHOST_LOG_CONFIG(INFO, - "send inflight mmap_offset: %"PRIu64"\n", - msg->payload.inflight.mmap_offset); - VHOST_LOG_CONFIG(INFO, - "send inflight fd: %d\n", msg->fds[0]); + VHOST_LOG_CONFIG(INFO, "(%s) send inflight mmap_size: %"PRIu64"\n", + dev->ifname, msg->payload.inflight.mmap_size); + VHOST_LOG_CONFIG(INFO, "(%s) send inflight mmap_offset: %"PRIu64"\n", + dev->ifname, msg->payload.inflight.mmap_offset); + VHOST_LOG_CONFIG(INFO, "(%s) send inflight fd: %d\n", dev->ifname, msg->fds[0]); return RTE_VHOST_MSG_RESULT_REPLY; } @@ -1706,9 +1698,8 @@ vhost_user_set_inflight_fd(struct virtio_net **pdev, VhostUserMsg *msg, fd = msg->fds[0]; if (msg->size != sizeof(msg->payload.inflight) || fd < 0) { - VHOST_LOG_CONFIG(ERR, - "invalid set_inflight_fd message size is %d,fd is %d\n", - msg->size, fd); + VHOST_LOG_CONFIG(ERR, "(%s) invalid set_inflight_fd message size is %d,fd is %d\n", + dev->ifname, msg->size, fd); return RTE_VHOST_MSG_RESULT_ERR; } @@ -1722,19 +1713,15 @@ vhost_user_set_inflight_fd(struct virtio_net **pdev, VhostUserMsg *msg, else pervq_inflight_size = get_pervq_shm_size_split(queue_size); - VHOST_LOG_CONFIG(INFO, - "set_inflight_fd mmap_size: %"PRIu64"\n", mmap_size); - VHOST_LOG_CONFIG(INFO, - "set_inflight_fd mmap_offset: %"PRIu64"\n", mmap_offset); - VHOST_LOG_CONFIG(INFO, - "set_inflight_fd num_queues: %u\n", num_queues); - VHOST_LOG_CONFIG(INFO, - "set_inflight_fd queue_size: %u\n", queue_size); - VHOST_LOG_CONFIG(INFO, - "set_inflight_fd fd: %d\n", fd); - VHOST_LOG_CONFIG(INFO, - "set_inflight_fd pervq_inflight_size: %d\n", - pervq_inflight_size); + VHOST_LOG_CONFIG(INFO, "(%s) set_inflight_fd mmap_size: %"PRIu64"\n", + dev->ifname, mmap_size); + VHOST_LOG_CONFIG(INFO, "(%s) set_inflight_fd mmap_offset: %"PRIu64"\n", + dev->ifname, mmap_offset); + VHOST_LOG_CONFIG(INFO, "(%s) set_inflight_fd num_queues: %u\n", dev->ifname, num_queues); + VHOST_LOG_CONFIG(INFO, "(%s) set_inflight_fd queue_size: %u\n", dev->ifname, queue_size); + VHOST_LOG_CONFIG(INFO, "(%s) set_inflight_fd fd: %d\n", dev->ifname, fd); + VHOST_LOG_CONFIG(INFO, "(%s) set_inflight_fd pervq_inflight_size: %d\n", + dev->ifname, pervq_inflight_size); /* * If VQ 0 has already been allocated, try to allocate on the same @@ -1747,8 +1734,8 @@ vhost_user_set_inflight_fd(struct virtio_net **pdev, VhostUserMsg *msg, dev->inflight_info = rte_zmalloc_socket("inflight_info", sizeof(struct inflight_mem_info), 0, numa_node); if (dev->inflight_info == NULL) { - VHOST_LOG_CONFIG(ERR, - "failed to alloc dev inflight area\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to alloc dev inflight area\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } dev->inflight_info->fd = -1; @@ -1762,7 +1749,7 @@ vhost_user_set_inflight_fd(struct virtio_net **pdev, VhostUserMsg *msg, addr = mmap(0, mmap_size, PROT_READ | PROT_WRITE, MAP_SHARED, fd, mmap_offset); if (addr == MAP_FAILED) { - VHOST_LOG_CONFIG(ERR, "failed to mmap share memory.\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to mmap share memory.\n", dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } @@ -1803,7 +1790,7 @@ vhost_user_set_vring_call(struct virtio_net **pdev, struct VhostUserMsg *msg, int expected_fds; expected_fds = (msg->payload.u64 & VHOST_USER_VRING_NOFD_MASK) ? 0 : 1; - if (validate_msg_fds(msg, expected_fds) != 0) + if (validate_msg_fds(dev, msg, expected_fds) != 0) return RTE_VHOST_MSG_RESULT_ERR; file.index = msg->payload.u64 & VHOST_USER_VRING_IDX_MASK; @@ -1811,8 +1798,8 @@ vhost_user_set_vring_call(struct virtio_net **pdev, struct VhostUserMsg *msg, file.fd = VIRTIO_INVALID_EVENTFD; else file.fd = msg->fds[0]; - VHOST_LOG_CONFIG(INFO, - "vring call idx:%d file:%d\n", file.index, file.fd); + VHOST_LOG_CONFIG(INFO, "(%s) vring call idx:%d file:%d\n", + dev->ifname, file.index, file.fd); vq = dev->virtqueue[file.index]; @@ -1829,19 +1816,20 @@ vhost_user_set_vring_call(struct virtio_net **pdev, struct VhostUserMsg *msg, return RTE_VHOST_MSG_RESULT_OK; } -static int vhost_user_set_vring_err(struct virtio_net **pdev __rte_unused, +static int vhost_user_set_vring_err(struct virtio_net **pdev, struct VhostUserMsg *msg, int main_fd __rte_unused) { + struct virtio_net *dev = *pdev; int expected_fds; expected_fds = (msg->payload.u64 & VHOST_USER_VRING_NOFD_MASK) ? 0 : 1; - if (validate_msg_fds(msg, expected_fds) != 0) + if (validate_msg_fds(dev, msg, expected_fds) != 0) return RTE_VHOST_MSG_RESULT_ERR; if (!(msg->payload.u64 & VHOST_USER_VRING_NOFD_MASK)) close(msg->fds[0]); - VHOST_LOG_CONFIG(INFO, "not implemented\n"); + VHOST_LOG_CONFIG(INFO, "(%s) not implemented\n", dev->ifname); return RTE_VHOST_MSG_RESULT_OK; } @@ -1908,7 +1896,8 @@ vhost_check_queue_inflights_split(struct virtio_net *dev, 0, vq->numa_node); if (!resubmit) { VHOST_LOG_CONFIG(ERR, - "failed to allocate memory for resubmit info.\n"); + "(%s) failed to allocate memory for resubmit info.\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } @@ -1917,7 +1906,8 @@ vhost_check_queue_inflights_split(struct virtio_net *dev, 0, vq->numa_node); if (!resubmit->resubmit_list) { VHOST_LOG_CONFIG(ERR, - "failed to allocate memory for inflight desc.\n"); + "(%s) failed to allocate memory for inflight desc.\n", + dev->ifname); rte_free(resubmit); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2004,7 +1994,8 @@ vhost_check_queue_inflights_packed(struct virtio_net *dev, 0, vq->numa_node); if (resubmit == NULL) { VHOST_LOG_CONFIG(ERR, - "failed to allocate memory for resubmit info.\n"); + "(%s) failed to allocate memory for resubmit info.\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2013,7 +2004,8 @@ vhost_check_queue_inflights_packed(struct virtio_net *dev, 0, vq->numa_node); if (resubmit->resubmit_list == NULL) { VHOST_LOG_CONFIG(ERR, - "failed to allocate memory for resubmit desc.\n"); + "(%s) failed to allocate memory for resubmit desc.\n", + dev->ifname); rte_free(resubmit); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2051,7 +2043,7 @@ vhost_user_set_vring_kick(struct virtio_net **pdev, struct VhostUserMsg *msg, int expected_fds; expected_fds = (msg->payload.u64 & VHOST_USER_VRING_NOFD_MASK) ? 0 : 1; - if (validate_msg_fds(msg, expected_fds) != 0) + if (validate_msg_fds(dev, msg, expected_fds) != 0) return RTE_VHOST_MSG_RESULT_ERR; file.index = msg->payload.u64 & VHOST_USER_VRING_IDX_MASK; @@ -2059,8 +2051,8 @@ vhost_user_set_vring_kick(struct virtio_net **pdev, struct VhostUserMsg *msg, file.fd = VIRTIO_INVALID_EVENTFD; else file.fd = msg->fds[0]; - VHOST_LOG_CONFIG(INFO, - "vring kick idx:%d file:%d\n", file.index, file.fd); + VHOST_LOG_CONFIG(INFO, "(%s) vring kick idx:%d file:%d\n", + dev->ifname, file.index, file.fd); /* Interpret ring addresses only when ring is started. */ dev = translate_ring_addresses(dev, file.index); @@ -2095,14 +2087,14 @@ vhost_user_set_vring_kick(struct virtio_net **pdev, struct VhostUserMsg *msg, if (vq_is_packed(dev)) { if (vhost_check_queue_inflights_packed(dev, vq)) { - VHOST_LOG_CONFIG(ERR, - "failed to inflights for vq: %d\n", file.index); + VHOST_LOG_CONFIG(ERR, "(%s) failed to inflights for vq: %d\n", + dev->ifname, file.index); return RTE_VHOST_MSG_RESULT_ERR; } } else { if (vhost_check_queue_inflights_split(dev, vq)) { - VHOST_LOG_CONFIG(ERR, - "failed to inflights for vq: %d\n", file.index); + VHOST_LOG_CONFIG(ERR, "(%s) failed to inflights for vq: %d\n", + dev->ifname, file.index); return RTE_VHOST_MSG_RESULT_ERR; } } @@ -2122,7 +2114,7 @@ vhost_user_get_vring_base(struct virtio_net **pdev, struct vhost_virtqueue *vq = dev->virtqueue[msg->payload.state.index]; uint64_t val; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; /* We have to stop the queue (virtio) if it is running. */ @@ -2144,9 +2136,9 @@ vhost_user_get_vring_base(struct virtio_net **pdev, msg->payload.state.num = vq->last_avail_idx; } - VHOST_LOG_CONFIG(INFO, - "vring base idx:%d file:%d\n", msg->payload.state.index, - msg->payload.state.num); + VHOST_LOG_CONFIG(INFO, "(%s) vring base idx:%d file:%d\n", + dev->ifname, msg->payload.state.index, + msg->payload.state.num); /* * Based on current qemu vhost-user implementation, this message is * sent and only sent in vhost_vring_stop. @@ -2201,17 +2193,17 @@ vhost_user_set_vring_enable(struct virtio_net **pdev, bool enable = !!msg->payload.state.num; int index = (int)msg->payload.state.index; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; - VHOST_LOG_CONFIG(INFO, - "set queue enable: %d to qp idx: %d\n", - enable, index); + VHOST_LOG_CONFIG(INFO, "(%s) set queue enable: %d to qp idx: %d\n", + dev->ifname, enable, index); if (enable && dev->virtqueue[index]->async) { if (dev->virtqueue[index]->async->pkts_inflight_n) { - VHOST_LOG_CONFIG(ERR, "failed to enable vring. " - "async inflight packets must be completed first\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to enable vring. " + "async inflight packets must be completed first\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } } @@ -2229,7 +2221,7 @@ vhost_user_get_protocol_features(struct virtio_net **pdev, struct virtio_net *dev = *pdev; uint64_t features, protocol_features; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; rte_vhost_driver_get_features(dev->ifname, &features); @@ -2251,22 +2243,19 @@ vhost_user_set_protocol_features(struct virtio_net **pdev, uint64_t protocol_features = msg->payload.u64; uint64_t slave_protocol_features = 0; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; rte_vhost_driver_get_protocol_features(dev->ifname, &slave_protocol_features); if (protocol_features & ~slave_protocol_features) { - VHOST_LOG_CONFIG(ERR, - "(%d) received invalid protocol features.\n", - dev->vid); + VHOST_LOG_CONFIG(ERR, "(%s) received invalid protocol features.\n", dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } dev->protocol_features = protocol_features; - VHOST_LOG_CONFIG(INFO, - "negotiated Vhost-user protocol features: 0x%" PRIx64 "\n", - dev->protocol_features); + VHOST_LOG_CONFIG(INFO, "(%s) negotiated Vhost-user protocol features: 0x%" PRIx64 "\n", + dev->ifname, dev->protocol_features); return RTE_VHOST_MSG_RESULT_OK; } @@ -2281,18 +2270,17 @@ vhost_user_set_log_base(struct virtio_net **pdev, struct VhostUserMsg *msg, void *addr; uint32_t i; - if (validate_msg_fds(msg, 1) != 0) + if (validate_msg_fds(dev, msg, 1) != 0) return RTE_VHOST_MSG_RESULT_ERR; if (fd < 0) { - VHOST_LOG_CONFIG(ERR, "invalid log fd: %d\n", fd); + VHOST_LOG_CONFIG(ERR, "(%s) invalid log fd: %d\n", dev->ifname, fd); return RTE_VHOST_MSG_RESULT_ERR; } if (msg->size != sizeof(VhostUserLog)) { - VHOST_LOG_CONFIG(ERR, - "invalid log base msg size: %"PRId32" != %d\n", - msg->size, (int)sizeof(VhostUserLog)); + VHOST_LOG_CONFIG(ERR, "(%s) invalid log base msg size: %"PRId32" != %d\n", + dev->ifname, msg->size, (int)sizeof(VhostUserLog)); goto close_msg_fds; } @@ -2302,14 +2290,13 @@ vhost_user_set_log_base(struct virtio_net **pdev, struct VhostUserMsg *msg, /* Check for mmap size and offset overflow. */ if (off >= -size) { VHOST_LOG_CONFIG(ERR, - "log offset %#"PRIx64" and log size %#"PRIx64" overflow\n", - off, size); + "(%s) log offset %#"PRIx64" and log size %#"PRIx64" overflow\n", + dev->ifname, off, size); goto close_msg_fds; } - VHOST_LOG_CONFIG(INFO, - "log mmap size: %"PRId64", offset: %"PRId64"\n", - size, off); + VHOST_LOG_CONFIG(INFO, "(%s) log mmap size: %"PRId64", offset: %"PRId64"\n", + dev->ifname, size, off); /* * mmap from 0 to workaround a hugepage mmap bug: mmap will @@ -2318,7 +2305,7 @@ vhost_user_set_log_base(struct virtio_net **pdev, struct VhostUserMsg *msg, addr = mmap(0, size + off, PROT_READ | PROT_WRITE, MAP_SHARED, fd, 0); close(fd); if (addr == MAP_FAILED) { - VHOST_LOG_CONFIG(ERR, "mmap log base failed!\n"); + VHOST_LOG_CONFIG(ERR, "(%s) mmap log base failed!\n", dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2347,7 +2334,8 @@ vhost_user_set_log_base(struct virtio_net **pdev, struct VhostUserMsg *msg, * caching will be done, which will impact performance */ if (!vq->log_cache) - VHOST_LOG_CONFIG(ERR, "Failed to allocate VQ logging cache\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate VQ logging cache\n", + dev->ifname); } /* @@ -2364,15 +2352,17 @@ vhost_user_set_log_base(struct virtio_net **pdev, struct VhostUserMsg *msg, return RTE_VHOST_MSG_RESULT_ERR; } -static int vhost_user_set_log_fd(struct virtio_net **pdev __rte_unused, +static int vhost_user_set_log_fd(struct virtio_net **pdev, struct VhostUserMsg *msg, int main_fd __rte_unused) { - if (validate_msg_fds(msg, 1) != 0) + struct virtio_net *dev = *pdev; + + if (validate_msg_fds(dev, msg, 1) != 0) return RTE_VHOST_MSG_RESULT_ERR; close(msg->fds[0]); - VHOST_LOG_CONFIG(INFO, "not implemented.\n"); + VHOST_LOG_CONFIG(INFO, "(%s) not implemented.\n", dev->ifname); return RTE_VHOST_MSG_RESULT_OK; } @@ -2393,12 +2383,11 @@ vhost_user_send_rarp(struct virtio_net **pdev, struct VhostUserMsg *msg, uint8_t *mac = (uint8_t *)&msg->payload.u64; struct rte_vdpa_device *vdpa_dev; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; - VHOST_LOG_CONFIG(DEBUG, - ":: mac: " RTE_ETHER_ADDR_PRT_FMT "\n", - mac[0], mac[1], mac[2], mac[3], mac[4], mac[5]); + VHOST_LOG_CONFIG(DEBUG, "(%s) MAC: " RTE_ETHER_ADDR_PRT_FMT "\n", + dev->ifname, mac[0], mac[1], mac[2], mac[3], mac[4], mac[5]); memcpy(dev->mac.addr_bytes, mac, 6); /* @@ -2422,13 +2411,13 @@ vhost_user_net_set_mtu(struct virtio_net **pdev, struct VhostUserMsg *msg, { struct virtio_net *dev = *pdev; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; if (msg->payload.u64 < VIRTIO_MIN_MTU || msg->payload.u64 > VIRTIO_MAX_MTU) { - VHOST_LOG_CONFIG(ERR, "Invalid MTU size (%"PRIu64")\n", - msg->payload.u64); + VHOST_LOG_CONFIG(ERR, "(%s) invalid MTU size (%"PRIu64")\n", + dev->ifname, msg->payload.u64); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2445,13 +2434,12 @@ vhost_user_set_req_fd(struct virtio_net **pdev, struct VhostUserMsg *msg, struct virtio_net *dev = *pdev; int fd = msg->fds[0]; - if (validate_msg_fds(msg, 1) != 0) + if (validate_msg_fds(dev, msg, 1) != 0) return RTE_VHOST_MSG_RESULT_ERR; if (fd < 0) { - VHOST_LOG_CONFIG(ERR, - "Invalid file descriptor for slave channel (%d)\n", - fd); + VHOST_LOG_CONFIG(ERR, "(%s) invalid file descriptor for slave channel (%d)\n", + dev->ifname, fd); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2547,7 +2535,7 @@ vhost_user_iotlb_msg(struct virtio_net **pdev, struct VhostUserMsg *msg, uint16_t i; uint64_t vva, len; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; switch (imsg->type) { @@ -2585,8 +2573,8 @@ vhost_user_iotlb_msg(struct virtio_net **pdev, struct VhostUserMsg *msg, } break; default: - VHOST_LOG_CONFIG(ERR, "Invalid IOTLB message type (%d)\n", - imsg->type); + VHOST_LOG_CONFIG(ERR, "(%s) invalid IOTLB message type (%d)\n", + dev->ifname, imsg->type); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2602,21 +2590,21 @@ vhost_user_set_postcopy_advise(struct virtio_net **pdev, #ifdef RTE_LIBRTE_VHOST_POSTCOPY struct uffdio_api api_struct; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; dev->postcopy_ufd = syscall(__NR_userfaultfd, O_CLOEXEC | O_NONBLOCK); if (dev->postcopy_ufd == -1) { - VHOST_LOG_CONFIG(ERR, "Userfaultfd not available: %s\n", - strerror(errno)); + VHOST_LOG_CONFIG(ERR, "(%s) userfaultfd not available: %s\n", + dev->ifname, strerror(errno)); return RTE_VHOST_MSG_RESULT_ERR; } api_struct.api = UFFD_API; api_struct.features = 0; if (ioctl(dev->postcopy_ufd, UFFDIO_API, &api_struct)) { - VHOST_LOG_CONFIG(ERR, "UFFDIO_API ioctl failure: %s\n", - strerror(errno)); + VHOST_LOG_CONFIG(ERR, "(%s) UFFDIO_API ioctl failure: %s\n", + dev->ifname, strerror(errno)); close(dev->postcopy_ufd); dev->postcopy_ufd = -1; return RTE_VHOST_MSG_RESULT_ERR; @@ -2640,12 +2628,12 @@ vhost_user_set_postcopy_listen(struct virtio_net **pdev, { struct virtio_net *dev = *pdev; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; if (dev->mem && dev->mem->nregions) { - VHOST_LOG_CONFIG(ERR, - "Regions already registered at postcopy-listen\n"); + VHOST_LOG_CONFIG(ERR, "(%s) regions already registered at postcopy-listen\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } dev->postcopy_listening = 1; @@ -2659,7 +2647,7 @@ vhost_user_postcopy_end(struct virtio_net **pdev, struct VhostUserMsg *msg, { struct virtio_net *dev = *pdev; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; dev->postcopy_listening = 0; @@ -2681,7 +2669,7 @@ vhost_user_get_status(struct virtio_net **pdev, struct VhostUserMsg *msg, { struct virtio_net *dev = *pdev; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; msg->payload.u64 = dev->status; @@ -2697,13 +2685,13 @@ vhost_user_set_status(struct virtio_net **pdev, struct VhostUserMsg *msg, { struct virtio_net *dev = *pdev; - if (validate_msg_fds(msg, 0) != 0) + if (validate_msg_fds(dev, msg, 0) != 0) return RTE_VHOST_MSG_RESULT_ERR; /* As per Virtio specification, the device status is 8bits long */ if (msg->payload.u64 > UINT8_MAX) { - VHOST_LOG_CONFIG(ERR, "Invalid VHOST_USER_SET_STATUS payload 0x%" PRIx64 "\n", - msg->payload.u64); + VHOST_LOG_CONFIG(ERR, "(%s) invalid VHOST_USER_SET_STATUS payload 0x%" PRIx64 "\n", + dev->ifname, msg->payload.u64); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2711,7 +2699,9 @@ vhost_user_set_status(struct virtio_net **pdev, struct VhostUserMsg *msg, if ((dev->status & VIRTIO_DEVICE_STATUS_FEATURES_OK) && (dev->flags & VIRTIO_DEV_FEATURES_FAILED)) { - VHOST_LOG_CONFIG(ERR, "FEATURES_OK bit is set but feature negotiation failed\n"); + VHOST_LOG_CONFIG(ERR, + "(%s) FEATURES_OK bit is set but feature negotiation failed\n", + dev->ifname); /* * Clear the bit to let the driver know about the feature * negotiation failure @@ -2719,7 +2709,7 @@ vhost_user_set_status(struct virtio_net **pdev, struct VhostUserMsg *msg, dev->status &= ~VIRTIO_DEVICE_STATUS_FEATURES_OK; } - VHOST_LOG_CONFIG(INFO, "New device status(0x%08x):\n" + VHOST_LOG_CONFIG(INFO, "(%s) new device status(0x%08x):\n" "\t-RESET: %u\n" "\t-ACKNOWLEDGE: %u\n" "\t-DRIVER: %u\n" @@ -2727,6 +2717,7 @@ vhost_user_set_status(struct virtio_net **pdev, struct VhostUserMsg *msg, "\t-DRIVER_OK: %u\n" "\t-DEVICE_NEED_RESET: %u\n" "\t-FAILED: %u\n", + dev->ifname, dev->status, (dev->status == VIRTIO_DEVICE_STATUS_RESET), !!(dev->status & VIRTIO_DEVICE_STATUS_ACK), @@ -2777,7 +2768,7 @@ static vhost_message_handler_t vhost_message_handlers[VHOST_USER_MAX] = { /* return bytes# of read on success or negative val on failure. */ static int -read_vhost_message(int sockfd, struct VhostUserMsg *msg) +read_vhost_message(struct virtio_net *dev, int sockfd, struct VhostUserMsg *msg) { int ret; @@ -2786,23 +2777,22 @@ read_vhost_message(int sockfd, struct VhostUserMsg *msg) if (ret <= 0) { return ret; } else if (ret != VHOST_USER_HDR_SIZE) { - VHOST_LOG_CONFIG(ERR, "Unexpected header size read\n"); + VHOST_LOG_CONFIG(ERR, "(%s) Unexpected header size read\n", dev->ifname); close_msg_fds(msg); return -1; } if (msg->size) { if (msg->size > sizeof(msg->payload)) { - VHOST_LOG_CONFIG(ERR, - "invalid msg size: %d\n", msg->size); + VHOST_LOG_CONFIG(ERR, "(%s) invalid msg size: %d\n", + dev->ifname, msg->size); return -1; } ret = read(sockfd, &msg->payload, msg->size); if (ret <= 0) return ret; if (ret != (int)msg->size) { - VHOST_LOG_CONFIG(ERR, - "read control message failed\n"); + VHOST_LOG_CONFIG(ERR, "(%s) read control message failed\n", dev->ifname); return -1; } } @@ -2878,8 +2868,7 @@ vhost_user_check_and_alloc_queue_pair(struct virtio_net *dev, } if (vring_idx >= VHOST_MAX_VRING) { - VHOST_LOG_CONFIG(ERR, - "invalid vring index: %u\n", vring_idx); + VHOST_LOG_CONFIG(ERR, "(%s) invalid vring index: %u\n", dev->ifname, vring_idx); return -1; } @@ -2942,21 +2931,18 @@ vhost_user_msg_handler(int vid, int fd) if (!dev->notify_ops) { dev->notify_ops = vhost_driver_callback_get(dev->ifname); if (!dev->notify_ops) { - VHOST_LOG_CONFIG(ERR, - "failed to get callback ops for driver %s\n", + VHOST_LOG_CONFIG(ERR, "(%s) failed to get callback ops for driver\n", dev->ifname); return -1; } } - ret = read_vhost_message(fd, &msg); + ret = read_vhost_message(dev, fd, &msg); if (ret <= 0) { if (ret < 0) - VHOST_LOG_CONFIG(ERR, - "vhost read message failed\n"); + VHOST_LOG_CONFIG(ERR, "(%s) vhost read message failed\n", dev->ifname); else - VHOST_LOG_CONFIG(INFO, - "vhost peer closed\n"); + VHOST_LOG_CONFIG(INFO, "(%s) vhost peer closed\n", dev->ifname); return -1; } @@ -2966,19 +2952,18 @@ vhost_user_msg_handler(int vid, int fd) if (request > VHOST_USER_NONE && request < VHOST_USER_MAX && vhost_message_str[request]) { if (request != VHOST_USER_IOTLB_MSG) - VHOST_LOG_CONFIG(INFO, "read message %s\n", - vhost_message_str[request]); + VHOST_LOG_CONFIG(INFO, "(%s) read message %s\n", + dev->ifname, vhost_message_str[request]); else - VHOST_LOG_CONFIG(DEBUG, "read message %s\n", - vhost_message_str[request]); + VHOST_LOG_CONFIG(DEBUG, "(%s) read message %s\n", + dev->ifname, vhost_message_str[request]); } else { - VHOST_LOG_CONFIG(DEBUG, "External request %d\n", request); + VHOST_LOG_CONFIG(DEBUG, "(%s) external request %d\n", dev->ifname, request); } ret = vhost_user_check_and_alloc_queue_pair(dev, &msg); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, - "failed to alloc queue\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to alloc queue\n", dev->ifname); return -1; } @@ -3041,21 +3026,18 @@ vhost_user_msg_handler(int vid, int fd) switch (ret) { case RTE_VHOST_MSG_RESULT_ERR: - VHOST_LOG_CONFIG(ERR, - "Processing %s failed.\n", - vhost_message_str[request]); + VHOST_LOG_CONFIG(ERR, "(%s) processing %s failed.\n", + dev->ifname, vhost_message_str[request]); handled = true; break; case RTE_VHOST_MSG_RESULT_OK: - VHOST_LOG_CONFIG(DEBUG, - "Processing %s succeeded.\n", - vhost_message_str[request]); + VHOST_LOG_CONFIG(DEBUG, "(%s) processing %s succeeded.\n", + dev->ifname, vhost_message_str[request]); handled = true; break; case RTE_VHOST_MSG_RESULT_REPLY: - VHOST_LOG_CONFIG(DEBUG, - "Processing %s succeeded and needs reply.\n", - vhost_message_str[request]); + VHOST_LOG_CONFIG(DEBUG, "(%s) processing %s succeeded and needs reply.\n", + dev->ifname, vhost_message_str[request]); send_vhost_reply(fd, &msg); handled = true; break; @@ -3084,8 +3066,8 @@ vhost_user_msg_handler(int vid, int fd) /* If message was not handled at this stage, treat it as an error */ if (!handled) { - VHOST_LOG_CONFIG(ERR, - "vhost message (req: %d) was not handled.\n", request); + VHOST_LOG_CONFIG(ERR, "(%s) vhost message (req: %d) was not handled.\n", + dev->ifname, request); close_msg_fds(&msg); ret = RTE_VHOST_MSG_RESULT_ERR; } @@ -3101,8 +3083,7 @@ vhost_user_msg_handler(int vid, int fd) msg.fd_num = 0; send_vhost_reply(fd, &msg); } else if (ret == RTE_VHOST_MSG_RESULT_ERR) { - VHOST_LOG_CONFIG(ERR, - "vhost message handling failed.\n"); + VHOST_LOG_CONFIG(ERR, "(%s) vhost message handling failed.\n", dev->ifname); return -1; } @@ -3139,8 +3120,8 @@ vhost_user_msg_handler(int vid, int fd) if (!(dev->flags & VIRTIO_DEV_VDPA_CONFIGURED)) { if (vdpa_dev->ops->dev_conf(dev->vid)) - VHOST_LOG_CONFIG(ERR, - "Failed to configure vDPA device\n"); + VHOST_LOG_CONFIG(ERR, "(%s) failed to configure vDPA device\n", + dev->ifname); else dev->flags |= VIRTIO_DEV_VDPA_CONFIGURED; } @@ -3158,23 +3139,21 @@ static int process_slave_message_reply(struct virtio_net *dev, if ((msg->flags & VHOST_USER_NEED_REPLY) == 0) return 0; - ret = read_vhost_message(dev->slave_req_fd, &msg_reply); + ret = read_vhost_message(dev, dev->slave_req_fd, &msg_reply); if (ret <= 0) { if (ret < 0) - VHOST_LOG_CONFIG(ERR, - "vhost read slave message reply failed\n"); + VHOST_LOG_CONFIG(ERR, "(%s) vhost read slave message reply failed\n", + dev->ifname); else - VHOST_LOG_CONFIG(INFO, - "vhost peer closed\n"); + VHOST_LOG_CONFIG(INFO, "(%s) vhost peer closed\n", dev->ifname); ret = -1; goto out; } ret = 0; if (msg_reply.request.slave != msg->request.slave) { - VHOST_LOG_CONFIG(ERR, - "Received unexpected msg type (%u), expected %u\n", - msg_reply.request.slave, msg->request.slave); + VHOST_LOG_CONFIG(ERR, "(%s) received unexpected msg type (%u), expected %u\n", + dev->ifname, msg_reply.request.slave, msg->request.slave); ret = -1; goto out; } @@ -3203,9 +3182,8 @@ vhost_user_iotlb_miss(struct virtio_net *dev, uint64_t iova, uint8_t perm) ret = send_vhost_message(dev->slave_req_fd, &msg); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, - "Failed to send IOTLB miss message (%d)\n", - ret); + VHOST_LOG_CONFIG(ERR, "(%s) failed to send IOTLB miss message (%d)\n", + dev->ifname, ret); return ret; } @@ -3227,9 +3205,8 @@ vhost_user_slave_config_change(struct virtio_net *dev, bool need_reply) ret = send_vhost_slave_message(dev, &msg); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, - "Failed to send config change (%d)\n", - ret); + VHOST_LOG_CONFIG(ERR, "(%s) failed to send config change (%d)\n", + dev->ifname, ret); return ret; } @@ -3274,8 +3251,8 @@ static int vhost_user_slave_set_vring_host_notifier(struct virtio_net *dev, ret = send_vhost_slave_message(dev, &msg); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, - "Failed to set host notifier (%d)\n", ret); + VHOST_LOG_CONFIG(ERR, "(%s) failed to set host notifier (%d)\n", + dev->ifname, ret); return ret; } From patchwork Thu Dec 23 08:36:58 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Maxime Coquelin X-Patchwork-Id: 105363 X-Patchwork-Delegate: maxime.coquelin@redhat.com Return-Path: X-Original-To: patchwork@inbox.dpdk.org Delivered-To: patchwork@inbox.dpdk.org Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id 9FCBBA0350; Thu, 23 Dec 2021 09:38:32 +0100 (CET) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 7C9B841101; Thu, 23 Dec 2021 09:38:32 +0100 (CET) Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.129.124]) by mails.dpdk.org (Postfix) with ESMTP id 001A0410F1 for ; Thu, 23 Dec 2021 09:38:30 +0100 (CET) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1640248710; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=lPsp9KBE0KhltqsyfWyGbnigHQrz9vCF+KCshEFvF/g=; b=dUh9k5pptsQ+7DnxgtydLhcmbhMIQS5vD5WEfZphoNLCkrzzAQQ28KMqTyBCUufSmCuIaS IOmWgIC9fTYnpqj8ZXoLf1bSHf4g0WIRrWN+p07MH/+5vm3Et/mQuk/lpE0xUvgFA0Wmz6 LJe28TWgSt/pNCQHfjJOfeMFrw5iU04= Received: from mimecast-mx01.redhat.com (mimecast-mx01.redhat.com [209.132.183.4]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-75-FslaKDzuM9yz4zgfVdYZjQ-1; Thu, 23 Dec 2021 03:37:49 -0500 X-MC-Unique: FslaKDzuM9yz4zgfVdYZjQ-1 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 mimecast-mx01.redhat.com (Postfix) with ESMTPS id 4DAC181EE62; Thu, 23 Dec 2021 08:37:48 +0000 (UTC) Received: from max-t490s.redhat.com (unknown [10.39.208.14]) by smtp.corp.redhat.com (Postfix) with ESMTP id 1A6205BD14; Thu, 23 Dec 2021 08:37:39 +0000 (UTC) From: Maxime Coquelin To: dev@dpdk.org, chenbo.xia@intel.com, david.marchand@redhat.com Cc: Maxime Coquelin Subject: [PATCH 6/7] vhost: improve Virtio-net layer logs Date: Thu, 23 Dec 2021 09:36:58 +0100 Message-Id: <20211223083659.245766-7-maxime.coquelin@redhat.com> In-Reply-To: <20211223083659.245766-1-maxime.coquelin@redhat.com> References: <20211223083659.245766-1-maxime.coquelin@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=maxime.coquelin@redhat.com X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org This patch standardizes logging done in Virtio-net, so that the Vhost-user socket path is always prepended to the logs. It will ease log analysis when multiple Vhost-user ports are in use. Signed-off-by: Maxime Coquelin --- lib/vhost/virtio_net.c | 165 ++++++++++++++++++++--------------------- 1 file changed, 79 insertions(+), 86 deletions(-) diff --git a/lib/vhost/virtio_net.c b/lib/vhost/virtio_net.c index b3d954aab4..f19713137c 100644 --- a/lib/vhost/virtio_net.c +++ b/lib/vhost/virtio_net.c @@ -792,12 +792,12 @@ copy_vnet_hdr_to_desc(struct virtio_net *dev, struct vhost_virtqueue *vq, } static __rte_always_inline int -async_iter_initialize(struct vhost_async *async) +async_iter_initialize(struct virtio_net *dev, struct vhost_async *async) { struct rte_vhost_iov_iter *iter; if (unlikely(async->iovec_idx >= VHOST_MAX_ASYNC_VEC)) { - VHOST_LOG_DATA(ERR, "no more async iovec available\n"); + VHOST_LOG_DATA(ERR, "(%s) no more async iovec available\n", dev->ifname); return -1; } @@ -809,7 +809,8 @@ async_iter_initialize(struct vhost_async *async) } static __rte_always_inline int -async_iter_add_iovec(struct vhost_async *async, void *src, void *dst, size_t len) +async_iter_add_iovec(struct virtio_net *dev, struct vhost_async *async, + void *src, void *dst, size_t len) { struct rte_vhost_iov_iter *iter; struct rte_vhost_iovec *iovec; @@ -818,7 +819,7 @@ async_iter_add_iovec(struct vhost_async *async, void *src, void *dst, size_t len static bool vhost_max_async_vec_log; if (!vhost_max_async_vec_log) { - VHOST_LOG_DATA(ERR, "no more async iovec available\n"); + VHOST_LOG_DATA(ERR, "(%s) no more async iovec available\n", dev->ifname); vhost_max_async_vec_log = true; } @@ -876,11 +877,11 @@ async_mbuf_to_desc_seg(struct virtio_net *dev, struct vhost_virtqueue *vq, hpa = (void *)(uintptr_t)gpa_to_first_hpa(dev, buf_iova + buf_offset, cpy_len, &mapped_len); if (unlikely(!hpa)) { - VHOST_LOG_DATA(ERR, "(%d) %s: failed to get hpa.\n", dev->vid, __func__); + VHOST_LOG_DATA(ERR, "(%s) %s: failed to get hpa.\n", dev->ifname, __func__); return -1; } - if (unlikely(async_iter_add_iovec(async, + if (unlikely(async_iter_add_iovec(dev, async, (void *)(uintptr_t)rte_pktmbuf_iova_offset(m, mbuf_offset), hpa, (size_t)mapped_len))) @@ -951,8 +952,8 @@ mbuf_to_desc(struct virtio_net *dev, struct vhost_virtqueue *vq, } else hdr = (struct virtio_net_hdr_mrg_rxbuf *)(uintptr_t)hdr_addr; - VHOST_LOG_DATA(DEBUG, "(%d) RX: num merge buffers %d\n", - dev->vid, num_buffers); + VHOST_LOG_DATA(DEBUG, "(%s) RX: num merge buffers %d\n", + dev->ifname, num_buffers); if (unlikely(buf_len < dev->vhost_hlen)) { buf_offset = dev->vhost_hlen - buf_len; @@ -970,7 +971,7 @@ mbuf_to_desc(struct virtio_net *dev, struct vhost_virtqueue *vq, mbuf_offset = 0; if (is_async) { - if (async_iter_initialize(async)) + if (async_iter_initialize(dev, async)) return -1; } @@ -1133,14 +1134,14 @@ virtio_dev_rx_split(struct virtio_net *dev, struct vhost_virtqueue *vq, pkt_len, buf_vec, &num_buffers, avail_head, &nr_vec) < 0)) { VHOST_LOG_DATA(DEBUG, - "(%d) failed to get enough desc from vring\n", - dev->vid); + "(%s) failed to get enough desc from vring\n", + dev->ifname); vq->shadow_used_idx -= num_buffers; break; } - VHOST_LOG_DATA(DEBUG, "(%d) current index %d | end index %d\n", - dev->vid, vq->last_avail_idx, + VHOST_LOG_DATA(DEBUG, "(%s) current index %d | end index %d\n", + dev->ifname, vq->last_avail_idx, vq->last_avail_idx + num_buffers); if (mbuf_to_desc(dev, vq, pkts[pkt_idx], buf_vec, nr_vec, @@ -1287,14 +1288,13 @@ virtio_dev_rx_single_packed(struct virtio_net *dev, if (unlikely(vhost_enqueue_single_packed(dev, vq, pkt, buf_vec, &nr_descs) < 0)) { - VHOST_LOG_DATA(DEBUG, - "(%d) failed to get enough desc from vring\n", - dev->vid); + VHOST_LOG_DATA(DEBUG, "(%s) failed to get enough desc from vring\n", + dev->ifname); return -1; } - VHOST_LOG_DATA(DEBUG, "(%d) current index %d | end index %d\n", - dev->vid, vq->last_avail_idx, + VHOST_LOG_DATA(DEBUG, "(%s) current index %d | end index %d\n", + dev->ifname, vq->last_avail_idx, vq->last_avail_idx + nr_descs); vq_inc_last_avail_packed(vq, nr_descs); @@ -1345,10 +1345,10 @@ virtio_dev_rx(struct virtio_net *dev, uint16_t queue_id, struct vhost_virtqueue *vq; uint32_t nb_tx = 0; - VHOST_LOG_DATA(DEBUG, "(%d) %s\n", dev->vid, __func__); + VHOST_LOG_DATA(DEBUG, "(%s) %s\n", dev->ifname, __func__); if (unlikely(!is_valid_virt_queue_idx(queue_id, 0, dev->nr_vring))) { - VHOST_LOG_DATA(ERR, "(%d) %s: invalid virtqueue idx %d.\n", - dev->vid, __func__, queue_id); + VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", + dev->ifname, __func__, queue_id); return 0; } @@ -1395,9 +1395,8 @@ rte_vhost_enqueue_burst(int vid, uint16_t queue_id, return 0; if (unlikely(!(dev->flags & VIRTIO_DEV_BUILTIN_VIRTIO_NET))) { - VHOST_LOG_DATA(ERR, - "(%d) %s: built-in vhost net backend is disabled.\n", - dev->vid, __func__); + VHOST_LOG_DATA(ERR, "(%s) %s: built-in vhost net backend is disabled.\n", + dev->ifname, __func__); return 0; } @@ -1479,14 +1478,14 @@ virtio_dev_rx_async_submit_split(struct virtio_net *dev, if (unlikely(reserve_avail_buf_split(dev, vq, pkt_len, buf_vec, &num_buffers, avail_head, &nr_vec) < 0)) { - VHOST_LOG_DATA(DEBUG, "(%d) failed to get enough desc from vring\n", - dev->vid); + VHOST_LOG_DATA(DEBUG, "(%s) failed to get enough desc from vring\n", + dev->ifname); vq->shadow_used_idx -= num_buffers; break; } - VHOST_LOG_DATA(DEBUG, "(%d) current index %d | end index %d\n", - dev->vid, vq->last_avail_idx, vq->last_avail_idx + num_buffers); + VHOST_LOG_DATA(DEBUG, "(%s) current index %d | end index %d\n", + dev->ifname, vq->last_avail_idx, vq->last_avail_idx + num_buffers); if (mbuf_to_desc(dev, vq, pkts[pkt_idx], buf_vec, nr_vec, num_buffers, true) < 0) { vq->shadow_used_idx -= num_buffers; @@ -1505,8 +1504,8 @@ virtio_dev_rx_async_submit_split(struct virtio_net *dev, n_xfer = async->ops.transfer_data(dev->vid, queue_id, async->iov_iter, 0, pkt_idx); if (unlikely(n_xfer < 0)) { - VHOST_LOG_DATA(ERR, "(%d) %s: failed to transfer data for queue id %d.\n", - dev->vid, __func__, queue_id); + VHOST_LOG_DATA(ERR, "(%s) %s: failed to transfer data for queue id %d.\n", + dev->ifname, __func__, queue_id); n_xfer = 0; } @@ -1619,12 +1618,12 @@ virtio_dev_rx_async_packed(struct virtio_net *dev, struct vhost_virtqueue *vq, if (unlikely(vhost_enqueue_async_packed(dev, vq, pkt, buf_vec, nr_descs, nr_buffers) < 0)) { - VHOST_LOG_DATA(DEBUG, "(%d) failed to get enough desc from vring\n", dev->vid); + VHOST_LOG_DATA(DEBUG, "(%s) failed to get enough desc from vring\n", dev->ifname); return -1; } - VHOST_LOG_DATA(DEBUG, "(%d) current index %d | end index %d\n", - dev->vid, vq->last_avail_idx, vq->last_avail_idx + *nr_descs); + VHOST_LOG_DATA(DEBUG, "(%s) current index %d | end index %d\n", + dev->ifname, vq->last_avail_idx, vq->last_avail_idx + *nr_descs); return 0; } @@ -1696,8 +1695,8 @@ virtio_dev_rx_async_submit_packed(struct virtio_net *dev, n_xfer = async->ops.transfer_data(dev->vid, queue_id, async->iov_iter, 0, pkt_idx); if (unlikely(n_xfer < 0)) { - VHOST_LOG_DATA(ERR, "(%d) %s: failed to transfer data for queue id %d.\n", - dev->vid, __func__, queue_id); + VHOST_LOG_DATA(ERR, "(%s) %s: failed to transfer data for queue id %d.\n", + dev->ifname, __func__, queue_id); n_xfer = 0; } @@ -1837,8 +1836,8 @@ vhost_poll_enqueue_completed(struct virtio_net *dev, uint16_t queue_id, n_cpl = async->ops.check_completed_copies(dev->vid, queue_id, 0, count); if (unlikely(n_cpl < 0)) { - VHOST_LOG_DATA(ERR, "(%d) %s: failed to check completed copies for queue id %d.\n", - dev->vid, __func__, queue_id); + VHOST_LOG_DATA(ERR, "(%s) %s: failed to check completed copies for queue id %d.\n", + dev->ifname, __func__, queue_id); return 0; } @@ -1891,18 +1890,18 @@ rte_vhost_poll_enqueue_completed(int vid, uint16_t queue_id, if (unlikely(!dev)) return 0; - VHOST_LOG_DATA(DEBUG, "(%d) %s\n", dev->vid, __func__); + VHOST_LOG_DATA(DEBUG, "(%s) %s\n", dev->ifname, __func__); if (unlikely(!is_valid_virt_queue_idx(queue_id, 0, dev->nr_vring))) { - VHOST_LOG_DATA(ERR, "(%d) %s: invalid virtqueue idx %d.\n", - dev->vid, __func__, queue_id); + VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", + dev->ifname, __func__, queue_id); return 0; } vq = dev->virtqueue[queue_id]; if (unlikely(!vq->async)) { - VHOST_LOG_DATA(ERR, "(%d) %s: async not registered for queue id %d.\n", - dev->vid, __func__, queue_id); + VHOST_LOG_DATA(ERR, "(%s) %s: async not registered for queue id %d.\n", + dev->ifname, __func__, queue_id); return 0; } @@ -1926,18 +1925,18 @@ rte_vhost_clear_queue_thread_unsafe(int vid, uint16_t queue_id, if (!dev) return 0; - VHOST_LOG_DATA(DEBUG, "(%d) %s\n", dev->vid, __func__); + VHOST_LOG_DATA(DEBUG, "(%s) %s\n", dev->ifname, __func__); if (unlikely(!is_valid_virt_queue_idx(queue_id, 0, dev->nr_vring))) { - VHOST_LOG_DATA(ERR, "(%d) %s: invalid virtqueue idx %d.\n", - dev->vid, __func__, queue_id); + VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", + dev->ifname, __func__, queue_id); return 0; } vq = dev->virtqueue[queue_id]; if (unlikely(!vq->async)) { - VHOST_LOG_DATA(ERR, "(%d) %s: async not registered for queue id %d.\n", - dev->vid, __func__, queue_id); + VHOST_LOG_DATA(ERR, "(%s) %s: async not registered for queue id %d.\n", + dev->ifname, __func__, queue_id); return 0; } @@ -1953,10 +1952,10 @@ virtio_dev_rx_async_submit(struct virtio_net *dev, uint16_t queue_id, struct vhost_virtqueue *vq; uint32_t nb_tx = 0; - VHOST_LOG_DATA(DEBUG, "(%d) %s\n", dev->vid, __func__); + VHOST_LOG_DATA(DEBUG, "(%s) %s\n", dev->ifname, __func__); if (unlikely(!is_valid_virt_queue_idx(queue_id, 0, dev->nr_vring))) { - VHOST_LOG_DATA(ERR, "(%d) %s: invalid virtqueue idx %d.\n", - dev->vid, __func__, queue_id); + VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", + dev->ifname, __func__, queue_id); return 0; } @@ -2005,9 +2004,8 @@ rte_vhost_submit_enqueue_burst(int vid, uint16_t queue_id, return 0; if (unlikely(!(dev->flags & VIRTIO_DEV_BUILTIN_VIRTIO_NET))) { - VHOST_LOG_DATA(ERR, - "(%d) %s: built-in vhost net backend is disabled.\n", - dev->vid, __func__); + VHOST_LOG_DATA(ERR, "(%s) %s: built-in vhost net backend is disabled.\n", + dev->ifname, __func__); return 0; } @@ -2114,7 +2112,8 @@ parse_headers(struct rte_mbuf *m, uint8_t *l4_proto) } static __rte_always_inline void -vhost_dequeue_offload_legacy(struct virtio_net_hdr *hdr, struct rte_mbuf *m) +vhost_dequeue_offload_legacy(struct virtio_net *dev, struct virtio_net_hdr *hdr, + struct rte_mbuf *m) { uint8_t l4_proto = 0; struct rte_tcp_hdr *tcp_hdr = NULL; @@ -2174,8 +2173,8 @@ vhost_dequeue_offload_legacy(struct virtio_net_hdr *hdr, struct rte_mbuf *m) m->l4_len = sizeof(struct rte_udp_hdr); break; default: - VHOST_LOG_DATA(WARNING, - "unsupported gso type %u.\n", hdr->gso_type); + VHOST_LOG_DATA(WARNING, "(%s) unsupported gso type %u.\n", + dev->ifname, hdr->gso_type); goto error; } } @@ -2188,8 +2187,8 @@ vhost_dequeue_offload_legacy(struct virtio_net_hdr *hdr, struct rte_mbuf *m) } static __rte_always_inline void -vhost_dequeue_offload(struct virtio_net_hdr *hdr, struct rte_mbuf *m, - bool legacy_ol_flags) +vhost_dequeue_offload(struct virtio_net *dev, struct virtio_net_hdr *hdr, + struct rte_mbuf *m, bool legacy_ol_flags) { struct rte_net_hdr_lens hdr_lens; int l4_supported = 0; @@ -2199,7 +2198,7 @@ vhost_dequeue_offload(struct virtio_net_hdr *hdr, struct rte_mbuf *m, return; if (legacy_ol_flags) { - vhost_dequeue_offload_legacy(hdr, m); + vhost_dequeue_offload_legacy(dev, hdr, m); return; } @@ -2412,8 +2411,8 @@ copy_desc_to_mbuf(struct virtio_net *dev, struct vhost_virtqueue *vq, if (mbuf_avail == 0) { cur = rte_pktmbuf_alloc(mbuf_pool); if (unlikely(cur == NULL)) { - VHOST_LOG_DATA(ERR, "Failed to " - "allocate memory for mbuf.\n"); + VHOST_LOG_DATA(ERR, "(%s) failed to allocate memory for mbuf.\n", + dev->ifname); error = -1; goto out; } @@ -2433,7 +2432,7 @@ copy_desc_to_mbuf(struct virtio_net *dev, struct vhost_virtqueue *vq, m->pkt_len += mbuf_offset; if (hdr) - vhost_dequeue_offload(hdr, m, legacy_ol_flags); + vhost_dequeue_offload(dev, hdr, m, legacy_ol_flags); out: @@ -2447,7 +2446,7 @@ virtio_dev_extbuf_free(void *addr __rte_unused, void *opaque) } static int -virtio_dev_extbuf_alloc(struct rte_mbuf *pkt, uint32_t size) +virtio_dev_extbuf_alloc(struct virtio_net *dev, struct rte_mbuf *pkt, uint32_t size) { struct rte_mbuf_ext_shared_info *shinfo = NULL; uint32_t total_len = RTE_PKTMBUF_HEADROOM + size; @@ -2471,7 +2470,7 @@ virtio_dev_extbuf_alloc(struct rte_mbuf *pkt, uint32_t size) virtio_dev_extbuf_free, buf); if (unlikely(shinfo == NULL)) { rte_free(buf); - VHOST_LOG_DATA(ERR, "Failed to init shinfo\n"); + VHOST_LOG_DATA(ERR, "(%s) failed to init shinfo\n", dev->ifname); return -1; } @@ -2493,7 +2492,7 @@ virtio_dev_pktmbuf_prep(struct virtio_net *dev, struct rte_mbuf *pkt, return 0; /* attach an external buffer if supported */ - if (dev->extbuf && !virtio_dev_extbuf_alloc(pkt, data_len)) + if (dev->extbuf && !virtio_dev_extbuf_alloc(dev, pkt, data_len)) return 0; /* check if chained buffers are allowed */ @@ -2525,12 +2524,12 @@ virtio_dev_tx_split(struct virtio_net *dev, struct vhost_virtqueue *vq, rte_prefetch0(&vq->avail->ring[vq->last_avail_idx & (vq->size - 1)]); - VHOST_LOG_DATA(DEBUG, "(%d) %s\n", dev->vid, __func__); + VHOST_LOG_DATA(DEBUG, "(%s) %s\n", dev->ifname, __func__); count = RTE_MIN(count, MAX_PKT_BURST); count = RTE_MIN(count, free_entries); - VHOST_LOG_DATA(DEBUG, "(%d) about to dequeue %u buffers\n", - dev->vid, count); + VHOST_LOG_DATA(DEBUG, "(%s) about to dequeue %u buffers\n", + dev->ifname, count); if (rte_pktmbuf_alloc_bulk(mbuf_pool, pkts, count)) return 0; @@ -2559,9 +2558,8 @@ virtio_dev_tx_split(struct virtio_net *dev, struct vhost_virtqueue *vq, * is required. Drop this packet. */ if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, - "Failed mbuf alloc of size %d from %s on %s.\n", - buf_len, mbuf_pool->name, dev->ifname); + VHOST_LOG_DATA(ERR, "(%s) failed mbuf alloc of size %d from %s.\n", + dev->ifname, buf_len, mbuf_pool->name); allocerr_warned = true; } dropped += 1; @@ -2573,8 +2571,7 @@ virtio_dev_tx_split(struct virtio_net *dev, struct vhost_virtqueue *vq, mbuf_pool, legacy_ol_flags); if (unlikely(err)) { if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, - "Failed to copy desc to mbuf on %s.\n", + VHOST_LOG_DATA(ERR, "(%s) failed to copy desc to mbuf.\n", dev->ifname); allocerr_warned = true; } @@ -2717,7 +2714,7 @@ virtio_dev_tx_batch_packed(struct virtio_net *dev, if (virtio_net_with_host_offload(dev)) { vhost_for_each_try_unroll(i, 0, PACKED_BATCH_SIZE) { hdr = (struct virtio_net_hdr *)(desc_addrs[i]); - vhost_dequeue_offload(hdr, pkts[i], legacy_ol_flags); + vhost_dequeue_offload(dev, hdr, pkts[i], legacy_ol_flags); } } @@ -2756,9 +2753,8 @@ vhost_dequeue_single_packed(struct virtio_net *dev, if (unlikely(virtio_dev_pktmbuf_prep(dev, pkts, buf_len))) { if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, - "Failed mbuf alloc of size %d from %s on %s.\n", - buf_len, mbuf_pool->name, dev->ifname); + VHOST_LOG_DATA(ERR, "(%s) failed mbuf alloc of size %d from %s.\n", + dev->ifname, buf_len, mbuf_pool->name); allocerr_warned = true; } return -1; @@ -2768,8 +2764,7 @@ vhost_dequeue_single_packed(struct virtio_net *dev, mbuf_pool, legacy_ol_flags); if (unlikely(err)) { if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, - "Failed to copy desc to mbuf on %s.\n", + VHOST_LOG_DATA(ERR, "(%s) failed to copy desc to mbuf.\n", dev->ifname); allocerr_warned = true; } @@ -2885,16 +2880,14 @@ rte_vhost_dequeue_burst(int vid, uint16_t queue_id, return 0; if (unlikely(!(dev->flags & VIRTIO_DEV_BUILTIN_VIRTIO_NET))) { - VHOST_LOG_DATA(ERR, - "(%d) %s: built-in vhost net backend is disabled.\n", - dev->vid, __func__); + VHOST_LOG_DATA(ERR, "(%s) %s: built-in vhost net backend is disabled.\n", + dev->ifname, __func__); return 0; } if (unlikely(!is_valid_virt_queue_idx(queue_id, 1, dev->nr_vring))) { - VHOST_LOG_DATA(ERR, - "(%d) %s: invalid virtqueue idx %d.\n", - dev->vid, __func__, queue_id); + VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", + dev->ifname, __func__, queue_id); return 0; } @@ -2939,7 +2932,7 @@ rte_vhost_dequeue_burst(int vid, uint16_t queue_id, rarp_mbuf = rte_net_make_rarp_packet(mbuf_pool, &dev->mac); if (rarp_mbuf == NULL) { - VHOST_LOG_DATA(ERR, "Failed to make RARP packet.\n"); + VHOST_LOG_DATA(ERR, "(%s) failed to make RARP packet.\n", dev->ifname); count = 0; goto out; } From patchwork Thu Dec 23 08:36:59 2021 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Maxime Coquelin X-Patchwork-Id: 105361 X-Patchwork-Delegate: maxime.coquelin@redhat.com Return-Path: X-Original-To: patchwork@inbox.dpdk.org Delivered-To: patchwork@inbox.dpdk.org Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id 3949CA0350; Thu, 23 Dec 2021 09:37:58 +0100 (CET) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 2D5B44113E; Thu, 23 Dec 2021 09:37:58 +0100 (CET) Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.133.124]) by mails.dpdk.org (Postfix) with ESMTP id 76972410E5 for ; Thu, 23 Dec 2021 09:37:56 +0100 (CET) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1640248676; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=FnBKIaPKbH5lcl2z8/5RH4qDQFnnFHxnJkuUbbdbSO4=; b=Ww8yMAmPPkkR/DPRH1AKO8MDQlPnWG4u6gHExw597cPbuenR/pb5X4INkDG8J96khtzCbR LCt6k9qmK+RfI2oAwuMxkhWdDybOucK0PIOvgucS3MP8vpQXkY7m3Y8sajmwbS0ODIkVsw KLlCRka0RSaKzP22I5aMMGDBd2jC2Iw= Received: from mimecast-mx01.redhat.com (mimecast-mx01.redhat.com [209.132.183.4]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-604-BRj5ytmxNz2Yk3MEPb_eYQ-1; Thu, 23 Dec 2021 03:37:54 -0500 X-MC-Unique: BRj5ytmxNz2Yk3MEPb_eYQ-1 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 mimecast-mx01.redhat.com (Postfix) with ESMTPS id B5B52100C622; Thu, 23 Dec 2021 08:37:53 +0000 (UTC) Received: from max-t490s.redhat.com (unknown [10.39.208.14]) by smtp.corp.redhat.com (Postfix) with ESMTP id 9C30C60BD8; Thu, 23 Dec 2021 08:37:48 +0000 (UTC) From: Maxime Coquelin To: dev@dpdk.org, chenbo.xia@intel.com, david.marchand@redhat.com Cc: Maxime Coquelin Subject: [PATCH 7/7] vhost: remove multi-line logs Date: Thu, 23 Dec 2021 09:36:59 +0100 Message-Id: <20211223083659.245766-8-maxime.coquelin@redhat.com> In-Reply-To: <20211223083659.245766-1-maxime.coquelin@redhat.com> References: <20211223083659.245766-1-maxime.coquelin@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.5.11.11 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=maxime.coquelin@redhat.com X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org This patch replaces multi-lines logs in multiple single- line logs in order to ease logs filtering based on their socket path. Signed-off-by: Maxime Coquelin --- lib/vhost/socket.c | 10 ++-- lib/vhost/vhost.c | 8 ++-- lib/vhost/vhost_user.c | 106 +++++++++++++++++++---------------------- 3 files changed, 60 insertions(+), 64 deletions(-) diff --git a/lib/vhost/socket.c b/lib/vhost/socket.c index fd6b3a3ee4..9c31498a87 100644 --- a/lib/vhost/socket.c +++ b/lib/vhost/socket.c @@ -865,8 +865,8 @@ rte_vhost_driver_register(const char *path, uint64_t flags) if (vsocket->async_copy && (flags & (RTE_VHOST_USER_IOMMU_SUPPORT | RTE_VHOST_USER_POSTCOPY_SUPPORT))) { - VHOST_LOG_CONFIG(ERR, "(%s) enabling async copy and IOMMU " - "or post-copy feature simultaneously is not supported\n", path); + VHOST_LOG_CONFIG(ERR, "(%s) async copy with IOMMU or post-copy not supported\n", + path); goto out_mutex; } @@ -905,8 +905,10 @@ rte_vhost_driver_register(const char *path, uint64_t flags) (1ULL << VIRTIO_NET_F_HOST_TSO6) | (1ULL << VIRTIO_NET_F_HOST_UFO); - VHOST_LOG_CONFIG(INFO, "(%s) Linear buffers requested without external buffers, " - "disabling host segmentation offloading support\n", path); + VHOST_LOG_CONFIG(INFO, "(%s) Linear buffers requested without external buffers,\n", + path); + VHOST_LOG_CONFIG(INFO, "(%s) disabling host segmentation offloading support\n", + path); vsocket->supported_features &= ~seg_offload_features; vsocket->features &= ~seg_offload_features; } diff --git a/lib/vhost/vhost.c b/lib/vhost/vhost.c index dac0915ac0..857cdc5ac1 100644 --- a/lib/vhost/vhost.c +++ b/lib/vhost/vhost.c @@ -1786,8 +1786,8 @@ rte_vhost_async_channel_unregister(int vid, uint16_t queue_id) } if (vq->async->pkts_inflight_n) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to unregister async channel. " - "async inflight packets must be completed before unregistration.\n", + VHOST_LOG_CONFIG(ERR, "(%s) failed to unregister async channel.\n", dev->ifname); + VHOST_LOG_CONFIG(ERR, "(%s) inflight packets must be completed before unregistration.\n", dev->ifname); ret = -1; goto out; @@ -1821,8 +1821,8 @@ rte_vhost_async_channel_unregister_thread_unsafe(int vid, uint16_t queue_id) return 0; if (vq->async->pkts_inflight_n) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to unregister async channel. " - "async inflight packets must be completed before unregistration.\n", + VHOST_LOG_CONFIG(ERR, "(%s) failed to unregister async channel.\n", dev->ifname); + VHOST_LOG_CONFIG(ERR, "(%s) inflight packets must be completed before unregistration.\n", dev->ifname); return -1; } diff --git a/lib/vhost/vhost_user.c b/lib/vhost/vhost_user.c index 923d619213..c34819f371 100644 --- a/lib/vhost/vhost_user.c +++ b/lib/vhost/vhost_user.c @@ -872,13 +872,13 @@ translate_ring_addresses(struct virtio_net *dev, int vq_index) } if (vq->last_used_idx != vq->used->idx) { - VHOST_LOG_CONFIG(WARNING, - "(%s) last_used_idx (%u) and vq->used->idx (%u) mismatches; " - "some packets maybe resent for Tx and dropped for Rx\n", + VHOST_LOG_CONFIG(WARNING, "(%s) last_used_idx (%u) and vq->used->idx (%u) mismatches;\n", dev->ifname, vq->last_used_idx, vq->used->idx); vq->last_used_idx = vq->used->idx; vq->last_avail_idx = vq->used->idx; + VHOST_LOG_CONFIG(WARNING, "(%s) some packets maybe resent for Tx and dropped for Rx\n", + dev->ifname); } vq->access_ok = true; @@ -1066,15 +1066,14 @@ dump_guest_pages(struct virtio_net *dev) for (i = 0; i < dev->nr_guest_pages; i++) { page = &dev->guest_pages[i]; - VHOST_LOG_CONFIG(INFO, - "(%s) guest physical page region %u\n" - "\t guest_phys_addr: %" PRIx64 "\n" - "\t host_phys_addr : %" PRIx64 "\n" - "\t size : %" PRIx64 "\n", - dev->ifname, i, - page->guest_phys_addr, - page->host_phys_addr, - page->size); + VHOST_LOG_CONFIG(INFO, "(%s) guest physical page region %u\n", + dev->ifname, i); + VHOST_LOG_CONFIG(INFO, "(%s)\tguest_phys_addr: %" PRIx64 "\n", + dev->ifname, page->guest_phys_addr); + VHOST_LOG_CONFIG(INFO, "(%s)\thost_phys_addr : %" PRIx64 "\n", + dev->ifname, page->host_phys_addr); + VHOST_LOG_CONFIG(INFO, "(%s)\tsize : %" PRIx64 "\n", + dev->ifname, page->size); } } #else @@ -1122,8 +1121,7 @@ vhost_user_postcopy_region_register(struct virtio_net *dev, if (ioctl(dev->postcopy_ufd, UFFDIO_REGISTER, ®_struct)) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to register ufd for region " - "%" PRIx64 " - %" PRIx64 " (ufd = %d) %s\n", + VHOST_LOG_CONFIG(ERR, "(%s) failed to register ufd for region %" PRIx64 " - %" PRIx64 " (ufd = %d) %s\n", dev->ifname, (uint64_t)reg_struct.range.start, (uint64_t)reg_struct.range.start + @@ -1133,7 +1131,8 @@ vhost_user_postcopy_region_register(struct virtio_net *dev, return -1; } - VHOST_LOG_CONFIG(INFO, "(%s)\t userfaultfd registered for range : %" PRIx64 " - %" PRIx64 "\n", + VHOST_LOG_CONFIG(INFO, + "(%s)\t userfaultfd registered for range : %" PRIx64 " - %" PRIx64 "\n", dev->ifname, (uint64_t)reg_struct.range.start, (uint64_t)reg_struct.range.start + @@ -1218,8 +1217,7 @@ vhost_user_mmap_region(struct virtio_net *dev, /* Check for memory_size + mmap_offset overflow */ if (mmap_offset >= -region->size) { - VHOST_LOG_CONFIG(ERR, "(%s) mmap_offset (%#"PRIx64") and memory_size " - "(%#"PRIx64") overflow\n", + VHOST_LOG_CONFIG(ERR, "(%s) mmap_offset (%#"PRIx64") and memory_size (%#"PRIx64") overflow\n", dev->ifname, mmap_offset, region->size); return -1; } @@ -1248,8 +1246,7 @@ vhost_user_mmap_region(struct virtio_net *dev, * mmap() kernel implementation would return an error, but * better catch it before and provide useful info in the logs. */ - VHOST_LOG_CONFIG(ERR, "(%s) mmap size (0x%" PRIx64 ") " - "or alignment (0x%" PRIx64 ") is invalid\n", + VHOST_LOG_CONFIG(ERR, "(%s) mmap size (0x%" PRIx64 ") or alignment (0x%" PRIx64 ") is invalid\n", dev->ifname, region->size + mmap_offset, alignment); return -1; } @@ -1285,24 +1282,22 @@ vhost_user_mmap_region(struct virtio_net *dev, } } - VHOST_LOG_CONFIG(INFO, - "(%s) guest memory region size: 0x%" PRIx64 "\n" - "\t guest physical addr: 0x%" PRIx64 "\n" - "\t guest virtual addr: 0x%" PRIx64 "\n" - "\t host virtual addr: 0x%" PRIx64 "\n" - "\t mmap addr : 0x%" PRIx64 "\n" - "\t mmap size : 0x%" PRIx64 "\n" - "\t mmap align: 0x%" PRIx64 "\n" - "\t mmap off : 0x%" PRIx64 "\n", - dev->ifname, - region->size, - region->guest_phys_addr, - region->guest_user_addr, - region->host_user_addr, - (uint64_t)(uintptr_t)mmap_addr, - mmap_size, - alignment, - mmap_offset); + VHOST_LOG_CONFIG(INFO, "(%s) guest memory region size: 0x%" PRIx64 "\n", + dev->ifname, region->size); + VHOST_LOG_CONFIG(INFO, "(%s)\t guest physical addr: 0x%" PRIx64 "\n", + dev->ifname, region->guest_phys_addr); + VHOST_LOG_CONFIG(INFO, "(%s)\t guest virtual addr: 0x%" PRIx64 "\n", + dev->ifname, region->guest_user_addr); + VHOST_LOG_CONFIG(INFO, "(%s)\t host virtual addr: 0x%" PRIx64 "\n", + dev->ifname, region->host_user_addr); + VHOST_LOG_CONFIG(INFO, "(%s)\t mmap addr : 0x%" PRIx64 "\n", + dev->ifname, (uint64_t)(uintptr_t)mmap_addr); + VHOST_LOG_CONFIG(INFO, "(%s)\t mmap size : 0x%" PRIx64 "\n", + dev->ifname, mmap_size); + VHOST_LOG_CONFIG(INFO, "(%s)\t mmap align: 0x%" PRIx64 "\n", + dev->ifname, alignment); + VHOST_LOG_CONFIG(INFO, "(%s)\t mmap off : 0x%" PRIx64 "\n", + dev->ifname, mmap_offset); return 0; } @@ -2201,9 +2196,9 @@ vhost_user_set_vring_enable(struct virtio_net **pdev, if (enable && dev->virtqueue[index]->async) { if (dev->virtqueue[index]->async->pkts_inflight_n) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to enable vring. " - "async inflight packets must be completed first\n", - dev->ifname); + VHOST_LOG_CONFIG(ERR, + "(%s) failed to enable vring. Inflight packets must be completed first\n", + dev->ifname); return RTE_VHOST_MSG_RESULT_ERR; } } @@ -2709,22 +2704,21 @@ vhost_user_set_status(struct virtio_net **pdev, struct VhostUserMsg *msg, dev->status &= ~VIRTIO_DEVICE_STATUS_FEATURES_OK; } - VHOST_LOG_CONFIG(INFO, "(%s) new device status(0x%08x):\n" - "\t-RESET: %u\n" - "\t-ACKNOWLEDGE: %u\n" - "\t-DRIVER: %u\n" - "\t-FEATURES_OK: %u\n" - "\t-DRIVER_OK: %u\n" - "\t-DEVICE_NEED_RESET: %u\n" - "\t-FAILED: %u\n", - dev->ifname, - dev->status, - (dev->status == VIRTIO_DEVICE_STATUS_RESET), - !!(dev->status & VIRTIO_DEVICE_STATUS_ACK), - !!(dev->status & VIRTIO_DEVICE_STATUS_DRIVER), - !!(dev->status & VIRTIO_DEVICE_STATUS_FEATURES_OK), - !!(dev->status & VIRTIO_DEVICE_STATUS_DRIVER_OK), - !!(dev->status & VIRTIO_DEVICE_STATUS_DEV_NEED_RESET), + VHOST_LOG_CONFIG(INFO, "(%s) new device status(0x%08x):\n", dev->ifname, + dev->status); + VHOST_LOG_CONFIG(INFO, "(%s)\t-RESET: %u\n", dev->ifname, + (dev->status == VIRTIO_DEVICE_STATUS_RESET)); + VHOST_LOG_CONFIG(INFO, "(%s)\t-ACKNOWLEDGE: %u\n", dev->ifname, + !!(dev->status & VIRTIO_DEVICE_STATUS_ACK)); + VHOST_LOG_CONFIG(INFO, "(%s)\t-DRIVER: %u\n", dev->ifname, + !!(dev->status & VIRTIO_DEVICE_STATUS_DRIVER)); + VHOST_LOG_CONFIG(INFO, "(%s)\t-FEATURES_OK: %u\n", dev->ifname, + !!(dev->status & VIRTIO_DEVICE_STATUS_FEATURES_OK)); + VHOST_LOG_CONFIG(INFO, "(%s)\t-DRIVER_OK: %u\n", dev->ifname, + !!(dev->status & VIRTIO_DEVICE_STATUS_DRIVER_OK)); + VHOST_LOG_CONFIG(INFO, "(%s)\t-DEVICE_NEED_RESET: %u\n", dev->ifname, + !!(dev->status & VIRTIO_DEVICE_STATUS_DEV_NEED_RESET)); + VHOST_LOG_CONFIG(INFO, "(%s)\t-FAILED: %u\n", dev->ifname, !!(dev->status & VIRTIO_DEVICE_STATUS_FAILED)); return RTE_VHOST_MSG_RESULT_OK;