New (only?) extensible logging package for Emacs

New (only?) extensible logging package for Emacs

[Matúš Goljer]

Hello.

Recently a need came to have an extensible and configurable package for
logging in Emacs.  As far as I know there's no such thing in Emacs
itself or the broader community.

Python has logging and Java has log4j, but there's nothing of the sort
for Emacs.  While Emacs is mostly interactive, there are many Elisp
tools out there working as batch tools (linters, language server,
package management tools...) that would benefit from a better logging
experience.

But even packages running inside Emacs could use a logging framework
where users can turn debugging on and off while investigating issues.
Currently many popular packages include `PACKAGE-debug` switches and
their own implementation of "selective logging".

I've created a package `lgr` currently available on github
https://github.com/Fuco1/emacs-lgr with the intention of including it in
Emacs proper (therefore keeping external dependencies out of it).

This is a request for feedback I guess :)

-- 
Best regards,
  Matúš Goljer

Re: New (only?) extensible logging package for Emacs

[Thomas Koch]

Such a logging library might also be helpful in interactive use when debugging problems that cause Emacs to freeze or (god forbid) to segfault. In that case I could still find log messages outside of Emacs.

Furthermore a standard logging library would help to fine-tune logging levels during debugging work for different parts of Emacs without digging how (or whether) each part allows such tuning.

In my case I'd love to feed logs into journald.

Re: New (only?) extensible logging package for Emacs

[Ihor Radchenko]

Matúš Goljer <matus.goljer@gmail.com> writes:

> I've created a package `lgr` currently available on github
> https://github.com/Fuco1/emacs-lgr with the intention of including it in
> Emacs proper (therefore keeping external dependencies out of it).

+1 for a unified interface to logging.

Some observations:

1. `lgr--def-level' does not provide a docstring
2. It would be nice to integrate the appenders with built-in warning
   system.

-- 
Ihor Radchenko // yantar92,
Org mode contributor,
Learn more about Org mode at <https://orgmode.org/>.
Support Org development at <https://liberapay.com/org-mode>,
or support my work at <https://liberapay.com/yantar92>

Re: New (only?) extensible logging package for Emacs

[Matúš Goljer]

> Such a logging library might also be helpful in interactive use when debugging problems that cause Emacs to freeze or (god forbid) to segfault. In that case I could still find log messages outside of Emacs.

This is a good point and in fact I just used it in this way today.  I'm
debugging some async code (via emacs-async) package and as you might
imagine, it's rather complicated.  Logging to files made it much
simpler, and I only had to add one line (the file appender)

> In my case I'd love to feed logs into journald.

What unit would it log to though?  Or can journald also ingest logs for
non-unit source?  Since I imagine not many people run Emacs as a systemd
service.  I'm not very knowledgable about this stuff :grin:

Ihor also mentioned appender to log into *warnings*... so there's
definitely a lot of potential destinations to be handled out of the box.

-- 
Best regards,
  Matúš Goljer

Re: New (only?) extensible logging package for Emacs

[Ruijie Yu via Emacs development discussions.]

Matúš Goljer <matus.goljer@gmail.com> writes:

> [...]
>> In my case I'd love to feed logs into journald.
>
> What unit would it log to though?  Or can journald also ingest logs for
> non-unit source?  Since I imagine not many people run Emacs as a systemd
> service.  I'm not very knowledgable about this stuff :grin:

IIUC, Emacs may connect(2) to the unix socket "/dev/log" on systmed
systems for journald integration.

--
Best,


RY

Re: New (only?) extensible logging package for Emacs

[Matúš Goljer]

>>> In my case I'd love to feed logs into journald.
>>
>> What unit would it log to though?  Or can journald also ingest logs for
>> non-unit source?  Since I imagine not many people run Emacs as a systemd
>> service.  I'm not very knowledgable about this stuff :grin:
>
> IIUC, Emacs may connect(2) to the unix socket "/dev/log" on systmed
> systems for journald integration.
>

Cool, I just tried

  echo 'test' | nc -u -U /dev/log

and it pops up in `journalctl`.  I'll add an appender for this, should
be somewhat simple.

-- 
Best regards,
  Matúš Goljer

Re: New (only?) extensible logging package for Emacs

[Matúš Goljer]

>  Ihor Radchenko <yantar92@posteo.net> writes:
>  Just take a look at warnings.el It is just 400LOC.
>  Ideally, the design of your package should use the existing conventions
>  on warning levels. Or you may even modify warnings.el to make use of
>  your package - it would be nice if existing calls of `warn' could be
>  logged to file, for example.

