Using debug printf with the virtual IOMMU can be extremely verbose. To ease debugging, add a few commands that can be sent via IPC. Format for commands is "cmd [iommu [address_space]]" (or cmd:[iommu:[address_space]]) $ lkvm debug -a -i list iommu 0 "viommu-vfio" ioas 1 device 0x2 # PCI bus ioas 2 device 0x3 iommu 1 "viommu-virtio" ioas 3 device 0x10003 # MMIO bus ioas 4 device 0x6 $ lkvm debug -a -i stats:0 # stats for viommu-vfio iommu 0 "viommu-virtio" kicks 510 # virtio kicks from driver requests 510 # requests received ioas 3 maps 1 # number of map requests unmaps 0 # " unmap " resident 8192 # bytes currently mapped accesses 1 # number of device accesses ioas 4 maps 290 unmaps 4 resident 1335296 accesses 982 $ lkvm debug -a -i "print 1, 2" # Start debug print for ... # ioas 2 in iommu 1 ... Info: VIOMMU map 0xffffffff000 -> 0x8f4e0000 (4096) to IOAS 2 ... $ lkvm debug -a -i noprint # Stop all debug print We don't use atomics for statistics at the moment, since there is no concurrent write on most of them. Only 'accesses' might be incremented concurrently, so we might get imprecise values. Signed-off-by: Jean-Philippe Brucker <jean-philippe.brucker@xxxxxxx> --- include/kvm/iommu.h | 17 +++ iommu.c | 56 +++++++++- virtio/iommu.c | 312 ++++++++++++++++++++++++++++++++++++++++++++++++---- virtio/mmio.c | 1 + virtio/pci.c | 1 + 5 files changed, 362 insertions(+), 25 deletions(-) diff --git a/include/kvm/iommu.h b/include/kvm/iommu.h index 60857fa5..70a09306 100644 --- a/include/kvm/iommu.h +++ b/include/kvm/iommu.h @@ -11,7 +11,20 @@ #define IOMMU_PROT_WRITE 0x2 #define IOMMU_PROT_EXEC 0x4 +enum iommu_debug_action { + IOMMU_DEBUG_LIST, + IOMMU_DEBUG_STATS, + IOMMU_DEBUG_SET_PRINT, + IOMMU_DEBUG_DUMP, + + IOMMU_DEBUG_NUM_ACTIONS, +}; + +#define IOMMU_DEBUG_SELECTOR_INVALID ((unsigned int)-1) + struct iommu_debug_params { + enum iommu_debug_action action; + unsigned int selector[2]; bool print_enabled; }; @@ -31,6 +44,8 @@ struct iommu_ops { int (*detach)(void *, struct device_header *); int (*map)(void *, u64 virt_addr, u64 phys_addr, u64 size, int prot); int (*unmap)(void *, u64 virt_addr, u64 size, int flags); + + int (*debug_address_space)(void *, int fd, struct iommu_debug_params *); }; struct iommu_properties { @@ -74,6 +89,8 @@ static inline struct device_header *iommu_get_device(u32 device_id) void *iommu_alloc_address_space(struct device_header *dev); void iommu_free_address_space(void *address_space); +int iommu_debug_address_space(void *address_space, int fd, + struct iommu_debug_params *params); int iommu_map(void *address_space, u64 virt_addr, u64 phys_addr, u64 size, int prot); diff --git a/iommu.c b/iommu.c index 2220e4b2..bc9fc631 100644 --- a/iommu.c +++ b/iommu.c @@ -9,6 +9,10 @@ #include "kvm/mutex.h" #include "kvm/rbtree-interval.h" +struct iommu_ioas_stats { + u64 accesses; +}; + struct iommu_mapping { struct rb_int_node iova_range; u64 phys; @@ -18,8 +22,31 @@ struct iommu_mapping { struct iommu_ioas { struct rb_root mappings; struct mutex mutex; + + struct iommu_ioas_stats stats; + bool debug_enabled; }; +static void iommu_dump(struct iommu_ioas *ioas, int fd) +{ + struct rb_node *node; + struct iommu_mapping *map; + + mutex_lock(&ioas->mutex); + + dprintf(fd, "START IOMMU DUMP [[[\n"); /* You did ask for it. */ + for (node = rb_first(&ioas->mappings); node; node = rb_next(node)) { + struct rb_int_node *int_node = rb_int(node); + map = container_of(int_node, struct iommu_mapping, iova_range); + + dprintf(fd, "%#llx-%#llx -> %#llx %#x\n", int_node->low, + int_node->high, map->phys, map->prot); + } + dprintf(fd, "]]] END IOMMU DUMP\n"); + + mutex_unlock(&ioas->mutex); +} + void *iommu_alloc_address_space(struct device_header *unused) { struct iommu_ioas *ioas = calloc(1, sizeof(*ioas)); @@ -33,6 +60,27 @@ void *iommu_alloc_address_space(struct device_header *unused) return ioas; } +int iommu_debug_address_space(void *address_space, int fd, + struct iommu_debug_params *params) +{ + struct iommu_ioas *ioas = address_space; + + switch (params->action) { + case IOMMU_DEBUG_STATS: + dprintf(fd, " accesses %llu\n", ioas->stats.accesses); + break; + case IOMMU_DEBUG_SET_PRINT: + ioas->debug_enabled = params->print_enabled; + break; + case IOMMU_DEBUG_DUMP: + iommu_dump(ioas, fd); + default: + break; + } + + return 0; +} + void iommu_free_address_space(void *address_space) { struct iommu_ioas *ioas = address_space; @@ -157,8 +205,12 @@ u64 iommu_access(void *address_space, u64 addr, size_t size, size_t *out_size, out_addr = map->phys + (addr - node->low); *out_size = min_t(size_t, node->high - addr + 1, size); - pr_debug("access %llx %zu/%zu %x -> %#llx", addr, *out_size, size, - prot, out_addr); + if (ioas->debug_enabled) + pr_info("access %llx %zu/%zu %s%s -> %#llx", addr, *out_size, + size, prot & IOMMU_PROT_READ ? "R" : "", + prot & IOMMU_PROT_WRITE ? "W" : "", out_addr); + + ioas->stats.accesses++; out_unlock: mutex_unlock(&ioas->mutex); diff --git a/virtio/iommu.c b/virtio/iommu.c index 5973cef1..153b537a 100644 --- a/virtio/iommu.c +++ b/virtio/iommu.c @@ -20,6 +20,17 @@ /* Max size */ #define VIOMMU_DEFAULT_QUEUE_SIZE 256 +struct viommu_ioas_stats { + u64 map; + u64 unmap; + u64 resident; +}; + +struct viommu_stats { + u64 kicks; + u64 requests; +}; + struct viommu_endpoint { struct device_header *dev; struct viommu_ioas *ioas; @@ -36,9 +47,14 @@ struct viommu_ioas { struct iommu_ops *ops; void *priv; + + bool debug_enabled; + struct viommu_ioas_stats stats; }; struct viommu_dev { + u32 id; + struct virtio_device vdev; struct virtio_iommu_config config; @@ -49,29 +65,77 @@ struct viommu_dev { struct thread_pool__job job; struct rb_root address_spaces; + struct mutex address_spaces_mutex; struct kvm *kvm; + + struct list_head list; + + bool debug_enabled; + struct viommu_stats stats; }; static int compat_id = -1; +static long long viommu_ids; +static LIST_HEAD(viommus); +static DEFINE_MUTEX(viommus_mutex); + +#define ioas_debug(ioas, fmt, ...) \ + do { \ + if ((ioas)->debug_enabled) \ + pr_info("ioas[%d] " fmt, (ioas)->id, ##__VA_ARGS__); \ + } while (0) + static struct viommu_ioas *viommu_find_ioas(struct viommu_dev *viommu, u32 ioasid) { struct rb_node *node; - struct viommu_ioas *ioas; + struct viommu_ioas *ioas, *found = NULL; + mutex_lock(&viommu->address_spaces_mutex); node = viommu->address_spaces.rb_node; while (node) { ioas = container_of(node, struct viommu_ioas, node); - if (ioas->id > ioasid) + if (ioas->id > ioasid) { node = node->rb_left; - else if (ioas->id < ioasid) + } else if (ioas->id < ioasid) { node = node->rb_right; - else - return ioas; + } else { + found = ioas; + break; + } } + mutex_unlock(&viommu->address_spaces_mutex); - return NULL; + return found; +} + +static int viommu_for_each_ioas(struct viommu_dev *viommu, + int (*fun)(struct viommu_dev *viommu, + struct viommu_ioas *ioas, + void *data), + void *data) +{ + int ret; + struct viommu_ioas *ioas; + struct rb_node *node, *next; + + mutex_lock(&viommu->address_spaces_mutex); + node = rb_first(&viommu->address_spaces); + while (node) { + next = rb_next(node); + ioas = container_of(node, struct viommu_ioas, node); + + ret = fun(viommu, ioas, data); + if (ret) + break; + + node = next; + } + + mutex_unlock(&viommu->address_spaces_mutex); + + return ret; } static struct viommu_ioas *viommu_alloc_ioas(struct viommu_dev *viommu, @@ -99,9 +163,12 @@ static struct viommu_ioas *viommu_alloc_ioas(struct viommu_dev *viommu, new_ioas->id = ioasid; new_ioas->ops = ops; new_ioas->priv = ops->alloc_address_space(device); + new_ioas->debug_enabled = viommu->debug_enabled; /* A NULL priv pointer is valid. */ + mutex_lock(&viommu->address_spaces_mutex); + node = &viommu->address_spaces.rb_node; while (*node) { ioas = container_of(*node, struct viommu_ioas, node); @@ -114,6 +181,7 @@ static struct viommu_ioas *viommu_alloc_ioas(struct viommu_dev *viommu, } else { pr_err("IOAS exists!"); free(new_ioas); + mutex_unlock(&viommu->address_spaces_mutex); return NULL; } } @@ -121,6 +189,8 @@ static struct viommu_ioas *viommu_alloc_ioas(struct viommu_dev *viommu, rb_link_node(&new_ioas->node, parent, node); rb_insert_color(&new_ioas->node, &viommu->address_spaces); + mutex_unlock(&viommu->address_spaces_mutex); + return new_ioas; } @@ -130,7 +200,9 @@ static void viommu_free_ioas(struct viommu_dev *viommu, if (ioas->priv) ioas->ops->free_address_space(ioas->priv); + mutex_lock(&viommu->address_spaces_mutex); rb_erase(&ioas->node, &viommu->address_spaces); + mutex_unlock(&viommu->address_spaces_mutex); free(ioas); } @@ -178,8 +250,7 @@ static int viommu_detach_device(struct viommu_dev *viommu, if (!ioas) return -EINVAL; - pr_debug("detaching device %#lx from IOAS %u", - device_to_iommu_id(device), ioas->id); + ioas_debug(ioas, "detaching device %#lx", device_to_iommu_id(device)); ret = device->iommu_ops->detach(ioas->priv, device); if (!ret) @@ -208,8 +279,6 @@ static int viommu_handle_attach(struct viommu_dev *viommu, return -ENODEV; } - pr_debug("attaching device %#x to IOAS %u", device_id, ioasid); - vdev = device->iommu_data; if (!vdev) { vdev = viommu_alloc_device(device); @@ -240,6 +309,9 @@ static int viommu_handle_attach(struct viommu_dev *viommu, if (ret && ioas->nr_devices == 0) viommu_free_ioas(viommu, ioas); + if (!ret) + ioas_debug(ioas, "attached device %#x", device_id); + return ret; } @@ -267,6 +339,7 @@ static int viommu_handle_detach(struct viommu_dev *viommu, static int viommu_handle_map(struct viommu_dev *viommu, struct virtio_iommu_req_map *map) { + int ret; int prot = 0; struct viommu_ioas *ioas; @@ -294,15 +367,21 @@ static int viommu_handle_map(struct viommu_dev *viommu, if (flags & VIRTIO_IOMMU_MAP_F_EXEC) prot |= IOMMU_PROT_EXEC; - pr_debug("map %#llx -> %#llx (%llu) to IOAS %u", virt_addr, - phys_addr, size, ioasid); + ioas_debug(ioas, "map %#llx -> %#llx (%llu)", virt_addr, phys_addr, size); + + ret = ioas->ops->map(ioas->priv, virt_addr, phys_addr, size, prot); + if (!ret) { + ioas->stats.resident += size; + ioas->stats.map++; + } - return ioas->ops->map(ioas->priv, virt_addr, phys_addr, size, prot); + return ret; } static int viommu_handle_unmap(struct viommu_dev *viommu, struct virtio_iommu_req_unmap *unmap) { + int ret; struct viommu_ioas *ioas; u32 ioasid = le32_to_cpu(unmap->address_space); @@ -315,10 +394,15 @@ static int viommu_handle_unmap(struct viommu_dev *viommu, return -ESRCH; } - pr_debug("unmap %#llx (%llu) from IOAS %u", virt_addr, size, - ioasid); + ioas_debug(ioas, "unmap %#llx (%llu)", virt_addr, size); + + ret = ioas->ops->unmap(ioas->priv, virt_addr, size, 0); + if (!ret) { + ioas->stats.resident -= size; + ioas->stats.unmap++; + } - return ioas->ops->unmap(ioas->priv, virt_addr, size, 0); + return ret; } static size_t viommu_get_req_len(union virtio_iommu_req *req) @@ -407,6 +491,8 @@ static ssize_t viommu_dispatch_commands(struct viommu_dev *viommu, continue; } + viommu->stats.requests++; + req = iov[i].iov_base; op = req->head.type; expected_len = viommu_get_req_len(req) - sizeof(*tail); @@ -458,6 +544,8 @@ static void viommu_command(struct kvm *kvm, void *dev) vq = &viommu->vq; + viommu->stats.kicks++; + while (virt_queue__available(vq)) { head = virt_queue__get_iov(vq, iov, &out, &in, kvm); @@ -594,6 +682,7 @@ void *viommu_register(struct kvm *kvm, struct iommu_properties *props) viommu->queue_size = VIOMMU_DEFAULT_QUEUE_SIZE; viommu->address_spaces = (struct rb_root)RB_ROOT; + viommu->address_spaces_mutex = (struct mutex)MUTEX_INITIALIZER; viommu->properties = props; viommu->config.page_sizes = props->pgsize_mask ?: pgsize_mask; @@ -607,6 +696,11 @@ void *viommu_register(struct kvm *kvm, struct iommu_properties *props) return NULL; } + mutex_lock(&viommus_mutex); + viommu->id = viommu_ids++; + list_add_tail(&viommu->list, &viommus); + mutex_unlock(&viommus_mutex); + pr_info("Loaded virtual IOMMU %s", props->name); if (compat_id == -1) @@ -616,21 +710,193 @@ void *viommu_register(struct kvm *kvm, struct iommu_properties *props) return viommu; } -void viommu_unregister(struct kvm *kvm, void *viommu) +void viommu_unregister(struct kvm *kvm, void *dev) { + struct viommu_dev *viommu = dev; + + mutex_lock(&viommus_mutex); + list_del(&viommu->list); + mutex_unlock(&viommus_mutex); + free(viommu); } +const char *debug_usage = +" list [iommu [ioas]] list iommus and address spaces\n" +" stats [iommu [ioas]] display statistics\n" +" dump [iommu [ioas]] dump mappings\n" +" print [iommu [ioas]] enable debug print\n" +" noprint [iommu [ioas]] disable debug print\n" +; + int viommu_parse_debug_string(const char *cmdline, struct iommu_debug_params *params) { - /* show instances numbers */ - /* send command to instance */ - /* - dump mappings */ - /* - statistics */ - return -ENOSYS; + int pos = 0; + int ret = -EINVAL; + char *cur, *args = strdup(cmdline); + params->action = IOMMU_DEBUG_NUM_ACTIONS; + + if (!args) + return -ENOMEM; + + params->selector[0] = IOMMU_DEBUG_SELECTOR_INVALID; + params->selector[1] = IOMMU_DEBUG_SELECTOR_INVALID; + + cur = strtok(args, " ,:"); + while (cur) { + if (pos > 2) + break; + + if (pos > 0) { + errno = 0; + params->selector[pos - 1] = strtoul(cur, NULL, 0); + if (errno) { + ret = -errno; + pr_err("Invalid number '%s'", cur); + break; + } + } else if (strncmp(cur, "list", 4) == 0) { + params->action = IOMMU_DEBUG_LIST; + } else if (strncmp(cur, "stats", 5) == 0) { + params->action = IOMMU_DEBUG_STATS; + } else if (strncmp(cur, "dump", 4) == 0) { + params->action = IOMMU_DEBUG_DUMP; + } else if (strncmp(cur, "print", 5) == 0) { + params->action = IOMMU_DEBUG_SET_PRINT; + params->print_enabled = true; + } else if (strncmp(cur, "noprint", 7) == 0) { + params->action = IOMMU_DEBUG_SET_PRINT; + params->print_enabled = false; + } else { + pr_err("Invalid command '%s'", cur); + break; + } + + cur = strtok(NULL, " ,:"); + pos++; + ret = 0; + } + + free(args); + + if (cur && cur[0]) + pr_err("Ignoring argument '%s'", cur); + + if (ret) + pr_info("Usage:\n%s", debug_usage); + + return ret; +} + +struct viommu_debug_context { + int sock; + struct iommu_debug_params *params; + bool disp; +}; + +static int viommu_debug_ioas(struct viommu_dev *viommu, + struct viommu_ioas *ioas, + void *data) +{ + int ret = 0; + struct viommu_endpoint *vdev; + struct viommu_debug_context *ctx = data; + + if (ctx->disp) + dprintf(ctx->sock, " ioas %u\n", ioas->id); + + switch (ctx->params->action) { + case IOMMU_DEBUG_LIST: + mutex_lock(&ioas->devices_mutex); + list_for_each_entry(vdev, &ioas->devices, list) { + dprintf(ctx->sock, " device 0x%lx\n", + device_to_iommu_id(vdev->dev)); + } + mutex_unlock(&ioas->devices_mutex); + break; + case IOMMU_DEBUG_STATS: + dprintf(ctx->sock, " maps %llu\n", + ioas->stats.map); + dprintf(ctx->sock, " unmaps %llu\n", + ioas->stats.unmap); + dprintf(ctx->sock, " resident %llu\n", + ioas->stats.resident); + break; + case IOMMU_DEBUG_SET_PRINT: + ioas->debug_enabled = ctx->params->print_enabled; + break; + default: + ret = -ENOSYS; + + } + + if (ioas->ops->debug_address_space) + ret = ioas->ops->debug_address_space(ioas->priv, ctx->sock, + ctx->params); + + return ret; +} + +static int viommu_debug_iommu(struct viommu_dev *viommu, + struct viommu_debug_context *ctx) +{ + struct viommu_ioas *ioas; + + if (ctx->disp) + dprintf(ctx->sock, "iommu %u \"%s\"\n", viommu->id, + viommu->properties->name); + + if (ctx->params->selector[1] != IOMMU_DEBUG_SELECTOR_INVALID) { + ioas = viommu_find_ioas(viommu, ctx->params->selector[1]); + return ioas ? viommu_debug_ioas(viommu, ioas, ctx) : -ESRCH; + } + + switch (ctx->params->action) { + case IOMMU_DEBUG_STATS: + dprintf(ctx->sock, " kicks %llu\n", + viommu->stats.kicks); + dprintf(ctx->sock, " requests %llu\n", + viommu->stats.requests); + break; + case IOMMU_DEBUG_SET_PRINT: + viommu->debug_enabled = ctx->params->print_enabled; + break; + default: + break; + } + + return viommu_for_each_ioas(viommu, viommu_debug_ioas, ctx); } int viommu_debug(int sock, struct iommu_debug_params *params) { - return -ENOSYS; + int ret = -ESRCH; + bool match; + struct viommu_dev *viommu; + bool any = (params->selector[0] == IOMMU_DEBUG_SELECTOR_INVALID); + + struct viommu_debug_context ctx = { + .sock = sock, + .params = params, + }; + + if (params->action == IOMMU_DEBUG_LIST || + params->action == IOMMU_DEBUG_STATS) + ctx.disp = true; + + mutex_lock(&viommus_mutex); + list_for_each_entry(viommu, &viommus, list) { + match = (params->selector[0] == viommu->id); + if (match || any) { + ret = viommu_debug_iommu(viommu, &ctx); + if (ret || match) + break; + } + } + mutex_unlock(&viommus_mutex); + + if (ret) + dprintf(sock, "error: %s\n", strerror(-ret)); + + return ret; } diff --git a/virtio/mmio.c b/virtio/mmio.c index 699d4403..7d39120a 100644 --- a/virtio/mmio.c +++ b/virtio/mmio.c @@ -307,6 +307,7 @@ static struct iommu_ops virtio_mmio_iommu_ops = { .get_properties = virtio__iommu_get_properties, .alloc_address_space = iommu_alloc_address_space, .free_address_space = iommu_free_address_space, + .debug_address_space = iommu_debug_address_space, .attach = virtio_mmio_iommu_attach, .detach = virtio_mmio_iommu_detach, .map = iommu_map, diff --git a/virtio/pci.c b/virtio/pci.c index c9f0e558..c5d30eb2 100644 --- a/virtio/pci.c +++ b/virtio/pci.c @@ -442,6 +442,7 @@ static struct iommu_ops virtio_pci_iommu_ops = { .get_properties = virtio__iommu_get_properties, .alloc_address_space = iommu_alloc_address_space, .free_address_space = iommu_free_address_space, + .debug_address_space = iommu_debug_address_space, .attach = virtio_pci_iommu_attach, .detach = virtio_pci_iommu_detach, .map = iommu_map, -- 2.12.1