[BUG] Throwing Python exception into the docker logs

itsalljustdata commented 3 years ago

Describe the bug TypeError: not all arguments converted during string formatting

To Reproduce Steps to reproduce the behavior: Launch the docker container...

Expected behavior A clear and concise description of what you expected to happen.

Screenshots If applicable, add screenshots to help explain your problem.

Environment information:

Octoprint Version: 1.5.3
Browser: n/a
Python Version: 3.8.7
Operating system that Octoprint is running on: Latest Docker Container (created 2021-01-19T10:37:02.068327827Z)

Additional context

octoprint    | 2021-01-21T11:21:59.852656992Z Exception in thread Thread-1919:
octoprint    | 2021-01-21T11:21:59.852689509Z Traceback (most recent call last):
octoprint    | 2021-01-21T11:21:59.852706312Z   File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner
octoprint    | 2021-01-21T11:21:59.852713219Z     self.run()
octoprint    | 2021-01-21T11:21:59.852726535Z   File "/usr/local/lib/python3.8/site-packages/sentry_sdk/integrations/threading.py", line 69, in run
octoprint    | 2021-01-21T11:21:59.852733659Z     reraise(*_capture_exception())
octoprint    | 2021-01-21T11:21:59.852739667Z   File "/usr/local/lib/python3.8/site-packages/sentry_sdk/_compat.py", line 54, in reraise
octoprint    | 2021-01-21T11:21:59.852746278Z     raise value
octoprint    | 2021-01-21T11:21:59.852763286Z   File "/usr/local/lib/python3.8/site-packages/sentry_sdk/integrations/threading.py", line 67, in run
octoprint    | 2021-01-21T11:21:59.852769821Z     return old_run_func(self, *a, **kw)
octoprint    | 2021-01-21T11:21:59.852775401Z   File "/usr/local/lib/python3.8/threading.py", line 1254, in run
octoprint    | 2021-01-21T11:21:59.852781282Z     self.function(*self.args, **self.kwargs)
octoprint    | 2021-01-21T11:21:59.852787031Z   File "/octoprint/plugins/lib/python3.8/site-packages/octoprint_ThermalRunaway/__init__.py", line 130, in check_temps
octoprint    | 2021-01-21T11:21:59.852792662Z     _logger.debug('bTemps: %s' % bTemps)
octoprint    | 2021-01-21T11:21:59.852798340Z TypeError: not all arguments converted during string formatting

AlexVerrico commented 3 years ago

G'day @TheFlyingBadger Does your printer have a heated bed? Cheers, Alex.

itsalljustdata commented 3 years ago

Yep. It's a pxmalion coreI3

itsalljustdata commented 3 years ago

A modified init.py which doesn't crash for me...

# coding=utf-8
from __future__ import absolute_import

import octoprint.plugin  # Import the core octoprint plugin components
import logging           # Import logging to allow for easier debugging
import threading         # Import threading. This is used to process the temps asynchronously so that we don't block octoprints communications with the printer
import time              # Import time. This is so that we can add delays to parts of the code

_logger = logging.getLogger('octoprint.plugins.ThermalRunaway')

heaterDict = dict(B     = dict  (highTemp           = 0.0
                                ,lowTemp            = 0.0
                                ,thermalHighWarning = False
                                ,thermalLowWarning  = False
                                ,thermalHighAlert   = False
                                ,thermalLowAlert    = False
                                )
                 ,T0    = dict  (highTemp           = 0.0
                                ,lowTemp            = 0.0
                                ,thermalHighWarning = False
                                ,thermalLowWarning  = False
                                ,thermalHighAlert   = False
                                ,thermalLowAlert    = False
                                )
                 )

class ThermalRunawayPlugin(octoprint.plugin.StartupPlugin,
                           octoprint.plugin.SettingsPlugin,
                           octoprint.plugin.TemplatePlugin):
    def on_after_startup(self):

        # global heaterList
        # global heaterDict
        # heaterDict = dict()
        # heaterDict['B'] = {'highTemp': 0.0, 'lowTemp': 0.0,
        #                    'thermalHighWarning': False, 'thermalLowWarning': False,
        #                    'thermalHighAlert': False, 'thermalLowAlert': False}

        # heaterDict['T0'] = {'highTemp': 0.0, 'lowTemp': 0.0,
        #                     'thermalHighWarning': False, 'thermalLowWarning': False,
        #                     'thermalHighAlert': False, 'thermalLowAlert': False}

