Convert server and uring to debugging

5 files changed, 182 insertions, 98 deletions

diff --git a/config.c b/config.c
index 86723fe..4ccd3c3 100644
--- a/config.c
+++ b/config.c
@@ -234,10 +234,10 @@ success:
 		return false;
 	} else {
 		int i = 0;
-		struct list_head *pos;
 
-		list_for_each(pos, list)
+		list_for_each_entry(addr, list, list)
 			i++;
+
 		fprintf(stderr, "Success, %i entries\n", i);
 	}
 
diff --git a/main.c b/main.c
index e47848c..ad99684 100644
--- a/main.c
+++ b/main.c
@@ -98,6 +98,12 @@ const struct {
 		.name = "signals",
 		.val = DBG_SIG
 	},{
+		.name = "uring",
+		.val = DBG_UR
+	},{
+		.name = "server",
+		.val = DBG_SRV
+	},{
 		.name = NULL,
 		.val = 0
 	}
@@ -245,7 +251,7 @@ signalfd_read(struct cfg *cfg, struct uring_task *task, int res)
 		sd_notifyf(0, "STOPPING=1\nSTATUS=Received signal, exiting");
 		exit(EXIT_SUCCESS);
 	} else {
-		info(stderr, "Got a signal to dump tree\n");
+		info("Got a signal to dump tree\n");
 		sd_notifyf(0, "STOPPING=1\nSTATUS=Received signal, exiting");
 		dump_tree(cfg);
 		uring_task_put(cfg, &sev->task);
@@ -382,7 +388,7 @@ main(int argc, char **argv)
 		   server_count,
 		   (unsigned long)getpid());
 
