fs_log: merge option, increase message buffer

Maximum amount of in-transit packets is TX_QUEUE_SIZE*2 + 1

Issue #1538

repos/os/src/server/fs_log/README

@@ -2,11 +2,12 @@ LOG server that writes log messages onto a file system.
 
 Log files are creating in a directory tree formed from session labels.
 As an example the session label "init -> nitpicker" would create
-a log file at "init/nitpicker.log". The behavior of opening two LOG
+a log file at "init/nitpicker.log".
-sessions with the same label is undefined.
 
-The only configuration and policy available is the option to truncate
+The option to truncate files at the start of each LOG session is available
-files at the start of the LOG session, which is disabled by default.
+through session policy, as well the option to merge the logs of any
+session matching a given policy. When a merged policy label contains a
+trailing "->", the log filename takes the name of the next label element.
 
 :Example configuration:
 ! <start name="log_file">
@@ -14,6 +15,7 @@ files at the start of the LOG session, which is disabled by default.
 !   <provides><service name="LOG"/></provides>
 !   <config>
 !     <policy label="nic_drv" truncate="no"/>
+!     <policy label="cli_monitor -> " merge="yes"/>
 !     <policy label="" truncate="yes"/>
 !   </config>
 ! </start>

repos/os/src/server/fs_log/log_file.h

@@ -0,0 +1,91 @@
+/*
+ * \brief  File object shared between log sessions
+ * \author Emery Hemingway
+ * \date   2015-06-09
+ */
+
+/*
+ * Copyright (C) 2015 Genode Labs GmbH
+ *
+ * This file is part of the Genode OS framework, which is distributed
+ * under the terms of the GNU General Public License version 2.
+ */
+
+#ifndef _FS_LOG__LOG_FILE_H_
+#define _FS_LOG__LOG_FILE_H_
+
+/* Genode includes */
+#include <log_session/log_session.h>
+#include <file_system_session/file_system_session.h>
+
+namespace Fs_log {
+
+	using namespace Genode;
+	using namespace File_system;
+
+	class Log_file;
+
+}
+
+class Fs_log::Log_file : public List<Log_file>::Element
+{
+	private:
+
+		char                  _dir_path[ MAX_PATH_LEN];
+		char                  _file_name[MAX_NAME_LEN];
+		File_system::Session &_fs;
+		File_handle           _handle;
+		seek_off_t            _offset;
+
+	public:
+
+		/**
+		 * Constructor
+		 */
+		Log_file(File_system::Session &fs, File_handle handle,
+		         char const *dir_path, char const *file_name,
+		         seek_off_t offset)
+		:
+			_fs(fs), _handle(handle), _offset(offset)
+		{
+			strncpy(_dir_path,   dir_path,  sizeof(_dir_path));
+			strncpy(_file_name, file_name, sizeof(_file_name));
+		}
+
+		bool match(char const *dir, char const *filename) const
+		{
+			return
+				(strcmp(_dir_path,  dir,      MAX_PATH_LEN) == 0) &&
+				(strcmp(_file_name, filename, MAX_NAME_LEN) == 0);
+		}
+
+		/**
+		 * Write a log message to the packet buffer.
+		 */
+		size_t write(char const *msg, size_t msg_len)
+		{
+			File_system::Session::Tx::Source &source = *_fs.tx();
+
+			File_system::Packet_descriptor raw_packet;
+			if (!source.ready_to_submit())
+				raw_packet = source.get_acked_packet();
+			else
+				raw_packet = source.alloc_packet(Log_session::String::MAX_SIZE);
+
+			File_system::Packet_descriptor
+				packet(raw_packet,
+				       0, /* The result struct. */
+				       _handle, File_system::Packet_descriptor::WRITE,
+				       msg_len, _offset);
+
+			_offset += msg_len;
+
+			char *buf = source.packet_content(packet);
+			memcpy(buf, msg, msg_len);
+
+			source.submit_packet(packet);
+			return msg_len;
+		}
+};
+
+#endif

repos/os/src/server/fs_log/main.cc

@@ -20,11 +20,13 @@
 #include <base/printf.h>
 
 /* Local includes */