#        # create global variables for storing bed temps and thermal warnings
#        global bHighTemp
#        global bLowTemp
#        global bThermalHighWarning
#        global bThermalHighAlert
#        global bThermalLowWarning
#        global bThermalLowAlert
#
#        # create global variables for storing tool temps and thermal warnings
#        global tHighTemp
#        global tLowTemp
#        global tThermalHighWarning
#        global tThermalHighAlert
#        global tThermalLowWarning
#        global tThermalLowAlert

#        # set initial values of bed variables
#        bHighTemp = 0.0
#        bLowTemp = 0.0
#        bThermalHighWarning = False
#        bThermalHighAlert = False
#        bThermalLowWarning = False
#        bThermalLowAlert = False
#
#        # set initial values of tool variables
#        tHighTemp = 0.0
#        tLowTemp = 0.0
#        tThermalHighWarning = False
#        tThermalHighAlert = False
#        tThermalLowWarning = False
#        tThermalLowAlert = False

        # log that we have completed this function successfully.
        _logger.debug('reached end of on_after_startup')

        return

    # SettingsPlugin mixin
    def get_settings_defaults(self):
        # Define default settings for this plugin
        return dict(
            numberExtruders=1,
            emergencyGcode="M112",
            bMaxDiff="10",
            bMaxOffTemp="30",
            tMaxDiff="20",
            tMaxOffTemp="30",
            tDelay="25",
            bDelay="20"
        )

    # TemplatePlugin mixin
    def get_template_configs(self):
        # Tell octoprint that we have a settings page
        return [
            dict(type="settings", custom_bindings=False)
        ]

    # Temperatures received hook

    def check_temps(self, temps):
        _logger.debug('Spawned new thread.')  # Log that we spawned the new thread
        _logger.debug('Reached start of check_temps')  # Log that we have reached the start of check_temps

#        # set the necessary variables to be global
#        global bHighTemp
#        global bLowTemp
#        global bThermalHighWarning
#        global bThermalHighAlert
#        global bThermalLowWarning
#        global bThermalLowAlert
#        global tHighTemp
#        global tLowTemp
#        global tThermalHighWarning
#        global tThermalHighAlert
#        global tThermalLowWarning
#        global tThermalLowAlert
        global heaterDict
        heaterList = ('B', 'T0')
