Azure / azure-functions-dotnet-worker

Azure Functions out-of-process .NET language worker
MIT License
418 stars 182 forks source link

Unable to overwrite log formatting into a console for Azure Function Isolated Host Worker #1856

Open kAleksei opened 1 year ago

kAleksei commented 1 year ago

At the moment I can change the log format for function logging, but unfortunately cannot overwrite log formatting into a console for host, unlike the in-process function.

Steps to reproduce:

Prerequisites


Actual log message in console:

info: Host.Function.Console[0]
      {"EventId":0,"LogLevel":"Error","Category":"MyTestServiceFunc.HealthFunction","Message":"Test works perfectly :). Some random number: 550","State":{"Message":"Test works perfectly :). Some random number: 550","0":550,"{OriginalFormat}":"Test works perfectly :). Some random number: {0}"}}

Expected log message:

{"EventId":0,"LogLevel":"Error","Category":"MyTestServiceFunc.HealthFunction","Message":"Test works perfectly :). Some random number: 987","State":{"Message":"Test works perfectly :). Some random number: 987","0":987,"{OriginalFormat}":"Test works perfectly :). Some random number: {0}"}}

So the main difference is in this line: info: Host.Function.Console[0] which brakes our logging agent which reads logs from container console (stdout) in JSON format only.

kAleksei commented 1 year ago

Hey, any comments on this?

dalibormesaric commented 1 year ago

We ended up filtering this out at promtail level, but that does not feel right.

kAleksei commented 1 year ago

It will not work for me, because I don't use application insights, but read logs from stdout.

jviau commented 1 year ago

To explain what is going on, standard out is piped to the host process and then it is written to the console. This is where that extra info: Host.Function.Console[0] comes from. No immediate plans to change that behavior, but we are looking into improving our logging abilities and may consider a change for this in the future.

dalibormesaric commented 1 year ago

Thanks for answering @jviau ! And just to clarify, we as developers have no control over this, and the only way to remove it is in our log scaping tool (promtail in my case)?

kAleksei commented 1 year ago

@jviau, it would be nice if this could be prioritized because we are writing the logs in JSON format single line. And every line is a separate log entry. Therefore every log that we want to write multiplies by two as functions host logs category and line breaks. As a result, logging costs are twice as high.

jviau commented 12 months ago

@dalibormesaric correct there is no control over this at the moment. The worker process is created as a child of the host process and as part of that the stdout is redirected to the host process.

@kAleksei we have no concrete plans to address this at the moment. Is using stdout your only option? Can you add a custom ILoggerProvider and ILogger which outputs to some other handle or stream?

kAleksei commented 12 months ago

@jviau unfortunately, this is only the option to log into stdout.

jviau commented 12 months ago

Can you help me understand your scenario a bit more? Why is it important to log to stdout? What system are you using which relies on stdout?

kAleksei commented 11 months ago

@jviau, we are deploying the azure functions isolated to k8s cluster. In the cluster, we have installed an agent, which is responsible for pulling logs from stdout of the container. So more than 1k different services are using this approach. We are using datadog agent for gathering the logs. Here are the docs how it actually works: https://docs.datadoghq.com/containers/kubernetes/log/?tab=operator

jviau commented 11 months ago

@kAleksei thank you, that is helpful to understand your scenario. I am familiar with k8s log pattern like this and sounds like a solid reason for us to evaluate supporting this. Unfortunately, it won't be possible now. But we have been discussing sweeping improvements for observability in Azure Functions and this can be considered as a part of it. There is no ETA on that and the work has not been started yet.

kAleksei commented 11 months ago

@jviau, I appreciate your understanding. If you require any further information, please don't hesitate to ask. Additionally, I am eagerly awaiting updates on this item, as this feature holds a high level of importance for us.

domingosliraneto commented 8 months ago

@jviau I believe I have a problem related to the topic. In my case, I cannot remove the datetime stamp in front of the json, this ends up impacting elastic collection, which only accepts files in json format.

image

kAleksei commented 8 months ago

@domingosliraneto, did you have a chance to run your functions without IDE (like Visual Studio tools) and azure-functions-core-tools? For instance in docker container. Looks like this output formatted and written to console with debugging tools.

brunomoura-dev commented 8 months ago

, você teve a chance de executar suas funções sem IDE (como ferramentas do Visual Studio) e ? Por exemplo, no contêiner docker. Parece que esta saída formatada e gravada no console com ferramentas de depuração.azure-functions-core-tools

Yes, I tested it in a container and the effect is the same as shown by @domingosliraneto

image

Remember, in the structured log configuration, dates are not defined. The same pattern is even used in other worker applications, for example.

brunomoura-dev commented 5 months ago

Guys, Any update on this? Were you able to carry out the necessary tests and verify the point in question?