ERL-1416: Add option to disable logger_proxy

[OTP-Maintainer]

Original reporter: seriyps Affected versions: OTP-21.0, OTP-22.0, OTP-23.0 Component: kernel Migrated from: https://bugs.erlang.org/browse/ERL-1416

---

We recently started a migration from custom solution to {{logger}} for our logs and were surprised when we noticed that some of our log messages were logged twice.

After some discovery work we found that it's because we are using Erlang cluster and do a lots of {{rpc:call}} between nodes (Klarna, KRED). In this scenario all the logs that are emitted from {{logger:log}} calls on remote node were logged on a remote node and then forwarded to the node that originated the {{rpc}} call via {{logger_proxy}} and logget there again.

Reading the docs, it seems an interesting feature and aligns well with the way group leaders and IO in general works in Erlang, but doesn't fit our previous logging model: all the logs are supposed to be logged on the node where {{logger:log}} is called.

We managed to find a workaround for that by implementing filter that is opposite of {{logger_filters:remote_gl}}, but the messages are still forwarded from remote node to local, creating substantial amount of inter-node traffic, for them to be discarded later and there seem to be no way to disable this, it's hardcoded:
 [https://github.com/erlang/otp/blob/9402968657925a1e82582399ab2c9be4ce4f01e5/lib/kernel/src/logger.erl#L1078-L1083]

 So, what I'm interested in is to have some way to disable {{logger_proxy}} or to make it more flexible (eg, make it a regular logger handler, so it could be guarded with filters / log levels or removed entirely).

[OTP-Maintainer]

lukas said:

Hello,

One way to do it would be to set the {{gl}} metadata in the logger call to {{node()}}, that would make the call think that it is a node-local call.

[OTP-Maintainer]

seriyps said:

Hi Lukas.

I see how it might work, but that also means that we have to update every log call (or set it via `set_process_metadata`). But, more importantly, it would mean we are lying in our logs?

[OTP-Maintainer]

lukas said:

yeah, it is not an ideal workaround, but at least it is better than having to send all messages over distribution to then discard them.

I think that adding an option to the proxy logger that disables remote logging would make sense.

[OTP-Maintainer]

seriyps said:

May I also use this opportunity to ask: is there any reason why {{logger_proxy}} is not implemented as just another logger handler?

[OTP-Maintainer]

lukas said:

As far as I remember it wasn't done that way because it would not be possible to do and keep backward compatibility. I don't remember the exact details about why that was the case.

[mikpe]

Since this was mentioned in one of our internal channels:

1. Logs using our private logging module (klog) could set gl to avoid the proxy. Alas much code has been converted to use logger directly, so it's not a 100% solution.
2. The reason logs are proxied is because rpc:call forcibly sets the callee's group_leader to the caller. We could change the Funs we rpc:call to start by resetting group_leader, but that would be a lot of work.
3. The newer erpc module does not set group_leader.

The erpc module has other benefits (not hiding throws for one), so I think a better solution is to migrate from old rpc to erpc. (I even created an internal ticket to do that, but didn't prioritize it yet.) @seriyps