Avoid additional operations after calling fork()

+Based on https://pubs.opengroup.org/onlinepubs/9699919799/functions/fork.html, the function called by the child process now avoids malloc's and only redirects its output to the corresponding pipes before doing the rsync execution with execvp().
+This fixes #35. Something at the musl implementation (very specific for docker+alpine) hangs the child process right after its creation, the parent process waits for the child to end but it never does, so the container runs for ever and never ends a validation cycle.
+Also, flush stderr/stdout before fork() to avoid a possible (in docker+alpine, almost sure) deadlock between parent process and its forked child.

src/log.c

@@ -140,6 +140,15 @@ log_teardown(void)
 	log_disable_syslog();
 }
 
+void
+log_flush(void)
+{
+	if (op_fprintf_enabled || val_fprintf_enabled) {
+		fflush(stdout);
+		fflush(stderr);
+	}
+}
+
 static struct level const *
 level2struct(int level)
 {

src/log.h

@@ -42,6 +42,8 @@ void log_setup(void);
 void log_start(void);
 void log_teardown(void);
 
+/* Call to flush the stdout/stderr streams */
+void log_flush(void);
 
 /*
  * Please note: The log message (excluding pr_errno's strerror and libcrypto's

src/rsync/rsync.c

@@ -192,14 +192,22 @@ duplicate_fds(int fds[2][2])
 }
 
 static void
-handle_child_thread(struct rpki_uri *uri, bool is_ta, int fds[2][2])
+release_args(char **args, unsigned int size)
 {
-	/* THIS FUNCTION MUST NEVER RETURN!!! */
+	unsigned int i;
 
+	/* args[0] wasn't allocated */
+	for (i = 1; i < size + 1; i++)
+		free(args[i]);
+	free(args);
+}
+
+static int
+prepare_rsync(struct rpki_uri *uri, bool is_ta, char ***args, size_t *args_len)
+{
 	struct string_array const *config_args;
 	char **copy_args;
 	unsigned int i;
-	int error;
 
 	config_args = config_get_rsync_args(is_ta);
 	/*
@@ -209,32 +217,44 @@ handle_child_thread(struct rpki_uri *uri, bool is_ta, int fds[2][2])
 	 */
 	copy_args = calloc(config_args->length + 2, sizeof(char *));
 	if (copy_args == NULL)
-		exit(pr_enomem());
+		return pr_enomem();
 
 	copy_args[0] = config_get_rsync_program();
 	copy_args[config_args->length + 1] = NULL;
 
 	memcpy(copy_args + 1, config_args->array,
 	    config_args->length * sizeof(char *));
 
-	for (i = 1; i < config_args->length + 1; i++) {
-		if (strcmp(copy_args[i], "$REMOTE") == 0)
-			copy_args[i] = strdup(uri_get_global(uri));
-		else if (strcmp(copy_args[i], "$LOCAL") == 0)
-			copy_args[i] = strdup(uri_get_local(uri));
-		if (copy_args[i] == NULL)
-			exit(pr_enomem());
+	for (i = 0; i < config_args->length; i++) {
+		if (strcmp(config_args->array[i], "$REMOTE") == 0)
+			copy_args[i + 1] = strdup(uri_get_global(uri));
+		else if (strcmp(config_args->array[i], "$LOCAL") == 0)
+			copy_args[i + 1] = strdup(uri_get_local(uri));
+		else
+			copy_args[i + 1] = strdup(config_args->array[i]);
+		if (copy_args[i + 1] == NULL) {
+			release_args(copy_args, i);
+			return pr_enomem();
+		}
 	}
 
-	pr_val_debug("Executing RSYNC:");
-	for (i = 0; i < config_args->length + 1; i++)
-		pr_val_debug("    %s", copy_args[i]);
+	*args = copy_args;
+	*args_len = config_args->length;
+	return 0;
+}
+
+static void
+handle_child_thread(char **args, int fds[2][2])
+{
+	/* THIS FUNCTION MUST NEVER RETURN!!! */
+	int error;
 
 	duplicate_fds(fds);
 
-	execvp(copy_args[0], copy_args);
+	execvp(args[0], args);
 	error = errno;
-	pr_val_err("Could not execute the rsync command: %s",
+	/* Log directly to stderr, redirected by the pipes */
+	fprintf(stderr, "Could not execute the rsync command: %s\n",
 	    strerror(error));
 
 	/* https://stackoverflow.com/a/14493459/1735458 */
@@ -246,8 +266,12 @@ create_pipes(int fds[2][2])
 {
 	if (pipe(fds[0]) == -1)
 		return -pr_op_errno(errno, "Piping rsync stderr");
-	if (pipe(fds[1]) == -1)
+	if (pipe(fds[1]) == -1) {
+		/* Close pipe previously created */
+		close(fds[0][0]);
+		close(fds[0][1]);
 		return -pr_op_errno(errno, "Piping rsync stdout");
+	}
 	return 0;
 }
 
@@ -297,30 +321,38 @@ read_pipe(int fd_pipe[2][2], int type, bool log_operation)
 		if (count == -1) {
 			if (errno == EINTR)
 				continue;
+			close(fd_pipe[type][0]); /* Close read end */
 			return -pr_val_errno(errno, "Reading rsync buffer");
 		}
 		if (count == 0)
 			break;
 
 		log_buffer(buffer, count, type, log_operation);
 	}
-	close(fd_pipe[type][0]);
+	close(fd_pipe[type][0]); /* Close read end */
 	return 0;
 }
 
+/*
+ * Read the piped output from the child, assures that all pipes are closed on
+ * success and on error.
+ */
 static int
 read_pipes(int fds[2][2], bool log_operation)
 {
 	int error;
 
-	/* Won't be needed */
+	/* Won't be needed (sterr/stdout write ends) */
 	close(fds[0][1]);
 	close(fds[1][1]);
 
 	/* stderr pipe */
 	error = read_pipe(fds, 0, log_operation);
-	if (error)
+	if (error) {
+		/* Close the other pipe pending to read */
+		close(fds[1][0]);
 		return error;
+	}
 
 	/* stdout pipe, always logs to info */
 	return read_pipe(fds, 1, true);
@@ -333,34 +365,70 @@ static int
 do_rsync(struct rpki_uri *uri, bool is_ta, bool log_operation)
 {
 	/* Descriptors to pipe stderr (first element) and stdout (second) */
+	char **args;
+	size_t args_len;
 	int fork_fds[2][2];
 	pid_t child_pid;
 	unsigned int retries;
+	unsigned int i;
 	int child_status;
 	int error;
 
+	/* Prepare everything for the child exec */
+	args = NULL;
+	args_len = 0;
+	error = prepare_rsync(uri, is_ta, &args, &args_len);
+	if (error)
+		return error;
+
+	pr_val_debug("Executing RSYNC:");
+	for (i = 0; i < args_len + 1; i++)
+		pr_val_debug("    %s", args[i]);
+
 	retries = 0;
 	do {
 		child_status = 0;
 		error = create_dir_recursive(uri_get_local(uri));
 		if (error)
-			return error;
+			goto release_args;
 
 		error = create_pipes(fork_fds);
 		if (error)
-			return error;
+			goto release_args;
+
+		/* Flush output (avoid locks between father and child) */
+		log_flush();
 
 		/* We need to fork because execvp() magics the thread away. */
 		child_pid = fork();
 		if (child_pid == 0) {
-			/* This code is run by the child. */
-			handle_child_thread(uri, is_ta, fork_fds);
+			/*
+			 * This code is run by the child, and should try to
+			 * call execvp() as soon as possible.
+			 *
+			 * Refer to
+			 * https://pubs.opengroup.org/onlinepubs/9699919799/functions/fork.html
+			 * "{..} to avoid errors, the child process may only
+			 * execute async-signal-safe operations until such time
+			 * as one of the exec functions is called."
+			 */
+			handle_child_thread(args, fork_fds);
+		}
+		if (child_pid < 0) {
+			pr_op_errno(errno, "Couldn't fork to execute rsync");
+			error = errno;
+			/* Close all ends from the created pipes */
+			close(fork_fds[0][0]);
+			close(fork_fds[1][0]);
+			close(fork_fds[0][1]);
+			close(fork_fds[1][1]);
+			goto release_args;
 		}
 
 		/* This code is run by us. */
 		error = read_pipes(fork_fds, log_operation);
 		if (error)
-			return error;
+			kill(child_pid, SIGCHLD); /* Stop the child */
 
 		error = waitpid(child_pid, &child_status, 0);
 		do {
@@ -370,7 +438,7 @@ do_rsync(struct rpki_uri *uri, bool is_ta, bool log_operation)
 				    error, strerror(error));
 				if (child_status > 0)
 					break;
-				return error;
+				goto release_args;
 			}
 		} while (0);
 
@@ -380,13 +448,13 @@ do_rsync(struct rpki_uri *uri, bool is_ta, bool log_operation)
 			pr_val_debug("Child terminated with error code %d.", error);
 			if (!error) {
 				reqs_errors_rem_uri(uri_get_global(uri));
-				return 0;
+				goto release_args;
 			}
 			if (retries == config_get_rsync_retry_count()) {
 				pr_val_warn("Max RSYNC retries (%u) reached on '%s', won't retry again.",
 				    retries, uri_get_global(uri));
-
-				return EREQFAILED;
+				error = EREQFAILED;
+				goto release_args;
 			}
 			pr_val_warn("Retrying RSYNC '%s' in %u seconds, %u attempts remaining.",
 			    uri_get_global(uri),
@@ -399,6 +467,8 @@ do_rsync(struct rpki_uri *uri, bool is_ta, bool log_operation)
 		break;
 	} while (true);
 
+	release_args(args, args_len);
+
 	if (WIFSIGNALED(child_status)) {
 		switch (WTERMSIG(child_status)) {
 		case SIGINT:
@@ -420,6 +490,10 @@ do_rsync(struct rpki_uri *uri, bool is_ta, bool log_operation)
 
 	pr_op_err("The RSYNC command died in a way I don't have a handler for. Dunno; guess I'll die as well.");
 	return -EINVAL;
+release_args:
+	/* The happy path also falls here */
+	release_args(args, args_len);
+	return error;
 }
 
 /**