Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

incompatibility with werkzeug 2.1+ and room for improvement in catching exceptions #323

Closed
arekm opened this issue Aug 16, 2022 · 4 comments

Comments

@arekm
Copy link
Contributor

arekm commented Aug 16, 2022

Hardware Setup
prusa mk3s+

Describe the problem
Plugin worked fine until I tried it on fresh system using octoprint from maintenance branch.

  • Clicking on "flash from file"
  • Progress bar shows "Flashing firmware..."
  • Nothing happens

Browser inspector shows me that POST call to /flash plugin endpoint is being made and server returns:
400 Bad Request: The browser (or proxy) sent a request that this server could not understand.

So that's the first problem - javascript part of flash plugin doesn't react correctly if endpoint returns any error. It should display some error to user in such case.

  • Nothing in octoprint log. Turns out that any exception in flash_firmware(self) (that's not catched inside) is not logged by octoprint. Don't know why.

To figure out what's happening I'm putting entire flash_firmware content in

try:
...
        except Exception as e:
            self._logger.exception(e)

block and now we have something:

2022-08-15 22:20:34,659 - octoprint.plugins.firmwareupdater - ERROR - 400 Bad Request: The browser (or proxy) sent a request that this server could not understand.
Traceback (most recent call last):
  File "/home/pi/devel/OctoPrint/venv/lib/python3.9/site-packages/flask/wrappers.py", line 128, in on_json_loading_failed
    return super().on_json_loading_failed(e)
  File "/home/pi/devel/OctoPrint/venv/lib/python3.9/site-packages/werkzeug/wrappers/request.py", line 611, in on_json_loading_failed
    raise BadRequest(
werkzeug.exceptions.BadRequest: 400 Bad Request: Did not attempt to load JSON data because the request Content-Type was not 'application/json'.

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/pi/devel/OctoPrint/venv/lib/python3.9/site-packages/octoprint_firmwareupdater/__init__.py", line 100, in flash_firmware
    value_source = flask.request.json if flask.request.json else flask.request.values
  File "/home/pi/devel/OctoPrint/venv/lib/python3.9/site-packages/werkzeug/wrappers/request.py", line 540, in json
    return self.get_json()
  File "/home/pi/devel/OctoPrint/venv/lib/python3.9/site-packages/werkzeug/wrappers/request.py", line 571, in get_json
    return self.on_json_loading_failed(None)
  File "/home/pi/devel/OctoPrint/venv/lib/python3.9/site-packages/flask/wrappers.py", line 133, in on_json_loading_failed
    raise BadRequest() from e
werkzeug.exceptions.BadRequest: 400 Bad Request: The browser (or proxy) sent a request that this server could not understand.
2022-08-15 22:20:34,661 - octoprint - ERROR - Exception on /plugin/firmwareupdater/flash [POST]
Traceback (most recent call last):
  File "/home/pi/devel/OctoPrint/venv/lib/python3.9/site-packages/flask/app.py", line 2525, in wsgi_app
    response = self.full_dispatch_request()
  File "/home/pi/devel/OctoPrint/venv/lib/python3.9/site-packages/flask/app.py", line 1823, in full_dispatch_request
    return self.finalize_request(rv)
  File "/home/pi/devel/OctoPrint/venv/lib/python3.9/site-packages/flask/app.py", line 1842, in finalize_request
    response = self.make_response(rv)
  File "/home/pi/devel/OctoPrint/venv/lib/python3.9/site-packages/flask/app.py", line 2134, in make_response
    raise TypeError(
TypeError: The view function for 'plugin.firmwareupdater.flash_firmware' did not return a valid response. The function either returned None or ended without a return statement.

werkzeug 2.1+ has a change which will raise BadRequest exception if there are json calls while Content-Type is not application/json. For firmwareupdater part Content-Type is multipart/form-data if I remember correctly.

pallets/werkzeug#2339

Solution for this is doing

import werkzeug

[...]

            try:
                value_source = flask.request.json if flask.request.json else flask.request.values
            except werkzeug.exceptions.BadRequest:
                value_source = flask.request.values

instead of current

          value_source = flask.request.json if flask.request.json else flask.request.values

So that was second problem - incompatibility with werkzeug 2.1+. With above change flashing succeeds.

And last thing, entire _flash_worker() should also sit in try except block since any exception there (that's not already catched inside) will be silently ignored without any trace in octoprint.log (as this is run in Thread and octoprint doesn't get exceptions from separate thread).

About octoprint not catching and logging exception in flash_firmware I'm not sure. IMO it should catch it and log it since it is not run in separate thread (I think). Probably flask is catching it or something. Didn't dig deeper.

Edit:

    @octoprint.plugin.BlueprintPlugin.errorhandler(Exception)
    def errorhandler(self, error):
        self._logger.exception(error)
        return error

seems to work (but possibly too broad)

@benlye
Copy link
Collaborator

benlye commented Aug 16, 2022

Feel free to submit pull requests for any improvements.

arekm added a commit to arekm/OctoPrint-FirmwareUpdater that referenced this issue Aug 16, 2022
Werkzeug 2.1+ created incompatibility (pallets/werkzeug#2339)
which caused plugin to fail with "400 Bad Request".

Fixes one (main) part of
OctoPrint#323
arekm added a commit to arekm/OctoPrint-FirmwareUpdater that referenced this issue Aug 16, 2022
Werkzeug 2.1+ created incompatibility (pallets/werkzeug#2339)
which caused plugin to fail with "400 Bad Request".

Fixes one (main) part of
OctoPrint#323
@github-actions
Copy link

This issue has been automatically marked as stale because it has not had any recent activity. Please add a reply if you want to keep this issue active, otherwise it will be automatically closed in 5 days.

@github-actions github-actions bot added the Stale label Aug 30, 2022
@arekm
Copy link
Contributor Author

arekm commented Aug 30, 2022

The problem is still there but issue can be closed. There is a open pull request fixing it.

@arekm arekm closed this as completed Aug 30, 2022
@benlye benlye added enhancement and removed Stale labels Aug 30, 2022
@github-actions
Copy link

This issue has been automatically locked because there was no further activity after it was closed. Please open a new issue for any related problems.

@github-actions github-actions bot locked and limited conversation to collaborators Sep 20, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

2 participants