Mailinabox: mail_log.py not working

[fmonts]

I have 2 boxes, both with the same problem.
The mail_log.py (Mail-in-a-Box Usage Report) fails every time, because of this error:

root@mail:~/mailinabox# management/mail_log.py
Scanning logs from 2019-06-27 00:00:00 to 2019-06-27 08:31:20
Traceback (most recent call last):
  File "management/mail_log.py", line 895, in <module>
    scan_mail_log(env_vars)
  File "management/mail_log.py", line 128, in scan_mail_log
    scan_files(collector)
  File "management/mail_log.py", line 84, in scan_files
    if scan_mail_log_line(line.strip(), collector) is False:
  File "management/mail_log.py", line 347, in scan_mail_log_line
    date = datetime.datetime.strptime(date, '%b %d %H:%M:%S')
  File "/usr/lib/python3.6/_strptime.py", line 565, in _strptime_datetime
    tt, fraction = _strptime(data_string, format)
  File "/usr/lib/python3.6/_strptime.py", line 362, in _strptime
    (data_string, format))
ValueError: time data 'JJun 27 08:14:28' does not match format '%b %d %H:%M:%S'

The strange thing is that there is no JJun 27 in the logs, there are only correct entries at that hour:

so the script randomly adds some characters... Every time I run the script, it finds a different wrong row.

If I run the script many times, about one out of ten times it works.

[JoshData]

I get this error as well from time to time but didn't consider that the problem might not actually be in the file! Interesting! Maybe it's reading the logs at the very moment the logs are being written.

Anyway, I'd appreciate any help in fixing the problem.

[jeremitu]

reverse_readline() seems to be the culprit, doubling characters so that datetime.strptime() format check fails. Could be a sync issue, mail.log being written at the same time. Python 3.6.7, Ubuntu 18.04.2.

[jeremitu]

reverse_readline() fails with UTF-8 encoding (which is the default and the right one) due to seek() counting in bytes and read() counting in characters. The solution using file_read_backwards module worked for me:

from file_read_backwards import FileReadBackwards

def reverse_readline(filename):
    """ A generator that returns the lines of a file in reverse order

    https://stackoverflow.com/a/41418158/4180279

    """
    with FileReadBackwards(filename, encoding="utf-8") as frb:
        for l in frb:
            yield l

[JoshData]

Good diagnosis of the problem!

Maybe we can fix this easily by just reading the files forwards....

[jeremitu]

I tried it and tested both ways in a mail_log_fix branch where mail_log.py uses file_read_backwards package and mail_log_fwd.py was fixed to read from oldest to newest.

I hope I got the time inversion right, at least both scripts output the same contents. The backward reading is faster (6 secs for ./mail_log.py -t week vs. 9 secs when reading forward), as it can stop parsing the lines past the END_DATE. It is also less risky for the compatibility reasons.

I think we should go with the file_read_backwards package, want to prepare a PR.

[jeremitu]

Finally I submitted a PR #1734 which reads the log forward as @JoshData has suggested. It is a bit slower, but more robust and without additional dependencies. Should also fix #1733 Feb 29 problem.