Always use FILE* for standard output.

The threads running commands for clients through the Posix daemon used
to write to a char buffer through snprintf (etc.) which was then written
directly to the file descriptor, whereas in the other case printf
(etc.) was used to write to stdout (FILE*). Both versions used some
macro's and repeated code to have the same output.

This change unifies these two cases by using a FILE* in both cases. The
(line) buffering is done by the standard C library's implementation
(just like with stdout), and px4_log.c now uses the same code in all
cases (using fprintf, etc.) for printing (colored) output.

platforms/posix/include/px4_daemon/server_io.h

@@ -1,6 +1,6 @@
 /****************************************************************************
  *
- *   Copyright (C) 2016 PX4 Development Team. All rights reserved.
+ *   Copyright (C) 2018 PX4 Development Team. All rights reserved.
  *
  * Redistribution and use in source and binary forms, with or without
  * modification, are permitted provided that the following conditions
@@ -33,11 +33,7 @@
 /**
  * @file server_io.h
  *
- * These are helper functions to send the stdout over a pipe
- * back to the client.
- *
- * @author Julian Oes <julian@oes.ch>
- * @author Beat Küng <beat-kueng@gmx.net>
+ * @author Mara Bos <m-ou.se@m-ou.se>
  */
 #pragma once
 
@@ -46,20 +42,11 @@
 __BEGIN_DECLS
 
 /**
- * Get the stdout pipe buffer in order to write to fill it.
+ * Get the stdout of the current thread.
  *
- * @param buffer: pointer to buffer that will be set in function.
- * @param max_length: length of the assigned buffer.
- * @param is_atty: true if we are writing to a terminal (and can e.g. use colors).
- * @return 0 on success
+ * @param isatty_: if not NULL, *isatty_ will be set to wether the stream points to a terminal (true) or not (false).
+ * @return The FILE* which represents the standard output of the current thread.
  */
-__EXPORT int get_stdout_pipe_buffer(char **buffer, unsigned *max_length, bool *is_atty);
+__EXPORT FILE *get_stdout(bool *isatty_);
 
-/**
- * Write the filled bytes to the pipe.
- *
- * @param buffer_length: the number of bytes that should be written.
- * @return 0 on success
- */
-__EXPORT int send_stdout_pipe_buffer(unsigned buffer_length);
 __END_DECLS

platforms/posix/src/px4_daemon/client.cpp

@@ -46,6 +46,7 @@
 #include <sys/socket.h>
 #include <sys/stat.h>
 #include <sys/un.h>
+#include <unistd.h>
 
 #include <string>
 

platforms/posix/src/px4_daemon/server.cpp

@@ -40,6 +40,7 @@
 
 #include <errno.h>
 #include <fcntl.h>
+#include <stdio.h>
 #include <unistd.h>
 #include <string.h>
 #include <string>
@@ -141,6 +142,10 @@ Server::_server_main()
 	// Watch the listening socket for incoming connections.
 	poll_fds.push_back(pollfd {_fd, POLLIN, 0});
 
+	// The list of FILE pointers that we'll need to fclose().
+	// stdouts[i] corresponds to poll_fds[i+1].
+	std::vector<FILE *> stdouts;
+
 	while (true) {
 		int n_ready = poll(poll_fds.data(), poll_fds.size(), -1);
 
@@ -162,22 +167,36 @@ Server::_server_main()
 				return;
 			}
 
-			// Start a new thread to handle the client.
-			pthread_t *thread = &_fd_to_thread[client];
-			ret = pthread_create(thread, nullptr, Server::_handle_client, (void *)(intptr_t)client);
+			FILE *thread_stdout = fdopen(client, "w");
 
-			if (ret != 0) {
-				PX4_ERR("could not start pthread (%i)", ret);
-				_fd_to_thread.erase(client);
+			if (thread_stdout == nullptr) {
+				PX4_ERR("could not open stdout for new thread");
 				close(client);
 
 			} else {
-				// We won't join the thread, so detach to automatically release resources at its end
-				pthread_detach(*thread);
-			}
+				// Set stream to line buffered.
+				setvbuf(thread_stdout, nullptr, _IOLBF, BUFSIZ);
 
-			// Start listening for the client hanging up.
-			poll_fds.push_back(pollfd {client, POLLHUP, 0});
+				// Start a new thread to handle the client.
+				pthread_t *thread = &_fd_to_thread[client];
+				ret = pthread_create(thread, nullptr, Server::_handle_client, thread_stdout);
+
+				if (ret != 0) {
+					PX4_ERR("could not start pthread (%i)", ret);
+					_fd_to_thread.erase(client);
+					fclose(thread_stdout);
+
+				} else {
+					// We won't join the thread, so detach to automatically release resources at its end
+					pthread_detach(*thread);
+
+					// Start listening for the client hanging up.
+					poll_fds.push_back(pollfd {client, POLLHUP, 0});
+
+					// Remember the FILE *, so we can fclose() it later.
+					stdouts.push_back(thread_stdout);
+				}
+			}
 		}
 
 		// Handle any closed connections.
