Updated common log interface.

VUnit · Jul 15, 2023 · b69eac2 · b69eac2
1 parent d14478f
commit b69eac2
Show file tree

Hide file tree

Showing 10 changed files with 233 additions and 69 deletions.
diff --git a/examples/vhdl/osvvm_log_integration/osvvm_integration/AlertLogPkg.vhd b/examples/vhdl/osvvm_log_integration/osvvm_integration/AlertLogPkg.vhd
@@ -944,7 +944,7 @@ package body AlertLogPkg is
         if WriteAlertErrorCountVar then
           return ErrorCount + 1;
         else
-          return no_val;
+          return -1;
         end if ;
       end;
 
@@ -1001,27 +1001,29 @@ package body AlertLogPkg is
           if not IsTranscriptOpen or IsTranscriptMirrored then
             write_to_log (
               output,
+              "",
               msg => message,
               log_time => log_time,
               log_level => alert_level,
               log_source_name => log_source_name,
-              val_1 => AlertLogJustifyAmountVar,
-              val_2 => error_count,
+              int_1 => AlertLogJustifyAmountVar,
+              int_2 => error_count,
               str_1 => AlertPrefixVar.Get(OSVVM_DEFAULT_ALERT_PREFIX),
               str_2 => prefix,
               str_3 => suffix
             );
           end if;
 