+#include "log_file.h"
 #include "session.h"
 
 namespace Fs_log {
 
 	using namespace Genode;
+	using namespace File_system;
 
 	class  Root_component;
 	struct Main;
@@ -32,26 +34,27 @@ namespace Fs_log {
 	enum {
 		 BLOCK_SIZE = Log_session::String::MAX_SIZE,
 		 QUEUE_SIZE = File_system::Session::TX_QUEUE_SIZE,
-		TX_BUF_SIZE = BLOCK_SIZE * QUEUE_SIZE
+		TX_BUF_SIZE = BLOCK_SIZE * (QUEUE_SIZE*2 + 1)
 	};
 
 }
 
-class Fs_log::Root_component : public Genode::Root_component<Fs_log::Session_component>
+class Fs_log::Root_component :
+	public Genode::Root_component<Fs_log::Session_component>
 {
 	private:
 
 		Allocator_avl            _write_alloc;
 		File_system::Connection  _fs;
+		List<Log_file>           _log_files;
 
-		File_system::File_handle open_file(File_system::Dir_handle &dir_handle,
+		Log_file *lookup(char const *dir, char const *filename)
-		                                   char const *name)
 		{
-			try {
+			for (Log_file *file = _log_files.first(); file; file = file->next())
-				return _fs.file(dir_handle, name, File_system::WRITE_ONLY, false);
+				if (file->match(dir, filename))
-			} catch (File_system::Lookup_failed) {
+					return file;
-				return _fs.file(dir_handle, name, File_system::WRITE_ONLY, true);
+
-			}
+			return 0;
 		}
 
 	protected:
@@ -60,85 +63,149 @@ class Fs_log::Root_component : public Genode::Root_component<Fs_log::Session_com
 		{
 			using namespace File_system;
 
-			char path[MAX_PATH_LEN];
+			char  dir_path[MAX_PATH_LEN];
-			path[0] = '/';
+			char file_name[MAX_NAME_LEN];
-			char name[MAX_NAME_LEN];
 
-			Session_label session_label(args);
+			dir_path[0] = '/';
-			strncpy(path+1, session_label.string(), sizeof(path)-1);
 
 			bool truncate = false;
+			Session_label session_label(args);
+			char const *label_str = session_label.string();
+			char const *label_prefix = nullptr;
+
 			try {
 				Session_policy policy(session_label);
 				try {
 					truncate = policy.attribute("truncate").has_value("yes");
 				} catch (Xml_node::Nonexistent_attribute) { }
 
-			} catch (Session_policy::No_policy_defined) { }
+				bool merge = false;
+				try {
+					merge = policy.attribute("merge").has_value("yes");
+				} catch (Xml_node::Nonexistent_attribute) { }
+				if (merge) {
+					/*
+					 * Use the policy label that was matched rather than
+					 * full session label for the path of the log file.
+					 */
+					policy.attribute("label").value(dir_path+1, sizeof(dir_path)-1);
+					if (!dir_path[1]) {
+						PERR("cannot merge an empty policy label");
+						throw Root::Unavailable();
+					}
 
-			size_t len = strlen(path);
+					/*
+					 * If the policy has a trailing '->', move first element
+					 * from the log prefix to the end of the log path.
+					 */
+					size_t label_len = strlen(dir_path);
+					label_prefix = label_str+(label_len-1);
+
+					if ((strcmp((dir_path+label_len)-3, " ->", 4) == 0) ||
+					    (strcmp((dir_path+label_len)-4, " -> ", 5) == 0)) {
+
+						for (size_t i = 0; *(label_str+i); ++i) {
+							if (strcmp(label_prefix+i, " -> ", 4))
+								continue;
+
+							strncpy(dir_path+label_len, label_prefix, i+1);
+							label_prefix += i+4;
+							break;
+						}
+
+						if (*label_prefix == ' ') ++label_prefix;
+					}
+
+				} else
+					strncpy(dir_path+1, label_str, MAX_PATH_LEN-1);
+
+			} catch (Session_policy::No_policy_defined) {
+				strncpy(dir_path+1, label_str, MAX_PATH_LEN-1);
+			}
+
+			{
+				/* Parse out a directory and file name. */
+				size_t len = strlen(dir_path);
 				size_t start = 1;
 				for (size_t i = 1; i < len;) {
 					/* Replace any slashes in label elements. */
-				if (path[i] == '/') path[i] = '_';
+					if (dir_path[i] == '/') dir_path[i] = '_';
-				if (strcmp(" -> ", path+i, 4) == 0) {
+					if (strcmp(" -> ", dir_path+i, 4) == 0) {
-					path[i++] = '/';
+						dir_path[i++] = '/';
-					strncpy(path+i, path+i+3, sizeof(path)-i);
+						strncpy(dir_path+i, dir_path+i+3, MAX_PATH_LEN-i);
 						start = i;
 						i += 3;
 					} else ++i;
 				}
 
-			snprintf(name, sizeof(name), "%s.log", path+start);
+				/* Copy the remainder to the file name. */
-			path[(start == 1) ? start : start-1] = '\0';
+				snprintf(file_name, MAX_NAME_LEN, "%s.log", dir_path+start);
+
+				/* Terminate the directory path. */
+				dir_path[(start == 1) ? start : start-1] = '\0';
 
 				/* Rewrite any slashes in the name. */
-			for (char *p = name; *p; ++p)
+				for (char *p = file_name; *p; ++p)
 					if (*p == '/') *p = '_';
+			}
 
-			File_handle file_handle;
+			Log_file *file = lookup(dir_path, file_name);
-			seek_off_t offset = 0;
+			if (!file) try {
-			try {
+
-				Dir_handle dir_handle = ensure_dir(_fs, path);
+				Dir_handle   dir_handle = ensure_dir(_fs, dir_path);
 				Handle_guard dir_guard(_fs, dir_handle);
+				File_handle  handle;
+				seek_off_t   offset = 0;
 
-				file_handle = open_file(dir_handle, name);
+				try {
+					handle = _fs.file(dir_handle, file_name,
+					                  File_system::WRITE_ONLY, false);
 
 					if (truncate)
-					_fs.truncate(file_handle, 0);
+						_fs.truncate(handle, 0);
 					else
-					offset = _fs.status(file_handle).size;
+						offset = _fs.status(handle).size;
+
+				} catch (File_system::Lookup_failed) {
+					handle = _fs.file(dir_handle, file_name,
+					                  File_system::WRITE_ONLY, true);
+				}
+
+				file = new (env()->heap())
+					Log_file(_fs, handle, dir_path, file_name, offset);
+
+				_log_files.insert(file);
 
 			} catch (Permission_denied) {
-				PERR("%s/%s: permission denied", path, name);
+				PERR("%s:%s: permission denied", dir_path, file_name);
-				throw Root::Unavailable();
 
 			} catch (Name_too_long) {
-				PERR("%s/%s: name too long", path, name);
+				PERR("%s:%s: name too long", dir_path, file_name);
-				throw Root::Unavailable();
 
 			} catch (No_space) {
-				PERR("%s/%s: no space", path, name);
+				PERR("%s:%s: no space", dir_path, file_name);
-				throw Root::Unavailable();
 
 			} catch (Out_of_node_handles) {
-				PERR("%s/%s: out of node handles", path, name);
+				PERR("%s:%s: out of node handles", dir_path, file_name);
-				throw Root::Unavailable();
 
 			} catch (Invalid_name) {
-				PERR("%s/%s: invalid_name", path, name);
+				PERR("%s:%s: invalid_name", dir_path, file_name);
-				throw Root::Unavailable();
 
 			} catch (Size_limit_reached) {
-				PERR("%s/%s: size limit reached", path, name);
+				PERR("%s:%s: size limit reached", dir_path, file_name);
-				throw Root::Unavailable();
 
 			} catch (...) {
-				PERR("%s/%s: unknown error", path, name);
+				PERR("%s:%s: unknown error", dir_path, file_name);
+				throw;
+			}
+			if (!file) {
+				PERR("file was null");
 				throw Root::Unavailable();
 			}
 
-			return new (md_alloc()) Session_component(_fs, file_handle, offset);
+			if (label_prefix && *label_prefix)
+				return new (md_alloc()) Labeled_session_component(label_prefix, *file);
+			return new (md_alloc()) Unlabeled_session_component(*file);
 		}
 
 	public:

repos/os/src/server/fs_log/session.h

@@ -2,6 +2,9 @@
  * \brief  Log session that writes messages to a file system.
  * \author Emery Hemingway
  * \date   2015-05-16
+ *
+ * Message writing is fire-and-forget to prevent
+ * logging from becoming I/O bound.
  */
 
 /*
@@ -19,81 +22,89 @@
 #include <file_system_session/file_system_session.h>
 #include <base/rpc_server.h>
 
+/* Local includes */
+#include "log_file.h"
+
 namespace Fs_log {
-
-	using namespace Genode;
-
 	class           Session_component;
-
+	class Unlabeled_session_component;
+	class   Labeled_session_component;
 }
 
-/**
+class Fs_log::Session_component : public Rpc_object<Log_session, Unlabeled_session_component>
- * A log session that writes messages to a file system node.
+{
- *
+	public:
- * Message writing is fire-and-forget to prevent
+		virtual size_t write(String const &string) = 0;
- * logging from becoming I/O bound.
+};
- */
+
-class Fs_log::Session_component : public Rpc_object<Log_session, Session_component>
+class Fs_log::Unlabeled_session_component : public Session_component
 {
 	private:
 
-		File_system::Session    &_fs;
+		Log_file &_log_file;
-		File_system::File_handle _file_handle;
-		File_system::seek_off_t  _offset;
 
 	public:
 
 		/**
 		 * Constructor
 		 */
-		Session_component(File_system::Session    &fs,
+		Unlabeled_session_component(Log_file &log_file)
-		                  File_system::File_handle fh,
+		: _log_file(log_file) { }
-		                  File_system::seek_off_t  offset)
-		: _fs(fs), _file_handle(fh), _offset(offset) { }
 
 		/*****************
 		 ** Log session **
 		 *****************/
 
-		size_t write(Log_session::String const &string)
+		size_t write(Log_session::String const &msg)
 		{
-			if (!(string.is_valid_string())) {
+			if (!msg.is_valid_string()) {
 				PERR("corrupted string");
 				return 0;
 			}
 
-			File_system::Session::Tx::Source &source = *_fs.tx();
+			char const *msg_str = msg.string();
+			size_t msg_len = Genode::strlen(msg_str);
 
-			char const *msg  = string.string();
+			return _log_file.write(msg_str, msg_len);
-			size_t msg_len   = Genode::strlen(msg);
+		}
-			size_t write_len = msg_len;
+};
 
-			/*
+class Fs_log::Labeled_session_component : public Session_component
-			 * If the message did not fill the incoming buffer
+{
-			 * make space to add a newline.
+	private:
+
+		char      _label[Log_session::String::MAX_SIZE];
+		size_t    _label_len;
+		Log_file &_log_file;
+
+	public:
+
+		/**
+		 * Constructor
 		 */
-			if ((msg_len < Log_session::String::MAX_SIZE) &&
+		Labeled_session_component(char const *label, Log_file &log_file)
-			    (msg[msg_len-1] != '\n'))
+		: _log_file(log_file)
-				++write_len;
+		{
+			snprintf(_label, sizeof(_label), "[%s] ", label);
+			_label_len = strlen(_label);
+		}
 
-			while (source.ack_avail())
+		/*****************
-				source.release_packet(source.get_acked_packet());
+		 ** Log session **
+		 *****************/
 
-			File_system::Packet_descriptor
+		size_t write(Log_session::String const &msg)
-				packet(source.alloc_packet(Log_session::String::MAX_SIZE),
+		{
-				       0, /* The result struct. */
+			if (!msg.is_valid_string()) {
-				       _file_handle, File_system::Packet_descriptor::WRITE,
+				PERR("corrupted string");
-				       write_len, _offset);
+				return 0;
-			_offset += write_len;
+			}
 
-			char *buf = source.packet_content(packet);
+			char const *msg_str = msg.string();
-			memcpy(buf, msg, msg_len);
+			size_t msg_len = Genode::strlen(msg_str);
 
-			if (msg_len != write_len)
+			_log_file.write(_label, _label_len);
-				buf[msg_len] = '\n';
+			return _log_file.write(msg_str, msg_len);
-
-			source.submit_packet(packet);
-			return msg_len;
 		}
 };