#        B = heaterList['B']
#        T0 = heaterList['T0']

        # Get all settings values
        emergencyGCode = self._settings.get(["emergencyGcode"])
        tMaxOffTempStr = self._settings.get(["tMaxOffTemp"])
        bMaxOffTempStr = self._settings.get(["bMaxOffTemp"])
        bDelayStr = self._settings.get(["bDelay"])
        tDelayStr = self._settings.get(["tDelay"])
        tMaxDiffStr = self._settings.get(["tMaxDiff"])
        bMaxDiffStr = self._settings.get(["bMaxDiff"])
        _logger.debug('got all values from settings.')
        bMaxDiff = float(bMaxDiffStr)
        tMaxDiff = float(tMaxDiffStr)
        bMaxOffTemp = float(bMaxOffTempStr)
        tMaxOffTemp = float(tMaxOffTempStr)
        _logger.debug('bMaxDiff = %s, tMaxDiff = %s, bMaxOffTemp = %s, tMaxOffTemp = %s' % (bMaxDiff, tMaxDiff, bMaxOffTemp, tMaxOffTemp))  # Log values to aid in debugging

        delaysDict = dict()
        delaysDict['B'] = int(bDelayStr)
        delaysDict['T0'] = int(tDelayStr)

        if temps is None:
            temps = []

        if 'B' in temps:
            bTemps = temps['B']
        else:
            bTemps = (-1,-1)
        if 'T0' in temps:
            tTemps = temps['T0']
        else:
            tTemps = (-1,-1)

        _logger.debug(f'bTemps: {bTemps}')
        _logger.debug(f'tTemps: {tTemps}')
        tempsDict = dict(B  = dict  (current    = bTemps[0]
                                    ,set        = bTemps[1]
                                    ,diff       = bMaxDiff
                                    ,maxOff     = bMaxOffTemp
                                    )
                        ,T0 = dict  (current    = tTemps[0]
                                    ,set        = tTemps[1]
                                    ,diff       = tMaxDiff
                                    ,maxOff     = tMaxOffTemp
                                    )
                        )

        _logger.debug("Got all values. Beginning to run through if statements...")

        # Check if thermalHighAlert = True
        for i in heaterList:
            if heaterDict[i]['thermalHighAlert'] is True:
                _logger.debug('%s thermalHighAlert = True' % i)
                if tempsDict[i]['current'] > heaterDict[i]['highTemp']:
                    self._printer.commands("M117 plugin.ThermalRunaway sent emergencyGCode due to %s OverTemp" % i)
                    self._printer.commands(emergencyGCode)
                    _logger.debug('%s currentTemp > %s highTemp. Sent emergencyGCode to printer' % (i, i))
                else:
                    heaterDict[i]['highTemp'] = tempsDict[i]['current']
                heaterDict[i]['thermalHighAlert'] = False
                _logger.debug('set %s thermalHighAlert to False' % i)

            # Check if thermalLowAlert = True
            if heaterDict[i]['thermalLowAlert'] is True:
                _logger.debug('%s thermalLowAlert = True' % i)
                if tempsDict[i]['current'] < heaterDict[i]['lowTemp']:
                    self._printer.commands("M117 plugin.ThermalRunaway sent emergencyGCode due to %s UnderTemp" % i)
                    self._printer.commands(emergencyGCode)
                    _logger.debug('%s currentTemp < %s lowTemp. Sent emergencyGCode to printer' % (i, i))
                else:
                    heaterDict[i]['lowTemp'] = tempsDict[i]['current']
                heaterDict[i]['thermalLowAlert'] = False
                _logger.debug('set %s thermalLowAlert to False' % i)

            # Check if thermalHighWarning is set to True
            if heaterDict[i]['thermalHighWarning'] is True:
                _logger.debug('%s thermalHighWarning = True' % i)
                if tempsDict[i]['current'] > heaterDict[i]['highTemp']:
                    _logger.debug('setting %s ThermalHighAlert to True...' % i)
                    time.sleep(delaysDict[i])
                    heaterDict[i]['thermalHighAlert'] = True
                    _logger.debug('set %s thermalHighAlert to True' % i)
                else:
                    heaterDict[i]['highTemp'] = tempsDict[i]['current']
                heaterDict[i]['thermalHighWarning'] = False
                _logger.debug('set %s thermalHighWarning to False' % i)

            # Check if thermalLowWarning is set to True
            if heaterDict[i]['thermalLowWarning'] is True:
                _logger.debug('%s thermalLowWarning = True' % i)
                if tempsDict[i]['current'] < heaterDict[i]['lowTemp']:
                    _logger.debug('setting %s thermalLowAlert to True...' % i)
                    time.sleep(delaysDict[i])
                    heaterDict[i]['thermalLowAlert'] = True
                    _logger.debug('set %s thermalLowAlert to True' % i)
                else:
                    heaterDict[i]['lowTemp'] = tempsDict[i]['current']
                heaterDict[i]['thermalLowWarning'] = False
                _logger.debug('set %s thermalLowWarning to False' % i)

            # If the heater is turned on then set maxTemp and minTemp
            if tempsDict[i]['set'] > 0.0:
                tempsDict[i]['max'] = tempsDict[i]['set'] + tempsDict[i]['diff']
                _logger.debug('%s maxTemp = %s' % (i, tempsDict[i]['max']))
                tempsDict[i]['min'] = tempsDict[i]['set'] - tempsDict[i]['diff']
                _logger.debug('%s minTemp = %s' % (i, tempsDict[i]['min']))

                # If the current temp of the heater is lower than the min allowed temp then set thermalLowWarning to True
                if tempsDict[i]['current'] < tempsDict[i]['min']:
                    heaterDict[i]['lowTemp'] = tempsDict[i]['current']
                    _logger.debug('%s currentTemp < %s lowTemp, set %s lowTemp to %s currentTemp. New %s lowTemp = %s' % (i, i, i, i, i, heaterDict[i]['lowTemp']))
                    heaterDict[i]['thermalLowWarning'] = True
                    _logger.debug('set %s thermalLowWarning to True' % i)

            # If the bed is turned off then set bMaxTemp to bMaxOffTemp
            if tempsDict[i]['set'] <= 0.0:
                tempsDict[i]['max'] = tempsDict[i]['maxOff']
                tempsDict[i]['min'] = 0.0

            # If the current temp of the heater is higher than the max allowed temp then set thermalHighWarning to True
            if tempsDict[i]['current'] > tempsDict[i]['max']:
                heaterDict[i]['highTemp'] = tempsDict[i]['current']
                _logger.debug('%s currentTemp > %s maxTemp, set %s highTemp to %s currentTemp. New %s highTemp = %s' % (i, i, i, i, i, heaterDict[i]['highTemp']))
                heaterDict[i]['thermalHighWarning'] = True
                _logger.debug('set %s thermalHighWarning to True' % i)

