Better Support for Structured Logging

[cconger]

Expected Behaviour

Structured Logging messages should not be split between lines. I want my message to appear:

stdout: {"level":"info", "msg":"No module named my-module", "pipe":"stderr", "time":"2019-08-08T01:47:55Z", "context": "this is a contrived long message of more than 256 bytes", "invoker": "cconger", "extra bits": ["there", "are", "so", "many", "things", "on", "this", "error"]}

Current Behaviour

Currently the behavior is to slurp 256 bytes per log line. This can cause long messages like the one above to be split:

stdout: {"level":"info", "msg":"No module named my-module", "pipe":"stderr","time":"2019-08-08T01:47:55Z",  "context": "this is a contrived long message of more than 256 bytes", "invoker": "cconger", "extra bits": ["there", "are", "so", "many", "things", "on

stdout: ", "this", "error"]}

Possible Solution

Use the token Scanner for newlines from bufio instead of a fixed buffer size.

Context

My functions use a structured logging library to have rich structured logging, however due to the log lines being split by the watchdog it becomes tricky to parse the properly when they exceed 256 bytes.

[alexellis]

Hi @cconger,

Thanks for using OpenFaaS. I can see how this would be problematic for your use-case.

The size of 256 should have been configurable. I seem to remember a PR to the classic watchdog or to this one perhaps (it doesn't appear to have been merged).

Would that above also be suitable for what you're looking for? ☝️

What would happen if you were scanning for a new-line, but your function never printed one?

Alex

[alexellis]

/msg: slack

[derek[bot]]

-- Join Slack to connect with the community https://docs.openfaas.com/community

[alexellis]

I also want to make sure you've read the guidelines on contributing, so I'll leave a link here.

[cconger]

Thanks for taking a look!

I should add tests for the case where no newline comes through, but I believe the golang impl has it terminate/flush after 64k but I should verify this by adding some tests.

My feeling is that I would ideally like the logging functionality to be as similar to the wrapped application as possible and have that wrapped app drive the behavior of the output. So having an adaptive buffer that affords line alignment that mirrors the output from the provided app would be ideal. Also by waiting for cmd.Wait() we can be sure that the stdout and stderr have flushed as EOF by the time we log.Fatal, which should flush the remaining buffer even if its below the 64k threshold.

I will review the documents you linked and update my pr tomorrow (PST) with the tests if there is still interest in this avenue.

[cconger]

If the guidelines comment is regarding that I seemingly had a solution before a problem, thats fair but I'm not fixated on this as the approach, if you believe that a larger parameterized buffer is the preferred path I'm happy to go that way. But I believe I gave more clarification into my goals of having the underlying application be the driver for formatting log files.

[alexellis]

Thanks for taking a look at the contribution guide. Would you like to create an issue if there isn't one already and write up a bit more about the the requirements or problem?

I'm interested in seeing this working well.

[cconger]

Closing this in favor of #75 which I think captures the proposal at a higher level.