Octoprint: [Bug] The Spaghetti Detective isn't receiving PrintStarted event because Octoprint isn't sending it out

[NovaViper]

What were you doing?

1. Install the Spaghetti Detective and setup the plugin
2. Enable debug logging for the plugin
3. Start a print
4. Notice on the plugin's website (https://www.thespaghettidetective.com/) is saying it's not tracking the print
5. Check in the octoprint logs, notice there is no PrintStarted event

What did you expect to happen?

The plugin should start watching the print, logging all information about the current print including time and the video feed

What happened instead?

The plugin's website says that it's not wataching the print, in spite of me having a pro membership and it worked before switching to the Octoprint v1.4.0 release candidates.

Did the same happen when running OctoPrint in safe mode?

Can't track it during safe mode because the plugin is off

Version of OctoPrint

1.4.0-rc3

Operating System running OctoPrint

OctoPi 0.16.0

Printer model & used firmware incl. version

Creality Ender 3, Marlin 2.0

Browser and version of browser, operating system running browser

Vivaldi v2.10.1745.21, Windows 10 Pro 1909

Link to octoprint.log

https://gist.github.com/NovaViper/14c1230962e30a0551fd107f8ffead48

Link to contents of terminal tab or serial.log

Link to contents of Javascript console in the browser

Screenshot(s)/video(s) showing the problem:

I have read the FAQ.

[Thorlokk]

I have same issue

[kennethjiang]

I helped debug this issue. From my analysis it seems that somehow PrintStarted events are not or otherwise received by TSD plugin. Let me know if there are anything else I can do to further debug it.

[foosel]

@kennethjiang could you please set octoprint.events.fire logging to DEBUG, reproduce and share the resulting log? That should hopefully give some insight if the event is actually fired or not.

I just tried against what's going to become 1.4.0rc4 and I could NOT see any issues with the firing of the event or receiving it inside plugins:

2020-01-14 15:10:51,543 - octoprint.plugins.eventtest - INFO - Got event PrintStarted with payload {'origin': u'local', 'name': u'TestCube_Box.gcode', u'user': 'admin', u'owner': 'admin', 'path': u'TestCube_Box.gcode', 'size': 59542L}

I need some help to narrow down on this I fear. If the events fire server side in general, as in, a log entry is produced after the aforementioned change to the logging configuration, and stuff like timelapses and thus also work which rely on the event to be fired, I fear the issue is something that is specific to the plugin and we need to work together to figure out what.

[raymondh2]

octoprint.log
Looks like the event is being fired but TSD isn't picking it up.

[kennethjiang]

Thanks @RaymondHimle . I don't have RC installed yet so can you help me check if PrintStarted event got delivered to TSD plugin? You can insert a print statement here: https://github.com/TheSpaghettiDetective/OctoPrint-TheSpaghettiDetective/blob/master/octoprint_thespaghettidetective/__init__.py#L165

Checked your log. I was expecting to see the log entry octoprint.plugins.thespaghettidetective - DEBUG - Sending printer status: xxx with 'octoprint_event': {xxx in the payload if PrintStarted events were delivered to TSD plugin (ie., on_event method was called). But I couldn't find that after the line octoprint.events.fire - DEBUG - Firing event: PrintStarted (, or anywhere in the log.

[kennethjiang]

@foosel It turns out the events did get delivered to the plugin.

Has the on_event method signature changed in 1.4.0 RC? Currently we use this line to test if this is an event that we need to process.

[foosel]

if type(event) is str

I'm pretty sure this is the issue. During the switch to make things Py3 compatible a lot of changes were done to use unicode (str in Py3) everywhere internally and only use str (bytes in Py3) where a bytestream is required.

The test above probably no longer matches because event is now a unicode string (which it should have been from the start anyhow but wasn't). Also I'm not really sure why you even do this type check tbh, feels a bit like mistrusting the interface ;) If you want to be on the safe side, do

from past.builtins import basestring

# ...

if isinstance(event, basestring) and event.startsWith("Print"):
# ...

[kennethjiang]

Thanks for the detailed input @foosel !

The reason why I did that check was there were exceptions in the log files from some users that says event doesn't have attribute "startswith". But it could have been some very old OctoPrint installation...?

Anyway I'll just remove that if condition. Will report back with more details if the same exception re-appears.

Please close this issue.