#        # Check if bThermalHighAlert = True
#        if (bThermalHighAlert == True):
#            _logger.debug('bThermalHighAlert = True')
#            if (bCurrentTemp > bHighTemp):
#                self._printer.commands("M117 plugin.ThermalRunaway sent emergencyGCode due to bed OverTemp")
#                self._printer.commands(emergencyGCode)
#                _logger.debug('bCurrentTemp > bHighTemp. Sent emergencyGCode to printer')
#            else:
#                bHighTemp = bCurrentTemp
#            bThermalHighAlert = False
#            _logger.debug('set bThermalHighAlert to False')

#        ## Check if bThermalLowAlert = True
#        if (bThermalLowAlert == True):
#            _logger.debug('bThermalLowAlert = True')
#            if (bCurrentTemp < bLowTemp):
#                self._printer.commands("M117 plugin.ThermalRunaway sent emergencyGCode due to bed UnderTemp")
#                self._printer.commands(emergencyGCode)
#                _logger.debug('bCurrentTemp < bLowTemp. Sent emergencyGCode to printer')
#            else:
#                bLowTemp = bCurrentTemp
#            bThermalLowAlert = False
#            _logger.debug('set bThermalLowAlert to False')

#        ## Check if tThermalHighWarning is set to True
#        if (tThermalHighWarning == True):
#            _logger.debug('tThermalHighWarning = True')
#            if (tCurrentTemp > tHighTemp):
#                _logger.debug('setting tThermalHighAlert to True...')
#                time.sleep(tDelay)
#                tThermalHighAlert = True
#                _logger.debug('set tThermalHighAlert to True')
#            else:
#                tHighTemp = tCurrentTemp
#            tThermalHighWarning = False
#            _logger.debug('set tThermalHighWarning to False')

#        ## Check if tThermalLowWarning is set to True
#        if (tThermalLowWarning == True):
#            _logger.debug('tThermalLowWarning = True')
#            if (tCurrentTemp < tLowTemp):
#                _logger.debug('setting tThermalLowAlert to True...')
#                time.sleep(tDelay)
#                tThermalLowAlert = True
#                _logger.debug('set tThermalLowAlert to True')
#            else:
#                tLowTemp = tCurrentTemp
#            tThermalLowWarning = False
#            _logger.debug('set tThermalLowWarning to False')

#        ## If the hotend is turned on then set tMaxTemp and tMinTemp
#        if (tSetTemp > 0.0):
#            tMaxTemp = tSetTemp + tMaxDiff
#            _logger.debug('tMaxTemp = %s' % tMaxTemp)
#            tMinTemp = tSetTemp - tMaxDiff
#            _logger.debug('tMinTemp = %s' % tMinTemp)
#
#            # If the current temp of the hotend is lower than the max allowed temp then set bThermalHighWarning to True
#            if (tCurrentTemp < tMinTemp):
#                tLowTemp = tCurrentTemp
#                _logger.debug('tCurrentTemp < tLowTemp, set tLowTemp to tCurrentTemp. New tLowTemp = %s' % tLowTemp)
#                tThermalLowWarning = True
#                _logger.debug('set tThermalLowWarning to True')

