Migrate to structured logging

[SOF3]

Description

Currently log messages interpolate variables into the middle of a message, e.g.

[12:34:56.789] [Server thread/INFO]: SOFe[/10.2.3.4:56789] logged in with entity id 3 at (4, 5, 6, world)

This is difficult for both humans and computers to read. It would be easier to parse if the message is formatted with space-separated values

time=12:34:56.789 thread="Server thread" level=info message="logged in" name=SOFe ip=10.2.3.4 port=56789 entityId=3 position=4,5,6 world=world

or JSON-formatted lines, subject to user configuration.

On a TTY console, log messages can be formatted similar to logrus, such that keys have a separate color and are more human-friendly, e.g.

This can be backwards compatible with the current API:

$logger->info("logged in", name: "SOFe", ip: "10.2.3.4", port: 56789, entityId: 3, position: "4,5,6", world: "world");

alternatively, using arrays:

$logger->info("logged in", ["name" => "SOFe", "ip" => "10.2.3.4", "port" => 56789, "entityId" => 3, "position" => "4,5,6", "world" "world"]);

Unresolved problem: How to enable convenient localization? Ideally, we only want to localize the TTY output but not the SSV/JSON output since those should be more easily grepable.

[SOF3]

Furthermore, I am working on slv, an interactive structured log viewer to group and auto classify log entries. Some ideas to borrow:

• We can classify log entries based on the combination of keys
• Users may want to filter away some log entries based on certain key values, e.g. they don't want to see anything from DevTools so they want to specify {key: plugin, value: "DevTools", rule: NotEqual} in their logging config.

[SOF3]

Currently the major challenge with configuring loggers is the cyclic dependency between config loading and logger initialization. There are two approaches to solve this issue

• config loading doesn't take a lot of time; maybe we don't need to log "loading pocketmine.yml" at all?
• what about we just separate logging format config from pocketmine.yml

[dktapps]

Currently the major challenge with configuring loggers is the cyclic dependency between config loading and logger initialization. There are two approaches to solve this issue

• config loading doesn't take a lot of time; maybe we don't need to log "loading pocketmine.yml" at all?
• what about we just separate logging format config from pocketmine.yml

There isn't a direct circular reference. The log message is emitted by Server, not Config.