-          if IsTranscriptOpen or IsTranscriptMirrored then
+          if IsTranscriptOpen then
             write_to_log (
               TranscriptFile,
+              "path/to/my_transcript.txt", -- TODO: Add support for retrieving transcript path
               msg => message,
               log_time => log_time,
               log_level => alert_level,
               log_source_name => log_source_name,
-              val_1 => AlertLogJustifyAmountVar,
-              val_2 => error_count,
+              int_1 => AlertLogJustifyAmountVar,
+              int_2 => error_count,
               str_1 => AlertPrefixVar.Get(OSVVM_DEFAULT_ALERT_PREFIX),
               str_2 => prefix,
               str_3 => suffix
@@ -2237,7 +2239,7 @@ package body AlertLogPkg is
         if WriteLogErrorCountVar and WriteAlertErrorCountVar then
           return ErrorCount;
         else
-          return no_val;
+          return -1;
         end if ;
       end;
 
@@ -2280,26 +2282,28 @@ package body AlertLogPkg is
       if not IsTranscriptOpen or IsTranscriptMirrored then
         write_to_log (
           output,
+          "",
           msg => Message,
           log_time => log_time,
           log_level => log_level,
           log_source_name => log_source_name,
-          val_1 => AlertLogJustifyAmountVar,
-          val_2 => error_count,
+          int_1 => AlertLogJustifyAmountVar,
+          int_2 => error_count,
           str_1 => LogPrefixVar.Get(OSVVM_DEFAULT_LOG_PREFIX),
           str_3 => suffix
         );
       end if;
 
-      if IsTranscriptOpen or IsTranscriptMirrored then
+      if IsTranscriptOpen then
         write_to_log (
           TranscriptFile,
+          "path/to/my_transcript.txt", -- TODO: Add support for retrieving transcript path
           msg => Message,
           log_time => log_time,
           log_level => log_level,
           log_source_name => log_source_name,
-          val_1 => AlertLogJustifyAmountVar,
-          val_2 => error_count,
+          int_1 => AlertLogJustifyAmountVar,
+          int_2 => error_count,
           str_1 => LogPrefixVar.Get(OSVVM_DEFAULT_LOG_PREFIX),
           str_3 => suffix
         );

diff --git a/examples/vhdl/osvvm_log_integration/osvvm_integration/osvvm_to_vunit_common_log_pkg-body.vhd b/examples/vhdl/osvvm_log_integration/osvvm_integration/osvvm_to_vunit_common_log_pkg-body.vhd
@@ -8,25 +8,57 @@ library vunit_lib;
 context vunit_lib.vunit_context;
 
 package body common_log_pkg is
+  constant is_original_pkg : boolean := false;
+  -- Create a namespace for OSVVM to avoid name collisions between OSVVM alert/log ID names
+  -- and VUnit logger names. The file handler handling the OSVVM transcript file is also
+  -- attached to this logger.
+  constant osvvm : logger_t := get_logger("OSVVM");
+
+  constant has_file_handler : integer_vector_ptr_t := new_integer_vector_ptr(1);
+
   procedure write_to_log(
     file log_destination : text;
-    msg : string := "";
+    log_destination_path : string := no_string;
+    msg : string := no_string;
     log_time : time := no_time;
-    log_level : string := "";
-    log_source_name : string := "";
+    log_level : string := no_string;
+    log_source_name : string := no_string;
     str_1, str_2, str_3, str_4, str_5, str_6, str_7, str_8, str_9, str_10 : string := "";
-    val_1, val_2, val_3, val_4, val_5, val_6, val_7, val_8, val_9, val_10 : integer := no_val
+    int_1, int_2, int_3, int_4, int_5, int_6, int_7, int_8, int_9, int_10 : integer := 0;
+    bool_1, bool_2, bool_3, bool_4, bool_5, bool_6, bool_7, bool_8, bool_9, bool_10 : boolean := false
   ) is
-    constant stripped_log_level : string := strip(log_level);
 
-    alias prefix is str_2;
-    alias suffix is str_3;
+    constant stripped_log_level : string := strip(log_level);
+    variable file_log_handler : log_handler_t;
 
     variable logger : logger_t;
     variable vunit_log_level : log_level_t;
-    variable full_msg : line;
+    variable reenable_display_handler : boolean := false;
+
+    impure function remove_parent_path(full_path : string) return string is
+      variable parts : lines_t :=  split(full_path, "/");
+    begin
+      return parts(parts'right).all;
+    end;
   begin
-    logger := get_logger(log_source_name);
+    logger := get_logger(log_source_name, parent => osvvm);
+
+    -- Here we do the simplified assumption that when the transcript is opened it stays
+    -- on and is always mirrored. Allowing arbitrary use of transcript and mirroring
+    -- requires additional code. The transcript file is moved to the VUnit output path
+    -- to avoid access from multiple threads when running parallel simulations.
+    if (log_destination_path /= no_string) then
+      if (get(has_file_handler, 0) = 0) then
+        file_log_handler := new_log_handler(join(get_string(run_db, "output_path"), remove_parent_path(log_destination_path)));
+        -- The message has already been logged to display so temporarily disable it
+        set_log_handlers(osvvm, (0 => file_log_handler));
+        show_all(logger, file_log_handler);
+        reenable_display_handler := true;
+        set(has_file_handler, 0, 1);
+      else
+        return;
+      end if;
+    end if;
 
     if stripped_log_level = "WARNING" then
       vunit_log_level := warning;
@@ -42,17 +74,11 @@ package body common_log_pkg is
       vunit_log_level := info;
     end if;
 
-    if prefix /= "" then
-      write(full_msg, prefix & " ");
-    end if;
-
-    write(full_msg, msg);
+    log(logger, msg, vunit_log_level, path_offset => 4);
 
-    if suffix /= "" then
-      write(full_msg, " " & suffix);
+    if reenable_display_handler then
+      set_log_handlers(osvvm, (display_handler, file_log_handler));
     end if;
-
-    log(logger, msg, vunit_log_level, path_offset => 4);
   end;
 
 end package body;
diff --git a/examples/vhdl/osvvm_log_integration/osvvm_integration/vunit_to_osvvm_common_log_pkg-body.vhd b/examples/vhdl/osvvm_log_integration/osvvm_integration/vunit_to_osvvm_common_log_pkg-body.vhd
@@ -7,22 +7,101 @@
 use work.ansi_pkg.all;
 use work.log_levels_pkg.all;
 use work.string_ops.upper;
+use work.integer_vector_ptr_pkg.all;
+use work.path.all;
+use work.run_types_pkg.all;
+use work.dict_pkg.all;
 
 library osvvm;
 use osvvm.AlertLogPkg.all;
+use osvvm.TranscriptPkg.all;
 
 package body common_log_pkg is
+  constant is_original_pkg : boolean := false;
+
+  constant mode : integer_vector_ptr_t := new_integer_vector_ptr(1);
+  constant init_mode : natural := 0;
+  constant stdout_mode : natural := 1;
+  constant file_mode : natural := 2;
+  constant mirror_mode : natural := 3;
+
+  constant last_sequence_number : integer_vector_ptr_t := new_integer_vector_ptr(2, value => -1);
+  constant stdout_idx : natural := 0;
+  constant file_idx : natural := 1;
 
   procedure write_to_log(
     file log_destination : text;
-    msg : string := "";
+    log_destination_path : string := no_string;
+    msg : string := no_string;
     log_time : time := no_time;
-    log_level : string := "";
-    log_source_name : string := "";
+    log_level : string := no_string;
+    log_source_name : string := no_string;
     str_1, str_2, str_3, str_4, str_5, str_6, str_7, str_8, str_9, str_10 : string := "";
-    val_1, val_2, val_3, val_4, val_5, val_6, val_7, val_8, val_9, val_10 : integer := no_val
+    int_1, int_2, int_3, int_4, int_5, int_6, int_7, int_8, int_9, int_10 : integer := 0;
+    bool_1, bool_2, bool_3, bool_4, bool_5, bool_6, bool_7, bool_8, bool_9, bool_10 : boolean := false
   ) is
+    alias sequence_number is int_3;
+    constant stdout : boolean := log_destination_path = no_string;
+    constant current_mode : natural range init_mode to mirror_mode := get(mode, 0);
+    variable reopen_transcript : boolean := false;
+    variable enable_mirror : boolean := false;
   begin
+    if stdout and (get(last_sequence_number, stdout_idx) = sequence_number) then
+      return;
+    end if;
+
+    if not stdout and (get(last_sequence_number, file_idx) = sequence_number) then
+      return;
+    end if;
+
+    case current_mode is
+      when init_mode =>
+        -- Close any open transcript and make sure that the transcript is in the output
+        -- path such that several threads do not share the same file
+        TranscriptClose;
+        SetTranscriptMirror(false);
+        if stdout then
+          set(last_sequence_number, stdout_idx, sequence_number);
+          set(mode, 0, stdout_mode);
+        else
+          TranscriptOpen(join(get_string(run_db, "output_path"), "osvvm_transcript.txt"));
+          set(last_sequence_number, file_idx, sequence_number);
+          set(mode, 0, file_mode);
+        end if;
+      when stdout_mode =>
+        if not stdout then
+          TranscriptOpen(join(get_string(run_db, "output_path"), "osvvm_transcript.txt"));
+          set(last_sequence_number, file_idx, sequence_number);
+          set(mode, 0, mirror_mode);
+          if get(last_sequence_number, stdout_idx) /= sequence_number then
+            SetTranscriptMirror;
+            set(last_sequence_number, stdout_idx, sequence_number);
+          else
+            enable_mirror := true;
+          end if;
+        else
+          set(last_sequence_number, stdout_idx, sequence_number);
+        end if;
+      when file_mode =>
+        if stdout then
+          set(last_sequence_number, stdout_idx, sequence_number);
+          set(mode, 0, mirror_mode);
+
+          if get(last_sequence_number, file_idx) /= sequence_number then
+            SetTranscriptMirror;
+            set(last_sequence_number, file_idx, sequence_number);
+          else
+            TranscriptClose;
+            reopen_transcript := true;
+          end if;
+        else
+          set(last_sequence_number, file_idx, sequence_number);
+        end if;
+      when mirror_mode =>
+        set(last_sequence_number, stdout_idx, sequence_number);
+        set(last_sequence_number, file_idx, sequence_number);
+    end case;
+
     if (log_level = "warning") or (log_level = "error") or (log_level = "failure") then
       Alert(GetAlertLogID(log_source_name), msg, AlertType'value(upper(log_level)));
     elsif (log_level = "debug") then
@@ -32,6 +111,15 @@ package body common_log_pkg is
     else
       osvvm.AlertLogPkg.Log(GetAlertLogID(log_source_name), msg);
     end if;
+
+    if reopen_transcript then
+      TranscriptOpen(join(get_string(run_db, "output_path"), "osvvm_transcript.txt"), append_mode);
+      SetTranscriptMirror;
+    end if;
+
+    if enable_mirror then
+      SetTranscriptMirror;
+    end if;
   end;
 
 end package body;
diff --git a/examples/vhdl/osvvm_log_integration/tb_example.vhd b/examples/vhdl/osvvm_log_integration/tb_example.vhd
@@ -9,6 +9,9 @@ context vunit_lib.vunit_context;
 
 library osvvm;
 use osvvm.AlertLogPkg.all;
+use osvvm.TranscriptPkg.TranscriptOpen;
+use osvvm.TranscriptPkg.TranscriptClose;
+use osvvm.TranscriptPkg.SetTranscriptMirror;
 
 library ieee;
 use ieee.std_logic_1164.all;
@@ -32,14 +35,27 @@ begin
     constant id : AlertLogIDType := GetAlertLogID("An OSVVM ID");
     constant parent_id : AlertLogIDType := GetAlertLogID("OSVVM parent");
     constant child_id : AlertLogIDType := GetAlertLogID("OSVVM child", parent_id);
+    constant logger_file_handler : log_handler_t := new_log_handler(join(output_path(runner_cfg), "logger.txt"));
+    constant logger_log_handlers : log_handler_vec_t(0 to 1) := (display_handler, logger_file_handler);
+    constant parent_logger_file_handler : log_handler_t := new_log_handler(join(output_path(runner_cfg), "parent_logger.txt"));
+    constant parent_logger_log_handlers : log_handler_vec_t(0 to 1) := (display_handler, parent_logger_file_handler);
   begin
     test_runner_setup(runner, runner_cfg);
+
     set_stop_level(failure);
+    set_log_handlers(logger, logger_log_handlers);
+    show_all(logger, logger_file_handler);
+    set_log_handlers(parent_logger, parent_logger_log_handlers);
+    show_all(parent_logger, parent_logger_file_handler);
+
+    TranscriptOpen(join(output_path(runner_cfg), "transcript.txt"));
+    SetTranscriptMirror;
 
     if use_osvvm_log then
-      print(LF & "-------------------------------------------------------------------");
-      print("This is what VUnit log messages look like when piped through OSVVM:");
-      print("-------------------------------------------------------------------" & LF);
+      print(LF & "-----------------------------------------------------------------------------");
+      print("This is what VUnit log messages look like when piped through OSVVM.");
+      print("All file entries are saved in ""osvvm_transcript.txt"" in the test output path.");
+      print("-----------------------------------------------------------------------------" & LF);
     else
       print(LF & "------------------------------------------------------------------------");
       print("This is what standard VUnit log messages look like. Call run.py");
@@ -53,7 +69,10 @@ begin
 
     if use_vunit_log then
       print(LF & "-------------------------------------------------------------------");
-      print("This is what OSVVM log messages look like when piped through VUnit:");
+      print("This is what OSVVM log messages look like when piped through VUnit.");
+      print("OSVVM IDs are placed under an OSVVM namespace to avoid name");
+      print("collisions. The transcript file name is maintained but is placed");
+      print("in the test output path");
       print("-------------------------------------------------------------------" & LF);
     else
       print(LF & "------------------------------------------------------------------------");

diff --git a/vunit/vhdl/logging/src/common_log_pkg-body.vhd b/vunit/vhdl/logging/src/common_log_pkg-body.vhd
@@ -9,24 +9,27 @@ use work.log_levels_pkg.all;
 use work.string_ops.upper;
 
 package body common_log_pkg is
+  constant is_original_pkg : boolean := true;
 
   procedure write_to_log(
     file log_destination : text;
-    msg : string := "";
+    log_destination_path : string := no_string;
+    msg : string := no_string;
     log_time : time := no_time;
-    log_level : string := "";
-    log_source_name : string := "";
+    log_level : string := no_string;
+    log_source_name : string := no_string;
     str_1, str_2, str_3, str_4, str_5, str_6, str_7, str_8, str_9, str_10 : string := "";
-    val_1, val_2, val_3, val_4, val_5, val_6, val_7, val_8, val_9, val_10 : integer := no_val
+    int_1, int_2, int_3, int_4, int_5, int_6, int_7, int_8, int_9, int_10 : integer := 0;
+    bool_1, bool_2, bool_3, bool_4, bool_5, bool_6, bool_7, bool_8, bool_9, bool_10 : boolean := false
   ) is
 
     alias file_name is str_1;
 
-    alias format is val_1;
-    alias line_num is val_2;
-    alias sequence_number is val_3;
-    alias use_color is val_4;
-    alias get_max_logger_name_length is val_5;
+    alias format is int_1;
+    alias line_num is int_2;
+    alias sequence_number is int_3;
+    alias use_color is int_4;
+    alias get_max_logger_name_length is int_5;
 
     constant max_time_str : string := time'image(1 sec);
     constant max_time_length : natural := max_time_str'length;