#        ## If the hotend is turned off then set tMaxTemp to tMaxOffTemp
#        if (tSetTemp <= 0.0):
#            tMaxTemp = tMaxOffTemp
#            tMinTemp = 0.0

#        ## If the current temp of the hotend is higher than the max allowed temp then set tThermalHighWarning to True
#        if (tCurrentTemp > tMaxTemp):
#            tHighTemp = tCurrentTemp
#            _logger.debug('tCurrentTemp > tMaxTemp, set tHighTemp to tCurrentTemp. New tHighTemp = %s' % tHighTemp)
#            tThermalHighWarning = True
#            _logger.debug('set tThermalHighWarning to True')

        # Log that we have reached the end of check_temps
        _logger.debug('Reached end of check_temps')
        return

    # Temperatures hook
    def get_temps(self, comm, parsed_temps):
        _logger.debug('Temps received')  # Log that temps have been received
        # print ("parsed_temps")
        # print (parsed_temps)
        # raise Exception
        temps = parsed_temps
        if temps == parsed_temps:
            _logger.debug('Spawning new thread...')  # Log that we are attempting to spawn a new thread to process the received temps in
            t = threading.Timer(0, self.check_temps, [temps])  # Create a threading Timer object
            t.start()  # Start the threading Timer object
        return parsed_temps  # return the temps to octoprint

    # Softwareupdate hook
    def get_update_information(self):
        # Define the configuration for your plugin to use with the Software Update
        # Plugin here. See https://docs.octoprint.org/en/master/bundledplugins/softwareupdate.html
        # for details.
        return dict(
            ThermalRunaway=dict(
                displayName="Thermal Runaway Plugin",
                displayVersion=self._plugin_version,

                # version check: github repository
                type="github_release",
                user="AlexVerrico",
                repo="Octoprint-ThermalRunaway",
                current=self._plugin_version,

                # update method: pip
                pip="https://github.com/AlexVerrico/Octoprint-ThermalRunaway/archive/{target_version}.zip"
            )
        )

__plugin_pythoncompat__ = ">=2.7,<4"  # python 2 and 3

def __plugin_load__():
    global __plugin_implementation__
    __plugin_implementation__ = ThermalRunawayPlugin()

    global __plugin_hooks__
    __plugin_hooks__ = {
        "octoprint.plugin.softwareupdate.check_config": __plugin_implementation__.get_update_information,
        "octoprint.comm.protocol.temperatures.received": __plugin_implementation__.get_temps
    }

AlexVerrico commented 3 years ago

G'Day @TheFlyingBadger Sorry for not responding for so long, I'm happy to look into this issue further, but it would be easiest if you could fork the repo and make your changes to your fork so that I can easily see the difference. Cheers, Alex.

zero-impedance commented 3 years ago

Hi, @AlexVerrico

I also got the same error and faced another problem.

Environment information:

Octoprint Version: 1.5.3
Printer: Anet A8
Firmware: Repetier
Python Version: 3.9.4
Linux raspberrypi 5.4.83+ #1379 Mon Dec 14 13:06:05 GMT 2020 armv6l GNU/Linux

`temps` data cleared

I continuously got this error message on printing.

Exception in thread Thread-33:
Traceback (most recent call last):
  File "/home/octoprint/.pyenv/versions/3.9.4/lib/python3.9/threading.py", line 954, in _bootstrap_inner
    self.run()
  File "/home/octoprint/.pyenv/versions/3.9.4/lib/python3.9/threading.py", line 1266, in run
    self.function(*self.args, **self.kwargs)
  File "/home/octoprint/.pyenv/versions/3.9.4/envs/octoprint/lib/python3.9/site-packages/octoprint_ThermalRunaway/__init__.py", line 130, in check_temps
    bTemps = temps['B']
KeyError: 'B'

