feat: adding log rotation to Azure-IPAM Zap logger via lumberjack

[behzad-mir]

Since Zap logger does not have a native rotation support. I added lumberjack filewriter that can rotate based on a given file size.

[rbtr]

no filename should not be an error, it just means don't log to a file

[behzad-mir]

Lumberjack log in <processname>-lumberjack.log within os.TempDir() if filename is empty.

I decided to avoid such scenario. If we make this package universal, then we can address this better.

[rbtr]

I think you misunderstood what I meant - if I don't specify a log file, you should not log to a file at all

[tamilmani1989]

can remove MaxAge. Lets add if needed

[behzad-mir]

Will address in the new commit

[tamilmani1989]

lets have 40 MB and 5 MB per file and 8 files in total

[behzad-mir]

Will address in the new commit

[rbtr]

@nddq do you mind giving this a look?

[tamilmani1989]

lgtm

[behzad-mir]

@rbtr Can you plz review the new commit?

[rbtr]

have you addressed my request that not setting a file name not be an error?

[behzad-mir]

The only error that the function returns is when the log level is set incorrectly.
In case of empty filepath then it will log into <processname>-lumberjack.log within os.TempDir()`
which is the default expectation of the lumberjack pkg.

[rbtr]

@rbtr 3 days ago
I think you misunderstood what I meant - if I don't specify a log file, you should not log to a file at all

[behzad-mir]

@rbtr 3 days ago
I think you misunderstood what I meant - if I don't specify a log file, you should not log to a file at all

Seems lumberjack don't support os.Stderr which is the default zap has when output path is empty. Do you want to log there?

[rbtr]

So don't load lumberjack. If I don't specify a log file, I don't need log file rotation.
That's the nice thing about the plugin/composable architecture of zap - we can construct exactly what we need at runtime out of the building blocks.

[rbtr]

I was not suggesting that we start logging on stderr; I'm not even sure if that is okay. I know that we can't log on stdout because that's how the CNI plugins communicate. Does the invoker expect request responses on stderr as well as stdout, or does it ignore it?
/cc @wedaly

[behzad-mir]

I was not suggesting that we start logging on stderr; I'm not even sure if that is okay. I know that we can't log on stdout because that's how the CNI plugins communicate. Does the invoker expect request responses on stderr as well as stdout, or does it ignore it? /cc @wedaly

Stderr is the default output of Zap if you don't specify any file. This is how the Azure-IPAM behave right now even before my PR.
https://github.com/uber-go/zap/blob/master/config.go

[wedaly]

Does the invoker expect request responses on stderr as well as stdout, or does it ignore it?

I believe the invoker copies stderr to os.Stderr

https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/pkg/invoke/raw_exec.go#L67

https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/pkg/invoke/exec.go#L185-L187

This is what the CNI spec has to say:

1. Plugin errors should go to stderr: https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/SPEC.md?plain=1#L195
2. Delegated plugins stderr should go to calling plugin's stderr: https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/SPEC.md?plain=1#L460

[behzad-mir]

Does the invoker expect request responses on stderr as well as stdout, or does it ignore it?

I believe the invoker copies stderr to os.Stderr

https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/pkg/invoke/raw_exec.go#L67

https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/pkg/invoke/exec.go#L185-L187

This is what the CNI spec has to say:

1. Plugin errors should go to stderr: https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/SPEC.md?plain=1#L195
2. Delegated plugins stderr should go to calling plugin's stderr: https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/SPEC.md?plain=1#L460

Do we have any specification for info and debug logs? Do we need to send them to stdout? @rbtr We have the option to set the outputpath to stdout and errorpath to stderr.

[behzad-mir]

Does the invoker expect request responses on stderr as well as stdout, or does it ignore it?

I believe the invoker copies stderr to os.Stderr
https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/pkg/invoke/raw_exec.go#L67
https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/pkg/invoke/exec.go#L185-L187
This is what the CNI spec has to say:

1. Plugin errors should go to stderr: https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/SPEC.md?plain=1#L195
2. Delegated plugins stderr should go to calling plugin's stderr: https://github.com/containernetworking/cni/blob/40fa4795fbee95922aa6f04b3cf0639563419055/SPEC.md?plain=1#L460

Do we have any specification for info and debug logs? Do we need to send them to stdout? @rbtr We have the option to set the outputpath to stdout and errorpath to stderr.

@wedaly Another thing that concerns me is that according to CNI spec Do we need to always have the delegated plugin Errors passed to the stderr even if we are writing all the logs to a file?

[rbtr]

Thanks @wedaly
I read that as only errors should go on stderr, and that logging to it might be interpreted as errors.
@AzureAhai while this might be Zap's default behavior, the logger config was previously hardcoded to have file paths making this a behavior change to azure-ipam that I don't think the CNI will handle.
CNI plugins communicate over stdout and stderr, where they expect input/output arguments and real errors. We can't log to those, because the CNI calling us will (fail to) interpret the logs as data.

[behzad-mir]

Thanks @wedaly I read that as only errors should go on stderr, and that logging to it might be interpreted as errors. @AzureAhai while this might be Zap's default behavior, the logger config was previously hardcoded to have file paths making this a behavior change to azure-ipam that I don't think the CNI will handle. CNI plugins communicate over stdout and stderr, where they expect input/output arguments and real errors. We can't log to those, because the CNI calling us will (fail to) interpret the logs as data.

We may need to always write the errors to stderr. For the info and debug log, we may need to decide to have a default path as before.

[behzad-mir]

Thanks @wedaly I read that as only errors should go on stderr, and that logging to it might be interpreted as errors. @AzureAhai while this might be Zap's default behavior, the logger config was previously hardcoded to have file paths making this a behavior change to azure-ipam that I don't think the CNI will handle. CNI plugins communicate over stdout and stderr, where they expect input/output arguments and real errors. We can't log to those, because the CNI calling us will (fail to) interpret the logs as data.

Just trying to make sure that I get your point here:
So currently we are hardcoding the filepath in the caller in main.go which is the same as this PR from the beginning. I was assuming your concern was that if we don't specify a filepath in the caller we should not log to a file. Due to issues with writing to Stderr or Stdout, I'm going to just specify a default filepath in the logger in case that the caller is not specifying a filepath. @rbtr is this alright?

[rbtr]

I do not like lumberjack's random filename default. I could be convinced that a hardcoded default filepath is okay, but you are correct that my initial suggestion was that if the caller does not specify a path, we do not log to a file (and this does not imply anything about any other behavior, only that no path => no log file).

[behzad-mir]

I do not like lumberjack's random filename default. I could be convinced that a hardcoded default filepath is okay, but you are correct that my initial suggestion was that if the caller does not specify a path, we do not log to a file (and this does not imply anything about any other behavior, only that no path => no log file).

Based on today's meeting I will put /var/log/azure-ipam.log as the default in the logger, even if we pass "" as the filepath because if we don't do that it will got to Stderr (If we pass "" the current code will also log in Stderr)
We can have this issue in mind to define a default path later on as @tamilmani1989 suggested.

[behzad-mir]

@rbtr Can you review this please? The merge is blocked because of the change request.

[rbtr]

nothing blocking, lgtm

[rbtr]

nit: DefaultFilepath

[rbtr]

nit: i think it's clear enough to return zap.New(core) and save the line. vertical space is valuable

[rbtr]

wondering if you did any testing to arrive at these values? I want to make sure we are not rotating the logs too aggressively - it would hard to troubleshoot if that was accidentally like, 10 minutes of logs in a decently sized cluster

[behzad-mir]

I did test that. We don't log much into this file for now. It took alot of time for me with an script to reach to 5 MB. It was @tamilmani1989 suggestion to go with these numbers for now.

[tamilmani1989]

keeping same as cni log files