WIP: Added timestamping of log entries written to the log server

Rakefile

@@ -24,6 +24,10 @@ end
 desc 'Creates the initial ramdisk image where the programs and their data is stored'
 task :create_ramdisk_image do
   sh "cd servers/block/initial_ramdisk && #{RAKE_COMMAND} create_ramdisk_image"
+
+  sh 'mmd -o u:/config'
+  sh 'mmd u:/config/servers'
+  sh 'mmd u:/config/servers/boot'
 end
 
 desc 'Compiles and installs chaos'

libraries/file/file.c

@@ -121,7 +121,6 @@ return_type file_read(ipc_structure_type *vfs_structure, file_handle_type file_h
     message_parameter.data = buffer;
     message_parameter.length = read.bytes;
 
-    system_call_mailbox_receive(vfs_structure->input_mailbox_id,
-                                &message_parameter);
+    system_call_mailbox_receive(vfs_structure->input_mailbox_id, &message_parameter);
     return FILE_RETURN_SUCCESS;
 }

libraries/ipc/log.h

@@ -26,4 +26,6 @@ typedef struct
 
   // How urgent is this log message? 0 is most urgent, and higher numbers are of less importance.
   unsigned int urgency;
+
+  time_type timestamp;
 } ipc_log_print_type;

libraries/log/log.c

@@ -72,6 +72,7 @@ return_type log_print_formatted(log_structure_type *log_structure, unsigned int
     va_end(arguments);
 
     ipc_log_print.urgency = urgency;
+    system_call_timer_read(&ipc_log_print.timestamp);
     string_copy_max(ipc_log_print.log_class, log_structure->log_class, IPC_LOG_MAX_CLASS_LENGTH);
     string_copy_max(ipc_log_print.message, output, IPC_LOG_MAX_MESSAGE_LENGTH);
     log(log_structure, &ipc_log_print);
@@ -85,6 +86,7 @@ return_type log_print(log_structure_type *log_structure, unsigned int urgency, c
     ipc_log_print_type ipc_log_print;
 
     ipc_log_print.urgency = urgency;
+    system_call_timer_read(&ipc_log_print.timestamp);
     string_copy_max(ipc_log_print.log_class, log_structure->log_class, IPC_LOG_MAX_CLASS_LENGTH);
     string_copy_max(ipc_log_print.message, message, IPC_LOG_MAX_MESSAGE_LENGTH);
 

menu.lst

@@ -7,7 +7,7 @@ module /servers/console.gz
 module /servers/keyboard.gz
 module /servers/vga.gz
 module /servers/log.gz
-module /servers/virtual_file_system.gz
-module /servers/fat.gz
 module /servers/initial_ramdisk.gz
+module /servers/fat.gz
+module /servers/virtual_file_system.gz
 module /servers/boot.gz

servers/file_system/fat/handle_connection.c

@@ -173,4 +173,3 @@ void handle_connection(mailbox_id_type *reply_mailbox_id)
         }
     }
 }
-

servers/file_system/virtual_file_system/virtual_file_system.c