After a bit of research, I found that at the beginning of check_temps(), argument temps had correct data (like {'B': (25.47, 50.0), 'T0': (27.79, 100.0)}). But just before bTemps = temps['B'] (line 130), temps became empty dict ({}).

I think the cause may be that OctoPrint cleared parsed_temps dict just after octoprint.comm.protocol.temperatures.received callback (get_temps()), and before using temps in check_temps().

Using a copy of parsed_temps worked for me.

     def get_temps(self, comm, parsed_temps):
         _logger.debug('Temps received')  # Log that temps have been received
+        temps = parsed_temps.copy()
-        temps = parsed_temps
         if temps == parsed_temps:

Logging format error

Logging bTemps and tTemps produced an error as @TheFlyingBadger reported.

Exception in thread Thread-31:h
Traceback (most recent call last):
  File "/home/octoprint/.pyenv/versions/3.9.4/lib/python3.9/threading.py", line 954, in _bootstrap_inner
    self.run()
  File "/home/octoprint/.pyenv/versions/3.9.4/lib/python3.9/threading.py", line 1266, in run
    self.function(*self.args, **self.kwargs)
  File "/home/octoprint/.pyenv/versions/3.9.4/envs/octoprint/lib/python3.9/site-packages/octoprint_ThermalRunaway/__init__.py", line 131, in check_temps
    _logger.debug('bTemps: %s' % bTemps)
TypeError: not all arguments converted during string formatting

Converting a tuple data to str worked for me.

-        _logger.debug('bTemps: %s' % bTemps)
+        _logger.debug('bTemps: %s' % str(bTemps))
         tTemps = temps['T0']
-        _logger.debug('tTemps: %s' % tTemps)
+        _logger.debug('tTemps: %s' % str(tTemps))

Dict key error

On creating tempsDict, I got this error.

Exception in thread Thread-35:
Traceback (most recent call last):
  File "/home/octoprint/.pyenv/versions/3.9.4/lib/python3.9/threading.py", line 954, in _bootstrap_inner
    self.run()
  File "/home/octoprint/.pyenv/versions/3.9.4/lib/python3.9/threading.py", line 1266, in run
    self.function(*self.args, **self.kwargs)
  File "/home/octoprint/.pyenv/versions/3.9.4/envs/octoprint/lib/python3.9/site-packages/octoprint_ThermalRunaway/__init__.py", line 135, in check_temps
    tempsDict['B']['current'] = bTemps[0]
KeyError: 'B'

Inserting placeholders for 'B' and 'T0' would be fine.

-        tempsDict = dict()
+        tempsDict = {'B' : {}, 'T0' : {}}
         tempsDict['B']['current'] = bTemps[0]
         # bCurrentTemp = bTemps[0]
         tempsDict['T0']['current'] = tTemps[0]

Here is all the diffs I made.

@@ -128,10 +127,10 @@
         delaysDict['T0'] = int(tDelayStr)

         bTemps = temps['B']
-        _logger.debug('bTemps: %s' % bTemps)
+        _logger.debug('bTemps: %s' % str(bTemps))
         tTemps = temps['T0']
-        _logger.debug('tTemps: %s' % tTemps)
+        _logger.debug('tTemps: %s' % str(tTemps))
-        tempsDict = dict()
+        tempsDict = {'B' : {}, 'T0' : {}}
         tempsDict['B']['current'] = bTemps[0]
         # bCurrentTemp = bTemps[0]
         tempsDict['T0']['current'] = tTemps[0]
@@ -307,7 +306,7 @@
     # Temperatures hook
     def get_temps(self, comm, parsed_temps):
         _logger.debug('Temps received')  # Log that temps have been received
-        temps = parsed_temps
+        temps = parsed_temps.copy()
         if temps == parsed_temps:
             _logger.debug('Spawning new thread...')  # Log that we are attempting to spawn a new thread to process the received temps in
             t = threading.Timer(0, self.check_temps, [temps])  # Create a threading Timer object

AlexVerrico commented 3 years ago

G'Day @TheFlyingBadger and @zero-impedance. I believe this issue is fixed by the latest release. Cheers, Alex.

AlexVerrico / Octoprint-ThermalRunaway