log: add function name, line number prefix

Add "function-name:line-number" prefix and a new-line suffix for
all messages. Use do-while(0) to define the metal_log macro. Add
convenience macros ML_ERR, ML_WRN, ML_INF, ML_DBG to avoid using
excessively long and redundant "metal_log(METAL_LOG_*".

Signed-off-by: Sergei Korneichuk <sergei.korneichuk@amd.com>

lib/device.c

@@ -23,7 +23,7 @@ int metal_bus_register(struct metal_bus *bus)
 		return -EEXIST;
 	metal_list_init(&bus->devices);
 	metal_list_add_tail(&_metal.common.bus_list, &bus->node);
-	metal_log(METAL_LOG_DEBUG, "registered %s bus\n", bus->name);
+	ML_DBG("registered %s bus", bus->name);
 	return 0;
 }
 
@@ -32,7 +32,7 @@ int metal_bus_unregister(struct metal_bus *bus)
 	metal_list_del(&bus->node);
 	if (bus->ops.bus_close)
 		bus->ops.bus_close(bus);
-	metal_log(METAL_LOG_DEBUG, "unregistered %s bus\n", bus->name);
+	ML_DBG("unregistered %s bus", bus->name);
 	return 0;
 }
 

lib/log.h

@@ -77,10 +77,17 @@ extern void metal_default_log_handler(enum metal_log_level level,
  * @param	level	Log level.
  * @param	...	Format string and arguments.
  */
-#define metal_log(level, ...)						       \
-	((level <= _metal.common.log_level && _metal.common.log_handler) \
-	       ? (void)_metal.common.log_handler(level, __VA_ARGS__)	       \
-	       : (void)0)
+#define metal_log(level, fmt, args ...)					\
+do {									\
+	if (_metal.common.log_handler && level <= _metal.common.log_level) \
+		_metal.common.log_handler(level, "%s:%u " fmt "\n",	\
+					  __func__, __LINE__, ##args);	\
+} while (0)
+
+#define ML_ERR(fmt, args ...) metal_log(METAL_LOG_ERROR, fmt, ##args)
+#define ML_WRN(fmt, args ...) metal_log(METAL_LOG_WARNING, fmt, ##args)
+#define ML_INF(fmt, args ...) metal_log(METAL_LOG_INFO, fmt, ##args)
+#define ML_DBG(fmt, args ...) metal_log(METAL_LOG_DEBUG, fmt, ##args)
 
 /** @} */
 

lib/softirq.c

@@ -72,8 +72,7 @@ int metal_softirq_allocate(int num)
 	int irq_base;
 
 	if ((metal_softirq_avail + num) >= metal_softirq_num) {
-		metal_log(METAL_LOG_ERROR, "No %d available soft irqs.\r\n",
-			  num);
+		ML_ERR("No %d available soft irqs.\r", num);
 		return -EINVAL;
 	}
 	irq_base = metal_softirq_avail;

lib/system/freertos/xlnx_common/irq.c

@@ -27,8 +27,7 @@ static void metal_xlnx_irq_set_enable(struct metal_irq_controller *irq_cntr,
 {
 	if (irq < irq_cntr->irq_base ||
 	    irq >= irq_cntr->irq_base + irq_cntr->irq_num) {
-		metal_log(METAL_LOG_ERROR, "%s: invalid irq %d\n",
-			  __func__, irq);
+		ML_ERR("invalid irq %d", irq);
 		return;
 	} else if (state == METAL_IRQ_ENABLE) {
 		sys_irq_enable((unsigned int)irq);
@@ -62,10 +61,9 @@ int metal_xlnx_irq_init(void)
 {
 	int ret;
 
-	ret =  metal_irq_register_controller(&xlnx_irq_cntr);
+	ret = metal_irq_register_controller(&xlnx_irq_cntr);
 	if (ret < 0) {
-		metal_log(METAL_LOG_ERROR, "%s: register irq controller failed.\n",
-			  __func__);
+		ML_ERR("register irq controller failed.");
 		return ret;
 	}
 	return 0;

lib/system/generic/xlnx_common/irq.c

@@ -27,8 +27,7 @@ static void metal_xlnx_irq_set_enable(struct metal_irq_controller *irq_cntr,
 {
 	if (irq < irq_cntr->irq_base ||
 	    irq >= irq_cntr->irq_base + irq_cntr->irq_num) {
-		metal_log(METAL_LOG_ERROR, "%s: invalid irq %d\n",
-			  __func__, irq);
+		ML_ERR("invalid irq %d", irq);
 		return;
 	} else if (state == METAL_IRQ_ENABLE) {
 		sys_irq_enable((unsigned int)irq);
@@ -64,8 +63,7 @@ int metal_xlnx_irq_init(void)
 
 	ret =  metal_irq_register_controller(&xlnx_irq_cntr);
 	if (ret < 0) {
-		metal_log(METAL_LOG_ERROR, "%s: register irq controller failed.\n",
-			  __func__);
+		ML_ERR("register irq controller failed.");
 		return ret;
 	}
 	return 0;

lib/system/linux/device.c

@@ -108,43 +108,40 @@ static int metal_uio_dev_bind(struct linux_device *ldev,
 		return 0;
 
 	if (strcmp(ldev->sdev->driver_name, SYSFS_UNKNOWN) != 0) {
-		metal_log(METAL_LOG_INFO, "device %s in use by driver %s\n",
-			  ldev->dev_name, ldev->sdev->driver_name);
+		ML_INF("device %s in use by driver %s",
+		       ldev->dev_name, ldev->sdev->driver_name);
 		return -EBUSY;
 	}
 
 	attr = sysfs_get_device_attr(ldev->sdev, "driver_override");
 	if (!attr) {
-		metal_log(METAL_LOG_ERROR, "device %s has no override\n",
-			  ldev->dev_name);
+		ML_ERR("device %s has no override", ldev->dev_name);
 		return -errno;
 	}
 
 	result = sysfs_write_attribute(attr, ldrv->drv_name,
 				       strlen(ldrv->drv_name));
 	if (result) {
-		metal_log(METAL_LOG_ERROR, "failed to set override on %s\n",
-			  ldev->dev_name);
+		ML_ERR("failed to set override on %s", ldev->dev_name);
 		return -errno;
 	}
 	ldev->override = attr;
 
 	attr = sysfs_get_driver_attr(ldrv->sdrv, "bind");
 	if (!attr) {
-		metal_log(METAL_LOG_ERROR, "driver %s has no bind\n", ldrv->drv_name);
+		ML_ERR("driver %s has no bind", ldrv->drv_name);
 		return -ENOTSUP;
 	}
 
 	result = sysfs_write_attribute(attr, ldev->dev_name,
 				       strlen(ldev->dev_name));
 	if (result) {
-		metal_log(METAL_LOG_ERROR, "failed to bind %s to %s\n",
-			  ldev->dev_name, ldrv->drv_name);
+		ML_ERR("failed to bind %s to %s",
+		       ldev->dev_name, ldrv->drv_name);
 		return -errno;
 	}
 
-	metal_log(METAL_LOG_DEBUG, "bound device %s to driver %s\n",
-		  ldev->dev_name, ldrv->drv_name);
+	ML_DBG("bound device %s to driver %s", ldev->dev_name, ldrv->drv_name);
 
 	return 0;
 }
@@ -160,18 +157,16 @@ static int metal_uio_dev_open(struct linux_bus *lbus, struct linux_device *ldev)
 	void *virt;
 	int irq_info;
 
-
 	ldev->fd = -1;
 	ldev->device.irq_info = (void *)-1;
 
 	ldev->sdev = sysfs_open_device(lbus->bus_name, ldev->dev_name);
 	if (!ldev->sdev) {
-		metal_log(METAL_LOG_ERROR, "device %s:%s not found\n",
-			  lbus->bus_name, ldev->dev_name);
+		ML_ERR("device %s:%s not found",
+		       lbus->bus_name, ldev->dev_name);
 		return -ENODEV;
 	}
-	metal_log(METAL_LOG_DEBUG, "opened sysfs device %s:%s\n",
-		  lbus->bus_name, ldev->dev_name);
+	ML_DBG("opened sysfs device %s:%s", lbus->bus_name, ldev->dev_name);
 
 	result = metal_uio_dev_bind(ldev, ldrv);
 	if (result)
@@ -182,8 +177,7 @@ static int metal_uio_dev_open(struct linux_bus *lbus, struct linux_device *ldev)
 		return -EOVERFLOW;
 	dlist = sysfs_open_directory_list(path);
 	if (!dlist) {
-		metal_log(METAL_LOG_ERROR, "failed to scan class path %s\n",
-			  path);
+		ML_ERR("failed to scan class path %s", path);
 		return -errno;
 	}
 
@@ -201,8 +195,7 @@ static int metal_uio_dev_open(struct linux_bus *lbus, struct linux_device *ldev)
 	sysfs_close_list(dlist);
 
 	if (sysfs_path_is_dir(ldev->cls_path) != 0) {
-		metal_log(METAL_LOG_ERROR, "invalid device class path %s\n",
-			  ldev->cls_path);
+		ML_ERR("invalid device class path %s", ldev->cls_path);
 		return -ENODEV;
 	}
 
@@ -214,20 +207,19 @@ static int metal_uio_dev_open(struct linux_bus *lbus, struct linux_device *ldev)
 		i++;
 	} while (i < 1000);
 	if (i >= 1000) {
-		metal_log(METAL_LOG_ERROR, "failed to open file %s, timeout.\n",
-			  ldev->dev_path);
+		ML_ERR("failed to open file %s, timeout.", ldev->dev_path);
 		return -ENODEV;
 	}
 	result = metal_open(ldev->dev_path, 0);
 	if (result < 0) {
-		metal_log(METAL_LOG_ERROR, "failed to open device %s\n",
-			  ldev->dev_path, strerror(-result));
+		ML_ERR("failed to open device %s",
+		       ldev->dev_path, strerror(-result));
 		return result;
 	}
 	ldev->fd = result;
 
-	metal_log(METAL_LOG_DEBUG, "opened %s:%s as %s\n",
-		  lbus->bus_name, ldev->dev_name, ldev->dev_path);
+	ML_DBG("opened %s:%s as %s",
+	       lbus->bus_name, ldev->dev_name, ldev->dev_path);
 
 	for (i = 0, result = 0; !result && i < METAL_MAX_DEVICE_REGIONS; i++) {
 		phys = &ldev->region_phys[ldev->device.num_regions];
@@ -248,9 +240,7 @@ static int metal_uio_dev_open(struct linux_bus *lbus, struct linux_device *ldev)
 
 	irq_info = 1;
 	if (write(ldev->fd, &irq_info, sizeof(irq_info)) <= 0) {
-		metal_log(METAL_LOG_INFO,
-			  "%s: No IRQ for device %s.\n",
-			  __func__, ldev->dev_name);
+		ML_INF("No IRQ for device %s.", ldev->dev_name);
 		ldev->device.irq_num =  0;
 		ldev->device.irq_info = (void *)-1;
 	} else {
@@ -297,14 +287,12 @@ static void metal_uio_dev_irq_ack(struct linux_bus *lbus,
 
 	ret = read(ldev->fd, (void *)&val, sizeof(val));
 	if (ret < 0) {
-		metal_log(METAL_LOG_ERROR, "%s, read uio irq fd %d failed: %d.\n",
-						__func__, ldev->fd, ret);
+		ML_ERR("read uio irq fd %d failed: %d.", ldev->fd, ret);
 		return;
 	}
 	ret = write(ldev->fd, &irq_info, sizeof(irq_info));
 	if (ret < 0) {
-		metal_log(METAL_LOG_ERROR, "%s, write uio irq fd %d failed: %d.\n",
-						__func__, ldev->fd, errno);
+		ML_ERR("write uio irq fd %d failed: %d.", ldev->fd, errno);
 	}
 }
 
@@ -336,9 +324,8 @@ static int metal_uio_dev_dma_map(struct linux_bus *lbus,
 			}
 		}
 		if (j == (int)ldev->device.num_regions) {
-			metal_log(METAL_LOG_WARNING,
-			  "%s,%s: input address isn't MMIO addr: 0x%x,%d.\n",
-			__func__, ldev->dev_name, vaddr_sg_lo, sg_in[i].len);
+			ML_WRN("%s: input address isn't MMIO addr: 0x%x,%d.",
+			       ldev->dev_name, vaddr_sg_lo, sg_in[i].len);
 			return -EINVAL;
 		}
 	}
@@ -566,9 +553,7 @@ static int metal_linux_probe_driver(struct linux_bus *lbus,
 			return -EOVERFLOW;
 		ret = system(command);
 		if (ret < 0) {
-			metal_log(METAL_LOG_WARNING,
-				  "%s: executing system command '%s' failed.\n",
-				  __func__, command);
+			ML_WRN("system('%s') failed.", command);
 		}
 		ldrv->sdrv = sysfs_open_driver(lbus->bus_name, ldrv->drv_name);
 	}
@@ -581,9 +566,7 @@ static int metal_linux_probe_driver(struct linux_bus *lbus,
 			return -EOVERFLOW;
 		ret = system(command);
 		if (ret < 0) {
-			metal_log(METAL_LOG_WARNING,
-				  "%s: executing system command '%s' failed.\n",
-				  __func__, command);
+			ML_WRN("system('%s') failed.", command);
 		}
 		ldrv->sdrv = sysfs_open_driver(lbus->bus_name, ldrv->drv_name);
 	}

lib/system/linux/init.c

@@ -34,14 +34,12 @@ static int metal_add_page_size(const char *path, int shift, int mmap_flags)
 	unsigned long size = 1UL << shift;
 
 	if (index >= MAX_PAGE_SIZES) {
-		metal_log(METAL_LOG_WARNING, "skipped page size %ld - overflow\n",
-			  size);
+		ML_WRN("skipped page size %ld - overflow", size);
 		return -EOVERFLOW;
 	}
 
 	if (!path || shift <= 0) {
-		metal_log(METAL_LOG_WARNING, "skipped page size %ld - invalid args\n",
-			  size);
+		ML_WRN("skipped page size %ld - invalid args", size);
 		return -EINVAL;
 	}
 
@@ -51,7 +49,7 @@ static int metal_add_page_size(const char *path, int shift, int mmap_flags)
 	strncpy(_metal.page_sizes[index].path, path, PATH_MAX);
 	_metal.num_page_sizes++;
 
-	metal_log(METAL_LOG_DEBUG, "added page size %ld @%s\n", size, path);
+	ML_DBG("added page size %ld @%s", size, path);
 
 	return 0;
 }
@@ -64,7 +62,7 @@ static int metal_init_page_sizes(void)
 	/* Determine system page size. */
 	sizes[0] = getpagesize();
 	if (sizes[0] <= 0) {
-		metal_log(METAL_LOG_ERROR, "failed to get page size\n");
+		ML_ERR("failed to get page size");
 		return -ENOSYS;
 	}
 	_metal.page_size  = sizes[0];
@@ -118,8 +116,7 @@ int metal_sys_init(const struct metal_init_params *params)
 	/* Determine sysfs mount point. */
 	result = sysfs_get_mnt_path(sysfs_path, sizeof(sysfs_path));
 	if (result) {
-		metal_log(METAL_LOG_ERROR, "failed to get sysfs path (%s)\n",
-			  strerror(-result));
+		ML_ERR("failed to get sysfs path (%s)", strerror(-result));
 		return result;
 	}
 	_metal.sysfs_path = sysfs_path;
@@ -133,12 +130,11 @@ int metal_sys_init(const struct metal_init_params *params)
 	/* Initialize the pseudo-random number generator. */
 	urandom = fopen("/dev/urandom", "r");
 	if (!urandom) {
-		metal_log(METAL_LOG_ERROR, "failed to open /dev/urandom (%s)\n",
-			  strerror(errno));
+		ML_ERR("failed to open /dev/urandom (%s)", strerror(errno));
 		return -errno;
 	}
 	if (fread(&seed, 1, sizeof(seed), urandom) <= 0) {
-		metal_log(METAL_LOG_DEBUG, "Failed fread /dev/urandom\n");
+		ML_DBG("Failed fread /dev/urandom");
 	}
 	fclose(urandom);
 	srand(seed);
@@ -153,8 +149,7 @@ int metal_sys_init(const struct metal_init_params *params)
 
 	result = open("/proc/self/pagemap", O_RDONLY | O_CLOEXEC);
 	if (result < 0) {
-		metal_log(METAL_LOG_DEBUG, "Failed pagemap open - %s\n",
-			  strerror(errno));
+		ML_DBG("Failed pagemap open - %s", strerror(errno));
 	}
 	_metal.pagemap_fd = result;