loghandler log level issue

[sjoerss]

Hello!

I am testing VUnit for some weeks and I would like to say thank you for this great framework to all contributors.

In my test bench I create a logfile to save logger messages additionally to the display_handler output.
If I understand the documentation right, all log handlers show these log levels by default:
info, warning, error, failure
and the others are not shown be default.

When I create a new file handler for my log file with

impure function new_log_handler(file_name : string; format : log_format_t := verbose; use_color : boolean := false) return log_handler_t;

and then
set_log_handlers(get_logger("my_file_logger"), (display_handler, filehandler);

no log level is shown by default.

If I use the command
show(get_logger("my_file_logger"), my_file_handler, info);
then ALL log levels are enabled, not just info.

When I use
hide_all(get_logger("my_file_logger"), my_file_handler);
and followed for example by
show(get_logger("my_file_logger"), my_file_handler, info);
then the desired log level is enabled only.

Is this behavior intended?
Maybe I do something wrong?

regards,
Sebastian

[LarsAsplund]

I see that there are a number of issues here:

1. Our documentation says that there are two log handlers by default, one for display and one for file. As you noticed, that is not the case but I think it might have been so a long time ago. That is a typo that needs to be updated.
2. Additionally, the user guide should be updated to include more instructions on how to add a new log handler. I guess you figured it out from the API documentation but it could be made more explicit.
3. The display handler shows info, warning, error, and failure by default to avoid flooding the user with more info than they can keep up with. File logs, however, are typically used after the completion of a simulation and usually contain more details
4. The behavior you experience is a bug and the workaround you found is the correct one. I wouldn't mind keeping the default visibility = hidden for all log levels. However, there are three reasons why I'm leaning towards making the default visibility = shown
   • File logs usually contain all details
   • Users who wanted something else have most likely already found your workaround, so they will not be affected by such a change
   • There may be users who postprocess the log and rely on it containing everything. By mistake they could have achieved "everything" without actually doing a show_all call. Those users will lose information if the default becomes all hidden. That could lead to silent errors

This is not a critical bug so I will probably exclude it from release v4.7 which is long overdue.

[sjoerss]

Thanks a lot for the fast response!
I can understand the thoughts on this and I will continue to use the workaround.

best regards
Sebastian

[pintert3]

Is there any new info on the issue of the file handlers and display handlers? Does it mean at the moment we have to log to two different loggers?

[umarcor]

@pintert3 this issue is about the "default log level" of each of the handlers, because the "display" handlers and the "file" handlers do have different defaults. However, that is unrelated to being able to call "info" once only and have it logged to both handlers at the same time.

For instance, this is what I use to log at the same time to the display/terminal and to a CSV file (which I can then post-process using VUnit's post-hook in Python to e.g. compute latencies and throughputs from the message timestamps):

...
  constant logger : logger_t := get_logger("tb");
  constant file_handler : log_handler_t := new_log_handler(
    output_path(runner_cfg) & "log.csv",
    format => csv,
    use_color => false
  );

begin

  clk <= not clk after clk_period/2;
  rstn <= not rst;

  main: process
  begin
    test_runner_setup(runner, runner_cfg);
    while test_suite loop
      if run("test") then
        set_log_handlers(logger, (display_handler, file_handler));
        show_all(logger, file_handler);
        show_all(logger, display_handler);

        rst <= '1';
        wait for 15*clk_period;
        rst <= '0';
        info(logger, "Init test");
...

[pintert3]

I see, thanks for that.