Convert server and uring to debugging

1 files changed, 85 insertions, 64 deletions

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");