Random Printing Paused with Filament Sensor Reloaded

Hi,

I have a z stop switch acting as my filament sensor, and I'm using the Filament Sensor Reloaded plugin. I verified that it works by cutting the filament... it pauses the print, backs out the filament, and everything works fine when I reload the filament and hit resume.

All of the sudden, I have a strange problem. At approximately the same time (1-2 hours) into a print, the printer pauses for no reason. I can hit Resume and it continues printing, but eventually stops again. I can't figure out why it would be doing this.

Here are my settings for Filament Sensor Reloaded:

Here are my GCODE scripts:

Here is my SystemInfo Bundle:

octoprint-systeminfo-20211018102943.zip (761.6 KB)

Tailing the log, here is where it pauses.

2021-10-18 10:00:24,235 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:24,489 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:24,663 - octoprint.printer.standard.job - INFO - Print job paused - origin: local, path: Wood Box.aw.gcode, owner: ender, user: None
2021-10-18 10:00:24,667 - octoprint.plugins.detailedprogress - INFO - Printing paused. Detailed progress paused.
2021-10-18 10:00:24,667 - octoprint.plugins.filamentreload - INFO - PrintPaused: Disabling filament sensor.
2021-10-18 10:00:24,742 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:24,756 - octoprint.util.comm - INFO - Changing monitoring state from "Pausing" to "Paused"
2021-10-18 10:00:24,994 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:25,247 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:25,500 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:25,754 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:25,836 - octoprint.plugins.octoeverywhere - INFO - NotificationsHandler successfully sent 'paused'; ETA: 86167
2021-10-18 10:00:26,007 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:26,260 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:26,512 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:26,764 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:27,017 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:27,273 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:27,528 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:27,783 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:28,000 - octoprint.plugins.printoid - INFO - //// Send alert to Printoid: 'printer-state' with value Paused (Ender 3 v2)
2021-10-18 10:00:28,035 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:28,288 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:28,541 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:28,619 - octoprint.plugins.printoid - INFO - //// Send alert to Printoid: 'printer-state' with value Paused (Ender 3 v2)
2021-10-18 10:00:28,793 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:28,917 - octoprint.plugins.printoid - INFO - //// Send alert to Printoid: 'printer-state' with value Paused (Ender 3 v2)
2021-10-18 10:00:29,044 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:29,298 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:29,325 - octoprint.plugins.printoid - INFO - //// Send alert to Printoid: 'printer-state' with value Paused (Ender 3 v2)
2021-10-18 10:00:29,551 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:29,605 - octoprint.plugins.printoid - INFO - //// Send alert to Printoid: 'printer-state' with value Paused (Ender 3 v2)
2021-10-18 10:00:29,804 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:29,902 - octoprint.plugins.printoid - INFO - //// Send alert to Printoid: 'printer-state' with value Paused (Ender 3 v2)
2021-10-18 10:00:30,056 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 10:00:30,308 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24

The printer just paused again. What's strange is that the "The value of the pin is 1. No filament = False" never changes to True? Suddenly, there is an "Out of filament!" message. Anyone have any ideas why this is happening?

Log tail...

2021-10-18 12:04:43,538 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 12:04:43,793 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 12:04:43,959 - octoprint.plugins.detailedprogress - INFO - Message: ETA 10/19 9.57AM
2021-10-18 12:04:44,047 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 12:04:44,301 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 12:04:44,302 - octoprint.plugins.filamentreload - INFO - Out of filament!
2021-10-18 12:04:44,302 - octoprint.plugins.filamentreload - INFO - Pausing print.
2021-10-18 12:04:44,302 - octoprint.util.comm - INFO - Pausing/resuming job on behalf of plugin filamentreload
2021-10-18 12:04:44,302 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Pausing"
2021-10-18 12:04:44,558 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24
2021-10-18 12:04:44,811 - octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 2

See the times between the messages: octoprint.plugins.filamentreload - INFO - The value of the pin is 1. No filament = False input = 24

That are just some tenth of a second.

Check for good wiring and that the filament securely is indicated. It seems to be hard on the edge. So it toggels around.

Had the same problem with the Smart Filament Sensor plugin after updating to Octoprint 1.7. My print was fine for over an hour, then would pause periodically even though there was filament present and extruding. I could reload the filament and continue, but it seemed to pause at Z height changes. I had to unplug the sensor to finish the print.

@foosel, I have the system bundle and log but serial logging wasn't enabled. Do you want me to reprint the file to capture serial logging?

Went for a few hours longer than normal (4-5 hours this time). But, came in this morning to a paused print, a cold bed, and all the prints had popped off. Don't think it's the plugs or wiring. It soldered and shrink wrapped, and NO amount of wiggling the plugs or wires causes the issue in question. Could it be the plugin? Should I try another filament sensor plugin?