@@ -234,6 +234,7 @@ static void vfs_file_get_info(file_verbose_directory_entry_type *directory_entry
 
     if (volume == mounted_volumes || volume == (unsigned int) -1)
     {
+        log_print_formatted(&log_structure, LOG_URGENCY_WARNING, "Failed to found matching volume for %s", directory_entry->path_name);
         directory_entry->success = FALSE;
         return;
     }
@@ -306,6 +307,7 @@ static void vfs_file_get_info(file_verbose_directory_entry_type *directory_entry
                 // Did the file not exist?
                 if (input_index == mounted_volumes)
                 {
+                    log_print_formatted(&log_structure, LOG_URGENCY_DEBUG, "Failed to find %s in meta-root filesystem", directory_entry->path_name);
                     directory_entry->success = FALSE;
                     return;
                 }
@@ -450,7 +452,7 @@ static bool vfs_mount(file_mount_type *mount, ipc_structure_type *ipc_structure)
     string_copy_max(mount_point[mounted_volumes].location, mount->location, MAX_PATH_NAME_LENGTH);
     mounted_volumes++;
 
-    log_print_formatted(&log_structure, LOG_URGENCY_INFORMATIVE, "Mounting %u at //%s.",
+    log_print_formatted(&log_structure, LOG_URGENCY_INFORMATIVE, "Mounted %u at //%s.",
                         ipc_structure->output_mailbox_id, mount->location);
     return TRUE;
 }
@@ -527,6 +529,7 @@ static void handle_connection(mailbox_id_type *reply_mailbox_id)
                 file_mount_type *mount = (file_mount_type *) data;
 
                 vfs_mount(mount, &ipc_structure);
+                ipc_send(ipc_structure.output_mailbox_id, &message_parameter);
                 break;
             }
 

servers/system/boot/boot.c

@@ -81,13 +81,15 @@ int main(void)
     // mount.mailbox_id = mailbox_id[0];
     string_copy(mount.location, "ramdisk");
 
-    // That's it. Send the message.
+    // That's it. Send the message. The receive is here just to ensure that we don't keep on going before the volume is
+    // actually mounted.
     message_parameter.protocol = IPC_PROTOCOL_FILE;
     message_parameter.message_class = IPC_FILE_MOUNT_VOLUME;
     message_parameter.data = &mount;
-    message_parameter.length = sizeof (file_mount_type);
+    message_parameter.length = sizeof(file_mount_type);
     message_parameter.block = TRUE;
     ipc_send(vfs_structure.output_mailbox_id, &message_parameter);
+    ipc_receive(vfs_structure.input_mailbox_id, &message_parameter, NULL);
 
     log_print(&log_structure, LOG_URGENCY_DEBUG, "Mounted the first available block service as //ramdisk.");
 

servers/system/log/log.c

@@ -2,7 +2,7 @@
 // from the kernel.
 // Authors: Per Lundberg <[email protected]>
 //          Henrik Hallin <[email protected]>
-
+//
 // © Copyright 2000 chaos development
 // © Copyright 2007 chaos development
 // © Copyright 2015 chaos development
@@ -79,7 +79,8 @@ static void log_add(console_structure_type *console, char *title, ipc_log_print_
                               urgency_colour[ipc_log_print->urgency][0],
                               urgency_colour[ipc_log_print->urgency][1],
                               urgency_colour[ipc_log_print->urgency][2]);
-        console_print_formatted(console, " [%s] %s ", ipc_log_print->log_class, ipc_log_print->message);
+        console_print_formatted(console, " [%u.%03u] [%s] %s ", (u32) ipc_log_print->timestamp / 1000,
+                                (u32) ipc_log_print->timestamp % 1000, ipc_log_print->log_class, ipc_log_print->message);
 
         // Go to next line (with correct colour). */
         console_attribute_set(console, CONSOLE_COLOUR_GRAY, CONSOLE_COLOUR_BLACK, CONSOLE_ATTRIBUTE_RESET);
@@ -119,8 +120,7 @@ static void handle_connection(void *argument)
         message_parameter.message_class = IPC_CLASS_NONE;
         message_parameter.length = data_size;
 
-        if (ipc_receive(ipc_structure.input_mailbox_id, &message_parameter,
-                        &data_size) != IPC_RETURN_SUCCESS)
+        if (ipc_receive(ipc_structure.input_mailbox_id, &message_parameter, &data_size) != IPC_RETURN_SUCCESS)
         {
             continue;
         }
@@ -131,8 +131,7 @@ static void handle_connection(void *argument)
             {
                 ipc_log_print_type *ipc_log_print = (ipc_log_print_type *) data;
 
-                log_add(&console_structure_server,  " " PACKAGE_NAME " version " PACKAGE_VERSION " server console.",
-                        ipc_log_print);
+                log_add(&console_structure_server,  " " PACKAGE_NAME " version " PACKAGE_VERSION " server console.", ipc_log_print);
 
                 break;
             }
@@ -143,8 +142,7 @@ static void handle_connection(void *argument)
 static return_type handle_server_logging(void)
 {
     // Open a new console for the log.
-    if (console_init(&console_structure_server, &empty_tag, IPC_CONSOLE_CONNECTION_CLASS_CLIENT) !=
-            CONSOLE_RETURN_SUCCESS)
+    if (console_init(&console_structure_server, &empty_tag, IPC_CONSOLE_CONNECTION_CLASS_CLIENT) != CONSOLE_RETURN_SUCCESS)
     {
         return -1;
     }
@@ -155,8 +153,7 @@ static return_type handle_server_logging(void)
         return -1;
     }
 
-    if (console_open(&console_structure_server, 80, 50, 4, VIDEO_MODE_TYPE_TEXT) !=
-            CONSOLE_RETURN_SUCCESS)
+    if (console_open(&console_structure_server, 80, 50, 4, VIDEO_MODE_TYPE_TEXT) != CONSOLE_RETURN_SUCCESS)
     {
         return -1;
     }
@@ -200,14 +197,12 @@ static void handle_kernel_logging(void *argument UNUSED)
     system_thread_name_set("Kernel log handler");
 
     // Open a new console for the log.
-    if (console_init(&console_structure_kernel, &empty_tag, IPC_CONSOLE_CONNECTION_CLASS_CLIENT) !=
-            CONSOLE_RETURN_SUCCESS)
+    if (console_init(&console_structure_kernel, &empty_tag, IPC_CONSOLE_CONNECTION_CLASS_CLIENT) != CONSOLE_RETURN_SUCCESS)
     {
         return;
     }
 
-    if (console_open(&console_structure_kernel, 80, 50, 4, VIDEO_MODE_TYPE_TEXT) !=
-            CONSOLE_RETURN_SUCCESS)
+    if (console_open(&console_structure_kernel, 80, 50, 4, VIDEO_MODE_TYPE_TEXT) != CONSOLE_RETURN_SUCCESS)
     {
         return;
     }
@@ -222,8 +217,7 @@ static void handle_kernel_logging(void *argument UNUSED)
     {
         system_call_kernelfs_entry_read(&kernelfs_log);
 
-        log_add(&console_structure_kernel, " " PACKAGE_NAME " version " PACKAGE_VERSION " kernel console.",
-                ipc_log_print);
+        log_add(&console_structure_kernel, " " PACKAGE_NAME " version " PACKAGE_VERSION " kernel console.", ipc_log_print);
     }
 }