The levels basically correspond, but I can rename them to be the same as
in warnings.el

:emergency = fatal
:error     = error
:warning   = warn
   ...     = info
:debug     = debug
   ...     = trace

In Emacs, I guess info is basically `message`, so maybe this "warnings"
appender should `message` info level events.  Trace could go to debug or
be ignored.

I like to have more than one level of "debug", in some situations you
want to only see some narrow part of the code at even higher level.

-- 
Best regards,
  Matúš Goljer

Re: New (only?) extensible logging package for Emacs

[Eli Zaretskii]

> From: Matúš Goljer <matus.goljer@gmail.com>
> Cc: emacs-devel@gnu.org
> Date: Mon, 13 Mar 2023 14:28:31 +0100
> 
> :emergency = fatal
> :error     = error
> :warning   = warn
>    ...     = info
> :debug     = debug
>    ...     = trace
> 
> In Emacs, I guess info is basically `message`, so maybe this "warnings"
> appender should `message` info level events.  Trace could go to debug or
> be ignored.
> 
> I like to have more than one level of "debug", in some situations you
> want to only see some narrow part of the code at even higher level.

I hope the log will end up in Emacs buffers, or at least that there
will be an option to do so.  While other logging frameworks are
designed to work with programs that leave log files, in Emacs it is
customary to have the log in a buffer (and then the user can save that
buffer if needed).  Direct writes of debug info to files is rare in
Emacs (see open-dribble-file and open-termscript as about the only
examples I'm aware of).

Thanks.

Re: New (only?) extensible logging package for Emacs

[Thomas Koch]

Besides the backwards compatible /dev/log, journald also listens to a more featureful native logging API:
https://systemd.io/JOURNAL_NATIVE_PROTOCOL/

As I understand, the journald API allows logs messages with more attached information, e.g. origin of the message in the source code, a message ID or a link to documentation.

Re: New (only?) extensible logging package for Emacs

[Matúš Goljer]

Eli Zaretskii <eliz@gnu.org> writes:

>> From: Matúš Goljer <matus.goljer@gmail.com>
>> Cc: emacs-devel@gnu.org
>> Date: Mon, 13 Mar 2023 14:28:31 +0100
>> 
>> :emergency = fatal
>> :error     = error
>> :warning   = warn
>>    ...     = info
>> :debug     = debug
>>    ...     = trace
>> 
>> In Emacs, I guess info is basically `message`, so maybe this "warnings"
>> appender should `message` info level events.  Trace could go to debug or
>> be ignored.
>> 
>> I like to have more than one level of "debug", in some situations you
>> want to only see some narrow part of the code at even higher level.
>
> I hope the log will end up in Emacs buffers, or at least that there
> will be an option to do so.  While other logging frameworks are
> designed to work with programs that leave log files, in Emacs it is
> customary to have the log in a buffer (and then the user can save that
> buffer if needed).

If you mean the "info" level logs I said we can log with message (the
function), they would end up in *Messages* but of course can go to some
other separate buffer.

I will also add a generic buffer appender where you can give it
buffer-or-name and logs will go there.

> Direct writes of debug info to files is rare in Emacs (see
> open-dribble-file and open-termscript as about the only examples I'm
> aware of).

My most immediate use-case for this package is the development of Elsa,
where I also develop a Language Server for LSP and use emacs-async with
async workers.  Having flexible appending logic in these subprocesses
allows me to use the single interface (say lgr-info) to dispatch
messages to:

- client via LSP notifications
- parent process via async-send
- CLI when running elsa from terminal

All just by configuring the loggers at the start of each process.

For use inside Emacs session for debugging etc, a buffer seems like an
obvious log destination.

-- 
Best regards,
  Matúš Goljer

Re: New (only?) extensible logging package for Emacs

[Eli Zaretskii]

> From: Matúš Goljer <matus.goljer@gmail.com>
> Cc: yantar92@posteo.net, emacs-devel@gnu.org
> Date: Mon, 13 Mar 2023 16:59:49 +0100
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> > I hope the log will end up in Emacs buffers, or at least that there
> > will be an option to do so.  While other logging frameworks are
> > designed to work with programs that leave log files, in Emacs it is
> > customary to have the log in a buffer (and then the user can save that
> > buffer if needed).
> 
> If you mean the "info" level logs I said we can log with message (the
> function), they would end up in *Messages* but of course can go to some
> other separate buffer.

*Messages* is not the best idea: in any long-running session, it is
full of uninteresting messages, and also wraps around after
message-log-max messages (and the default value of message-log-max is
quite low for serious logging).

So yes, I think these logs should go to a separate buffer.

> My most immediate use-case for this package is the development of Elsa,
> where I also develop a Language Server for LSP and use emacs-async with
> async workers.  Having flexible appending logic in these subprocesses
> allows me to use the single interface (say lgr-info) to dispatch
> messages to:
> 
> - client via LSP notifications
> - parent process via async-send
> - CLI when running elsa from terminal
> 
> All just by configuring the loggers at the start of each process.
> 
> For use inside Emacs session for debugging etc, a buffer seems like an
> obvious log destination.

Yes.  Moreover, saving a buffer to a file, either from time to time or
based on some other trigger, is trivial.

Re: New (only?) extensible logging package for Emacs

[Matúš Goljer]

Thomas Koch <thomas@koch.ro> writes:

> Besides the backwards compatible /dev/log, journald also listens to a more featureful native logging API:
> https://systemd.io/JOURNAL_NATIVE_PROTOCOL/
>
> As I understand, the journald API allows logs messages with more attached information, e.g. origin of the message in the source code, a message ID or a link to documentation.

Interesting, and pretty simple.  I've implemented the journald appender,
you can review it on github.

Mar 13 18:21:55 parmenides emacs-lgr[516715]: [2023-03-13T17:21:55+0000] (FATAL) local.journald - Fatal log to journald nil
Mar 13 18:21:56 parmenides emacs-lgr[516715]: [2023-03-13T17:21:56+0000] (ERROR) local.journald - Error log to journald nil
Mar 13 18:21:56 parmenides emacs-lgr[516715]: [2023-03-13T17:21:56+0000] (WARN) local.journald - Warn log to journald nil
Mar 13 18:21:57 parmenides emacs-lgr[516715]: [2023-03-13T17:21:57+0000] (INFO) local.journald - Info log to journald nil
Mar 13 18:21:57 parmenides emacs-lgr[516715]: [2023-03-13T17:21:57+0000] (DEBUG) local.journald - Debug log to journald nil
Mar 13 18:21:58 parmenides emacs-lgr[516715]: [2023-03-13T17:21:58+0000] (TRACE) local.journald - Trace log to journald nil

(the timestamps are superfluous but can be removed obviously, I just
used the default message layout)

Some of the meta fields (CODE_*) are also supported but it's super easy
to add more.

-- 
Best regards,
  Matúš Goljer

Re: New (only?) extensible logging package for Emacs

[Matúš Goljer]

> Eli Zaretskii <eliz@gnu.org> writes:
>
> *Messages* is not the best idea: in any long-running session, it is
> full of uninteresting messages, and also wraps around after
> message-log-max messages (and the default value of message-log-max is
> quite low for serious logging).
>
> So yes, I think these logs should go to a separate buffer.

I've added a generic buffer appender where you pass a buffer (or name)
to initialize it and it will log there.

The beauty of having the "scaffolding" is that adding these destinations
is rather straight forward :grin:

-- 
Best regards,
  Matúš Goljer

RE: [External] : Re: New (only?) extensible logging package for Emacs

[Drew Adams]

Not what you're looking for, I guess, and not really for general logging, but there's also `open-dribble-file'.

Re: New (only?) extensible logging package for Emacs

[Björn Bidar]

Matúš Goljer <matus.goljer@gmail.com> writes:

>> Such a logging library might also be helpful in interactive use when
>> debugging problems that cause Emacs to freeze or (god forbid) to
>> segfault. In that case I could still find log messages outside of
>> Emacs.
>
> This is a good point and in fact I just used it in this way today.  I'm
> debugging some async code (via emacs-async) package and as you might
> imagine, it's rather complicated.  Logging to files made it much
> simpler, and I only had to add one line (the file appender)
>
>> In my case I'd love to feed logs into journald.
>
> What unit would it log to though?  Or can journald also ingest logs for
> non-unit source?  Since I imagine not many people run Emacs as a systemd
> service.  I'm not very knowledgable about this stuff :grin:

Slightly offtopic but  Emacs includes a systemd unit and can can notify
systemd when startup finishes or shutdown begins.

When logging into journal deciphering from which package by adding meta
data to the logs could be very handy.