Logger

[mobius-eng]

Will a logger be a part of stdlib? For my projects I've written this logger

https://gist.github.com/mobius-eng/16d2a309f80eeee25547d6725334a1a1

It is intended to be used through macros: if the logging level is set to

#define LOGERROR

this statement will produce no code

 _DEBUG_('TIMESTEP: Calling STEPLSODA')

I would like to contribute it to stdlib if there is a scope for it.

[milancurcic]

Hi @mobius-eng, according to our current agreed-upon scope, logging does belong in stdlib. I personally am very interested in it.

Take a look at the workflow. You can go ahead and propose the API (step 2), and we'll discuss it. In the API proposal, please also list prior art for logging in Fortran (I'm aware of flogging), and also some examples of how other languages do it (e.g. Python, MATLAB, Julia, Rust).

[mobius-eng]

I looked at flogging. I am also familiar with the Julia's logger. There is one important and one not-so-important decisions that need to be made:

1. (IMPORTANT) flogger uses local variable to keep the information about the logger (most importantly, where to log to). In my implementation, I used private global variable initialized by default with ERROR_UNIT. Which one to use? See below for trade offs.

2. (NOT-SO-IMPORTANT) Use of colors. flogger and Julia's logger use colors. I didn't add this to my logger.

Local vs global local variable

Local is generally better, we know it. However, global logger state allows individual modules not to think about where to log to, but rather use program's log output. Are there use cases where a program might need multiple logger outputs? We can also have a hybrid system with the global logger used by default and local loggers setup on request.

Colors

Julia (and Python and R) are meant to be used interactively. Thus, colors play an important role with the output to the terminal. By contrast, Fortran programs are meant to be run in the "batch mode" with log going to the file. Colors seem to work on most terminals, but I am not that familiar with the exact functionality and where it can break.

And one more thing... Asynchronous IO. My thinking is to avoid it as writing out the log might be the last thing the program can do before crashing. In this case the output might not reach the file if async is enabled. Thoughts?

[jvdp1]

Are there use cases where a program might need multiple logger outputs?

Sometimes I use multiple logger outputs. e.g, for large programs with multiple phases.
Also, I would suggest to use local variables, to avoid possible clashs with user-defined variables.

Colors are not needed for me.

[aradi]

As for colors: I am fine, as long as they are optional. I think most people typically run Fortran programs in batch systems with redirected output. Seeing a lot of color control sequences when opening the output files is rather disturbing...

[nncarlson]

Are there use cases where a program might need multiple logger outputs?

Sometimes I use multiple logger outputs. e.g, for large programs with multiple phases.

Same here. In my case that comes to mind the "phases" are multiple concurrent (but independent) instances of some solver. I think it is generally a bad idea to use global variables in any code that aims to be used as a library procedure, for doing so will limit it to single-threaded contexts.

[nncarlson]

We can also have a hybrid system with the global logger used by default and local loggers setup on request.

This is the approach I've taken in my own logger and timer modules and I think it works pretty well. For example, a local logger might be an instance of a DT that holds the local variable(s) that need to be hauled around (which is a nuisance as @mobius-eng pointed out), with the DT perhaps something like this

type logger
  integer :: unit
contains
  procedure :: message
end type

And the global logger is simply module procedures that operate on a private module variable (a singleton):

type(logger) :: global_logger ! private module variable
public :: log_message
...
subroutine log_message(...)
  call global_logger%message(...)
end subroutine

I know there's a real push to avoid OO stuff (even DT) at the low level and build OO stuff on top of that. This flips things around in this case.

[jvdp1]

This is the approach I've taken in my own logger and timer modules and I think it works pretty well. For example, a local logger might be an instance of a DT that holds the local variable(s) that need to be hauled around (which is a nuisance as @mobius-eng pointed out), with the DT perhaps something like this

type logger
  integer :: unit
contains
  procedure :: message
end type

And the global logger is simply module procedures that operate on a private module variable (a singleton):

type(logger) :: global_logger ! private module variable
public :: log_message
...
subroutine log_message(...)
  call global_logger%message(...)
end subroutine

I know there's a real push to avoid OO stuff (even DT) at the low level and build OO stuff on top of that. This flips things around in this case.

I would think this is a manageagle solution. For the low-level, DT would be hidden to the user, and accessible with public procedures. In this sense, there would be no global variables. For an higher level, DT would be accessible by the user.

[certik]

@nncarlson's design seems fine to me.

[jvdp1]

I think that this could move to the step 2 of the workflow: API proposal.
@mobius-eng would you like to open a PR with an initial implementation to discuss the API?

[mobius-eng]

Yes. Never done the PR thing before. Just need to figure out the technicalities.

[urbanjost]

