Plugin dies on printing

Super happy with my plugin development progress so far I decided to use the virtual printer to snag some @commands to further enhance my plugin. It was at this point I discovered that my plugin dies during a print.
During this code:

def on_api_get(self, request):
return check_output(['commandline_util', 'params'])

The return is JSON. But for some reason, even though the response is ns fast it dies during a print. Only during a print, whilst idle eveything is awesome.
My Python foo is weak, I figure this is a blocking vs non-blocking occasion.. not sure. Any help much appreciated.

Can you post a bit more of your code, or link to a repo? That would help figure out what is going on.

Also, are you using something like flask.jsonify in your check_output call? I imagine it would be doing something like this at some point:

return flask.jsonify(
  {
    'key':value
  }
)

Hi, There is nothing much else to it. The command line util basically returns JSON. Check_Output just gets the output of the util. That will be either the good stuff or errors all wrapped up in JSON. The problem I'm encountering is this:

2019-12-16 14:45:30,125 - octoprint.server.api - ERROR - Error calling SimpleApiPlugin cabhat
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/server/api/init.py", line 68, in pluginData
response = api_plugin.on_api_get(request)
File "/home/pi/OctoPrint-Cabhat/octoprint_cabhat/init.py", line 35, in on_api_get
return check_output(['cabhat', 'get-everything'])
File "/usr/lib/python2.7/subprocess.py", line 223, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command '['cabhat', 'get-everything']' returned non-zero exit status 254
2019-12-16 14:45:30,136 - tornado.access - ERROR - 500 GET /api/plugin/cabhat (::ffff:192.168.1.199) 111.09ms

line 35 is: return check_output(['commandline_util', 'params'])

Just did a little more sense checking. Octoprint is in full swing, printing. I'm getting the errors in my plugin. I'm also using the command line util via putty. Even in that scenario the JSON is all ... cannot read etc. Seems while printing the I2C bus is mostly shut down. So I think looking for the error in my plugin is pointless. This is something to do with printing and I2C??

I can see it on the logic analyser too. I2C is all screwed up once I hit print. Not yet sure why.

You might try instead...

['/full/path/to/cabhat', 'get-everything']

Additionally, you might try to verify if the pi user has the rights to run your executable from the command line.

I didn't expect that to make a difference but changing it to '/bin/cabhat' did actually make the error logs go away. Still getting abnormal output to the UI though. It actually behaves strangely like it is competing for resources. One step closer :slightly_smiling_face: I'm going to check the logic analyser next see if it is still talking gibberish from the PI.

The 254 error code was possibly trying to say "not in path". You might also try this version:

['/full/path/to/cabhat', 'get-everything', '&']

The final ampersand means "run this in the background, don't block the calling thread".

Well that definitely improves things. However, still not 100%. It works sometimes but not others. As if it is sometimes succeeding within a given window of opportunity. It occurs to me that the Virtual Printer might actually be the cause of the issue so I'm going to wire up a real one to make further tests.

Is there anything more reliable that can be done with callbacks/futures? To expand that window of success?

1 Like

Oh, sorry... I didn't see this earlier: check_output(). That one wants to see the output from the command so background mode probably isn't what you want here.

scanOutput = check_output([os.path.join(op.obj.plugin_folder, "bin/rfid/scan"), "30"],shell=True,stderr=STDOUT)

Here's some code which I have which is spawned in Python from a new thread. The scan executable is a C program and the output of this is the ID of the RFID card so it's obviously necessary to return that. I see that I'm redirecting the STDERR messages as well back to Python so that I can investigate things in the log. All this is wrapped in a try/except block.

The except line looks like this:

except CalledProcessError as e:

And then you can decide what to do with it. You'll have e.cmd, e.returncode, e.output that you can investigate from here.