/var/log/ispcp/logdb doesn't get properly updated and is causing wrong statistics

[aseques]

After looking a bit more in depth the problems with stats we noted that the file keeping the pointers to the most recent logs is always properly updated. The proper solution it to update the logdb values just after reloading the apache in logrotate.d We are using this perl script (located in /var/www/ispcp/engine/traffic/update_logdb_apache) in the postrotate execution of logrotate.

It depends partly on #2097 because there's need to know how is the apache rotation handled

[aseques]

Perl script to update logdb contents

[aseques]

apache logrotate file to replace the distribution one

[kilburn]

I think that you misunderstood how does this "logdb" stuff work. As I understand it, this "db" stores the offset at where EOF was found in the previous execution. Therefore, on the next execution, the statistic parser reads this value, and:

If prev_offset < file_size, it assumes that it's the same logfile, seeks to offset and processes the remaining lines until the end of file.

If prev_offset > file_size, it assumes that the file has been rotated. Thus, it opens logfile.1 (the rotated log), seeks to offset, processes the lines until EOF *and* then opens the current (after-rotation) logfile and processes it to EOF.

Whatever the case, it ends up by storing the new offset in the logdb to be used on the following execution.

Now, which problem do you see in this approach?

[aseques]

I just tested a case that causes problems. To reproduce:

.- The initial case is some logs for domain example.com and with the logdb part:

example.com-traf.log 1964

.- Force a rotation of the logs (without the patch in this thread). In debian it would be logrotate -f /etc/logrotate.d/apache2 , this would rotate both /var/log/apache2/example.com-combined.log and /var/log/apache2/example.com-traf.log

.- After the rotation both files (example.com-traf.log and example.com-combined.log) are empty, and the old version is in the *.1 file

.- You manually execute /var/www/ispcp/engine/traffic/ispcp-vrl-traff and this is the intersting part:

DEBUG: push_el() sub_name: gen_log_file(), msg: Taking the domain log positions from '/var/log/ispcp/logdb'...
DEBUG: push_el() sub_name: gen_log_file, msg: /var/log/ispcp/example.com-traf.log was rotated. Parsing begins at position 1964 in  /var/log/apache2/example.com-traf.log.1
DEBUG: push_el() sub_name: sys_command(), msg: Starting...
DEBUG: push_el() sub_name: sys_command('/bin/cp /var/log/apache2/example.com-traf.log.1 /var/log/ispcp/example.com-traf.log.1'), msg: Ending...
DEBUG: push_el() sub_name: del_file(), msg: Starting...
DEBUG: push_el() sub_name: del_file(), msg: Ending...
DEBUG: push_el() sub_name: sys_command(), msg: Starting...
DEBUG: push_el() sub_name: sys_command('/bin/mv /var/log/ispcp/example.com-traf.log /var/log/ispcp/example.com-traf.log.prev'), msg: Ending...
DEBUG: push_el() sub_name: gen_log_file(), msg: Saving new domain log positions in '/var/log/ispcp/logdb'...

.- The problem is that the relevant part of the logdb still remains the same:

example.com-traf.log 1964

So we should either fix this behavior or take care of logdb in the rotation scripts.

[kilburn]

Aseques, can you stress-test the patch that I've attached to the ticket? (Tested by myself against current trunk, so please test it without appliying your other patches)

Thx!

[kilburn]

Fixed in r2551.

[kilburn]

Aseques found some situations where my patch was misbehaving. I'm looking into it...

[kilburn]

Fixed in r2552 (thanks aseques!)