vhost: prefix logs with context

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 <david.marchand@redhat.com>
Reviewed-by: Maxime Coquelin <maxime.coquelin@redhat.com>
This commit is contained in:
David Marchand 2022-07-01 15:20:56 +02:00 committed by Maxime Coquelin
parent 481a2c7ef2
commit 36c525a035
7 changed files with 636 additions and 595 deletions

View File

@ -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;
}

View File

@ -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 @@ again:
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;
}

View File

@ -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;
}

View File

@ -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,17 +1871,17 @@ 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;
}
if (rte_dma_info_get(dma_id, &info) != 0) {
VHOST_LOG_CONFIG(ERR, "Fail to get DMA %d information.\n", dma_id);
VHOST_LOG_CONFIG("dma", ERR, "Fail to get DMA %d information.\n", dma_id);
return -1;
}
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;
}
@ -1884,8 +1891,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;
}
@ -1893,8 +1901,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;
}
@ -1904,8 +1912,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);
@ -1941,9 +1950,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;
}
@ -1974,8 +1982,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;
}

View File

@ -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)) ||

File diff suppressed because it is too large Load Diff

View File

@ -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;
}
}
@ -2765,8 +2781,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;
}
@ -2832,7 +2848,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;
}
@ -2886,12 +2902,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;
@ -2920,8 +2935,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;
@ -2933,8 +2949,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;
@ -3116,8 +3131,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;
@ -3127,8 +3143,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;
@ -3243,14 +3258,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;
}
@ -3295,7 +3312,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;
}
@ -3414,8 +3431,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;
@ -3445,9 +3461,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;
@ -3459,9 +3475,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;
@ -3489,8 +3505,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 */
@ -3579,8 +3595,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;
}
@ -3592,7 +3608,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;
@ -3618,7 +3634,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);
@ -3723,27 +3739,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;
}
@ -3758,8 +3774,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;
}
@ -3795,7 +3811,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;
}