-	info(stderr, "%s: started, %u server configurations loaded\n",
+	info("%s: started, %u server configurations loaded\n",
 	     argv[0], server_count);
 
 	uring_event_loop(cfg);
diff --git a/main.h b/main.h
index 5d34042..4d73f2b 100644
--- a/main.h
+++ b/main.h
@@ -21,6 +21,8 @@ enum debug_category {
 	DBG_MALLOC	= (0x1 << 6),
 	DBG_ANN		= (0x1 << 7),
 	DBG_SIG		= (0x1 << 7),
+	DBG_UR		= (0x1 << 8),
+	DBG_SRV		= (0x1 << 9),
 };
 
 static inline bool
diff --git a/server.c b/server.c
index 377945f..f6b59b1 100644
--- a/server.c
+++ b/server.c
@@ -39,7 +39,7 @@ set_property(struct cfg *cfg, struct server *scfg, char **property, const char *
 
 	*property = xstrdup(value);
 	if (!*property) {
-		perror("strdup");
+		error("strdup: %m");
 		return false;
 	}
 
@@ -66,7 +66,7 @@ server_free(struct uring_task *task)
 {
 	struct server *scfg = container_of(task, struct server, task);
 
-	fprintf(stderr, "Freeing scfg %s\n", scfg->name);
+	debug(DBG_SRV, "freeing server %s (%p)\n", scfg->name, scfg);
 	list_del(&scfg->list);
 	xfree(scfg->pretty_name);
 	xfree(scfg->start_exec);
@@ -86,7 +86,7 @@ server_delete(struct cfg *cfg, struct server *scfg)
 	struct sockaddr_in46 *remote, *rtmp;
 	struct sockaddr_in46 *rcon, *rctmp;
 
-	fprintf(stderr, "Removing server cfg: %s\n", scfg->name);
+	verbose("Removing server %s\n", scfg->name);
 
 	idle_delete(cfg, scfg);
 	rcon_delete(cfg, scfg);
@@ -136,30 +136,40 @@ server_dump(struct server *scfg)
 	struct sockaddr_in46 *rcon;
 	char abuf[ADDRSTRLEN];
 
-	fprintf(stderr, "\nDumping server %s\n", scfg->name);
+	verbose("Server %s:\n", scfg->name);
 	switch (scfg->type) {
 	case SERVER_TYPE_ANNOUNCE:
-		fprintf(stderr, "  * Type: announce\n");
+		verbose("  * Type: announce\n");
 		break;
 	case SERVER_TYPE_PROXY:
-		fprintf(stderr, "  * Type: proxy\n");
+		verbose("  * Type: proxy\n");
 		break;
 	default:
-		fprintf(stderr, "  * Type: unknown\n");
+		verbose("  * Type: unknown\n");
 		break;
 	}
-	fprintf(stderr, "  * Pretty name: %s\n", scfg->pretty_name ? scfg->pretty_name : "<undefined>");
-	fprintf(stderr, "  * Announce port: %" PRIu16 "\n", scfg->announce_port); 
-	fprintf(stderr, "  * Listening:\n");
-	list_for_each_entry(local, &scfg->locals, list)
-		fprintf(stderr, "    * %s\n", local->addrstr);
-	fprintf(stderr, "  * Remote:\n");
-	list_for_each_entry(remote, &scfg->remotes, list)
-		fprintf(stderr, "    * %s\n", sockaddr_to_str(remote, abuf, sizeof(abuf)));
-	fprintf(stderr, "  * RCon:\n");
-	list_for_each_entry(rcon, &scfg->rcons, list)
-		fprintf(stderr, "    * %s\n", sockaddr_to_str(rcon, abuf, sizeof(abuf)));
-	fprintf(stderr, "\n");
+	verbose("  * Name: %s\n", scfg->pretty_name ? scfg->pretty_name : "<undefined>");
+	verbose("  * Announce port: %" PRIu16 "\n", scfg->announce_port); 
+
+	if (!list_empty(&scfg->locals)) {
+		verbose("  * Listening:\n");
+		list_for_each_entry(local, &scfg->locals, list)
+			verbose("    * %s\n", local->addrstr);
+	}
+
+	if (!list_empty(&scfg->remotes)) {
+		verbose("  * Remote:\n");
+		list_for_each_entry(remote, &scfg->remotes, list)
+			verbose("    * %s\n", sockaddr_to_str(remote, abuf, sizeof(abuf)));
+	}
+
+	if (!list_empty(&scfg->rcons)) {
+		verbose("  * RCon:\n");
+		list_for_each_entry(rcon, &scfg->rcons, list)
+			verbose("    * %s\n", sockaddr_to_str(rcon, abuf, sizeof(abuf)));
+	}
+
+	verbose("\n");
 }
 
 static void
@@ -167,8 +177,7 @@ server_local_free(struct uring_task *task)
 {
 	struct server_local *local = container_of(task, struct server_local, task);
 
-	fprintf(stderr, "%s called: task 0x%p\n", __func__, task);
-
+	debug(DBG_SRV, "task %p, local %p\n", task, local);
 	list_del(&local->list);
 	xfree(local);
 }
@@ -183,16 +192,15 @@ server_local_accept(struct cfg *cfg, struct uring_task *task, int res)
 	struct sockaddr_in46 laddr = { .addrlen = sizeof(laddr) } ;
 	char lbuf[ADDRSTRLEN];
 
-	fprintf(stderr, "%s called: task 0x%p and res %i\n", __func__, task, res);
-	fprintf(stderr, "%s called: scfg name is %s\n", __func__, scfg->name);
+	debug(DBG_SRV, "task %p, res %i, scfg %s\n", task, res, scfg->name);
 
 	if (task->dead) {
-		fprintf(stderr, "Task dead!\n");
+		debug(DBG_SRV, "task dead\n");
 		return;
 	}
 
 	if (res < 0) {
-		fprintf(stderr, "%s: result was %i\n", __func__, res);
+		error("result was %i\n", res);
 		goto out;
 	}
 
@@ -203,7 +211,7 @@ server_local_accept(struct cfg *cfg, struct uring_task *task, int res)
 
 	sockaddr_to_str(&local->peer, pbuf, sizeof(pbuf));
 
-	fprintf(stderr, "%s: incoming proxy connection: %s -> %s (%s)\n",
+	verbose("%s: incoming proxy connection: %s -> %s (%s)\n",
 		scfg->name, pbuf, lbuf, local->addrstr);
 
 	if (list_empty(&scfg->remotes)) {
@@ -230,13 +238,13 @@ server_local_open(struct cfg *cfg, struct server *scfg, struct server_local *loc
 
 	sfd = socket(local->addr.storage.ss_family, SOCK_STREAM | SOCK_CLOEXEC, 0);
 	if (sfd < 0) {
-		perror("socket");
+		error("socket: %m");
 		goto out;
 	}
 
 	option = true;
 	if (setsockopt(sfd, SOL_SOCKET, SO_REUSEADDR, &option, sizeof(option)) < 0) {
-		perror("setsockopt");
+		error("setsockopt: %m");
 		goto out;
 	}
 
@@ -244,30 +252,29 @@ server_local_open(struct cfg *cfg, struct server *scfg, struct server_local *loc
 	/* FIXME: could make this configurable */
 	option = true;
 	if (setsockopt(sfd, IPPROTO_TCP, TCP_DEFER_ACCEPT, &option, sizeof(option)) < 0)
-		perror("setsockopt");
+		error("setsockopt: %m");
 
 	/* FIXME: could make this configurable */
 	option = true;
 	if (setsockopt(sfd, IPPROTO_IP, IP_FREEBIND, &option, sizeof(option)) < 0)
-		perror("setsockopt");
+		error("setsockopt: %m");
 
 	socket_set_low_latency(cfg, sfd);
 
 	r = bind(sfd, (struct sockaddr *)&local->addr.storage, local->addr.addrlen);
 	if (r < 0) {
-		perror("bind");
+		error("bind: %m");
 		goto out;
 	}
 
 	r = listen(sfd, 100);
 	if (r < 0) {
-		perror("listen");
+		error("listen: %m");
 		goto out;
 	}
 
 	uring_task_set_fd(&local->task, sfd);
 	uring_accept(cfg, &local->task, &local->peer, server_local_accept);
-	fprintf(stderr, "** Opened listening socket: %s\n", local->addrstr);
 	return true;
 
 out:
@@ -281,7 +288,7 @@ server_exec_free(struct uring_task *task)
 {
 	//struct server *scfg = container_of(task, struct server, exec_task);
 
-	fprintf(stderr, "%s called\n", __func__);
+	debug(DBG_SRV, "called\n");
 }
 
 #ifndef P_PIDFD
@@ -297,21 +304,25 @@ server_exec_done(struct cfg *cfg, struct uring_task *task, int res)
 
 	if (task->dead) {
 		/* Should we leave child processes running? */
+		debug(DBG_SRV, "task dead\n");
 		goto out;
 	}
 
 	if (!(res & POLLIN)) {
-		fprintf(stderr, "%s: unexpected result: %i\n", __func__, res);
+		error("unexpected result: %i\n", res);
 		goto out;
 	}
 
 	r = waitid(P_PIDFD, scfg->exec_task.fd, &info, WEXITED);
         if (r < 0) {
-                perror("waitid");
+                error("waitid: %m");
 		goto out;
         }
 
-	fprintf(stderr, "Command executed, return value: %i\n", info.si_status);
+	if (info.si_status == 0)
+		debug(DBG_SRV, "command successfully executed\n");
+	else
+		error("command failed: %i\n", info.si_status);
 out:
 	uring_task_close_fd(cfg, &scfg->exec_task);
 }
@@ -346,7 +357,7 @@ server_exec(struct cfg *cfg, struct server *scfg, const char *cmd)
                   CLONE_VM | CLONE_VFORK | CLONE_PIDFD | SIGCHLD,
                   (void *)cmd, &pidfd);
 	if (r < 0) {
-		perror("clone");
+		error("clone: %m");
 		return false;
 	}
 
@@ -364,9 +375,12 @@ server_start(struct cfg *cfg, struct server *scfg)
 	switch (scfg->start_method) {
 
 	case SERVER_START_METHOD_EXEC:
+		verbose("Starting server %s via external cmd\n", scfg->name);
 		return server_exec(cfg, scfg, scfg->start_exec);
 
 	case SERVER_START_METHOD_SYSTEMD:
+		verbose("Starting server %s via systemd (%s)\n",
+			scfg->name, scfg->systemd_service);
 		return systemd_service_start(cfg, scfg);
 
 	case SERVER_START_METHOD_UNDEFINED:
@@ -386,12 +400,16 @@ server_stop(struct cfg *cfg, struct server *scfg)
 	switch (scfg->stop_method) {
 
 	case SERVER_STOP_METHOD_EXEC:
+		verbose("Stopping server %s via external cmd\n", scfg->name);
 		return server_exec(cfg, scfg, scfg->stop_exec);
 
 	case SERVER_STOP_METHOD_SYSTEMD:
+		verbose("Stopping server %s via systemd (%s)\n",
+			scfg->name, scfg->systemd_service);
 		return systemd_service_stop(cfg, scfg);
 
 	case SERVER_STOP_METHOD_RCON:
+		verbose("Stopping server %s via rcon\n", scfg->name);
 		rcon_init(cfg, scfg);
 		return true;
 
@@ -410,12 +428,12 @@ server_commit(struct cfg *cfg, struct server *scfg)
 	uint16_t port;
 
 	if (!scfg || !scfg->name) {
-		fprintf(stderr, "%s: called with invalid parameters\n", __func__);
+		error("called with invalid parameters\n");
 		return false;
 	}
 
 	if (!list_empty(&scfg->proxys)) {
-		fprintf(stderr, "%s(%s): proxys not empty?\n", __func__, scfg->name);
+		error("%s: proxys not empty?\n", scfg->name);
 		return false;
 	}
 
@@ -423,14 +441,14 @@ server_commit(struct cfg *cfg, struct server *scfg)
 
 	if (scfg->stop_method == SERVER_STOP_METHOD_RCON &&
 	    (list_empty(&scfg->rcons) || !scfg->rcon_password)) {
-		fprintf(stderr, "%s(%s): rcon stop method but missing rcon password\n", __func__, scfg->name); 
+		error("%s: rcon stop method but missing rcon password\n", scfg->name); 
 		return false;
 	}
 
 	if ((scfg->start_method == SERVER_START_METHOD_SYSTEMD ||
 	     scfg->stop_method == SERVER_STOP_METHOD_SYSTEMD) &&
 	    !scfg->systemd_service) {
-		fprintf(stderr, "%s(%s): systemd start/stop method but missing systemd service\n", __func__, scfg->name); 
+		error("%s: systemd start/stop method but missing systemd service\n", scfg->name); 
 		return false;
 	}
 
@@ -438,36 +456,36 @@ server_commit(struct cfg *cfg, struct server *scfg)
 		scfg->systemd_obj = systemd_service_object_path(cfg,
 								scfg->systemd_service);
 		if (!scfg->systemd_obj) {
-			fprintf(stderr, "%s(%s): failed to create systemd object path (%s)\n", __func__, scfg->name, scfg->systemd_service);
+			error("%s: failed to create systemd object path (%s)\n", scfg->name, scfg->systemd_service);
 			return false;
 		}
 	}
 
 	if (scfg->idle_timeout > 0 &&
 	    scfg->stop_method == SERVER_STOP_METHOD_UNDEFINED) {
-		fprintf(stderr, "%s(%s): idle_timeout set but missing stop method\n", __func__, scfg->name); 
+		error("%s: idle_timeout set but missing stop method\n", scfg->name); 
 		return false;
 	}
 
 	switch (scfg->type) {
 	case SERVER_TYPE_ANNOUNCE:
 		if (scfg->announce_port < 1) {
-			fprintf(stderr, "%s(%s): missing announce port\n", __func__, scfg->name); 
+			error("%s: missing announce port\n", scfg->name); 
 			return false;
 		}
 
 		if (scfg->start_method != SERVER_START_METHOD_UNDEFINED) {
-			fprintf(stderr, "%s(%s): can't set start_method for announce server\n", __func__, scfg->name);
+			error("%s: can't set start_method for announce server\n", scfg->name);
 			return false;
 		}
 
 		if (!list_empty(&scfg->locals)) {
-			fprintf(stderr, "%s(%s): can't set local addresses for announce server\n", __func__, scfg->name);
+			error("%s: can't set local addresses for announce server\n", scfg->name);
 			return false;
 		}
 
 		if (!list_empty(&scfg->remotes)) {
-			fprintf(stderr, "%s(%s): can't set remote addresses for announce server\n", __func__, scfg->name);
+			error("%s: can't set remote addresses for announce server\n", scfg->name);
 			return false;
 		}
 
@@ -475,17 +493,17 @@ server_commit(struct cfg *cfg, struct server *scfg)
 
 	case SERVER_TYPE_PROXY:
 		if (scfg->announce_port >= 1) {
-			fprintf(stderr, "%s(%s): can't set announce port for proxy server\n", __func__, scfg->name); 
+			error("%s: can't set announce port for proxy server\n", scfg->name); 
 			return false;
 		}
 
 		if (list_empty(&scfg->locals)) {
-			fprintf(stderr, "%s(%s): missing local addresses for proxy server\n", __func__, scfg->name);
+			error("%s: missing local addresses for proxy server\n", scfg->name);
 			return false;
 		}
 
 		if (list_empty(&scfg->remotes)) {
-			fprintf(stderr, "%s(%s): missing remote addresses for proxy server\n", __func__, scfg->name);
+			error("%s: missing remote addresses for proxy server\n", scfg->name);
 			return false;
 		}
 
@@ -493,7 +511,7 @@ server_commit(struct cfg *cfg, struct server *scfg)
 			port = sockaddr_port(&local->addr);
 
 			if (port == 0) {
-				fprintf(stderr, "%s(%s): invalid local port\n", __func__, scfg->name);
+				error("%s: invalid local port\n", scfg->name);
 				return false;
 			}
 
@@ -501,20 +519,20 @@ server_commit(struct cfg *cfg, struct server *scfg)
 				scfg->announce_port = port;
 
 			if (scfg->announce_port != port) {
-				fprintf(stderr, "%s(%s): multiple local ports\n", __func__, scfg->name);
+				error("%s: multiple local ports\n", scfg->name);
 				return false;
 			}
 		}
 
 		if (scfg->announce_port < 1) {
-			fprintf(stderr, "%s(%s): can't determine which port to announce\n", __func__, scfg->name);
+			error("%s: can't determine which port to announce\n", scfg->name);
 			return false;
 		}
 
 		break;
 
 	default:
-		fprintf(stderr, "%s(%s): can't determine server type\n", __func__, scfg->name);
+		error("%s: can't determine server type\n", scfg->name);
 		return false;
 	}
 
@@ -523,13 +541,13 @@ server_commit(struct cfg *cfg, struct server *scfg)
 		
 		suffix = strrchr(scfg->name, '.');
 		if (!suffix || suffix == scfg->name) {
-			fprintf(stderr, "%s(%s): invalid server name\n", __func__, scfg->name);
+			error("%s: invalid server name\n", scfg->name);
 			return false;
 		}
 
 		scfg->pretty_name = xstrndup(scfg->name, suffix - scfg->name);
 		if (!scfg->pretty_name) {
-			fprintf(stderr, "%s(%s): failed to create display name\n", __func__, scfg->name);
+			error("%s: failed to create display name\n", scfg->name);
 			return false;
 		}
 	}
@@ -544,7 +562,7 @@ server_commit(struct cfg *cfg, struct server *scfg)
 	idle_init(cfg, scfg);
 
 	if (scfg->systemd_service) {
-		fprintf(stderr, "Checking if systemd service is running\n");
+		verbose("%s: checking if systemd service is running\n", scfg->name);
 		systemd_service_running(cfg, scfg);
 	}
 
@@ -566,18 +584,21 @@ server_add_local(struct cfg *cfg, struct server *scfg, struct sockaddr_in46 *add
 {
 	struct server_local *local;
 
-	if (!scfg || !addr)
+	if (!scfg || !addr) {
+		error("missing arguments\n");
 		return false;
+	}
 
 	local = zmalloc(sizeof(*local));
-	if (!local)
+	if (!local) {
+		error("malloc: %m");
 		return false;
+	}
 
 	local->addr.storage = addr->storage;
 	local->addr.addrlen = addr->addrlen;
 	uring_task_init(&local->task, "local", &scfg->task, server_local_free);
 	sockaddr_to_str(&local->addr, local->addrstr, sizeof(local->addrstr));
-	fprintf(stderr, "Adding local: %s\n", local->addrstr);
 	list_add(&local->list, &scfg->locals);
 	xfree(addr);
 	return true;
@@ -620,7 +641,7 @@ server_set_systemd_service(struct cfg *cfg, struct server *scfg,
 		tmp = xstrdup(service);
 
 	if (!tmp) {
-		perror("malloc/strdup");
+		error("malloc/strdup: %m");
 		return false;
 	}
 
@@ -718,11 +739,11 @@ server_new(struct cfg *cfg, const char *name)
 	list_for_each_entry(scfg, &cfg->servers, list) {
 		if (strcmp(name, scfg->name))
 			continue;
-		fprintf(stderr, "Server already exists: %s\n", name);
+		error("attempt to add duplicate server: %s\n", name);
 		return scfg;
 	}
 
-	fprintf(stderr, "Would add server cfg: %s\n", name);
+	verbose("Adding server %s\n", name);
 	scfg = zmalloc(sizeof(*scfg));
 	if (!scfg) {
 		error("malloc");
diff --git a/uring.c b/uring.c
index 37b65eb..dc095c8 100644
--- a/uring.c
+++ b/uring.c
@@ -88,11 +88,11 @@ uring_task_refdump(struct uring_task *task)
 void
 uring_task_destroy(struct cfg *cfg, struct uring_task *task)
 {
-	fprintf(stderr, "%s: called (task: %s (%p), fd: %i, refcount: %u)\n",
-		__func__, task->name, task, task->fd, task->refcount);
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
 
 	if (!task) {
-		error("%s: called with no task\n", __func__);
+		error("called with no task\n");
 		return;
 	}
 
@@ -156,6 +156,9 @@ uring_task_get(struct cfg *cfg, struct uring_task *task)
 void
 uring_task_set_buf(struct uring_task *task, struct uring_task_buf *tbuf)
 {
+	debug(DBG_UR, "task %s (%p), buf %p, refcount %u\n",
+	      task->name, task, tbuf, task->refcount);
+
 	if (tbuf) {
 		/* iov_len and msg_namelen are set at send/receive time */
 		tbuf->iov.iov_base = tbuf->buf;
@@ -172,16 +175,17 @@ uring_task_set_buf(struct uring_task *task, struct uring_task_buf *tbuf)
 void
 uring_task_set_fd(struct uring_task *task, int fd)
 {
-	fprintf(stderr, "%s: task %s (%p) now uses fd %i\n",
-		__func__, task->name, task, fd);
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, fd, task->refcount);
+
 	task->fd = fd;
 }
 
 void
 uring_task_close_fd(struct cfg *cfg, struct uring_task *task)
 {
-	fprintf(stderr, "%s: called with task %s (0x%p)\n",
-		__func__, task->name, task);
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
 
 	if (task->fd < 0)
 		return;
@@ -225,8 +229,10 @@ uring_task_init(struct uring_task *task, const char *name,
 	task->tbuf = NULL;
 
 	if (task->parent) {
-		fprintf(stderr, "%s: task %s (%p) getting parent %s (%p)\n",
-			__func__, task->name, task, task->parent->name, task->parent);
+		debug(DBG_REF, "task %s (%p), refcount %u, "
+		      "getting parent %s (%p), refcount %u\n",
+		      task->name, task, task->refcount,
+		      task->parent->name, task->parent, task->parent->refcount);
 		uring_task_get(NULL, task->parent);
 	}
 }
@@ -236,10 +242,11 @@ uring_close(struct cfg *cfg, struct uring_task *task, int fd)
 {
 	struct io_uring_sqe *sqe;
 
-	fprintf(stderr, "%s: called (task: %p (%s), fd: %i)\n", __func__, task, task->name, fd);
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
 
 	if (!task || fd < 0) {
-		error("%s: invalid parameters (task: %p (%s), fd: %i)\n", __func__, task, task->name, fd);
+		error("invalid parameters (task: %p (%s), fd: %i)\n", task, task->name, fd);
 		return;
 	}
 
@@ -256,6 +263,9 @@ uring_tbuf_write_cb(struct cfg *cfg, struct uring_task *task, int res)
 	if (!task || !task->tbuf || !task->final_callback)
 		die("missing parameters");
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	if (res < 0) {
 		r = res;
 		goto finished;
@@ -282,10 +292,13 @@ void
 uring_tbuf_write(struct cfg *cfg, struct uring_task *task, callback_t callback)
 {
 	if (!task || task->fd < 0 || !task->tbuf || task->tbuf->len < 0) {
-		error("%s invalid parameters\n", __func__);
+		error("invalid parameters\n");
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	task->tbuf->done = 0;
 	task->final_callback = callback;
 	uring_write(cfg, task, &task->tbuf->buf, task->tbuf->len, uring_tbuf_write_cb);
@@ -297,10 +310,13 @@ uring_write(struct cfg *cfg, struct uring_task *task, void *buf, size_t len, cal
 	struct io_uring_sqe *sqe;
 
 	if (task->fd < 0) {
-		error("uring_write called with no fd set\n");
+		error("no fd set\n");
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
        	sqe = get_sqe(cfg, task);
 	task->callback = callback;
 	io_uring_prep_write(sqe, task->fd, buf, len, 0);
@@ -313,10 +329,13 @@ uring_tbuf_read_until_cb(struct cfg *cfg, struct uring_task *task, int res)
 	int r;
 
 	if (!task || !task->tbuf || !task->final_callback || !task->complete_callback) {
-		error("%s: invalid parameters\n", __func__);
+		error("invalid parameters\n");
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	if (res < 0) {
 		r = res;
 		goto finished;
@@ -357,6 +376,9 @@ uring_tbuf_read_until(struct cfg *cfg, struct uring_task *task,
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	task->tbuf->len = 0;
 	task->complete_callback = complete;
 	task->final_callback = callback;
@@ -408,6 +430,9 @@ uring_read_offset(struct cfg *cfg, struct uring_task *task, void *buf, size_t le
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	sqe = get_sqe(cfg, task);
 	task->callback = callback;
 	io_uring_prep_read(sqe, task->fd, buf, len, offset);
@@ -419,6 +444,9 @@ uring_openat(struct cfg *cfg, struct uring_task *task, const char *path, callbac
 {
 	struct io_uring_sqe *sqe;
        
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	sqe = get_sqe(cfg, task);
 	task->callback = callback;
 	io_uring_prep_openat(sqe, AT_FDCWD, path, O_RDONLY | O_CLOEXEC, 0);
@@ -431,10 +459,13 @@ uring_tbuf_recvmsg(struct cfg *cfg, struct uring_task *task, callback_t callback
 	struct io_uring_sqe *sqe;
 
 	if (!task->tbuf) {
-		error("%s: called with no tbuf set\n", __func__);
+		error("called with no tbuf set\n");
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	sqe = get_sqe(cfg, task);
 	task->tbuf->done = 0;
 	task->tbuf->len = 0;
@@ -455,6 +486,9 @@ uring_tbuf_sendmsg(struct cfg *cfg, struct uring_task *task, callback_t callback
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	sqe = get_sqe(cfg, task);
 	task->tbuf->done = 0;
 	task->tbuf->iov.iov_len = task->tbuf->len;
@@ -470,10 +504,13 @@ uring_connect(struct cfg *cfg, struct uring_task *task, struct sockaddr_in46 *ad
 	struct io_uring_sqe *sqe;
 
 	if (task->fd < 0) {
-		error("uring_connect called with no fd set\n");
+		error("fd set\n");
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	sqe = get_sqe(cfg, task);
 	task->callback = callback;
 	io_uring_prep_connect(sqe, task->fd, (struct sockaddr *)&addr->storage, addr->addrlen);
@@ -486,10 +523,13 @@ uring_accept(struct cfg *cfg, struct uring_task *task, struct sockaddr_in46 *add
 	struct io_uring_sqe *sqe;
 
 	if (task->fd < 0) {
-		error("uring_accept called with no fd set\n");
+		error("no fd set\n");
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	sqe = get_sqe(cfg, task);
 	addr->addrlen = sizeof(addr->storage);
 	task->callback = callback;
@@ -507,6 +547,9 @@ uring_poll(struct cfg *cfg, struct uring_task *task, short poll_mask, callback_t
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	sqe = get_sqe(cfg, task);
 	task->callback = callback;
 	io_uring_prep_poll_add(sqe, task->fd, poll_mask);
@@ -523,6 +566,9 @@ uring_poll_cancel(struct cfg *cfg, struct uring_task *task)
 		return;
 	}
 
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
 	sqe = get_sqe(cfg, task);
 	task->dead = true;
 	io_uring_prep_poll_remove(sqe, task);
@@ -534,7 +580,8 @@ uring_free(struct uring_task *task)
 {
 	struct uring_ev *uev = container_of(task, struct uring_ev, task);
 
-	fprintf(stderr, "%s: called\n", __func__);
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
 
 	io_uring_queue_exit(&uev->uring);
 	uev->cfg->uev = NULL;
@@ -550,7 +597,12 @@ uring_refdump(struct uring_ev *uev)
 void
 uring_delete(struct cfg *cfg)
 {
-	uring_task_put(cfg, &cfg->uev->task);
+	struct uring_task *task = &cfg->uev->task;
+
+	debug(DBG_UR, "task %s (%p), fd %i, refcount %u\n",
+	      task->name, task, task->fd, task->refcount);
+
+	uring_task_put(cfg, task);
 }
 
 void
@@ -565,7 +617,7 @@ uring_init(struct cfg *cfg)
 	if (io_uring_queue_init_params(4096, &uev->uring, &uev->uring_params) < 0)
 		perrordie("io_uring_queue_init_params");
 
-	fprintf(stderr, "uring initialized, features: 0x%08x\n", uev->uring_params.features);
+	verbose("uring initialized, features: 0x%08x\n", uev->uring_params.features);
 
 	uring_task_init(&uev->task, "uev", &cfg->task, uring_free);
 	cfg->uev = uev;
@@ -576,15 +628,18 @@ static inline void
 uring_print_cqe(struct cfg *cfg, const char *type, struct uring_task *task,
 		struct io_uring_cqe *cqe)
 {
-	fprintf(stderr, "uring_event_loop: got %s CQE "
-		"(res: %i (%s), task: %s (%p), fd: %i, cb: %p)\n",
-		type,
-		cqe->res,
-		cqe->res < 0 ? strerror(-cqe->res) : "ok",
-		task->name ? task->name : "<none>",
-		task,
-		task->fd,
-		task->callback);
+	if (!debug_enabled(DBG_UR))
+		return;
+
+	error("got CQE "
+	      "(type: %s, res: %i (%s), task: %s (%p), fd: %i, cb: %p)\n",
+	      type,
+	      cqe->res,
+	      cqe->res < 0 ? strerror(-cqe->res) : "ok",
+	      task->name ? task->name : "<none>",
+	      task,
+	      task->fd,
+	      task->callback);
 }
 
 void
@@ -616,7 +671,7 @@ uring_event_loop(struct cfg *cfg)
 			task = (void *)((uintptr_t)task & ~CQE_TYPE_PTR_MASK);
 
 			if (!task)
-				die("%s: null task\n", __func__);
+				die("null task");
 
 			switch (cqe_type) {
 			case CQE_TYPE_CANCEL: