octoprint.log gets spammed when sensor

[jx2014]

After filament sensor gets triggered, the octoprint.log is getting spammed by the following INFO, causing the log file to grow to nearly 7G per day:

octoprint.plugins.filamentsensorsimplified - INFO - Reading sensor values
octoprint.plugins.filamentsensorsimplified - INFO - Reading result: False
octoprint.plugins.filamentsensorsimplified - INFO - Filament not detected
octoprint.plugins.filamentsensorsimplified - INFO - Sensor was triggered
octoprint.plugins.filamentsensorsimplified - INFO - Sensor callback called
octoprint.plugins.filamentsensorsimplified - INFO - Reading sensor values
octoprint.plugins.filamentsensorsimplified - INFO - Repeating sensor read due to false positives
octoprint.plugins.filamentsensorsimplified - INFO - Repeating sensor read due to false positives
octoprint.plugins.filamentsensorsimplified - INFO - Repeating sensor read due to false positives
octoprint.plugins.filamentsensorsimplified - INFO - Repeating sensor read due to false positives
octoprint.plugins.filamentsensorsimplified - INFO - Repeating sensor read due to false positives
......

If I leave the printer as-is for several days, eventually the octoprint.logs will fill up the entire flash drive. There should be a way to set the sensor read logs to a higher level like critical, or debug.

[valemaio2]

I've been having the same issue, so I forked the plugin and commented out the culprit for the log spamming. Please test this and feel free to expand on it or merge it with your version.

https://github.com/valemaio2/Filament_sensor_simplified

@jx2014 If you can't install the fork on your Octopi (because I don't know how to myself), you can SSH into it, go to folder

/home/pi/oprint/lib/python3.7/site-packages/octoprint_filamentsensorsimplified

(you might need to change the folder python3.7 according to your python version), edit the file

init.py

and comment out the line

self._logger.info("Repeating sensor read due to false positives")

To comment it, just put a pound sign at the start of the line, like so:

#self._logger.info("Repeating sensor read due to false positives")

I'm testing this just now, so please treat this bugfix carefully and make a backup of your Octopi installation before using this.

[CafeNoir64]

i also have this issue, 4GB of log files caused octoprint not to boot up anymore. Worked again after clearing the logs. Logs are full of useless filament sensor messages.

Please incorporate a solution such as @valemaio2 proposes. Or only write to the log files if the status of the sensor changes so that there arent thousands of repeated messages.

[valemaio2]

@CafeNoir64 @jx2014 After some more testing I've found there are some more info log messages being spammed in the log file. I've commented them out here; if you want to try this too, I'd suggest you download the whole init.py to your Octopi installation, or at least make a backup of the existing one and copy-paste my version in nano-vim-ed-emacs or whatever your flavour is.

I'm currently printing something and this plugin is active; this is my log file as it appears with tail -f:

pi@octopi:~ $ tail -f ~/.octoprint/logs/octoprint.log
2023-01-06 13:50:16,029 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-06 13:54:50,561 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.200
2023-01-06 14:05:16,031 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-06 14:20:16,044 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-06 14:35:16,046 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-06 14:50:16,058 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-06 15:05:16,062 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-06 15:20:16,072 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-06 15:35:16,076 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2023-01-06 15:50:16,082 - octoprint.server.heartbeat - INFO - Server heartbeat <3

As you can see no more spamming, just heartbeat logs every 15 minutes.

[CafeNoir64]

Thanks @valemaio2! I will definitely try it out once my printer is done printing.

I looked around in the file system, I'm a bit of a linux noob so just asking to confirm. Should I just replace the init.py file by yours located in:
~/oprint/lib/python3.7/site-packages/octoprint_filamentsensorsimplified $

I can keep the rest as it is using the regulare installation of the plugin through the octoprint interface?

[valemaio2]

@CafeNoir64 that's correct, just replace init.py and leave everything else as is. If you want to play it safe, you can rename the original file with the command
mv ~/oprint/lib/python3.7/site-packages/octoprint_filamentsensorsimplified/__init__.py ~/oprint/lib/python3.7/site-packages/octoprint_filamentsensorsimplified/__init__.py.OLD
so you have a backup copy if for some reasons it doesn't work, then move inside the plugin folder (if you're not already there) with
cd ~/oprint/lib/python3.7/site-packages/octoprint_filamentsensorsimplified/
and download there my version of the file with
wget https://raw.githubusercontent.com/valemaio2/Filament_sensor_simplified/master/octoprint_filamentsensorsimplified/__init__.py

Reboot your Raspberry and the plugin should stop spamming the log file.

[Ratler5]

Sorry if this is a silly question, would this be why after 5-30 minutes of the sensor being triggered my Pi stops responding and will not come back till it is rebooted?

[valemaio2]

@Ratler5 It's not a silly question at all, and it could very well be. After you reboot, open a terminal on the Raspberry and launch the command
df -h /
That should tell you if you have any storage space left.

[Ratler5]

looks like I have plenty of space left at the moment, I just I just followed your instructions for replacing the init.py. I will go start a print and trigger the sensor to see if the issue persists. Would be great if this resolved it! I normally use filament runout on the board directly but someone is being weird and if i plug the sensor in and trigger it my board bowers off... So till at the moment this is my only option.

[Ratler5]

@valemaio2 now after changing the file the sensor is not trigggering at all. going to try changing it back and see if it was something else i did.

Edit- had to reinstall the plugin I must have doen something, it is working now with the new file. about to start test if it locks up again after i let it sit triggered

[Ratler5]

No change with my issue, guess its not related. lost my SSH connection and everything. Pi is powered still but no respose. :(
put more filament in and after about 5-10 min the Pi started responding again, but could not save the print.

any ideas out there?

[jx2014]

Thank you for this solution. It works.

this is what I did:

~/oprint/lib/python3.7/site-packages/octoprint_filamentsensorsimplified/

backup existing init.py

mv __init__.py __init__.py.backup

Download directly from github:

wget https://raw.githubusercontent.com/valemaio2/Filament_sensor_simplified/master/octoprint_filamentsensorsimplified/__init__.py ./

[chattah]

I had this same issue as well and it caused my printer to freeze up. Thank you for doing this!

[imapping]

I think the excess logging is caused by an error in the logic of the read_sensor_multiple function. It is supposed to looking for ten consecutive readings of the same value, but it is actually recording what the value is when the function is first called and then waiting until it sees that value another nine times. If the first value is a false positive then it stays in a loop until it sees another nine false positives and writes log messages every reading.

I'm changing my function to:

if oldTrigger is None:
oldTrigger = newTrigger
elif oldTrigger != newTrigger:
x = 0
oldTrigger = newTrigger

which I think does what the function should do.

[CafeNoir64]

@CafeNoir64 that's correct, just replace init.py and leave everything else as is. If you want to play it safe, you can rename the original file with the command mv ~/oprint/lib/python3.7/site-packages/octoprint_filamentsensorsimplified/__init__.py ~/oprint/lib/python3.7/site-packages/octoprint_filamentsensorsimplified/__init__.py.OLD so you have a backup copy if for some reasons it doesn't work, then move inside the plugin folder (if you're not already there) with cd ~/oprint/lib/python3.7/site-packages/octoprint_filamentsensorsimplified/ and download there my version of the file with wget https://raw.githubusercontent.com/valemaio2/Filament_sensor_simplified/master/octoprint_filamentsensorsimplified/__init__.py

Reboot your Raspberry and the plugin should stop spamming the log file.

This fix is not working anymore.

I had to restore my raspberry pi after a corrupted SD card. After applying the same fix (with a fresh install of the plugin) copying the init file still spams the logs. I don't know why as I believe there haven't been any updates to the plugin, though the python version is no longer 3.7 but 3.9, maybe this has an influence?