:bug: [BUG]: Nginx/Canarie logging parsing bottleneck

[fmigneault]

Summary

There is an issue with the logging/parsing strategy of nginx access logs.

Details

Since the conversion of CanarieAPI with separate cron/nginx/api definitions, the cron command that was invoked (https://github.com/Ouranosinc/CanarieAPI/blob/39c32e7ee2b21b5a3a6ba671ab41aa6195fde5b7/Dockerfile#L39) that led to some log rotation to occur (since logrotate config is available by default, but not cron or logrotate utilities, see below), is not being done anymore (current proxy only calls nginx -g daemon off;).

> docker exec -ti proxy bash 
> service --status-all
 [ ? ]  hwclock.sh
 [ + ]  nginx
 [ + ]  nginx-debug
> cat /etc/logrotate.d/nginx 
/var/log/nginx/*.log {
        daily
        missingok
        rotate 52
        compress
        delaycompress
        notifempty
        create 640 nginx adm
        sharedscripts
        postrotate
                if [ -f /var/run/nginx.pid ]; then
                        kill -USR1 `cat /var/run/nginx.pid`
                fi
        endscript
}

This leads to, eventually, very large logs to be collected.

3.9G Oct 2 06:26 access_file.log

This was not "that much a big deal" before.

However, since the fix of the log parser (Ouranosinc/CanarieAPI#53) and its integration (#588), the operation ran by CanarieAPI actually runs rather than preemptively failing. With this big file, it then proceeds to parse the log, which can take ~4min to parse based on the above size:

[2025-10-02 06:24:44,766] [13] [INFO] canarieapi.app_object : Loading log file : /var/logs/access_file.log
[2025-10-02 06:28:43,812] [13] [INFO] canarieapi.app_object : Compiling stats from 27483724 records

Provided that this command is launched every minute (https://github.com/Ouranosinc/CanarieAPI/blob/master/docker/canarieapi-cron), this leads to an ever-growing amount of duplicate tasks in parallel.

I have received memory monitoring alarms from our server, and found that dozens of cron jobs were hogging the memory and bringing the server to a halt.

Potential Strategies to Fix

Note

I can think of a few strategies to fix the problem.
Maybe others are possible, suggestions/concerns welcomed.

1. use a docker with nginx+logrotate preinstalled and actually run it
   • mostly drop-in replacement, but one must be defined
   • maybe it could be considered to provide template/vars to override the default logrotate config provided by nginx
2. discard the log-file method (https://github.com/search?q=repo%3Abird-house%2Fbirdhouse-deploy+%28PROXY_LOG_FILE+OR+proxy-logs%29&type=code) and use stdout (default of nginx) to leverage docker's log rotation
   • a separate config than our current x-logging: &default-logging in composes would be nedded to have a dedicated log
   • prometheus and canarieapi would need remapping to that resulting file
3. define a cron on the host
   • since the file is mapped to the host, the logrotate config could be on the server directly, making it transparent to the stack
   • however, that is not very portable, and will most likely break on new servers where we will forget to set it up

To Reproduce

Steps to reproduce the behavior:

1. Let the server run for a while with nginx + canarieapi.
2. Trigger a lot of requests to force the creation of many access logs.
3. Observe the logs reaching a big size.
4. Inspect running commands on the host (eg: ps faux), there should be a lot of cron commands with canarie.logparser calls.

Concerned Organizations

@tlvu @mishaschwartz

[tlvu]

Oh boy, Ouranos did not see that because we did not catch up with the tip yet, but basically are you saying the logrotate of the proxy container /var/log/nginx/access_file.log file is broken leading to a very large file?

[fmigneault]

@tlvu
Yes. From my interpretation at least, log rotation does not seem to happen anymore. Our instance is not targeted that much by requests, so it is not too critical after a temporary/manual fix, but I would be interested to see if similar impact is observed in PAVICS.

[mishaschwartz]

I am in favour of option 2 which would simplify a lot of things I think.

The other component that parses logs from nginx is the prometheus-log-parser component. I've recently made an update so that the underlying log_parser library supports reading logs from a stdout stream (see DACCS-Climate/log-parser#7).

For Canarie we'd have to change things around a little bit. Reading from a stream is different from reading from a file because it has to be constantly monitored (logging sidecar pattern) instead of just polling the file occasionally. I would recommend using another instance of the log parser with a line parser function that updates the database with the various access counts.

You could even have another async function as part of the code that runs the log parser that polls each service every minute instead of relying on cron. I'd be interested in developing a demo of this if this seems like a viable solution to you guys @fmigneault and @tlvu

[fmigneault]

I think option 2 would be possible without any change in CanarieAPI side if we leveraged the files created by docker and mounting their directory in the container.

My temp workaround was to put in place logparser with a size limit on the host and let Canarie can deal with the single file directly.

You can give it a try using the stream and async. I unfortunately cannot invest time developing it.

[mishaschwartz]

if we leveraged the files created by docker and mounting their directory in the container.

That's definitely possible but it's not very portable depending on where docker engine on a specific distribution puts their log files. Though it could be an OK temporary workaround.

You can give it a try using the stream and async.

If there's no huge rush on this I can give it a try in the next little while. I might have some questions about canarie-api though.

[tlvu]

I am actually more in favor of option 1 (add logrotate to the nginx image) as it is the easiest and least disruptive change to fix this issue. We are actually lucky this do not happen in Ouranos production yet !

So I would prefer a quick fix, then we can transition to a nicer fix later (option 2) without having to rush this option.

[fmigneault]

I agree it is the easiest replicable approach.

[mishaschwartz]

I'm happy with option 1 until we can get option 2 working properly.

If we implement option 1 can we leave this issue open though so that I don't forget to implement option 2 later?

[fmigneault]

Sure, or create a specific feature/issue about option 2 referring to this one.

[tlvu]

Thinking about option 2, does this means the proxy container is not standalone anymore because it will require the log-parser container to be deployed at the same time? The proxy container being enabled by default, I think it should rather be 100% standalone.