I have my own journal/logger/unit test routines, but they are in need of an update. I find it very useful to use class(*) and some optional variables to simplify putting variable values into the messages without having to do internal writes first. If class(*) is not supported by enough variables I had an older generic routine that optionally did not generate a line terminator that let you compose a longer message with multiple values. Just to give a sense of what I mean I included an example program that uses the same concept. It works quite nicely for standard scalar types and is easily extended for other types. So is something using class(*) in the running?

module m_debug
use, intrinsic :: iso_fortran_env, only : ERROR_UNIT,OUTPUT_UNIT 
implicit none
private
public stderr
contains
subroutine stderr(msg, generic0, generic1, generic2, generic3, generic4, generic5, generic6, generic7, generic8, generic9)
implicit none
class(*),intent(in),optional :: msg
class(*),intent(in),optional :: generic0, generic1, generic2, generic3, generic4
class(*),intent(in),optional :: generic5, generic6, generic7, generic8, generic9
integer                      :: ios
   if(present(msg))     call print_generic(msg)
   if(present(generic0))call print_generic(generic0)
   if(present(generic1))call print_generic(generic1)
   if(present(generic2))call print_generic(generic2)
   if(present(generic3))call print_generic(generic3)
   if(present(generic4))call print_generic(generic4)
   if(present(generic5))call print_generic(generic5)
   if(present(generic6))call print_generic(generic6)
   if(present(generic7))call print_generic(generic7)
   if(present(generic8))call print_generic(generic8)
   if(present(generic9))call print_generic(generic9)
   write(error_unit,'(a)',iostat=ios)
   flush(unit=output_unit,iostat=ios)
   flush(unit=error_unit,iostat=ios)
contains
!===================================================================================================================================
subroutine print_generic(generic)
!use, intrinsic :: iso_fortran_env, only : int8, int16, int32, biggest=>int64, real32, real64, dp=>real128
use,intrinsic :: iso_fortran_env, only : int8, int16, int32, int64, real32, real64, real128
class(*),intent(in) :: generic
   write(error_unit,'(1x)',advance='no')
   select type(generic)
      type is (integer(kind=int8));     write(error_unit,'(i0)',advance='no') generic
      type is (integer(kind=int16));    write(error_unit,'(i0)',advance='no') generic
      type is (integer(kind=int32));    write(error_unit,'(i0)',advance='no') generic
      type is (integer(kind=int64));    write(error_unit,'(i0)',advance='no') generic
      type is (real(kind=real32));      write(error_unit,'(1pg0)',advance='no') generic
      type is (real(kind=real64));      write(error_unit,'(1pg0)',advance='no') generic
      type is (real(kind=real128));     write(error_unit,'(1pg0)',advance='no') generic
      type is (logical);                write(error_unit,'(1l)',advance='no') generic
      type is (character(len=*));       write(error_unit,'(a)',advance='no') trim(generic)
      type is (complex);                write(error_unit,'("(",1pg0,",",1pg0,")")',advance='no') generic
      class default
         stop 'unknown type in *print_generic*'
   end select
end subroutine print_generic
end subroutine stderr
end module m_debug
program demo_stderr
use M_debug, only: stderr
implicit none
integer :: least=10, most=999, ival=-10
    call stderr('A simple message')
    call stderr('error: RVALUE=', 3.0/4.0, 'IVALUE=', 123456789, 'LVALUE=', .true.)
    call stderr('error: value',ival,'should be between',least,'and',most)
end program demo_stderr

[wclodius2]

In #227 I have proposed a fairly comprehensive API for a global logging system, but it can be adapted to provide both local and global logging capabilities using a derived type as suggested by @nncarlson. It got some favorable comments at the monthly meeting so I suspect it will become part of STDLIB. But before I submit a PR for a more formal API document, I would like some more feedback on what I have proposed. In summary:

This module defines procedures and constants to be used for reporting
of errors and other information. The reports normally go to formatted
output units represented by the array of logical unit, LOG_UNITS. An
arbitrary number of log units can be open at a time. LOG_UNITS may
be associated with files dedicated to STDLIB_LOGGER or may be
associated with independently opened files. If LOG_UNITS is empty
then the output goes to OUTPUT_UNIT of ISO_FORTRAN_ENV. Otherwise
reports go to OUTPUT_UNIT only if it has been explicitly added to
LOG_UNITS with ADD_LOG_UNIT. It currently provides no capability to
colorize output.

The logger has the options to:

• change which units receive the log messages;
• report which units receive the log messages;
• precede messages by a blank line;
• precede messages by a time stamp of the form
  yyyy-mm-dd hh:mm:ss.sss;
• precede messages with the names of a module and procedure;
• follow a message with the STAT and ERRMSG of the error report
  that prompted the log message;
• follow a message with the IOSTAT and IOMSG of the I/O error
  report that prompted the log message;
• label a message with one of 'INFORMATION: ', 'WARNING: ',
  'ERROR: ', or 'I/O ERROR: ';
• indent subsequent lines of the messages; and
• format the text to fit within a maximum column width.