Sized Rotating Logger bug for BLFWriter file_size (-s) argument

[j-c-cook]

Describe the bug

The BaseRotatingLogger performs a check to see if it should_rollover(msg), which is an abstract method that invokes the SizedRotatingLogger function should_rollover(msg). Inside of the should_rollover function, the writer.tell() function is utilized to see how large the file being written to is. The issue when the writer is of type BLFWriter is that writer.tell() always returns a size of 144 bytes, until the buffer grows to be larger than the max_container_size and the buffer is flushed. Then the function writer.tell() returns something around 26,500 bytes (25.8 KiB). As long as the -s option is larger than the header (144 bytes), then the file written will always be around 25.8 KiB.

To Reproduce

Enable virtual can: sudo ip link add dev vcan0 type vcan && sudo ip link set up vcan0
Spam the virtual bus with random can messages 1 ms apart: cangen vcan0 -e -I 18EAFF26 -L i -v -v -v -g 1
Log the virtual bus: python -m can.logger -c vcan0 -i socketcan -b 250000 -f file.blf -s 150

Expected behavior

I expected for a blf file of size 150 bytes to be written.

Additional context

OS and version: Ubuntu 20.04.4 LTS
Python version: Python 3.7.17
python-can version: b9d9d01
python-can interface/s (if applicable):

Details

I have added print statements in the io/blf.py and io/logger.py modules to highlight the bug here: 977e1e0.

[zariiii9003]

I set the size to 1048576 bytes and the resulting file size is pretty close to that:

1MiB is already pretty tiny, why do you need 150byte sized blf files?

I suspect the SizedRotatingLogger might be the wrong tool for the job, maybe you need a logger which depends on time, not size?

[j-c-cook]

I want to be careful not to conflate two issues here. I posted a detailed description of a bug (see above). I put in print statements in commit SHA j-c-cook@977e1e0 to help communicate the bug I was highlighting. When I checkout a branch at that commit, git checkout -b branch 977e1e0c6dc85b709eb16b6fea9a719144440603, and run the blf rotating logger, I get the following set of debug statements.

Connected to SocketcanBus: socketcan channel 'vcan0'
Can Logger (Started on 2022-08-06 13:32:07.116596)
Flush the buffer to a file. Larger than max container!
NOT 144!
Rollover: 31374 bytes
Buffer size: 16 bytes

Have you checked out a branch at that commit and seen those debug statements? I'm not sure if you are disagreeing with the premises that there is a bug. Are you saying you believe the -s option plays a roll in the size of a blf log file when rollover is being used?

On the second issue you've now brought up; As it turns out, you are correct that a TimedRotatingLogger would be more suitable for my application. Two things can be true at the same time. I am seeing the bug I described above, and a suitable enhancement to python-can for my application would be a TimedRotatingLogger.

[zariiii9003]

I understand what you mean. The BLF Writer compresses and writes data in 128KiB chunks. But the SizedRotatingLogger cannot and was never intended to ensure file sizes within a few bytes. The SizedRotatingLoggers primary use case is avoiding huge files. 128KiB are irrelevant when dealing with gigabytes of data.
I'd like to avoid adding unnecessary complexity to the logging API which benefits 0.0000000001% of users.

A TimedRotatingLogger would be a very useful addition though.

[j-c-cook]

Can you think of a good place to communicate that information about how the BLF Writer rolling logger is not adjustable, but rather has a reasonable nonadjustable (from the API) maximum buffer size?

Your comment about writing files within a few bytes applies to method (2) in my initial pull request comment. I was unsure how to do (2), so I went with (1), which opened up the ability to adjust max_buffer_size via the **kwargs variable. Does allowing modification of the buffer size add complexity to the API when the can.logger documentation claims the ability to adjust output size via the -s option? Do you foresee any other Logger specific optional variables being opened up to the API via **kwargs in the future?

I'll put TimedRotatingLogger on my list. It's a good idea, thank you for bringing it up.

[j-c-cook]

@zariiii9003 When you get the chance, could you give me some direction on how you would like for me to finish this up?

[zhoulian1992]

how to call "can.io.SizedRotatingLogger" fucntion? The following is my code.

t = time.localtime()
t_str = time.strftime("%Y-%m-%d %H.%M.%S", t) + '_log'

BLF_filename = r'./log/' + t_str + '.blf'            
BLF_logger = can.io.SizedRotatingLogger(base_filename=BLF_filename,max_bytes=5 * 1024)
BLF_logger.on_message_received(msg)

When I run those codes,only one blf log file is built.The file name is "2022-08-08 14.07.35_log_2022-08-08T140739_#000.blf".The size of the file is 17 KB.
Last, when I call the BLF_logger.stop() function,there is an error:

 File "C:\Users\m\AppData\Local\Programs\Python\Python310-32\lib\site-packages\can\io\logger.py", line 240, in stop
    self.writer.stop()
  File "C:\Users\m\AppData\Local\Programs\Python\Python310-32\lib\site-packages\can\io\blf.py", line 565, in stop
    if self.file.seekable():
ValueError: I/O operation on closed file

If I change the "BLF_filename = r'./log/' + t_str + '.blf'" into "BLF_filename = r'./log/' + t_str + '.asc'", the code can work very well.

So, could you provide a good suggestion for this?
Thank you!

[zariiii9003]

Hello @zhoulian1992, that's a bug that was fixed in #1317. It's only available on the develop branch so far, but i hope we get a new release out soon.

[j-c-cook]

@zhoulian1992 Use pip install git+https://github.com/hardbyte/python-can@develop to install python-can with the most recent updates.

@zariiii9003 A way for us to push out hot fix releases quicker could be to create a 4.1.x branch upon release. We continue to work on develop and cherry-pick bug fixes into the 4.1.x branch. We could choose to support 4.1.x until the next major release.

Edit: I meant to say we could support 4.1.x until the next minor release (4.2.x).