@@ -193,7 +212,8 @@ Server::_server_main()
 					_fd_to_thread.erase(thread);
 				}
 
-				close(poll_fds[i].fd);
+				fclose(stdouts[i - 1]);
+				stdouts.erase(stdouts.begin() + i - 1);
 				poll_fds.erase(poll_fds.begin() + i);
 
 			} else {
@@ -210,7 +230,8 @@ Server::_server_main()
 void
 *Server::_handle_client(void *arg)
 {
-	int fd = (int)(intptr_t)arg;
+	FILE *out = (FILE *)arg;
+	int fd = fileno(out);
 
 	// Read until the end of the incoming stream.
 	std::string cmd;
@@ -247,7 +268,7 @@ void
 
 	if ((thread_data_ptr = (CmdThreadSpecificData *)pthread_getspecific(_instance->_key)) == nullptr) {
 		thread_data_ptr = new CmdThreadSpecificData;
-		thread_data_ptr->fd = fd;
+		thread_data_ptr->thread_stdout = out;
 		thread_data_ptr->is_atty = isatty;
 
 		(void)pthread_setspecific(_instance->_key, (void *)thread_data_ptr);
@@ -259,10 +280,13 @@ void
 	// Report return value.
 	char buf[2] = {0, (char)retval};
 
-	if (write(fd, buf, sizeof buf) < 0) {
+	if (fwrite(buf, sizeof buf, 1, out) != 1) {
 		// Don't care it went wrong, as we're cleaning up anyway.
 	}
 
+	// Flush the FILE*'s buffer before we shut down the connection.
+	fflush(out);
+
 	_cleanup(fd);
 	return nullptr;
 }

platforms/posix/src/px4_daemon/server.h

@@ -49,6 +49,7 @@
  */
 #pragma once
 
+#include <stdio.h>
 #include <stdint.h>
 #include <stdbool.h>
 #include <pthread.h>
@@ -75,9 +76,8 @@ public:
 	int start();
 
 	struct CmdThreadSpecificData {
-		int fd; // fd to send stdout to
+		FILE *thread_stdout; // stdout of this thread
 		bool is_atty; // whether file descriptor refers to a terminal
-		char buffer[1024];
 	};
 
 	static bool is_running()

platforms/posix/src/px4_daemon/server_io.cpp

@@ -1,6 +1,6 @@
 /****************************************************************************
  *
- *   Copyright (C) 2016 PX4 Development Team. All rights reserved.
+ *   Copyright (C) 2016-2018 PX4 Development Team. All rights reserved.
  *
  * Redistribution and use in source and binary forms, with or without
  * modification, are permitted provided that the following conditions
@@ -35,8 +35,10 @@
  *
  * @author Julian Oes <julian@oes.ch>
  * @author Beat Küng <beat-kueng@gmx.net>
+ * @author Mara Bos <m-ou.se@m-ou.se>
  */
 
+#include <stdio.h>
 #include <fcntl.h>
 #include <unistd.h>
 #include <string>
@@ -56,21 +58,19 @@
 using namespace px4_daemon;
 
 
-int get_stdout_pipe_buffer(char **buffer, unsigned *max_length, bool *is_atty)
+FILE *get_stdout(bool *isatty_)
 {
-	// The thread specific data won't be initialized if the server is not running.
 	Server::CmdThreadSpecificData *thread_data_ptr;
 
-	if (!Server::is_running()) {
-		return -1;
-	}
-
 	// If we are not in a thread that has been started by a client, we don't
 	// have any thread specific data set and we won't have a pipe to write
 	// stdout to.
-	if ((thread_data_ptr = (Server::CmdThreadSpecificData *)pthread_getspecific(
+	if (!Server::is_running() ||
+	    (thread_data_ptr = (Server::CmdThreadSpecificData *)pthread_getspecific(
 				       Server::get_pthread_key())) == nullptr) {
-		return -1;
+		if (isatty_) { *isatty_ = isatty(1); }
+
+		return stdout;
 	}
 
 #ifdef __PX4_POSIX_EAGLE
@@ -79,37 +79,20 @@ int get_stdout_pipe_buffer(char **buffer, unsigned *max_length, bool *is_atty)
 	// even though the pthread_key has been created.
 	// We can catch this using the check below but we have no clue why this happens.
 	if (thread_data_ptr == (void *)0x1) {
-		return -1;
+		if (isatty_) { *isatty_ = isatty(1); }
+
+		return stdout;
 	}
 
 #endif
 
-	*buffer = thread_data_ptr->buffer;
-	*max_length = sizeof(thread_data_ptr->buffer);
-	*is_atty = thread_data_ptr->is_atty;
+	if (thread_data_ptr->thread_stdout == nullptr) {
+		if (isatty_) { *isatty_ = isatty(1); }
 
-	return 0;
-}
-
-int send_stdout_pipe_buffer(unsigned buffer_length)
-{
-	Server::CmdThreadSpecificData *thread_data_ptr;
-
-	if (!Server::is_running()) {
-		return -1;
-	}
-
-	if ((thread_data_ptr = (Server::CmdThreadSpecificData *)pthread_getspecific(
-				       Server::get_pthread_key())) == nullptr) {
-		return -1;
-	}
-
-	int bytes_sent = write(thread_data_ptr->fd, thread_data_ptr->buffer, buffer_length);
-
-	if (bytes_sent != (int)buffer_length) {
-		printf("write fail\n");
-		return -1;
-	}
-
-	return 0;
+		return stdout;
+	}
+
+	if (isatty_) { *isatty_ = thread_data_ptr->is_atty; }
+
+	return thread_data_ptr->thread_stdout;
 }

src/drivers/linux_pwm_out/navio_sysfs.cpp

@@ -35,6 +35,7 @@
 
 #include <fcntl.h>
 #include <errno.h>
+#include <unistd.h>
 #include <px4_log.h>
 
 using namespace linux_pwm_out;

src/drivers/linux_pwm_out/ocpoc_mmap.cpp

@@ -37,6 +37,7 @@
 
 #include <fcntl.h>
 #include <sys/mman.h>
+#include <unistd.h>
 
 using namespace linux_pwm_out;
 

src/drivers/navio_sysfs_rc_in/navio_sysfs_rc_in.cpp

@@ -37,6 +37,7 @@
 #include <fcntl.h>
 #include <stdio.h>
 #include <stdint.h>
+#include <unistd.h>
 
 #include <px4_config.h>
 #include <px4_workqueue.h>

src/drivers/rpi_rc_in/rpi_rc_in.h

@@ -46,6 +46,7 @@
 #include <fcntl.h>
 #include <stdio.h>
 #include <stdint.h>
+#include <unistd.h>
 
 #include <px4_config.h>
 #include <px4_workqueue.h>

src/modules/logger/util.cpp

@@ -37,6 +37,7 @@
 #include <sys/stat.h>
 #include <string.h>
 #include <stdlib.h>
+#include <unistd.h>
 
 #include <uORB/topics/vehicle_gps_position.h>
 

src/modules/uORB/uORB_tests/uORBTest_UnitTest.hpp

@@ -37,6 +37,7 @@
 #include "../uORB.h"
 #include <px4_time.h>
 #include <px4_tasks.h>
+#include <unistd.h>
 
 struct orb_test {
 	int val;

src/platforms/common/CMakeLists.txt

@@ -33,7 +33,7 @@
 
 set(SRCS)
 
-if (NOT "${OS}" MATCHES "qurt")
+if (NOT "${OS}" MATCHES "qurt" AND NOT "${CONFIG}" MATCHES "px4io")
 	list(APPEND SRCS
 		px4_log.c
 		)

src/platforms/common/px4_log.c

@@ -31,6 +31,7 @@
  *
  ****************************************************************************/
 
+#include <stdio.h>
 #include <stdlib.h>
 #include <string.h>
 #include <px4_log.h>
@@ -95,78 +96,38 @@ void px4_backtrace()
 
 __EXPORT void px4_log_modulename(int level, const char *moduleName, const char *fmt, ...)
 {
+	FILE *out = stdout;
+	bool use_color = true;
 
 #ifdef __PX4_POSIX
-	char *buffer;
-	unsigned max_length;
-	bool is_atty = false;
-
-	if (get_stdout_pipe_buffer(&buffer, &max_length, &is_atty) == 0) {
-		if (level >= _PX4_LOG_LEVEL_INFO) {
-
-			unsigned pos = 0;
-
-			if (is_atty) { pos += snprintf(buffer + pos, max_length - pos, "%s", __px4_log_level_color[level]); }
-
-			if (pos >= max_length) { return; }
-
-			pos += snprintf(buffer + pos, max_length - pos, __px4__log_level_fmt __px4__log_level_arg(level));
-
-			if (pos >= max_length) { return; }
-
-			if (is_atty) { pos += snprintf(buffer + pos, max_length - pos, "%s", PX4_ANSI_COLOR_GRAY); }
-
-			if (pos >= max_length) { return; }
-
-			pos += snprintf(buffer + pos, max_length - pos, __px4__log_modulename_pfmt, moduleName);
-			va_list argptr;
-
-			if (pos >= max_length) { return; }
-
-			if (is_atty) { pos += snprintf(buffer + pos, max_length - pos, "%s", __px4_log_level_color[level]); }
-
-			if (pos >= max_length) { return; }
-
-			va_start(argptr, fmt);
-			pos += vsnprintf(buffer + pos, max_length - pos, fmt, argptr);
-
-			if (pos >= max_length) { return; }
-
-			va_end(argptr);
-			pos += snprintf(buffer + pos, max_length - pos, "\n");
-
-			if (pos >= max_length) { return; }
-
-			if (is_atty) { pos += snprintf(buffer + pos, max_length - pos, "%s", PX4_ANSI_COLOR_RESET); }
-
-			if (pos >= max_length) { return; }
-
-			// +1 for the terminating 0 char.
-			send_stdout_pipe_buffer(pos + 1);
-		}
-
-	} else {
+	out = get_stdout(&use_color);
 #endif
 
-		if (level >= _PX4_LOG_LEVEL_INFO) {
-			PX4_LOG_COLOR_START
-			printf(__px4__log_level_fmt __px4__log_level_arg(level));
-			PX4_LOG_COLOR_MODULE
-			printf(__px4__log_modulename_pfmt, moduleName);
-			PX4_LOG_COLOR_MESSAGE
-			va_list argptr;
-			va_start(argptr, fmt);
-			vprintf(fmt, argptr);
-			va_end(argptr);
-			PX4_LOG_COLOR_END
-			printf("\n");
-		}
+#ifndef PX4_LOG_COLORIZED_OUTPUT
+	use_color = false;
+#endif
 
-#ifdef __PX4_POSIX
+	if (level >= _PX4_LOG_LEVEL_INFO) {
+		if (use_color) { fputs(__px4_log_level_color[level], out); }
+
+		fprintf(out, __px4__log_level_fmt __px4__log_level_arg(level));
+
+		if (use_color) { fputs(PX4_ANSI_COLOR_GRAY, out); }
+
+		fprintf(out, __px4__log_modulename_pfmt, moduleName);
+
+		if (use_color) { fputs(__px4_log_level_color[level], out); }
+
+		va_list argptr;
+		va_start(argptr, fmt);
+		vfprintf(out, fmt, argptr);
+		va_end(argptr);
+
+		if (use_color) { fputs(PX4_ANSI_COLOR_RESET, out); }
+
+		fputc('\n', out);
 	}
 
-#endif
-
 	/* publish an orb log message */
 	if (level >= _PX4_LOG_LEVEL_WARN && orb_log_message_pub) { //only publish important messages
 
@@ -201,52 +162,25 @@ __EXPORT void px4_log_modulename(int level, const char *moduleName, const char *
 
 __EXPORT void px4_log_raw(int level, const char *fmt, ...)
 {
+	FILE *out = stdout;
+	bool use_color = true;
 
 #ifdef __PX4_POSIX
-	char *buffer;
-	unsigned max_length;
-	bool is_atty = false;
-
-	if (get_stdout_pipe_buffer(&buffer, &max_length, &is_atty) == 0) {
-		if (level >= _PX4_LOG_LEVEL_INFO) {
-
-			unsigned pos = 0;
-
-			va_list argptr;
-
-			if (is_atty) { pos += snprintf(buffer + pos, max_length - pos, "%s", __px4_log_level_color[level]); }
-
-			if (pos >= max_length) { return; }
-
-			va_start(argptr, fmt);
-			pos += vsnprintf(buffer + pos, max_length - pos, fmt, argptr);
-			va_end(argptr);
-
-			if (pos >= max_length) { return; }
-
-			if (is_atty) { pos += snprintf(buffer + pos, max_length - pos, "%s", PX4_ANSI_COLOR_RESET); }
-
-			if (pos >= max_length) { return; }
-
-			// +1 for the terminating 0 char.
-			send_stdout_pipe_buffer(pos + 1);
-		}
-
-	} else {
+	out = get_stdout(&use_color);
 #endif
 
-		if (level >= _PX4_LOG_LEVEL_INFO) {
-			PX4_LOG_COLOR_START
-			PX4_LOG_COLOR_MESSAGE
-			va_list argptr;
-			va_start(argptr, fmt);
-			vprintf(fmt, argptr);
-			va_end(argptr);
-			PX4_LOG_COLOR_END
-		}
+#ifndef PX4_LOG_COLORIZED_OUTPUT
+	use_color = false;
+#endif
 
-#ifdef __PX4_POSIX
+	if (level >= _PX4_LOG_LEVEL_INFO) {
+		if (use_color) { fputs(__px4_log_level_color[level], out); }
+
+		va_list argptr;
+		va_start(argptr, fmt);
+		vfprintf(out, fmt, argptr);
+		va_end(argptr);
+
+		if (use_color) { fputs(PX4_ANSI_COLOR_RESET, out); }
 	}
-
-#endif
 }

src/platforms/px4_log.h

@@ -196,24 +196,6 @@ __END_DECLS
 #endif /* __PX4_POSIX */
 
 
-#ifdef PX4_LOG_COLORIZED_OUTPUT
-#include <unistd.h>
-#define PX4_LOG_COLOR_START \
-	int use_color = isatty(STDOUT_FILENO); \
-	if (use_color) printf("%s", __px4_log_level_color[level]);
-#define PX4_LOG_COLOR_MODULE \
-	if (use_color) printf(PX4_ANSI_COLOR_GRAY);
-#define PX4_LOG_COLOR_MESSAGE \
-	if (use_color) printf("%s", __px4_log_level_color[level]);
-#define PX4_LOG_COLOR_END \
-	if (use_color) printf(PX4_ANSI_COLOR_RESET);
-#else
-#define PX4_LOG_COLOR_START
-#define PX4_LOG_COLOR_MODULE
-#define PX4_LOG_COLOR_MESSAGE
-#define PX4_LOG_COLOR_END
-#endif /* PX4_LOG_COLORIZED_OUTPUT */
-
 /****************************************************************************
  * Output format macros
  * Use these to implement the code level macros below

src/systemcmds/tests/test_hysteresis.cpp

@@ -1,4 +1,5 @@
 #include <unit_test.h>
+#include <unistd.h>
 
 #include <systemlib/hysteresis/hysteresis.h>
 

src/systemcmds/tests/test_microbench_hrt.cpp

@@ -35,6 +35,7 @@
 
 #include <time.h>
 #include <stdlib.h>
+#include <unistd.h>
 
 #include <drivers/drv_hrt.h>
 #include <perf/perf_counter.h>

src/systemcmds/tests/test_microbench_math.cpp

@@ -35,6 +35,7 @@
 
 #include <time.h>
 #include <stdlib.h>
+#include <unistd.h>
 
 #include <drivers/drv_hrt.h>
 #include <perf/perf_counter.h>

src/systemcmds/tests/test_microbench_matrix.cpp

@@ -35,6 +35,7 @@
 
 #include <time.h>
 #include <stdlib.h>
+#include <unistd.h>
 
 #include <drivers/drv_hrt.h>
 #include <perf/perf_counter.h>

src/systemcmds/tests/test_microbench_uorb.cpp

@@ -35,6 +35,7 @@
 
 #include <time.h>
 #include <stdlib.h>
+#include <unistd.h>
 
 #include <drivers/drv_hrt.h>
 #include <perf/perf_counter.h>

src/systemcmds/tests/test_mixer.cpp

@@ -40,6 +40,7 @@
 #include <limits>
 #include <dirent.h>
 #include <string.h>
+#include <unistd.h>
 
 #include <px4_config.h>
 #include <mixer/mixer.h>

src/systemcmds/tests/test_parameters.cpp

@@ -2,6 +2,7 @@
 
 #include <px4_defines.h>
 #include <fcntl.h>
+#include <unistd.h>
 
 class ParameterTest : public UnitTest
 {