Python exception set prior to callback

[ferrosk]

Hello,

I developed Domoticz plugin for Volumio. It is using Volumio websocket API. All is working fine when running it alone (no other plugins enabled) on Domoticz (version 2021.1) on my testing VM. But when I tested the plugin on my "production" Domoticz (the same 2021.1 version) running on RPI, together with other 3 plugins, I see messages:

Code: Select all

Python exception set prior to callback 'onMessage'

Those are not an error messages just normal messages and Volumio plugin and other enabled plugins seems to working but I think it is not normal... Could you point me out me how can I solve this problem. How can I debug, what exception occurred before 'onMessage' callback, please?

Thanks!

Frantisek

[ferrosk]

When checking Domoticz source code (2021.1), the message is logged by Domoticz Plugin system 'hardware/plugins/Plugins.cpp':

Code: Select all

       void CPlugin::Callback(PyObject *pTarget, const std::string &sHandler, PyObject *pParams)
        {
                try
                {
                        // Callbacks MUST already have taken the PythonMutex lock otherwise bad thin
gs will happen
                        if (pTarget && !sHandler.empty())
                        {
                                if (PyErr_Occurred())
                                {
                                        PyErr_Clear();
                                        Log(LOG_NORM, "(%s) Python exception set prior to callback '%s'", m_Name.c_str(), sHandler.c_str());
                                }

Is the error I see when running the plugin with other plugins related to thread locking? Do I have implement threading in my plugin?

Here is the code of my Volumio plugin:
https://github.com/frepkovsky/Domoticz-Volumio-Plugin

If you have any suggestion, which direction I should go to get rid of those messages, please let me know. It is my first Domoticz plugin so I'm still learning only

[ferrosk]

I found running my Volumio plugin in combination with other plugins was not the cause of the problem. When I disabled all plugins except Volumio the issue persist.

For further investigation, I had to modify Domoticz source code to log what Python exception was raised and not just message "Python exception set prior to callback" - just this one line added to Plugin.cpp:

Code: Select all

$ diff ./hardware/plugins/Plugins.cpp.orig ./hardware/plugins/Plugins.cpp
1831a1832,1833
> 
>                                       LogPythonException(sHandler);

so the part of the code looks as follows:

Code: Select all

        void CPlugin::Callback(PyObject *pTarget, const std::string &sHandler, PyObject *pParams)
        {
                try
                {
                        // Callbacks MUST already have taken the PythonMutex lock otherwise bad things will happen
                        if (pTarget && !sHandler.empty())
                        {
                                if (PyErr_Occurred())
                                {

                                        LogPythonException(sHandler);
                                        PyErr_Clear();
                                        Log(LOG_NORM, "(%s) Python exception set prior to callback '%s'", m_Name.c_str(), sHandler.c_str());
                                }

After rebuilding Domoticz and running it, I finally got Python error logged by Domoticz:

Code: Select all

2022-02-10 15:55:06.120 Volumio: (Volumio) Python exception set prior to callback 'onMessage'
2022-02-10 15:55:06.119 Error: Volumio: (Volumio) 'onMessage' failed 'OverflowError':'Python int too large to convert to C long'. 

so the reason is an overflow error when converting Python int to C long int value. I did not notice this problem when testing the plugin on my Domoticz test VM because it was running 64-bit OS version (allows bigger value of long int) while my "production" Domoticz system on Raspberry Pi is running Raspbian which is available as 32-bit OS only.

Knowing the cause of the issue, I identified problematic code in the plugin - masking key generated for Websocket frame was passed to Send() method as (int) number instead of string. I'm testing the fix now and will commit the fix in Volumio plugin repository soon.