From patchwork Mon Jun 27 09:27:28 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: David Marchand X-Patchwork-Id: 113466 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 73182A0552; Mon, 27 Jun 2022 11:28:05 +0200 (CEST) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 69CC742B71; Mon, 27 Jun 2022 11:27:57 +0200 (CEST) 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 DA454400D5 for ; Mon, 27 Jun 2022 11:27:55 +0200 (CEST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1656322075; 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=jU4NYq3TTVpKqUVarCnFOKeQ/0kEoe5/t9/gQT2qd1M=; b=Pic61JJmRO2gjx3nmZdvke0E+43arlvSChVgpZSV8l+JZgPWZIhFTdCWJZ1tgEkDSbpSRK WQzNqF4DMLlGW0K6Vl+AW2ityje4Q63W5S5UmQ+0i6Pp8rhiUUwtclMCcMHgoMkXpZXeIe JkQSuRl4TCbfjuXyGfQB1zV1N3DmQYo= Received: from mimecast-mx02.redhat.com (mimecast-mx02.redhat.com [66.187.233.88]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-568-DUnQhc0zPYePBYmVIN7Fkg-1; Mon, 27 Jun 2022 05:27:51 -0400 X-MC-Unique: DUnQhc0zPYePBYmVIN7Fkg-1 Received: from smtp.corp.redhat.com (int-mx05.intmail.prod.int.rdu2.redhat.com [10.11.54.5]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mimecast-mx02.redhat.com (Postfix) with ESMTPS id 83EDB811E83; Mon, 27 Jun 2022 09:27:51 +0000 (UTC) Received: from localhost.localdomain (unknown [10.40.192.104]) by smtp.corp.redhat.com (Postfix) with ESMTP id 3846C9D54; Mon, 27 Jun 2022 09:27:50 +0000 (UTC) From: David Marchand To: dev@dpdk.org Cc: maxime.coquelin@redhat.com, chenbo.xia@intel.com Subject: [PATCH 4/4] vhost: prefix logs with context Date: Mon, 27 Jun 2022 11:27:28 +0200 Message-Id: <20220627092728.78214-5-david.marchand@redhat.com> In-Reply-To: <20220627092728.78214-1-david.marchand@redhat.com> References: <20220627092728.78214-1-david.marchand@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 2.79 on 10.11.54.5 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=david.marchand@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 We recently improved the log messages in the vhost library, adding some context that helps filtering for a given vhost-user device. However, some parts of the code were missed, and some later code changes broke this new convention (fixes were sent previous to this patch). Change the VHOST_LOG_CONFIG/DATA helpers and always ask for a string used as context. This should help limit regressions on this topic. Most of the time, the context is the vhost-user device socket path. For the rest when a vhost-user device can not be related, generic names were chosen: - "dma", for vhost-user async DMA operations, - "device", for vhost-user device creation and lookup, - "thread", for threads management, Signed-off-by: David Marchand --- lib/vhost/iotlb.c | 30 +- lib/vhost/socket.c | 129 ++++----- lib/vhost/vdpa.c | 4 +- lib/vhost/vhost.c | 144 ++++----- lib/vhost/vhost.h | 20 +- lib/vhost/vhost_user.c | 642 +++++++++++++++++++++-------------------- lib/vhost/virtio_net.c | 258 +++++++++-------- 7 files changed, 634 insertions(+), 593 deletions(-) diff --git a/lib/vhost/iotlb.c b/lib/vhost/iotlb.c index 5a5ba8b82a..35b4193606 100644 --- a/lib/vhost/iotlb.c +++ b/lib/vhost/iotlb.c @@ -70,18 +70,18 @@ vhost_user_iotlb_pending_insert(struct virtio_net *dev, struct vhost_virtqueue * ret = rte_mempool_get(vq->iotlb_pool, (void **)&node); if (ret) { - VHOST_LOG_CONFIG(DEBUG, - "(%s) IOTLB pool %s empty, clear entries for pending insertion\n", - dev->ifname, vq->iotlb_pool->name); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, + "IOTLB pool %s empty, clear entries for pending insertion\n", + 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, - "(%s) IOTLB pool %s still empty, pending insertion failure\n", - dev->ifname, vq->iotlb_pool->name); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "IOTLB pool %s still empty, pending insertion failure\n", + vq->iotlb_pool->name); return; } } @@ -169,18 +169,18 @@ vhost_user_iotlb_cache_insert(struct virtio_net *dev, struct vhost_virtqueue *vq ret = rte_mempool_get(vq->iotlb_pool, (void **)&new_node); if (ret) { - VHOST_LOG_CONFIG(DEBUG, - "(%s) IOTLB pool %s empty, clear entries for cache insertion\n", - dev->ifname, vq->iotlb_pool->name); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, + "IOTLB pool %s empty, clear entries for cache insertion\n", + 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, - "(%s) IOTLB pool %s still empty, cache insertion failed\n", - dev->ifname, vq->iotlb_pool->name); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "IOTLB pool %s still empty, cache insertion failed\n", + vq->iotlb_pool->name); return; } } @@ -320,7 +320,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, "(%s) IOTLB cache name: %s\n", dev->ifname, pool_name); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "IOTLB cache name: %s\n", pool_name); /* If already created, free it and recreate */ vq->iotlb_pool = rte_mempool_lookup(pool_name); @@ -332,8 +332,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, "(%s) Failed to create IOTLB cache pool %s\n", - dev->ifname, pool_name); + VHOST_LOG_CONFIG(dev->ifname, ERR, "Failed to create IOTLB cache pool %s\n", + pool_name); return -1; } diff --git a/lib/vhost/socket.c b/lib/vhost/socket.c index 24d60ca149..a8df2d484a 100644 --- a/lib/vhost/socket.c +++ b/lib/vhost/socket.c @@ -124,13 +124,13 @@ read_fd_message(char *ifname, int sockfd, char *buf, int buflen, int *fds, int m ret = recvmsg(sockfd, &msgh, 0); if (ret <= 0) { if (ret) - VHOST_LOG_CONFIG(ERR, "(%s) recvmsg failed on fd %d (%s)\n", - ifname, sockfd, strerror(errno)); + VHOST_LOG_CONFIG(ifname, ERR, "recvmsg failed on fd %d (%s)\n", + sockfd, strerror(errno)); return ret; } if (msgh.msg_flags & (MSG_TRUNC | MSG_CTRUNC)) { - VHOST_LOG_CONFIG(ERR, "(%s) truncated msg (fd %d)\n", ifname, sockfd); + VHOST_LOG_CONFIG(ifname, ERR, "truncated msg (fd %d)\n", sockfd); return -1; } @@ -175,7 +175,7 @@ send_fd_message(char *ifname, int sockfd, char *buf, int buflen, int *fds, int f msgh.msg_controllen = sizeof(control); cmsg = CMSG_FIRSTHDR(&msgh); if (cmsg == NULL) { - VHOST_LOG_CONFIG(ERR, "(%s) cmsg == NULL\n", ifname); + VHOST_LOG_CONFIG(ifname, ERR, "cmsg == NULL\n"); errno = EINVAL; return -1; } @@ -193,8 +193,8 @@ send_fd_message(char *ifname, int sockfd, char *buf, int buflen, int *fds, int f } while (ret < 0 && errno == EINTR); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) sendmsg error on fd %d (%s)\n", - ifname, sockfd, strerror(errno)); + VHOST_LOG_CONFIG(ifname, ERR, "sendmsg error on fd %d (%s)\n", + sockfd, strerror(errno)); return ret; } @@ -245,14 +245,14 @@ vhost_user_add_connection(int fd, struct vhost_user_socket *vsocket) dev->async_copy = 1; } - VHOST_LOG_CONFIG(INFO, "(%s) new device, handle is %d\n", vsocket->path, vid); + VHOST_LOG_CONFIG(vsocket->path, INFO, "new device, handle is %d\n", vid); if (vsocket->notify_ops->new_connection) { ret = vsocket->notify_ops->new_connection(vid); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to add vhost user connection with fd %d\n", - vsocket->path, fd); + VHOST_LOG_CONFIG(vsocket->path, ERR, + "failed to add vhost user connection with fd %d\n", + fd); goto err_cleanup; } } @@ -263,8 +263,9 @@ 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, "(%s) failed to add fd %d into vhost server fdset\n", - vsocket->path, fd); + VHOST_LOG_CONFIG(vsocket->path, ERR, + "failed to add fd %d into vhost server fdset\n", + fd); if (vsocket->notify_ops->destroy_connection) vsocket->notify_ops->destroy_connection(conn->vid); @@ -296,8 +297,7 @@ vhost_user_server_new_connection(int fd, void *dat, int *remove __rte_unused) if (fd < 0) return; - VHOST_LOG_CONFIG(INFO, "(%s) new vhost user connection is %d\n", - vsocket->path, fd); + VHOST_LOG_CONFIG(vsocket->path, INFO, "new vhost user connection is %d\n", fd); vhost_user_add_connection(fd, vsocket); } @@ -345,13 +345,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, "(%s) vhost-user %s: socket created, fd: %d\n", - vsocket->path, vsocket->is_server ? "server" : "client", fd); + VHOST_LOG_CONFIG(vsocket->path, INFO, "vhost-user %s: socket created, fd: %d\n", + vsocket->is_server ? "server" : "client", fd); if (!vsocket->is_server && fcntl(fd, F_SETFL, O_NONBLOCK)) { - VHOST_LOG_CONFIG(ERR, - "(%s) vhost-user: can't set nonblocking mode for socket, fd: %d (%s)\n", - vsocket->path, fd, strerror(errno)); + VHOST_LOG_CONFIG(vsocket->path, ERR, + "vhost-user: can't set nonblocking mode for socket, fd: %d (%s)\n", + fd, strerror(errno)); close(fd); return -1; } @@ -384,11 +384,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, "(%s) failed to bind: %s; remove it and try again\n", - path, strerror(errno)); + VHOST_LOG_CONFIG(path, ERR, "failed to bind: %s; remove it and try again\n", + strerror(errno)); goto err; } - VHOST_LOG_CONFIG(INFO, "(%s) binding succeeded\n", path); + VHOST_LOG_CONFIG(path, INFO, "binding succeeded\n"); ret = listen(fd, MAX_VIRTIO_BACKLOG); if (ret < 0) @@ -397,9 +397,8 @@ vhost_user_start_server(struct vhost_user_socket *vsocket) ret = fdset_add(&vhost_user.fdset, fd, vhost_user_server_new_connection, NULL, vsocket); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to add listen fd %d to vhost server fdset\n", - path, fd); + VHOST_LOG_CONFIG(path, ERR, "failed to add listen fd %d to vhost server fdset\n", + fd); goto err; } @@ -438,12 +437,12 @@ vhost_user_connect_nonblock(char *path, int fd, struct sockaddr *un, size_t sz) flags = fcntl(fd, F_GETFL, 0); if (flags < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) can't get flags for connfd %d (%s)\n", - path, fd, strerror(errno)); + VHOST_LOG_CONFIG(path, ERR, "can't get flags for connfd %d (%s)\n", + fd, strerror(errno)); return -2; } if ((flags & O_NONBLOCK) && fcntl(fd, F_SETFL, flags & ~O_NONBLOCK)) { - VHOST_LOG_CONFIG(ERR, "(%s) can't disable nonblocking on fd %d\n", path, fd); + VHOST_LOG_CONFIG(path, ERR, "can't disable nonblocking on fd %d\n", fd); return -2; } return 0; @@ -471,14 +470,15 @@ vhost_user_client_reconnect(void *arg __rte_unused) sizeof(reconn->un)); if (ret == -2) { close(reconn->fd); - VHOST_LOG_CONFIG(ERR, "(%s) reconnection for fd %d failed\n", - reconn->vsocket->path, reconn->fd); + VHOST_LOG_CONFIG(reconn->vsocket->path, ERR, + "reconnection for fd %d failed\n", + reconn->fd); goto remove_fd; } if (ret == -1) continue; - VHOST_LOG_CONFIG(INFO, "(%s) connected\n", reconn->vsocket->path); + VHOST_LOG_CONFIG(reconn->vsocket->path, INFO, "connected\n"); vhost_user_add_connection(reconn->fd, reconn->vsocket); remove_fd: TAILQ_REMOVE(&reconn_list.head, reconn, next); @@ -499,7 +499,7 @@ vhost_user_reconnect_init(void) ret = pthread_mutex_init(&reconn_list.mutex, NULL); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, "%s: failed to initialize mutex\n", __func__); + VHOST_LOG_CONFIG("thread", ERR, "%s: failed to initialize mutex\n", __func__); return ret; } TAILQ_INIT(&reconn_list.head); @@ -507,9 +507,11 @@ vhost_user_reconnect_init(void) ret = rte_ctrl_thread_create(&reconn_tid, "vhost_reconn", NULL, vhost_user_client_reconnect, NULL); if (ret != 0) { - VHOST_LOG_CONFIG(ERR, "failed to create reconnect thread\n"); + VHOST_LOG_CONFIG("thread", ERR, "failed to create reconnect thread\n"); if (pthread_mutex_destroy(&reconn_list.mutex)) - VHOST_LOG_CONFIG(ERR, "%s: failed to destroy reconnect mutex\n", __func__); + VHOST_LOG_CONFIG("thread", ERR, + "%s: failed to destroy reconnect mutex\n", + __func__); } return ret; @@ -530,17 +532,17 @@ vhost_user_start_client(struct vhost_user_socket *vsocket) return 0; } - VHOST_LOG_CONFIG(WARNING, "(%s) failed to connect: %s\n", path, strerror(errno)); + VHOST_LOG_CONFIG(path, WARNING, "failed to connect: %s\n", strerror(errno)); if (ret == -2 || !vsocket->reconnect) { close(fd); return -1; } - VHOST_LOG_CONFIG(INFO, "(%s) reconnecting...\n", path); + VHOST_LOG_CONFIG(path, INFO, "reconnecting...\n"); reconn = malloc(sizeof(*reconn)); if (reconn == NULL) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate memory for reconnect\n", path); + VHOST_LOG_CONFIG(path, ERR, "failed to allocate memory for reconnect\n"); close(fd); return -1; } @@ -630,9 +632,7 @@ rte_vhost_driver_get_vdpa_dev_type(const char *path, uint32_t *type) pthread_mutex_lock(&vhost_user.mutex); vsocket = find_vhost_user_socket(path); if (!vsocket) { - VHOST_LOG_CONFIG(ERR, - "(%s) socket file is not registered yet.\n", - path); + VHOST_LOG_CONFIG(path, ERR, "socket file is not registered yet.\n"); ret = -1; goto unlock_exit; } @@ -646,9 +646,8 @@ rte_vhost_driver_get_vdpa_dev_type(const char *path, uint32_t *type) if (vdpa_dev->ops->get_dev_type) { ret = vdpa_dev->ops->get_dev_type(vdpa_dev, &vdpa_type); if (ret) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to get vdpa dev type for socket file.\n", - path); + VHOST_LOG_CONFIG(path, ERR, + "failed to get vdpa dev type for socket file.\n"); ret = -1; goto unlock_exit; } @@ -738,7 +737,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, "(%s) socket file is not registered yet.\n", path); + VHOST_LOG_CONFIG(path, ERR, "socket file is not registered yet.\n"); ret = -1; goto unlock_exit; } @@ -750,7 +749,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, "(%s) failed to get vdpa features for socket file.\n", path); + VHOST_LOG_CONFIG(path, ERR, "failed to get vdpa features for socket file.\n"); ret = -1; goto unlock_exit; } @@ -788,7 +787,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, "(%s) socket file is not registered yet.\n", path); + VHOST_LOG_CONFIG(path, ERR, "socket file is not registered yet.\n"); ret = -1; goto unlock_exit; } @@ -801,8 +800,7 @@ 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, "(%s) failed to get vdpa protocol features.\n", - path); + VHOST_LOG_CONFIG(path, ERR, "failed to get vdpa protocol features.\n"); ret = -1; goto unlock_exit; } @@ -826,7 +824,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, "(%s) socket file is not registered yet.\n", path); + VHOST_LOG_CONFIG(path, ERR, "socket file is not registered yet.\n"); ret = -1; goto unlock_exit; } @@ -838,8 +836,7 @@ 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, "(%s) failed to get vdpa queue number.\n", - path); + VHOST_LOG_CONFIG(path, ERR, "failed to get vdpa queue number.\n"); ret = -1; goto unlock_exit; } @@ -882,8 +879,7 @@ 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, "(%s) the number of vhost sockets reaches maximum\n", - path); + VHOST_LOG_CONFIG(path, ERR, "the number of vhost sockets reaches maximum\n"); goto out; } @@ -893,14 +889,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, "(%s) failed to copy socket path string\n", path); + VHOST_LOG_CONFIG(path, ERR, "failed to copy socket path string\n"); 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, "(%s) failed to init connection mutex\n", path); + VHOST_LOG_CONFIG(path, ERR, "failed to init connection mutex\n"); goto out_free; } vsocket->vdpa_dev = NULL; @@ -913,8 +909,7 @@ 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) async copy with IOMMU or post-copy not supported\n", - path); + VHOST_LOG_CONFIG(path, ERR, "async copy with IOMMU or post-copy not supported\n"); goto out_mutex; } @@ -938,8 +933,7 @@ 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, "(%s) logging feature is disabled in async copy mode\n", - path); + VHOST_LOG_CONFIG(path, INFO, "logging feature is disabled in async copy mode\n"); } /* @@ -953,10 +947,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, "(%s) Linear buffers requested without external buffers,\n", - path); - VHOST_LOG_CONFIG(INFO, "(%s) disabling host segmentation offloading support\n", - path); + VHOST_LOG_CONFIG(path, INFO, "Linear buffers requested without external buffers,\n"); + VHOST_LOG_CONFIG(path, INFO, "disabling host segmentation offloading support\n"); vsocket->supported_features &= ~seg_offload_features; vsocket->features &= ~seg_offload_features; } @@ -971,7 +963,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, "(%s) Postcopy requested but not compiled\n", path); + VHOST_LOG_CONFIG(path, ERR, "Postcopy requested but not compiled\n"); ret = -1; goto out_mutex; #endif @@ -998,7 +990,7 @@ rte_vhost_driver_register(const char *path, uint64_t flags) out_mutex: if (pthread_mutex_destroy(&vsocket->conn_mutex)) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to destroy connection mutex\n", path); + VHOST_LOG_CONFIG(path, ERR, "failed to destroy connection mutex\n"); } out_free: vhost_user_socket_mem_free(vsocket); @@ -1086,7 +1078,7 @@ rte_vhost_driver_unregister(const char *path) goto again; } - VHOST_LOG_CONFIG(INFO, "(%s) free connfd %d\n", path, conn->connfd); + VHOST_LOG_CONFIG(path, INFO, "free connfd %d\n", conn->connfd); close(conn->connfd); vhost_destroy_device(conn->vid); TAILQ_REMOVE(&vsocket->conn_list, conn, next); @@ -1162,7 +1154,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, "(%s) failed to create pipe for vhost fdset\n", path); + VHOST_LOG_CONFIG(path, ERR, "failed to create pipe for vhost fdset\n"); return -1; } @@ -1170,8 +1162,7 @@ rte_vhost_driver_start(const char *path) "vhost-events", NULL, fdset_event_dispatch, &vhost_user.fdset); if (ret != 0) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to create fdset handling thread\n", - path); + VHOST_LOG_CONFIG(path, ERR, "failed to create fdset handling thread\n"); fdset_pipe_uninit(&vhost_user.fdset); return -1; } diff --git a/lib/vhost/vdpa.c b/lib/vhost/vdpa.c index 8fa2153023..b2a2919fc0 100644 --- a/lib/vhost/vdpa.c +++ b/lib/vhost/vdpa.c @@ -81,8 +81,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, "(%s) Some mandatory vDPA ops aren't implemented\n", - rte_dev->name); + VHOST_LOG_CONFIG(rte_dev->name, ERR, + "Some mandatory vDPA ops aren't implemented\n"); return NULL; } diff --git a/lib/vhost/vhost.c b/lib/vhost/vhost.c index b14521e4d1..8003031026 100644 --- a/lib/vhost/vhost.c +++ b/lib/vhost/vhost.c @@ -87,8 +87,9 @@ __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_DATA(ERR, "(%s) IOTLB miss req failed for IOVA 0x%" PRIx64 "\n", - dev->ifname, iova); + VHOST_LOG_DATA(dev->ifname, ERR, + "IOTLB miss req failed for IOVA 0x%" PRIx64 "\n", + iova); vhost_user_iotlb_pending_remove(vq, iova, 1, perm); } @@ -153,9 +154,9 @@ __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, - "(%s) failed to write log for IOVA 0x%" PRIx64 ". No IOTLB entry found\n", - dev->ifname, iova); + VHOST_LOG_DATA(dev->ifname, ERR, + "failed to write log for IOVA 0x%" PRIx64 ". No IOTLB entry found\n", + iova); return; } @@ -270,9 +271,9 @@ __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, - "(%s) failed to write log for IOVA 0x%" PRIx64 ". No IOTLB entry found\n", - dev->ifname, iova); + VHOST_LOG_DATA(dev->ifname, ERR, + "failed to write log for IOVA 0x%" PRIx64 ". No IOTLB entry found\n", + iova); return; } @@ -450,10 +451,10 @@ translate_log_addr(struct virtio_net *dev, struct vhost_virtqueue *vq, gpa = hva_to_gpa(dev, hva, exp_size); if (!gpa) { - VHOST_LOG_DATA(ERR, - "(%s) failed to find GPA for log_addr: 0x%" + VHOST_LOG_DATA(dev->ifname, ERR, + "failed to find GPA for log_addr: 0x%" PRIx64 " hva: 0x%" PRIx64 "\n", - dev->ifname, log_addr, hva); + log_addr, hva); return 0; } return gpa; @@ -580,15 +581,14 @@ 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, "(%s) failed to init vring, out of bound (%d)\n", - dev->ifname, vring_idx); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to init vring, out of bound (%d)\n", + vring_idx); return; } vq = dev->virtqueue[vring_idx]; if (!vq) { - VHOST_LOG_CONFIG(ERR, "(%s) virtqueue not allocated (%d)\n", - dev->ifname, vring_idx); + VHOST_LOG_CONFIG(dev->ifname, ERR, "virtqueue not allocated (%d)\n", vring_idx); return; } @@ -600,8 +600,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, "(%s) failed to query numa node: %s\n", - dev->ifname, rte_strerror(errno)); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to query numa node: %s\n", + rte_strerror(errno)); numa_node = SOCKET_ID_ANY; } #endif @@ -617,16 +617,16 @@ reset_vring_queue(struct virtio_net *dev, uint32_t vring_idx) int callfd; if (vring_idx >= VHOST_MAX_VRING) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to reset vring, out of bound (%d)\n", - dev->ifname, vring_idx); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to reset vring, out of bound (%d)\n", + vring_idx); return; } vq = dev->virtqueue[vring_idx]; if (!vq) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to reset vring, virtqueue not allocated (%d)\n", - dev->ifname, vring_idx); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to reset vring, virtqueue not allocated (%d)\n", + vring_idx); return; } @@ -648,8 +648,9 @@ 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, "(%s) failed to allocate memory for vring %u.\n", - dev->ifname, i); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate memory for vring %u.\n", + i); return -1; } @@ -701,14 +702,14 @@ vhost_new_device(void) } if (i == RTE_MAX_VHOST_DEVICE) { - VHOST_LOG_CONFIG(ERR, "failed to find a free slot for new device.\n"); + VHOST_LOG_CONFIG("device", 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 device.\n"); + VHOST_LOG_CONFIG("device", ERR, "failed to allocate memory for new device.\n"); pthread_mutex_unlock(&vhost_dev_lock); return -1; } @@ -864,8 +865,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, "(%s) failed to query numa node: %s\n", - dev->ifname, rte_strerror(errno)); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to query numa node: %s\n", + rte_strerror(errno)); return -1; } @@ -1503,8 +1504,9 @@ 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, "(%s) %s: invalid virtqueue idx %d.\n", - dev->ifname, __func__, qid); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: invalid virtqueue idx %d.\n", + __func__, qid); return 0; } @@ -1667,32 +1669,35 @@ async_channel_register(int vid, uint16_t queue_id) int node = vq->numa_node; if (unlikely(vq->async)) { - VHOST_LOG_CONFIG(ERR, - "(%s) async register failed: already registered (qid: %d)\n", - dev->ifname, queue_id); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "async register failed: already registered (qid: %d)\n", + queue_id); return -1; } async = rte_zmalloc_socket(NULL, sizeof(struct vhost_async), 0, node); if (!async) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate async metadata (qid: %d)\n", - dev->ifname, queue_id); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate async metadata (qid: %d)\n", + 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, "(%s) failed to allocate async_pkts_info (qid: %d)\n", - dev->ifname, queue_id); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate async_pkts_info (qid: %d)\n", + queue_id); goto out_free_async; } async->pkts_cmpl_flag = rte_zmalloc_socket(NULL, vq->size * sizeof(bool), RTE_CACHE_LINE_SIZE, node); if (!async->pkts_cmpl_flag) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate async pkts_cmpl_flag (qid: %d)\n", - dev->ifname, queue_id); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate async pkts_cmpl_flag (qid: %d)\n", + queue_id); goto out_free_async; } @@ -1701,8 +1706,9 @@ 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, "(%s) failed to allocate async buffers (qid: %d)\n", - dev->ifname, queue_id); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate async buffers (qid: %d)\n", + queue_id); goto out_free_inflight; } } else { @@ -1710,8 +1716,9 @@ 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, "(%s) failed to allocate async descs (qid: %d)\n", - dev->ifname, queue_id); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate async descs (qid: %d)\n", + queue_id); goto out_free_inflight; } } @@ -1770,8 +1777,8 @@ rte_vhost_async_channel_register_thread_unsafe(int vid, uint16_t queue_id) return -1; if (unlikely(!rte_spinlock_is_locked(&vq->access_lock))) { - VHOST_LOG_CONFIG(ERR, "(%s) %s() called without access lock taken.\n", - dev->ifname, __func__); + VHOST_LOG_CONFIG(dev->ifname, ERR, "%s() called without access lock taken.\n", + __func__); return -1; } @@ -1797,17 +1804,17 @@ rte_vhost_async_channel_unregister(int vid, uint16_t queue_id) return ret; if (!rte_spinlock_trylock(&vq->access_lock)) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to unregister async channel, virtqueue busy.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to unregister async channel, virtqueue busy.\n"); return ret; } if (!vq->async) { ret = 0; } else if (vq->async->pkts_inflight_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); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to unregister async channel.\n"); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "inflight packets must be completed before unregistration.\n"); } else { vhost_free_async_mem(vq); ret = 0; @@ -1836,8 +1843,8 @@ rte_vhost_async_channel_unregister_thread_unsafe(int vid, uint16_t queue_id) return -1; if (unlikely(!rte_spinlock_is_locked(&vq->access_lock))) { - VHOST_LOG_CONFIG(ERR, "(%s) %s() called without access lock taken.\n", - dev->ifname, __func__); + VHOST_LOG_CONFIG(dev->ifname, ERR, "%s() called without access lock taken.\n", + __func__); return -1; } @@ -1845,9 +1852,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, "(%s) failed to unregister async channel.\n", dev->ifname); - VHOST_LOG_CONFIG(ERR, "(%s) inflight packets must be completed before unregistration.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to unregister async channel.\n"); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "inflight packets must be completed before unregistration.\n"); return -1; } @@ -1864,13 +1871,13 @@ rte_vhost_async_dma_configure(int16_t dma_id, uint16_t vchan_id) uint16_t max_desc; if (!rte_dma_is_valid(dma_id)) { - VHOST_LOG_CONFIG(ERR, "DMA %d is not found.\n", dma_id); + VHOST_LOG_CONFIG("dma", ERR, "DMA %d is not found.\n", dma_id); return -1; } rte_dma_info_get(dma_id, &info); if (vchan_id >= info.max_vchans) { - VHOST_LOG_CONFIG(ERR, "Invalid DMA %d vChannel %u.\n", dma_id, vchan_id); + VHOST_LOG_CONFIG("dma", ERR, "Invalid DMA %d vChannel %u.\n", dma_id, vchan_id); return -1; } @@ -1880,8 +1887,9 @@ rte_vhost_async_dma_configure(int16_t dma_id, uint16_t vchan_id) vchans = rte_zmalloc(NULL, sizeof(struct async_dma_vchan_info) * info.max_vchans, RTE_CACHE_LINE_SIZE); if (vchans == NULL) { - VHOST_LOG_CONFIG(ERR, "Failed to allocate vchans for DMA %d vChannel %u.\n", - dma_id, vchan_id); + VHOST_LOG_CONFIG("dma", ERR, + "Failed to allocate vchans for DMA %d vChannel %u.\n", + dma_id, vchan_id); return -1; } @@ -1889,8 +1897,8 @@ rte_vhost_async_dma_configure(int16_t dma_id, uint16_t vchan_id) } if (dma_copy_track[dma_id].vchans[vchan_id].pkts_cmpl_flag_addr) { - VHOST_LOG_CONFIG(INFO, "DMA %d vChannel %u already registered.\n", dma_id, - vchan_id); + VHOST_LOG_CONFIG("dma", INFO, "DMA %d vChannel %u already registered.\n", + dma_id, vchan_id); return 0; } @@ -1900,8 +1908,9 @@ rte_vhost_async_dma_configure(int16_t dma_id, uint16_t vchan_id) pkts_cmpl_flag_addr = rte_zmalloc(NULL, sizeof(bool *) * max_desc, RTE_CACHE_LINE_SIZE); if (!pkts_cmpl_flag_addr) { - VHOST_LOG_CONFIG(ERR, "Failed to allocate pkts_cmpl_flag_addr for DMA %d " - "vChannel %u.\n", dma_id, vchan_id); + VHOST_LOG_CONFIG("dma", ERR, + "Failed to allocate pkts_cmpl_flag_addr for DMA %d vChannel %u.\n", + dma_id, vchan_id); if (dma_copy_track[dma_id].nr_vchans == 0) { rte_free(dma_copy_track[dma_id].vchans); @@ -1937,9 +1946,8 @@ rte_vhost_async_get_inflight(int vid, uint16_t queue_id) return ret; if (!rte_spinlock_trylock(&vq->access_lock)) { - VHOST_LOG_CONFIG(DEBUG, - "(%s) failed to check in-flight packets. virtqueue busy.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, + "failed to check in-flight packets. virtqueue busy.\n"); return ret; } @@ -1970,8 +1978,8 @@ rte_vhost_async_get_inflight_thread_unsafe(int vid, uint16_t queue_id) return ret; if (unlikely(!rte_spinlock_is_locked(&vq->access_lock))) { - VHOST_LOG_CONFIG(ERR, "(%s) %s() called without access lock taken.\n", - dev->ifname, __func__); + VHOST_LOG_CONFIG(dev->ifname, ERR, "%s() called without access lock taken.\n", + __func__); return -1; } diff --git a/lib/vhost/vhost.h b/lib/vhost/vhost.h index 810bc71c9d..310aaf88ff 100644 --- a/lib/vhost/vhost.h +++ b/lib/vhost/vhost.h @@ -625,14 +625,14 @@ vhost_log_write_iova(struct virtio_net *dev, struct vhost_virtqueue *vq, extern int vhost_config_log_level; extern int vhost_data_log_level; -#define VHOST_LOG_CONFIG(level, fmt, args...) \ +#define VHOST_LOG_CONFIG(prefix, level, fmt, args...) \ rte_log(RTE_LOG_ ## level, vhost_config_log_level, \ - "VHOST_CONFIG: " fmt, ##args) + "VHOST_CONFIG: (%s): " fmt, prefix, ##args) -#define VHOST_LOG_DATA(level, fmt, args...) \ +#define VHOST_LOG_DATA(prefix, level, fmt, args...) \ (void)((RTE_LOG_ ## level <= RTE_LOG_DP_LEVEL) ? \ rte_log(RTE_LOG_ ## level, vhost_data_log_level, \ - "VHOST_DATA : " fmt, ##args) : \ + "VHOST_DATA: (%s):" fmt, prefix, ##args) : \ 0) #ifdef RTE_LIBRTE_VHOST_DEBUG @@ -652,7 +652,7 @@ extern int vhost_data_log_level; } \ snprintf(packet + strnlen(packet, VHOST_MAX_PRINT_BUFF), VHOST_MAX_PRINT_BUFF - strnlen(packet, VHOST_MAX_PRINT_BUFF), "\n"); \ \ - VHOST_LOG_DATA(DEBUG, "(%s) %s", device->ifname, packet); \ + VHOST_LOG_DATA(device->ifname, DEBUG, "%s", packet); \ } while (0) #else #define PRINT_PACKET(device, addr, size, header) do {} while (0) @@ -777,8 +777,7 @@ get_device(int vid) struct virtio_net *dev = vhost_devices[vid]; if (unlikely(!dev)) { - VHOST_LOG_CONFIG(ERR, - "(%d) device not found.\n", vid); + VHOST_LOG_CONFIG("device", ERR, "(%d) device not found.\n", vid); } return dev; @@ -866,10 +865,9 @@ vhost_vring_call_split(struct virtio_net *dev, struct vhost_virtqueue *vq) vq->signalled_used = new; vq->signalled_used_valid = true; - VHOST_LOG_DATA(DEBUG, "(%s) %s: used_event_idx=%d, old=%d, new=%d\n", - dev->ifname, __func__, - vhost_used_event(vq), - old, new); + VHOST_LOG_DATA(dev->ifname, DEBUG, + "%s: used_event_idx=%d, old=%d, new=%d\n", + __func__, vhost_used_event(vq), old, new); if ((vhost_need_event(vhost_used_event(vq), new, old) && (vq->callfd >= 0)) || diff --git a/lib/vhost/vhost_user.c b/lib/vhost/vhost_user.c index f324f822d6..09acf50e4d 100644 --- a/lib/vhost/vhost_user.c +++ b/lib/vhost/vhost_user.c @@ -93,9 +93,9 @@ validate_msg_fds(struct virtio_net *dev, struct vhu_msg_context *ctx, int expect if (ctx->fd_num == expected_fds) return 0; - VHOST_LOG_CONFIG(ERR, "(%s) expect %d FDs for request %s, received %d\n", - dev->ifname, expected_fds, - vhost_message_handlers[ctx->msg.request.master].description, + VHOST_LOG_CONFIG(dev->ifname, ERR, + "expect %d FDs for request %s, received %d\n", + expected_fds, vhost_message_handlers[ctx->msg.request.master].description, ctx->fd_num); close_msg_fds(ctx); @@ -144,8 +144,7 @@ async_dma_map(struct virtio_net *dev, bool do_map) return; /* DMA mapping errors won't stop VHOST_USER_SET_MEM_TABLE. */ - VHOST_LOG_CONFIG(ERR, "(%s) DMA engine map failed\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "DMA engine map failed\n"); } } @@ -161,8 +160,7 @@ async_dma_map(struct virtio_net *dev, bool do_map) if (rte_errno == EINVAL) return; - VHOST_LOG_CONFIG(ERR, "(%s) DMA engine unmap failed\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "DMA engine unmap failed\n"); } } } @@ -341,8 +339,7 @@ vhost_user_set_features(struct virtio_net **pdev, rte_vhost_driver_get_features(dev->ifname, &vhost_features); if (features & ~vhost_features) { - VHOST_LOG_CONFIG(ERR, "(%s) received invalid negotiated features.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "received invalid negotiated features.\n"); dev->flags |= VIRTIO_DEV_FEATURES_FAILED; dev->status &= ~VIRTIO_DEVICE_STATUS_FEATURES_OK; @@ -359,8 +356,8 @@ vhost_user_set_features(struct virtio_net **pdev, * is enabled when the live-migration starts. */ if ((dev->features ^ features) & ~(1ULL << VHOST_F_LOG_ALL)) { - VHOST_LOG_CONFIG(ERR, "(%s) features changed while device is running.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "features changed while device is running.\n"); return RTE_VHOST_MSG_RESULT_ERR; } @@ -377,10 +374,11 @@ vhost_user_set_features(struct virtio_net **pdev, } else { dev->vhost_hlen = sizeof(struct virtio_net_hdr); } - 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, + VHOST_LOG_CONFIG(dev->ifname, INFO, + "negotiated Virtio features: 0x%" PRIx64 "\n", + dev->features); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, + "mergeable RX buffers %s, virtio 1 %s\n", (dev->features & (1 << VIRTIO_NET_F_MRG_RXBUF)) ? "on" : "off", (dev->features & (1ULL << VIRTIO_F_VERSION_1)) ? "on" : "off"); @@ -425,8 +423,9 @@ vhost_user_set_vring_num(struct virtio_net **pdev, struct vhost_virtqueue *vq = dev->virtqueue[ctx->msg.payload.state.index]; if (ctx->msg.payload.state.num > 32768) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid virtqueue size %u\n", - dev->ifname, ctx->msg.payload.state.num); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "invalid virtqueue size %u\n", + ctx->msg.payload.state.num); return RTE_VHOST_MSG_RESULT_ERR; } @@ -443,8 +442,9 @@ vhost_user_set_vring_num(struct virtio_net **pdev, */ if (!vq_is_packed(dev)) { if (vq->size & (vq->size - 1)) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid virtqueue size %u\n", - dev->ifname, vq->size); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "invalid virtqueue size %u\n", + vq->size); return RTE_VHOST_MSG_RESULT_ERR; } } @@ -456,9 +456,8 @@ vhost_user_set_vring_num(struct virtio_net **pdev, sizeof(struct vring_used_elem_packed), RTE_CACHE_LINE_SIZE, vq->numa_node); if (!vq->shadow_used_packed) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to allocate memory for shadow used ring.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate memory for shadow used ring.\n"); return RTE_VHOST_MSG_RESULT_ERR; } @@ -470,9 +469,8 @@ vhost_user_set_vring_num(struct virtio_net **pdev, RTE_CACHE_LINE_SIZE, vq->numa_node); if (!vq->shadow_used_split) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to allocate memory for vq internal data.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate memory for vq internal data.\n"); return RTE_VHOST_MSG_RESULT_ERR; } } @@ -482,8 +480,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, "(%s) failed to allocate memory for batching copy.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate memory for batching copy.\n"); return RTE_VHOST_MSG_RESULT_ERR; } @@ -519,8 +517,9 @@ 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, "(%s) unable to get virtqueue %d numa information.\n", - dev->ifname, index); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "unable to get virtqueue %d numa information.\n", + index); return dev; } @@ -529,14 +528,14 @@ numa_realloc(struct virtio_net *dev, int index) vq = rte_realloc_socket(vq, sizeof(*vq), 0, node); if (!vq) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to realloc virtqueue %d on node %d\n", - dev->ifname, index, node); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to realloc virtqueue %d on node %d\n", + index, node); return dev; } if (vq != dev->virtqueue[index]) { - VHOST_LOG_CONFIG(INFO, "(%s) reallocated virtqueue on node %d\n", - dev->ifname, node); + VHOST_LOG_CONFIG(dev->ifname, INFO, "reallocated virtqueue on node %d\n", node); dev->virtqueue[index] = vq; vhost_user_iotlb_init(dev, index); } @@ -547,8 +546,9 @@ 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, "(%s) failed to realloc shadow packed on node %d\n", - dev->ifname, node); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to realloc shadow packed on node %d\n", + node); return dev; } vq->shadow_used_packed = sup; @@ -558,8 +558,9 @@ 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, "(%s) failed to realloc shadow split on node %d\n", - dev->ifname, node); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to realloc shadow split on node %d\n", + node); return dev; } vq->shadow_used_split = sus; @@ -568,8 +569,9 @@ 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, "(%s) failed to realloc batch copy elem on node %d\n", - dev->ifname, node); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to realloc batch copy elem on node %d\n", + node); return dev; } vq->batch_copy_elems = bce; @@ -579,8 +581,9 @@ 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, "(%s) failed to realloc log cache on node %d\n", - dev->ifname, node); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to realloc log cache on node %d\n", + node); return dev; } vq->log_cache = lc; @@ -591,8 +594,9 @@ 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, "(%s) failed to realloc resubmit inflight on node %d\n", - dev->ifname, node); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to realloc resubmit inflight on node %d\n", + node); return dev; } vq->resubmit_inflight = ri; @@ -603,8 +607,9 @@ 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, "(%s) failed to realloc resubmit list on node %d\n", - dev->ifname, node); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to realloc resubmit list on node %d\n", + node); return dev; } ri->resubmit_list = rd; @@ -620,7 +625,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, "(%s) unable to get numa information.\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "unable to get numa information.\n"); return dev; } @@ -629,20 +634,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, "(%s) failed to realloc dev on node %d\n", - old_dev->ifname, node); + VHOST_LOG_CONFIG(old_dev->ifname, ERR, "failed to realloc dev on node %d\n", node); return old_dev; } - VHOST_LOG_CONFIG(INFO, "(%s) reallocated device on node %d\n", dev->ifname, node); + VHOST_LOG_CONFIG(dev->ifname, INFO, "reallocated device on node %d\n", 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, "(%s) failed to realloc mem table on node %d\n", - dev->ifname, node); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to realloc mem table on node %d\n", + node); return dev; } dev->mem = mem; @@ -650,8 +655,9 @@ 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, "(%s) failed to realloc guest pages on node %d\n", - dev->ifname, node); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to realloc guest pages on node %d\n", + node); return dev; } dev->guest_pages = gp; @@ -743,8 +749,7 @@ 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, "(%s) failed to map log_guest_addr.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "failed to map log_guest_addr.\n"); return dev; } } @@ -756,8 +761,7 @@ 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, "(%s) failed to map desc_packed ring.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "failed to map desc_packed ring.\n"); return dev; } @@ -771,8 +775,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, "(%s) failed to find driver area address.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, + "failed to find driver area address.\n"); return dev; } @@ -782,8 +786,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, "(%s) failed to find device area address.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, + "failed to find device area address.\n"); return dev; } @@ -799,7 +803,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, "(%s) failed to map desc ring.\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "failed to map desc ring.\n"); return dev; } @@ -814,7 +818,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, "(%s) failed to map avail ring.\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "failed to map avail ring.\n"); return dev; } @@ -826,27 +830,26 @@ 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, "(%s) failed to map used ring.\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "failed to map used ring.\n"); return dev; } if (vq->last_used_idx != vq->used->idx) { - VHOST_LOG_CONFIG(WARNING, "(%s) last_used_idx (%u) and vq->used->idx (%u) mismatches;\n", - dev->ifname, + VHOST_LOG_CONFIG(dev->ifname, WARNING, + "last_used_idx (%u) and vq->used->idx (%u) mismatches;\n", 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); + VHOST_LOG_CONFIG(dev->ifname, WARNING, + "some packets maybe resent for Tx and dropped for Rx\n"); } vq->access_ok = true; - 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); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "mapped address desc: %p\n", vq->desc); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "mapped address avail: %p\n", vq->avail); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "mapped address used: %p\n", vq->used); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "log_guest_addr: %" PRIx64 "\n", vq->log_guest_addr); return dev; } @@ -925,10 +928,9 @@ vhost_user_set_vring_base(struct virtio_net **pdev, vq->last_avail_idx = ctx->msg.payload.state.num; } - VHOST_LOG_CONFIG(INFO, - "(%s) vring base idx:%u last_used_idx:%u last_avail_idx:%u.\n", - dev->ifname, ctx->msg.payload.state.index, vq->last_used_idx, - vq->last_avail_idx); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "vring base idx:%u last_used_idx:%u last_avail_idx:%u.\n", + ctx->msg.payload.state.index, vq->last_used_idx, vq->last_avail_idx); return RTE_VHOST_MSG_RESULT_OK; } @@ -947,8 +949,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, "(%s) cannot realloc guest_pages\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "cannot realloc guest_pages\n"); rte_free(old_pages); return -1; } @@ -1029,14 +1030,13 @@ 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", - 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_iova : %" PRIx64 "\n", - dev->ifname, page->host_iova); - VHOST_LOG_CONFIG(INFO, "(%s)\tsize : %" PRIx64 "\n", - dev->ifname, page->size); + VHOST_LOG_CONFIG(dev->ifname, INFO, "guest physical page region %u\n", i); + VHOST_LOG_CONFIG(dev->ifname, INFO, "\tguest_phys_addr: %" PRIx64 "\n", + page->guest_phys_addr); + VHOST_LOG_CONFIG(dev->ifname, INFO, "\thost_iova : %" PRIx64 "\n", + page->host_iova); + VHOST_LOG_CONFIG(dev->ifname, INFO, "\tsize : %" PRIx64 "\n", + page->size); } } #else @@ -1084,23 +1084,22 @@ 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", - dev->ifname, - (uint64_t)reg_struct.range.start, - (uint64_t)reg_struct.range.start + - (uint64_t)reg_struct.range.len - 1, - dev->postcopy_ufd, - strerror(errno)); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to register ufd for region " + "%" PRIx64 " - %" PRIx64 " (ufd = %d) %s\n", + (uint64_t)reg_struct.range.start, + (uint64_t)reg_struct.range.start + + (uint64_t)reg_struct.range.len - 1, + dev->postcopy_ufd, + strerror(errno)); return -1; } - 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); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t userfaultfd registered for range : %" PRIx64 " - %" PRIx64 "\n", + (uint64_t)reg_struct.range.start, + (uint64_t)reg_struct.range.start + + (uint64_t)reg_struct.range.len - 1); return 0; } @@ -1144,8 +1143,8 @@ vhost_user_postcopy_register(struct virtio_net *dev, int main_fd, * we've got to wait before we're allowed to generate faults. */ if (read_vhost_message(dev, main_fd, &ack_ctx) <= 0) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to read qemu ack on postcopy set-mem-table\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to read qemu ack on postcopy set-mem-table\n"); return -1; } @@ -1153,8 +1152,9 @@ vhost_user_postcopy_register(struct virtio_net *dev, int main_fd, return -1; if (ack_ctx.msg.request.master != VHOST_USER_SET_MEM_TABLE) { - VHOST_LOG_CONFIG(ERR, "(%s) bad qemu ack on postcopy set-mem-table (%d)\n", - dev->ifname, ack_ctx.msg.request.master); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "bad qemu ack on postcopy set-mem-table (%d)\n", + ack_ctx.msg.request.master); return -1; } @@ -1180,8 +1180,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, "(%s) mmap_offset (%#"PRIx64") and memory_size (%#"PRIx64") overflow\n", - dev->ifname, mmap_offset, region->size); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "mmap_offset (%#"PRIx64") and memory_size (%#"PRIx64") overflow\n", + mmap_offset, region->size); return -1; } @@ -1195,8 +1196,7 @@ vhost_user_mmap_region(struct virtio_net *dev, */ alignment = get_blk_size(region->fd); if (alignment == (uint64_t)-1) { - VHOST_LOG_CONFIG(ERR, "(%s) couldn't get hugepage size through fstat\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "couldn't get hugepage size through fstat\n"); return -1; } mmap_size = RTE_ALIGN_CEIL(mmap_size, alignment); @@ -1209,8 +1209,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, "(%s) mmap size (0x%" PRIx64 ") or alignment (0x%" PRIx64 ") is invalid\n", - dev->ifname, region->size + mmap_offset, alignment); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "mmap size (0x%" PRIx64 ") or alignment (0x%" PRIx64 ") is invalid\n", + region->size + mmap_offset, alignment); return -1; } @@ -1219,7 +1220,7 @@ vhost_user_mmap_region(struct virtio_net *dev, MAP_SHARED | populate, region->fd, 0); if (mmap_addr == MAP_FAILED) { - VHOST_LOG_CONFIG(ERR, "(%s) mmap failed (%s).\n", dev->ifname, strerror(errno)); + VHOST_LOG_CONFIG(dev->ifname, ERR, "mmap failed (%s).\n", strerror(errno)); return -1; } @@ -1229,28 +1230,36 @@ vhost_user_mmap_region(struct virtio_net *dev, if (dev->async_copy) { if (add_guest_pages(dev, region, alignment) < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) adding guest pages to region failed.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "adding guest pages to region failed.\n"); return -1; } } - 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); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "guest memory region size: 0x%" PRIx64 "\n", + region->size); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t guest physical addr: 0x%" PRIx64 "\n", + region->guest_phys_addr); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t guest virtual addr: 0x%" PRIx64 "\n", + region->guest_user_addr); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t host virtual addr: 0x%" PRIx64 "\n", + region->host_user_addr); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t mmap addr : 0x%" PRIx64 "\n", + (uint64_t)(uintptr_t)mmap_addr); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t mmap size : 0x%" PRIx64 "\n", + mmap_size); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t mmap align: 0x%" PRIx64 "\n", + alignment); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t mmap off : 0x%" PRIx64 "\n", + mmap_offset); return 0; } @@ -1272,13 +1281,14 @@ vhost_user_set_mem_table(struct virtio_net **pdev, return RTE_VHOST_MSG_RESULT_ERR; if (memory->nregions > VHOST_MEMORY_MAX_NREGIONS) { - VHOST_LOG_CONFIG(ERR, "(%s) too many memory regions (%u)\n", - dev->ifname, memory->nregions); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "too many memory regions (%u)\n", + memory->nregions); goto close_msg_fds; } if (dev->mem && !vhost_memory_changed(memory, dev->mem)) { - VHOST_LOG_CONFIG(INFO, "(%s) memory regions not changed\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, INFO, "memory regions not changed\n"); close_msg_fds(ctx); @@ -1329,9 +1339,8 @@ vhost_user_set_mem_table(struct virtio_net **pdev, RTE_CACHE_LINE_SIZE, numa_node); if (dev->guest_pages == NULL) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to allocate memory for dev->guest_pages\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate memory for dev->guest_pages\n"); goto close_msg_fds; } } @@ -1339,9 +1348,7 @@ vhost_user_set_mem_table(struct virtio_net **pdev, dev->mem = rte_zmalloc_socket("vhost-mem-table", sizeof(struct rte_vhost_memory) + sizeof(struct rte_vhost_mem_region) * memory->nregions, 0, numa_node); if (dev->mem == NULL) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to allocate memory for dev->mem\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to allocate memory for dev->mem\n"); goto free_guest_pages; } @@ -1362,7 +1369,7 @@ vhost_user_set_mem_table(struct virtio_net **pdev, mmap_offset = memory->regions[i].mmap_offset; if (vhost_user_mmap_region(dev, reg, mmap_offset) < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to mmap region %u\n", dev->ifname, i); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to mmap region %u\n", i); goto free_mem_table; } @@ -1477,7 +1484,7 @@ virtio_is_ready(struct virtio_net *dev) dev->flags |= VIRTIO_DEV_READY; if (!(dev->flags & VIRTIO_DEV_RUNNING)) - VHOST_LOG_CONFIG(INFO, "(%s) virtio is now ready for processing.\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, INFO, "virtio is now ready for processing.\n"); return 1; } @@ -1497,8 +1504,7 @@ inflight_mem_alloc(struct virtio_net *dev, const char *name, size_t size, int *f if (mfd == -1) { mfd = mkstemp(fname); if (mfd == -1) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to get inflight buffer fd\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to get inflight buffer fd\n"); return NULL; } @@ -1506,14 +1512,14 @@ inflight_mem_alloc(struct virtio_net *dev, const char *name, size_t size, int *f } if (ftruncate(mfd, size) == -1) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to alloc inflight buffer\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to alloc inflight buffer\n"); close(mfd); return NULL; } ptr = mmap(0, size, PROT_READ | PROT_WRITE, MAP_SHARED, mfd, 0); if (ptr == MAP_FAILED) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to mmap inflight buffer\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to mmap inflight buffer\n"); close(mfd); return NULL; } @@ -1553,8 +1559,9 @@ vhost_user_get_inflight_fd(struct virtio_net **pdev, void *addr; if (ctx->msg.size != sizeof(ctx->msg.payload.inflight)) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid get_inflight_fd message size is %d\n", - dev->ifname, ctx->msg.size); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "invalid get_inflight_fd message size is %d\n", + ctx->msg.size); return RTE_VHOST_MSG_RESULT_ERR; } @@ -1569,8 +1576,7 @@ 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, "(%s) failed to alloc dev inflight area\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to alloc dev inflight area\n"); return RTE_VHOST_MSG_RESULT_ERR; } dev->inflight_info->fd = -1; @@ -1579,10 +1585,12 @@ vhost_user_get_inflight_fd(struct virtio_net **pdev, num_queues = ctx->msg.payload.inflight.num_queues; queue_size = ctx->msg.payload.inflight.queue_size; - VHOST_LOG_CONFIG(INFO, "(%s) get_inflight_fd num_queues: %u\n", - dev->ifname, ctx->msg.payload.inflight.num_queues); - VHOST_LOG_CONFIG(INFO, "(%s) get_inflight_fd queue_size: %u\n", - dev->ifname, ctx->msg.payload.inflight.queue_size); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "get_inflight_fd num_queues: %u\n", + ctx->msg.payload.inflight.num_queues); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "get_inflight_fd queue_size: %u\n", + ctx->msg.payload.inflight.queue_size); if (vq_is_packed(dev)) pervq_inflight_size = get_pervq_shm_size_packed(queue_size); @@ -1592,7 +1600,7 @@ vhost_user_get_inflight_fd(struct virtio_net **pdev, mmap_size = num_queues * pervq_inflight_size; addr = inflight_mem_alloc(dev, "vhost-inflight", mmap_size, &fd); if (!addr) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to alloc vhost inflight area\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to alloc vhost inflight area\n"); ctx->msg.payload.inflight.mmap_size = 0; return RTE_VHOST_MSG_RESULT_ERR; } @@ -1626,11 +1634,14 @@ vhost_user_get_inflight_fd(struct virtio_net **pdev, } } - VHOST_LOG_CONFIG(INFO, "(%s) send inflight mmap_size: %"PRIu64"\n", - dev->ifname, ctx->msg.payload.inflight.mmap_size); - VHOST_LOG_CONFIG(INFO, "(%s) send inflight mmap_offset: %"PRIu64"\n", - dev->ifname, ctx->msg.payload.inflight.mmap_offset); - VHOST_LOG_CONFIG(INFO, "(%s) send inflight fd: %d\n", dev->ifname, ctx->fds[0]); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "send inflight mmap_size: %"PRIu64"\n", + ctx->msg.payload.inflight.mmap_size); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "send inflight mmap_offset: %"PRIu64"\n", + ctx->msg.payload.inflight.mmap_offset); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "send inflight fd: %d\n", ctx->fds[0]); return RTE_VHOST_MSG_RESULT_REPLY; } @@ -1654,8 +1665,9 @@ vhost_user_set_inflight_fd(struct virtio_net **pdev, fd = ctx->fds[0]; if (ctx->msg.size != sizeof(ctx->msg.payload.inflight) || fd < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid set_inflight_fd message size is %d,fd is %d\n", - dev->ifname, ctx->msg.size, fd); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "invalid set_inflight_fd message size is %d,fd is %d\n", + ctx->msg.size, fd); return RTE_VHOST_MSG_RESULT_ERR; } @@ -1669,15 +1681,22 @@ vhost_user_set_inflight_fd(struct virtio_net **pdev, else pervq_inflight_size = get_pervq_shm_size_split(queue_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); + VHOST_LOG_CONFIG(dev->ifname, INFO, "set_inflight_fd mmap_size: %"PRIu64"\n", mmap_size); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "set_inflight_fd mmap_offset: %"PRIu64"\n", + mmap_offset); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "set_inflight_fd num_queues: %u\n", + num_queues); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "set_inflight_fd queue_size: %u\n", + queue_size); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "set_inflight_fd fd: %d\n", + fd); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "set_inflight_fd pervq_inflight_size: %d\n", + pervq_inflight_size); /* * If VQ 0 has already been allocated, try to allocate on the same @@ -1690,8 +1709,7 @@ vhost_user_set_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 == NULL) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to alloc dev inflight area\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to alloc dev inflight area\n"); return RTE_VHOST_MSG_RESULT_ERR; } dev->inflight_info->fd = -1; @@ -1705,7 +1723,7 @@ vhost_user_set_inflight_fd(struct virtio_net **pdev, addr = mmap(0, mmap_size, PROT_READ | PROT_WRITE, MAP_SHARED, fd, mmap_offset); if (addr == MAP_FAILED) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to mmap share memory.\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to mmap share memory.\n"); return RTE_VHOST_MSG_RESULT_ERR; } @@ -1755,8 +1773,9 @@ vhost_user_set_vring_call(struct virtio_net **pdev, file.fd = VIRTIO_INVALID_EVENTFD; else file.fd = ctx->fds[0]; - VHOST_LOG_CONFIG(INFO, "(%s) vring call idx:%d file:%d\n", - dev->ifname, file.index, file.fd); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "vring call idx:%d file:%d\n", + file.index, file.fd); vq = dev->virtqueue[file.index]; @@ -1786,7 +1805,7 @@ static int vhost_user_set_vring_err(struct virtio_net **pdev, if (!(ctx->msg.payload.u64 & VHOST_USER_VRING_NOFD_MASK)) close(ctx->fds[0]); - VHOST_LOG_CONFIG(INFO, "(%s) not implemented\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, INFO, "not implemented\n"); return RTE_VHOST_MSG_RESULT_OK; } @@ -1852,9 +1871,8 @@ vhost_check_queue_inflights_split(struct virtio_net *dev, resubmit = rte_zmalloc_socket("resubmit", sizeof(struct rte_vhost_resubmit_info), 0, vq->numa_node); if (!resubmit) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to allocate memory for resubmit info.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate memory for resubmit info.\n"); return RTE_VHOST_MSG_RESULT_ERR; } @@ -1862,9 +1880,8 @@ vhost_check_queue_inflights_split(struct virtio_net *dev, resubmit_num * sizeof(struct rte_vhost_resubmit_desc), 0, vq->numa_node); if (!resubmit->resubmit_list) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to allocate memory for inflight desc.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate memory for inflight desc.\n"); rte_free(resubmit); return RTE_VHOST_MSG_RESULT_ERR; } @@ -1950,9 +1967,8 @@ vhost_check_queue_inflights_packed(struct virtio_net *dev, resubmit = rte_zmalloc_socket("resubmit", sizeof(struct rte_vhost_resubmit_info), 0, vq->numa_node); if (resubmit == NULL) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to allocate memory for resubmit info.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate memory for resubmit info.\n"); return RTE_VHOST_MSG_RESULT_ERR; } @@ -1960,9 +1976,8 @@ vhost_check_queue_inflights_packed(struct virtio_net *dev, resubmit_num * sizeof(struct rte_vhost_resubmit_desc), 0, vq->numa_node); if (resubmit->resubmit_list == NULL) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to allocate memory for resubmit desc.\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate memory for resubmit desc.\n"); rte_free(resubmit); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2009,8 +2024,9 @@ vhost_user_set_vring_kick(struct virtio_net **pdev, file.fd = VIRTIO_INVALID_EVENTFD; else file.fd = ctx->fds[0]; - VHOST_LOG_CONFIG(INFO, "(%s) vring kick idx:%d file:%d\n", - dev->ifname, file.index, file.fd); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "vring kick idx:%d file:%d\n", + file.index, file.fd); /* Interpret ring addresses only when ring is started. */ dev = translate_ring_addresses(dev, file.index); @@ -2045,14 +2061,16 @@ vhost_user_set_vring_kick(struct virtio_net **pdev, if (vq_is_packed(dev)) { if (vhost_check_queue_inflights_packed(dev, vq)) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to inflights for vq: %d\n", - dev->ifname, file.index); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to inflights for vq: %d\n", + file.index); return RTE_VHOST_MSG_RESULT_ERR; } } else { if (vhost_check_queue_inflights_split(dev, vq)) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to inflights for vq: %d\n", - dev->ifname, file.index); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to inflights for vq: %d\n", + file.index); return RTE_VHOST_MSG_RESULT_ERR; } } @@ -2091,9 +2109,9 @@ vhost_user_get_vring_base(struct virtio_net **pdev, ctx->msg.payload.state.num = vq->last_avail_idx; } - VHOST_LOG_CONFIG(INFO, "(%s) vring base idx:%d file:%d\n", - dev->ifname, ctx->msg.payload.state.index, - ctx->msg.payload.state.num); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "vring base idx:%d file:%d\n", + ctx->msg.payload.state.index, ctx->msg.payload.state.num); /* * Based on current qemu vhost-user implementation, this message is * sent and only sent in vhost_vring_stop. @@ -2148,14 +2166,14 @@ vhost_user_set_vring_enable(struct virtio_net **pdev, bool enable = !!ctx->msg.payload.state.num; int index = (int)ctx->msg.payload.state.index; - VHOST_LOG_CONFIG(INFO, "(%s) set queue enable: %d to qp idx: %d\n", - dev->ifname, enable, index); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "set queue enable: %d to qp idx: %d\n", + enable, index); if (enable && dev->virtqueue[index]->async) { if (dev->virtqueue[index]->async->pkts_inflight_n) { - VHOST_LOG_CONFIG(ERR, - "(%s) failed to enable vring. Inflight packets must be completed first\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to enable vring. Inflight packets must be completed first\n"); return RTE_VHOST_MSG_RESULT_ERR; } } @@ -2195,13 +2213,14 @@ vhost_user_set_protocol_features(struct virtio_net **pdev, rte_vhost_driver_get_protocol_features(dev->ifname, &slave_protocol_features); if (protocol_features & ~slave_protocol_features) { - VHOST_LOG_CONFIG(ERR, "(%s) received invalid protocol features.\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "received invalid protocol features.\n"); return RTE_VHOST_MSG_RESULT_ERR; } dev->protocol_features = protocol_features; - VHOST_LOG_CONFIG(INFO, "(%s) negotiated Vhost-user protocol features: 0x%" PRIx64 "\n", - dev->ifname, dev->protocol_features); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "negotiated Vhost-user protocol features: 0x%" PRIx64 "\n", + dev->protocol_features); return RTE_VHOST_MSG_RESULT_OK; } @@ -2221,13 +2240,14 @@ vhost_user_set_log_base(struct virtio_net **pdev, return RTE_VHOST_MSG_RESULT_ERR; if (fd < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid log fd: %d\n", dev->ifname, fd); + VHOST_LOG_CONFIG(dev->ifname, ERR, "invalid log fd: %d\n", fd); return RTE_VHOST_MSG_RESULT_ERR; } if (ctx->msg.size != sizeof(VhostUserLog)) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid log base msg size: %"PRId32" != %d\n", - dev->ifname, ctx->msg.size, (int)sizeof(VhostUserLog)); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "invalid log base msg size: %"PRId32" != %d\n", + ctx->msg.size, (int)sizeof(VhostUserLog)); goto close_msg_fds; } @@ -2236,14 +2256,15 @@ vhost_user_set_log_base(struct virtio_net **pdev, /* Check for mmap size and offset overflow. */ if (off >= -size) { - VHOST_LOG_CONFIG(ERR, - "(%s) log offset %#"PRIx64" and log size %#"PRIx64" overflow\n", - dev->ifname, off, size); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "log offset %#"PRIx64" and log size %#"PRIx64" overflow\n", + off, size); goto close_msg_fds; } - VHOST_LOG_CONFIG(INFO, "(%s) log mmap size: %"PRId64", offset: %"PRId64"\n", - dev->ifname, size, off); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "log mmap size: %"PRId64", offset: %"PRId64"\n", + size, off); /* * mmap from 0 to workaround a hugepage mmap bug: mmap will @@ -2252,7 +2273,7 @@ vhost_user_set_log_base(struct virtio_net **pdev, addr = mmap(0, size + off, PROT_READ | PROT_WRITE, MAP_SHARED, fd, 0); close(fd); if (addr == MAP_FAILED) { - VHOST_LOG_CONFIG(ERR, "(%s) mmap log base failed!\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "mmap log base failed!\n"); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2281,8 +2302,8 @@ vhost_user_set_log_base(struct virtio_net **pdev, * caching will be done, which will impact performance */ if (!vq->log_cache) - VHOST_LOG_CONFIG(ERR, "(%s) failed to allocate VQ logging cache\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to allocate VQ logging cache\n"); } /* @@ -2309,7 +2330,7 @@ static int vhost_user_set_log_fd(struct virtio_net **pdev, return RTE_VHOST_MSG_RESULT_ERR; close(ctx->fds[0]); - VHOST_LOG_CONFIG(INFO, "(%s) not implemented.\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, INFO, "not implemented.\n"); return RTE_VHOST_MSG_RESULT_OK; } @@ -2331,8 +2352,9 @@ vhost_user_send_rarp(struct virtio_net **pdev, uint8_t *mac = (uint8_t *)&ctx->msg.payload.u64; struct rte_vdpa_device *vdpa_dev; - 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]); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, + "MAC: " RTE_ETHER_ADDR_PRT_FMT "\n", + mac[0], mac[1], mac[2], mac[3], mac[4], mac[5]); memcpy(dev->mac.addr_bytes, mac, 6); /* @@ -2359,8 +2381,9 @@ vhost_user_net_set_mtu(struct virtio_net **pdev, if (ctx->msg.payload.u64 < VIRTIO_MIN_MTU || ctx->msg.payload.u64 > VIRTIO_MAX_MTU) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid MTU size (%"PRIu64")\n", - dev->ifname, ctx->msg.payload.u64); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "invalid MTU size (%"PRIu64")\n", + ctx->msg.payload.u64); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2382,8 +2405,8 @@ vhost_user_set_req_fd(struct virtio_net **pdev, return RTE_VHOST_MSG_RESULT_ERR; if (fd < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid file descriptor for slave channel (%d)\n", - dev->ifname, fd); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "invalid file descriptor for slave channel (%d)\n", fd); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2483,8 +2506,7 @@ vhost_user_get_config(struct virtio_net **pdev, return RTE_VHOST_MSG_RESULT_ERR; if (!vdpa_dev) { - VHOST_LOG_CONFIG(ERR, "(%s) is not vDPA device!\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "is not vDPA device!\n"); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2494,13 +2516,10 @@ vhost_user_get_config(struct virtio_net **pdev, ctx->msg.payload.cfg.size); if (ret != 0) { ctx->msg.size = 0; - VHOST_LOG_CONFIG(ERR, - "(%s) get_config() return error!\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "get_config() return error!\n"); } } else { - VHOST_LOG_CONFIG(ERR, "(%s) get_config() not supported!\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "get_config() not supported!\n"); } return RTE_VHOST_MSG_RESULT_REPLY; @@ -2519,16 +2538,14 @@ vhost_user_set_config(struct virtio_net **pdev, return RTE_VHOST_MSG_RESULT_ERR; if (ctx->msg.payload.cfg.size > VHOST_USER_MAX_CONFIG_SIZE) { - VHOST_LOG_CONFIG(ERR, - "(%s) vhost_user_config size: %"PRIu32", should not be larger than %d\n", - dev->ifname, ctx->msg.payload.cfg.size, - VHOST_USER_MAX_CONFIG_SIZE); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "vhost_user_config size: %"PRIu32", should not be larger than %d\n", + ctx->msg.payload.cfg.size, VHOST_USER_MAX_CONFIG_SIZE); goto out; } if (!vdpa_dev) { - VHOST_LOG_CONFIG(ERR, "(%s) is not vDPA device!\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "is not vDPA device!\n"); goto out; } @@ -2539,12 +2556,9 @@ vhost_user_set_config(struct virtio_net **pdev, ctx->msg.payload.cfg.size, ctx->msg.payload.cfg.flags); if (ret) - VHOST_LOG_CONFIG(ERR, - "(%s) set_config() return error!\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "set_config() return error!\n"); } else { - VHOST_LOG_CONFIG(ERR, "(%s) set_config() not supported!\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "set_config() not supported!\n"); } return RTE_VHOST_MSG_RESULT_OK; @@ -2604,8 +2618,9 @@ vhost_user_iotlb_msg(struct virtio_net **pdev, } break; default: - VHOST_LOG_CONFIG(ERR, "(%s) invalid IOTLB message type (%d)\n", - dev->ifname, imsg->type); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "invalid IOTLB message type (%d)\n", + imsg->type); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2624,15 +2639,17 @@ vhost_user_set_postcopy_advise(struct virtio_net **pdev, dev->postcopy_ufd = syscall(__NR_userfaultfd, O_CLOEXEC | O_NONBLOCK); if (dev->postcopy_ufd == -1) { - VHOST_LOG_CONFIG(ERR, "(%s) userfaultfd not available: %s\n", - dev->ifname, strerror(errno)); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "userfaultfd not available: %s\n", + 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, "(%s) UFFDIO_API ioctl failure: %s\n", - dev->ifname, strerror(errno)); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "UFFDIO_API ioctl failure: %s\n", + strerror(errno)); close(dev->postcopy_ufd); dev->postcopy_ufd = -1; return RTE_VHOST_MSG_RESULT_ERR; @@ -2657,8 +2674,8 @@ vhost_user_set_postcopy_listen(struct virtio_net **pdev, struct virtio_net *dev = *pdev; if (dev->mem && dev->mem->nregions) { - VHOST_LOG_CONFIG(ERR, "(%s) regions already registered at postcopy-listen\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "regions already registered at postcopy-listen\n"); return RTE_VHOST_MSG_RESULT_ERR; } dev->postcopy_listening = 1; @@ -2709,8 +2726,9 @@ vhost_user_set_status(struct virtio_net **pdev, /* As per Virtio specification, the device status is 8bits long */ if (ctx->msg.payload.u64 > UINT8_MAX) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid VHOST_USER_SET_STATUS payload 0x%" PRIx64 "\n", - dev->ifname, ctx->msg.payload.u64); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "invalid VHOST_USER_SET_STATUS payload 0x%" PRIx64 "\n", + ctx->msg.payload.u64); return RTE_VHOST_MSG_RESULT_ERR; } @@ -2718,9 +2736,8 @@ vhost_user_set_status(struct virtio_net **pdev, if ((dev->status & VIRTIO_DEVICE_STATUS_FEATURES_OK) && (dev->flags & VIRTIO_DEV_FEATURES_FAILED)) { - VHOST_LOG_CONFIG(ERR, - "(%s) FEATURES_OK bit is set but feature negotiation failed\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "FEATURES_OK bit is set but feature negotiation failed\n"); /* * Clear the bit to let the driver know about the feature * negotiation failure @@ -2728,22 +2745,28 @@ vhost_user_set_status(struct virtio_net **pdev, dev->status &= ~VIRTIO_DEVICE_STATUS_FEATURES_OK; } - 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)); + VHOST_LOG_CONFIG(dev->ifname, INFO, "new device status(0x%08x):\n", dev->status); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t-RESET: %u\n", + (dev->status == VIRTIO_DEVICE_STATUS_RESET)); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t-ACKNOWLEDGE: %u\n", + !!(dev->status & VIRTIO_DEVICE_STATUS_ACK)); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t-DRIVER: %u\n", + !!(dev->status & VIRTIO_DEVICE_STATUS_DRIVER)); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t-FEATURES_OK: %u\n", + !!(dev->status & VIRTIO_DEVICE_STATUS_FEATURES_OK)); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t-DRIVER_OK: %u\n", + !!(dev->status & VIRTIO_DEVICE_STATUS_DRIVER_OK)); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t-DEVICE_NEED_RESET: %u\n", + !!(dev->status & VIRTIO_DEVICE_STATUS_DEV_NEED_RESET)); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "\t-FAILED: %u\n", + !!(dev->status & VIRTIO_DEVICE_STATUS_FAILED)); return RTE_VHOST_MSG_RESULT_OK; } @@ -2800,22 +2823,22 @@ read_vhost_message(struct virtio_net *dev, int sockfd, struct vhu_msg_context * if (ret <= 0) { return ret; } else if (ret != VHOST_USER_HDR_SIZE) { - VHOST_LOG_CONFIG(ERR, "(%s) Unexpected header size read\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "Unexpected header size read\n"); close_msg_fds(ctx); return -1; } if (ctx->msg.size) { if (ctx->msg.size > sizeof(ctx->msg.payload)) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid msg size: %d\n", - dev->ifname, ctx->msg.size); + VHOST_LOG_CONFIG(dev->ifname, ERR, "invalid msg size: %d\n", + ctx->msg.size); return -1; } ret = read(sockfd, &ctx->msg.payload, ctx->msg.size); if (ret <= 0) return ret; if (ret != (int)ctx->msg.size) { - VHOST_LOG_CONFIG(ERR, "(%s) read control message failed\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "read control message failed\n"); return -1; } } @@ -2895,7 +2918,7 @@ vhost_user_check_and_alloc_queue_pair(struct virtio_net *dev, } if (vring_idx >= VHOST_MAX_VRING) { - VHOST_LOG_CONFIG(ERR, "(%s) invalid vring index: %u\n", dev->ifname, vring_idx); + VHOST_LOG_CONFIG(dev->ifname, ERR, "invalid vring index: %u\n", vring_idx); return -1; } @@ -2959,8 +2982,8 @@ 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, "(%s) failed to get callback ops for driver\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to get callback ops for driver\n"); return -1; } } @@ -2968,9 +2991,9 @@ vhost_user_msg_handler(int vid, int fd) ret = read_vhost_message(dev, fd, &ctx); if (ret <= 0) { if (ret < 0) - VHOST_LOG_CONFIG(ERR, "(%s) vhost read message failed\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "vhost read message failed\n"); else - VHOST_LOG_CONFIG(INFO, "(%s) vhost peer closed\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, INFO, "vhost peer closed\n"); return -1; } @@ -2983,18 +3006,20 @@ vhost_user_msg_handler(int vid, int fd) if (msg_handler != NULL && msg_handler->description != NULL) { if (request != VHOST_USER_IOTLB_MSG) - VHOST_LOG_CONFIG(INFO, "(%s) read message %s\n", - dev->ifname, msg_handler->description); + VHOST_LOG_CONFIG(dev->ifname, INFO, + "read message %s\n", + msg_handler->description); else - VHOST_LOG_CONFIG(DEBUG, "(%s) read message %s\n", - dev->ifname, msg_handler->description); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, + "read message %s\n", + msg_handler->description); } else { - VHOST_LOG_CONFIG(DEBUG, "(%s) external request %d\n", dev->ifname, request); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, "external request %d\n", request); } ret = vhost_user_check_and_alloc_queue_pair(dev, &ctx); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to alloc queue\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to alloc queue\n"); return -1; } @@ -3061,18 +3086,21 @@ vhost_user_msg_handler(int vid, int fd) switch (ret) { case RTE_VHOST_MSG_RESULT_ERR: - VHOST_LOG_CONFIG(ERR, "(%s) processing %s failed.\n", - dev->ifname, msg_handler->description); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "processing %s failed.\n", + msg_handler->description); handled = true; break; case RTE_VHOST_MSG_RESULT_OK: - VHOST_LOG_CONFIG(DEBUG, "(%s) processing %s succeeded.\n", - dev->ifname, msg_handler->description); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, + "processing %s succeeded.\n", + msg_handler->description); handled = true; break; case RTE_VHOST_MSG_RESULT_REPLY: - VHOST_LOG_CONFIG(DEBUG, "(%s) processing %s succeeded and needs reply.\n", - dev->ifname, msg_handler->description); + VHOST_LOG_CONFIG(dev->ifname, DEBUG, + "processing %s succeeded and needs reply.\n", + msg_handler->description); send_vhost_reply(dev, fd, &ctx); handled = true; break; @@ -3100,8 +3128,9 @@ 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, "(%s) vhost message (req: %d) was not handled.\n", - dev->ifname, request); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "vhost message (req: %d) was not handled.\n", + request); close_msg_fds(&ctx); ret = RTE_VHOST_MSG_RESULT_ERR; } @@ -3117,7 +3146,7 @@ vhost_user_msg_handler(int vid, int fd) ctx.fd_num = 0; send_vhost_reply(dev, fd, &ctx); } else if (ret == RTE_VHOST_MSG_RESULT_ERR) { - VHOST_LOG_CONFIG(ERR, "(%s) vhost message handling failed.\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "vhost message handling failed.\n"); ret = -1; goto unlock; } @@ -3157,8 +3186,7 @@ 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, "(%s) failed to configure vDPA device\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to configure vDPA device\n"); else dev->flags |= VIRTIO_DEV_VDPA_CONFIGURED; } @@ -3179,18 +3207,19 @@ static int process_slave_message_reply(struct virtio_net *dev, ret = read_vhost_message(dev, dev->slave_req_fd, &msg_reply); if (ret <= 0) { if (ret < 0) - VHOST_LOG_CONFIG(ERR, "(%s) vhost read slave message reply failed\n", - dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "vhost read slave message reply failed\n"); else - VHOST_LOG_CONFIG(INFO, "(%s) vhost peer closed\n", dev->ifname); + VHOST_LOG_CONFIG(dev->ifname, INFO, "vhost peer closed\n"); ret = -1; goto out; } ret = 0; if (msg_reply.msg.request.slave != ctx->msg.request.slave) { - VHOST_LOG_CONFIG(ERR, "(%s) received unexpected msg type (%u), expected %u\n", - dev->ifname, msg_reply.msg.request.slave, ctx->msg.request.slave); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "received unexpected msg type (%u), expected %u\n", + msg_reply.msg.request.slave, ctx->msg.request.slave); ret = -1; goto out; } @@ -3221,8 +3250,9 @@ vhost_user_iotlb_miss(struct virtio_net *dev, uint64_t iova, uint8_t perm) ret = send_vhost_message(dev, dev->slave_req_fd, &ctx); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to send IOTLB miss message (%d)\n", - dev->ifname, ret); + VHOST_LOG_CONFIG(dev->ifname, ERR, + "failed to send IOTLB miss message (%d)\n", + ret); return ret; } @@ -3246,8 +3276,7 @@ vhost_user_slave_config_change(struct virtio_net *dev, bool need_reply) ret = send_vhost_slave_message(dev, &ctx); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to send config change (%d)\n", - dev->ifname, ret); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to send config change (%d)\n", ret); return ret; } @@ -3294,8 +3323,7 @@ static int vhost_user_slave_set_vring_host_notifier(struct virtio_net *dev, ret = send_vhost_slave_message(dev, &ctx); if (ret < 0) { - VHOST_LOG_CONFIG(ERR, "(%s) failed to set host notifier (%d)\n", - dev->ifname, ret); + VHOST_LOG_CONFIG(dev->ifname, ERR, "failed to set host notifier (%d)\n", ret); return ret; } diff --git a/lib/vhost/virtio_net.c b/lib/vhost/virtio_net.c index f7ced96cbf..e4227abc5b 100644 --- a/lib/vhost/virtio_net.c +++ b/lib/vhost/virtio_net.c @@ -131,8 +131,9 @@ vhost_async_dma_transfer_one(struct virtio_net *dev, struct vhost_virtqueue *vq, */ if (unlikely(copy_idx < 0)) { if (!vhost_async_dma_copy_log) { - VHOST_LOG_DATA(ERR, "(%s) DMA copy failed for channel %d:%u\n", - dev->ifname, dma_id, vchan_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "DMA copy failed for channel %d:%u\n", + dma_id, vchan_id); vhost_async_dma_copy_log = true; } return -1; @@ -200,8 +201,9 @@ vhost_async_dma_check_completed(struct virtio_net *dev, int16_t dma_id, uint16_t */ nr_copies = rte_dma_completed(dma_id, vchan_id, max_pkts, &last_idx, &has_error); if (unlikely(!vhost_async_dma_complete_log && has_error)) { - VHOST_LOG_DATA(ERR, "(%s) DMA completion failure on channel %d:%u\n", dev->ifname, - dma_id, vchan_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "DMA completion failure on channel %d:%u\n", + dma_id, vchan_id); vhost_async_dma_complete_log = true; } else if (nr_copies == 0) { goto out; @@ -993,7 +995,7 @@ async_iter_initialize(struct virtio_net *dev, struct vhost_async *async) struct vhost_iov_iter *iter; if (unlikely(async->iovec_idx >= VHOST_MAX_ASYNC_VEC)) { - VHOST_LOG_DATA(ERR, "(%s) no more async iovec available\n", dev->ifname); + VHOST_LOG_DATA(dev->ifname, ERR, "no more async iovec available\n"); return -1; } @@ -1015,7 +1017,7 @@ async_iter_add_iovec(struct virtio_net *dev, struct vhost_async *async, static bool vhost_max_async_vec_log; if (!vhost_max_async_vec_log) { - VHOST_LOG_DATA(ERR, "(%s) no more async iovec available\n", dev->ifname); + VHOST_LOG_DATA(dev->ifname, ERR, "no more async iovec available\n"); vhost_max_async_vec_log = true; } @@ -1074,8 +1076,9 @@ async_fill_seg(struct virtio_net *dev, struct vhost_virtqueue *vq, host_iova = (void *)(uintptr_t)gpa_to_first_hpa(dev, buf_iova + buf_offset, cpy_len, &mapped_len); if (unlikely(!host_iova)) { - VHOST_LOG_DATA(ERR, "(%s) %s: failed to get host iova.\n", - dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: failed to get host iova.\n", + __func__); return -1; } @@ -1168,8 +1171,7 @@ 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, "(%s) RX: num merge buffers %d\n", - dev->ifname, num_buffers); + VHOST_LOG_DATA(dev->ifname, DEBUG, "RX: num merge buffers %d\n", num_buffers); if (unlikely(buf_len < dev->vhost_hlen)) { buf_offset = dev->vhost_hlen - buf_len; @@ -1349,16 +1351,15 @@ virtio_dev_rx_split(struct virtio_net *dev, struct vhost_virtqueue *vq, if (unlikely(reserve_avail_buf_split(dev, vq, pkt_len, buf_vec, &num_buffers, avail_head, &nr_vec) < 0)) { - VHOST_LOG_DATA(DEBUG, - "(%s) failed to get enough desc from vring\n", - dev->ifname); + VHOST_LOG_DATA(dev->ifname, DEBUG, + "failed to get enough desc from vring\n"); vq->shadow_used_idx -= num_buffers; break; } - VHOST_LOG_DATA(DEBUG, "(%s) current index %d | end index %d\n", - dev->ifname, vq->last_avail_idx, - vq->last_avail_idx + num_buffers); + VHOST_LOG_DATA(dev->ifname, DEBUG, + "current index %d | end index %d\n", + 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, false) < 0) { @@ -1504,14 +1505,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, "(%s) failed to get enough desc from vring\n", - dev->ifname); + VHOST_LOG_DATA(dev->ifname, DEBUG, "failed to get enough desc from vring\n"); return -1; } - VHOST_LOG_DATA(DEBUG, "(%s) current index %d | end index %d\n", - dev->ifname, vq->last_avail_idx, - vq->last_avail_idx + nr_descs); + VHOST_LOG_DATA(dev->ifname, DEBUG, + "current index %d | end index %d\n", + vq->last_avail_idx, vq->last_avail_idx + nr_descs); vq_inc_last_avail_packed(vq, nr_descs); @@ -1561,10 +1561,11 @@ virtio_dev_rx(struct virtio_net *dev, uint16_t queue_id, struct vhost_virtqueue *vq; uint32_t nb_tx = 0; - VHOST_LOG_DATA(DEBUG, "(%s) %s\n", dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, DEBUG, "%s\n", __func__); if (unlikely(!is_valid_virt_queue_idx(queue_id, 0, dev->nr_vring))) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: invalid virtqueue idx %d.\n", + __func__, queue_id); return 0; } @@ -1613,8 +1614,9 @@ 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, "(%s) %s: built-in vhost net backend is disabled.\n", - dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: built-in vhost net backend is disabled.\n", + __func__); return 0; } @@ -1696,14 +1698,15 @@ virtio_dev_rx_async_submit_split(struct virtio_net *dev, struct vhost_virtqueue if (unlikely(reserve_avail_buf_split(dev, vq, pkt_len, buf_vec, &num_buffers, avail_head, &nr_vec) < 0)) { - VHOST_LOG_DATA(DEBUG, "(%s) failed to get enough desc from vring\n", - dev->ifname); + VHOST_LOG_DATA(dev->ifname, DEBUG, + "failed to get enough desc from vring\n"); vq->shadow_used_idx -= num_buffers; break; } - VHOST_LOG_DATA(DEBUG, "(%s) current index %d | end index %d\n", - dev->ifname, vq->last_avail_idx, vq->last_avail_idx + num_buffers); + VHOST_LOG_DATA(dev->ifname, DEBUG, + "current index %d | end index %d\n", + 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; @@ -1727,8 +1730,9 @@ virtio_dev_rx_async_submit_split(struct virtio_net *dev, struct vhost_virtqueue if (unlikely(pkt_err)) { uint16_t num_descs = 0; - VHOST_LOG_DATA(DEBUG, "(%s) %s: failed to transfer %u packets for queue %u.\n", - dev->ifname, __func__, pkt_err, queue_id); + VHOST_LOG_DATA(dev->ifname, DEBUG, + "%s: failed to transfer %u packets for queue %u.\n", + __func__, pkt_err, queue_id); /* update number of completed packets */ pkt_idx = n_xfer; @@ -1835,12 +1839,13 @@ 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, "(%s) failed to get enough desc from vring\n", dev->ifname); + VHOST_LOG_DATA(dev->ifname, DEBUG, "failed to get enough desc from vring\n"); return -1; } - VHOST_LOG_DATA(DEBUG, "(%s) current index %d | end index %d\n", - dev->ifname, vq->last_avail_idx, vq->last_avail_idx + *nr_descs); + VHOST_LOG_DATA(dev->ifname, DEBUG, + "current index %d | end index %d\n", + vq->last_avail_idx, vq->last_avail_idx + *nr_descs); return 0; } @@ -1917,8 +1922,9 @@ virtio_dev_rx_async_submit_packed(struct virtio_net *dev, struct vhost_virtqueue pkt_err = pkt_idx - n_xfer; if (unlikely(pkt_err)) { - VHOST_LOG_DATA(DEBUG, "(%s) %s: failed to transfer %u packets for queue %u.\n", - dev->ifname, __func__, pkt_err, queue_id); + VHOST_LOG_DATA(dev->ifname, DEBUG, + "%s: failed to transfer %u packets for queue %u.\n", + __func__, pkt_err, queue_id); dma_error_handler_packed(vq, slot_idx, pkt_err, &pkt_idx); } @@ -2118,31 +2124,35 @@ rte_vhost_poll_enqueue_completed(int vid, uint16_t queue_id, if (unlikely(!dev)) return 0; - VHOST_LOG_DATA(DEBUG, "(%s) %s\n", dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, DEBUG, "%s\n", __func__); if (unlikely(!is_valid_virt_queue_idx(queue_id, 0, dev->nr_vring))) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: invalid virtqueue idx %d.\n", + __func__, queue_id); return 0; } if (unlikely(!dma_copy_track[dma_id].vchans || !dma_copy_track[dma_id].vchans[vchan_id].pkts_cmpl_flag_addr)) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid channel %d:%u.\n", dev->ifname, __func__, - dma_id, vchan_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: invalid channel %d:%u.\n", + __func__, dma_id, vchan_id); return 0; } vq = dev->virtqueue[queue_id]; if (!rte_spinlock_trylock(&vq->access_lock)) { - VHOST_LOG_DATA(DEBUG, "(%s) %s: virtqueue %u is busy.\n", dev->ifname, __func__, - queue_id); + VHOST_LOG_DATA(dev->ifname, DEBUG, + "%s: virtqueue %u is busy.\n", + __func__, queue_id); return 0; } if (unlikely(!vq->async)) { - VHOST_LOG_DATA(ERR, "(%s) %s: async not registered for virtqueue %d.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: async not registered for virtqueue %d.\n", + __func__, queue_id); goto out; } @@ -2169,37 +2179,39 @@ rte_vhost_clear_queue_thread_unsafe(int vid, uint16_t queue_id, if (!dev) return 0; - VHOST_LOG_DATA(DEBUG, "(%s) %s\n", dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, DEBUG, "%s\n", __func__); if (unlikely(queue_id >= dev->nr_vring)) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: invalid virtqueue idx %d.\n", + __func__, queue_id); return 0; } if (unlikely(dma_id < 0 || dma_id >= RTE_DMADEV_DEFAULT_MAX)) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid dma id %d.\n", - dev->ifname, __func__, dma_id); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: invalid dma id %d.\n", + __func__, dma_id); return 0; } vq = dev->virtqueue[queue_id]; if (unlikely(!rte_spinlock_is_locked(&vq->access_lock))) { - VHOST_LOG_DATA(ERR, "(%s) %s() called without access lock taken.\n", - dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, ERR, "%s() called without access lock taken.\n", + __func__); return -1; } if (unlikely(!vq->async)) { - VHOST_LOG_DATA(ERR, "(%s) %s: async not registered for queue id %d.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: async not registered for virtqueue %d.\n", + __func__, queue_id); return 0; } if (unlikely(!dma_copy_track[dma_id].vchans || !dma_copy_track[dma_id].vchans[vchan_id].pkts_cmpl_flag_addr)) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid channel %d:%u.\n", dev->ifname, __func__, - dma_id, vchan_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: invalid channel %d:%u.\n", + __func__, dma_id, vchan_id); return 0; } @@ -2228,37 +2240,37 @@ rte_vhost_clear_queue(int vid, uint16_t queue_id, struct rte_mbuf **pkts, if (!dev) return 0; - VHOST_LOG_DATA(DEBUG, "(%s) %s\n", dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, DEBUG, "%s\n", __func__); if (unlikely(queue_id >= dev->nr_vring)) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %u.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: invalid virtqueue idx %u.\n", + __func__, queue_id); return 0; } if (unlikely(dma_id < 0 || dma_id >= RTE_DMADEV_DEFAULT_MAX)) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid dma id %d.\n", - dev->ifname, __func__, dma_id); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: invalid dma id %d.\n", + __func__, dma_id); return 0; } vq = dev->virtqueue[queue_id]; if (!rte_spinlock_trylock(&vq->access_lock)) { - VHOST_LOG_DATA(DEBUG, "(%s) %s: virtqueue %u is busy.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, DEBUG, "%s: virtqueue %u is busy.\n", + __func__, queue_id); return 0; } if (unlikely(!vq->async)) { - VHOST_LOG_DATA(ERR, "(%s) %s: async not registered for queue id %u.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: async not registered for queue id %u.\n", + __func__, queue_id); goto out_access_unlock; } if (unlikely(!dma_copy_track[dma_id].vchans || !dma_copy_track[dma_id].vchans[vchan_id].pkts_cmpl_flag_addr)) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid channel %d:%u.\n", dev->ifname, __func__, - dma_id, vchan_id); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: invalid channel %d:%u.\n", + __func__, dma_id, vchan_id); goto out_access_unlock; } @@ -2286,17 +2298,19 @@ 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, "(%s) %s\n", dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, DEBUG, "%s\n", __func__); if (unlikely(!is_valid_virt_queue_idx(queue_id, 0, dev->nr_vring))) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: invalid virtqueue idx %d.\n", + __func__, queue_id); return 0; } if (unlikely(!dma_copy_track[dma_id].vchans || !dma_copy_track[dma_id].vchans[vchan_id].pkts_cmpl_flag_addr)) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid channel %d:%u.\n", dev->ifname, __func__, - dma_id, vchan_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: invalid channel %d:%u.\n", + __func__, dma_id, vchan_id); return 0; } @@ -2348,8 +2362,9 @@ 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, "(%s) %s: built-in vhost net backend is disabled.\n", - dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: built-in vhost net backend is disabled.\n", + __func__); return 0; } @@ -2517,8 +2532,9 @@ vhost_dequeue_offload_legacy(struct virtio_net *dev, struct virtio_net_hdr *hdr, m->l4_len = sizeof(struct rte_udp_hdr); break; default: - VHOST_LOG_DATA(WARNING, "(%s) unsupported gso type %u.\n", - dev->ifname, hdr->gso_type); + VHOST_LOG_DATA(dev->ifname, WARNING, + "unsupported gso type %u.\n", + hdr->gso_type); goto error; } } @@ -2757,8 +2773,8 @@ 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, "(%s) failed to allocate memory for mbuf.\n", - dev->ifname); + VHOST_LOG_DATA(dev->ifname, ERR, + "failed to allocate memory for mbuf.\n"); goto error; } @@ -2824,7 +2840,7 @@ virtio_dev_extbuf_alloc(struct virtio_net *dev, struct rte_mbuf *pkt, uint32_t s virtio_dev_extbuf_free, buf); if (unlikely(shinfo == NULL)) { rte_free(buf); - VHOST_LOG_DATA(ERR, "(%s) failed to init shinfo\n", dev->ifname); + VHOST_LOG_DATA(dev->ifname, ERR, "failed to init shinfo\n"); return -1; } @@ -2878,12 +2894,11 @@ 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, "(%s) %s\n", dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, DEBUG, "%s\n", __func__); count = RTE_MIN(count, MAX_PKT_BURST); count = RTE_MIN(count, avail_entries); - VHOST_LOG_DATA(DEBUG, "(%s) about to dequeue %u buffers\n", - dev->ifname, count); + VHOST_LOG_DATA(dev->ifname, DEBUG, "about to dequeue %u buffers\n", count); if (rte_pktmbuf_alloc_bulk(mbuf_pool, pkts, count)) return 0; @@ -2912,8 +2927,9 @@ virtio_dev_tx_split(struct virtio_net *dev, struct vhost_virtqueue *vq, * is required. Drop this packet. */ if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, "(%s) failed mbuf alloc of size %d from %s.\n", - dev->ifname, buf_len, mbuf_pool->name); + VHOST_LOG_DATA(dev->ifname, ERR, + "failed mbuf alloc of size %d from %s.\n", + buf_len, mbuf_pool->name); allocerr_warned = true; } dropped += 1; @@ -2925,8 +2941,7 @@ virtio_dev_tx_split(struct virtio_net *dev, struct vhost_virtqueue *vq, mbuf_pool, legacy_ol_flags, 0, false); if (unlikely(err)) { if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, "(%s) failed to copy desc to mbuf.\n", - dev->ifname); + VHOST_LOG_DATA(dev->ifname, ERR, "failed to copy desc to mbuf.\n"); allocerr_warned = true; } dropped += 1; @@ -3108,8 +3123,9 @@ 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, "(%s) failed mbuf alloc of size %d from %s.\n", - dev->ifname, buf_len, mbuf_pool->name); + VHOST_LOG_DATA(dev->ifname, ERR, + "failed mbuf alloc of size %d from %s.\n", + buf_len, mbuf_pool->name); allocerr_warned = true; } return -1; @@ -3119,8 +3135,7 @@ vhost_dequeue_single_packed(struct virtio_net *dev, mbuf_pool, legacy_ol_flags, 0, false); if (unlikely(err)) { if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, "(%s) failed to copy desc to mbuf.\n", - dev->ifname); + VHOST_LOG_DATA(dev->ifname, ERR, "failed to copy desc to mbuf.\n"); allocerr_warned = true; } return -1; @@ -3235,14 +3250,16 @@ 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, "(%s) %s: built-in vhost net backend is disabled.\n", - dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: built-in vhost net backend is disabled.\n", + __func__); return 0; } if (unlikely(!is_valid_virt_queue_idx(queue_id, 1, dev->nr_vring))) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: invalid virtqueue idx %d.\n", + __func__, queue_id); return 0; } @@ -3287,7 +3304,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, "(%s) failed to make RARP packet.\n", dev->ifname); + VHOST_LOG_DATA(dev->ifname, ERR, "failed to make RARP packet.\n"); count = 0; goto out; } @@ -3406,8 +3423,7 @@ virtio_dev_tx_async_split(struct virtio_net *dev, struct vhost_virtqueue *vq, count = RTE_MIN(count, MAX_PKT_BURST); count = RTE_MIN(count, avail_entries); - VHOST_LOG_DATA(DEBUG, "(%s) about to dequeue %u buffers\n", - dev->ifname, count); + VHOST_LOG_DATA(dev->ifname, DEBUG, "about to dequeue %u buffers\n", count); if (rte_pktmbuf_alloc_bulk(mbuf_pool, pkts_prealloc, count)) goto out; @@ -3437,9 +3453,9 @@ virtio_dev_tx_async_split(struct virtio_net *dev, struct vhost_virtqueue *vq, * is required. Drop this packet. */ if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, - "(%s) %s: Failed mbuf alloc of size %d from %s\n", - dev->ifname, __func__, buf_len, mbuf_pool->name); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: Failed mbuf alloc of size %d from %s\n", + __func__, buf_len, mbuf_pool->name); allocerr_warned = true; } dropped = true; @@ -3451,9 +3467,9 @@ virtio_dev_tx_async_split(struct virtio_net *dev, struct vhost_virtqueue *vq, legacy_ol_flags, slot_idx, true); if (unlikely(err)) { if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, - "(%s) %s: Failed to offload copies to async channel.\n", - dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, ERR, + "%s: Failed to offload copies to async channel.\n", + __func__); allocerr_warned = true; } dropped = true; @@ -3481,8 +3497,8 @@ virtio_dev_tx_async_split(struct virtio_net *dev, struct vhost_virtqueue *vq, pkt_err = pkt_idx - n_xfer; if (unlikely(pkt_err)) { - VHOST_LOG_DATA(DEBUG, "(%s) %s: failed to transfer data.\n", - dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, DEBUG, "%s: failed to transfer data.\n", + __func__); pkt_idx = n_xfer; /* recover available ring */ @@ -3571,8 +3587,8 @@ virtio_dev_tx_async_single_packed(struct virtio_net *dev, if (unlikely(virtio_dev_pktmbuf_prep(dev, pkts, buf_len))) { if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, "(%s) Failed mbuf alloc of size %d from %s.\n", - dev->ifname, buf_len, mbuf_pool->name); + VHOST_LOG_DATA(dev->ifname, ERR, "Failed mbuf alloc of size %d from %s.\n", + buf_len, mbuf_pool->name); allocerr_warned = true; } @@ -3584,7 +3600,7 @@ virtio_dev_tx_async_single_packed(struct virtio_net *dev, if (unlikely(err)) { rte_pktmbuf_free(pkts); if (!allocerr_warned) { - VHOST_LOG_DATA(ERR, "(%s) Failed to copy desc to mbuf on.\n", dev->ifname); + VHOST_LOG_DATA(dev->ifname, ERR, "Failed to copy desc to mbuf on.\n"); allocerr_warned = true; } return -1; @@ -3610,7 +3626,7 @@ virtio_dev_tx_async_packed(struct virtio_net *dev, struct vhost_virtqueue *vq, struct async_inflight_info *pkts_info = async->pkts_info; struct rte_mbuf *pkts_prealloc[MAX_PKT_BURST]; - VHOST_LOG_DATA(DEBUG, "(%d) about to dequeue %u buffers\n", dev->vid, count); + VHOST_LOG_DATA(dev->ifname, DEBUG, "(%d) about to dequeue %u buffers\n", dev->vid, count); async_iter_reset(async); @@ -3715,27 +3731,27 @@ rte_vhost_async_try_dequeue_burst(int vid, uint16_t queue_id, *nr_inflight = -1; if (unlikely(!(dev->flags & VIRTIO_DEV_BUILTIN_VIRTIO_NET))) { - VHOST_LOG_DATA(ERR, "(%s) %s: built-in vhost net backend is disabled.\n", - dev->ifname, __func__); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: built-in vhost net backend is disabled.\n", + __func__); return 0; } if (unlikely(!is_valid_virt_queue_idx(queue_id, 1, dev->nr_vring))) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid virtqueue idx %d.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: invalid virtqueue idx %d.\n", + __func__, queue_id); return 0; } if (unlikely(dma_id < 0 || dma_id >= RTE_DMADEV_DEFAULT_MAX)) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid dma id %d.\n", - dev->ifname, __func__, dma_id); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: invalid dma id %d.\n", + __func__, dma_id); return 0; } if (unlikely(!dma_copy_track[dma_id].vchans || !dma_copy_track[dma_id].vchans[vchan_id].pkts_cmpl_flag_addr)) { - VHOST_LOG_DATA(ERR, "(%s) %s: invalid channel %d:%u.\n", dev->ifname, __func__, - dma_id, vchan_id); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: invalid channel %d:%u.\n", + __func__, dma_id, vchan_id); return 0; } @@ -3750,8 +3766,8 @@ rte_vhost_async_try_dequeue_burst(int vid, uint16_t queue_id, } if (unlikely(!vq->async)) { - VHOST_LOG_DATA(ERR, "(%s) %s: async not registered for queue id %d.\n", - dev->ifname, __func__, queue_id); + VHOST_LOG_DATA(dev->ifname, ERR, "%s: async not registered for queue id %d.\n", + __func__, queue_id); count = 0; goto out_access_unlock; } @@ -3787,7 +3803,7 @@ rte_vhost_async_try_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, "(%s) failed to make RARP packet.\n", dev->ifname); + VHOST_LOG_DATA(dev->ifname, ERR, "failed to make RARP packet.\n"); count = 0; goto out; }