Domoticz received fatal signal 11 (Segmentation fault) when integrating Zigpy stack

[pipiche]

That is quiet an interesting and crasy issue.

I'm currently trying to develop a plugin for Domoticz based on the zigpy python library. That library allow to be independent of the HW layer and provide a full Zigbee 3.0, ZHA stack .


Any hints would be welcome .

The library is based on asyncio , and in order to get it integrated into the Python Framework, I have dedicated a thread for that.

My current issue is related to sqlite access. And I get a systematic segmentation fault on an sql.execute() call when doing a SELECT statement. For instance during the Table Creation the same method is called, and there is no issue at all. Only when the first SELECT * from table statement is made that I get a full crash

In the here after crash stack:

line 54 is :

Code: Select all

result = self._cursor.execute(sql_statement)

where sql_statement = 'SELECT * FROM devices' and where devices is a table which have been created before in the same run by

Code: Select all

sql_statement = CREATE TABLE IF NOT EXISTS devices (ieee ieee, nwk, status)

here after is the crash stack for reference, but I dout that it can be of any use

Code: Select all

Aug 13 10:31:08 rasp domoticz[18067]: Fatal Python error: Segmentation fault
Aug 13 10:31:08 rasp domoticz[18067]: Current thread 0xaaf963a0 (most recent call first):
Aug 13 10:31:08 rasp domoticz[18067]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/appdb.py", line 54 in execute
Aug 13 10:31:08 rasp domoticz[18067]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/appdb.py", line 320 in _scan
Aug 13 10:31:08 rasp domoticz[18067]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/appdb.py", line 373 in _load_devices
Aug 13 10:31:08 rasp domoticz[18067]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/appdb.py", line 325 in load
Aug 13 10:31:08 rasp domoticz[18067]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/application.py", line 53 in _load_db
Aug 13 10:31:08 rasp domoticz[18067]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/application.py", line 61 in new
Aug 13 10:31:08 rasp domoticz[18067]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/plugin.py", line 138 in main
Aug 13 10:31:08 rasp domoticz[18067]:   File "/usr/lib/python3.7/asyncio/events.py", line 88 in _run
Aug 13 10:31:08 rasp domoticz[18067]:   File "/usr/lib/python3.7/asyncio/base_events.py", line 1786 in _run_once
Aug 13 10:31:08 rasp domoticz[18067]:   File "/usr/lib/python3.7/asyncio/base_events.py", line 541 in run_forever
Aug 13 10:31:08 rasp domoticz[18067]:   File "/usr/lib/python3.7/asyncio/base_events.py", line 574 in run_until_complete
Aug 13 10:31:08 rasp domoticz[18067]:   File "/usr/lib/python3.7/asyncio/runners.py", line 43 in run
Aug 13 10:31:08 rasp domoticz[18067]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/plugin.py", line 183 in zigpy_thread
Aug 13 10:31:08 rasp domoticz[18067]:   File "/usr/lib/python3.7/threading.py", line 870 in run
Aug 13 10:31:08 rasp domoticz[18067]:   File "/usr/lib/python3.7/threading.py", line 926 in _bootstrap_inner
Aug 13 10:31:08 rasp domoticz[18067]:   File "/usr/lib/python3.7/threading.py", line 890 in _bootstrap
Aug 13 10:31:08 rasp domoticz[18067]: Thread 0xb4fe93a0 (most recent call first):
Aug 13 10:31:08 rasp domoticz[18067]: Error: Domoticz(pid:18067, tid:18090('PluginMgr')) received fatal signal 11 (Segmentation fault)
Aug 13 10:31:08 rasp domoticz[18067]: Error: siginfo address=0x4693, address=0xaaf943ec
Aug 13 10:31:08 rasp domoticz[18067]: Error: Failed to start gdb, will use backtrace() for printing stack frame
Aug 13 10:31:08 rasp domoticz[18067]:
Aug 13 10:31:08 rasp domoticz[18067]: Error: #0  /usr/share/domoticz/beta-domoticz/domoticz() [0x2f598c]
Aug 13 10:31:08 rasp domoticz[18067]: Error: #1  /usr/share/domoticz/beta-domoticz/domoticz : signal_handler(int, siginfo_t*, void*) + 0x238 [0x2f63a8]
Aug 13 10:31:08 rasp domoticz[18067]: Error: #2  /lib/libc.so.6 : __default_rt_sa_restorer + 0 [0xb6947570]

[pipiche]

I did a trick on plugin.py in order to run it directly from the unix prompt (and do not get it launched by Domoticz).
In that case I don't have any issue.

So the segmentation fault is due to the Python Framework in the context of this plugin and all the zigpy stack .

Could it be related to a Heap or Stack size ?

[Dnpwwo]

I would suspect there is a conflict between Domoticz and the plugin accessing the database simultaneously. I've successfully done database reads before but not much writing.

I've never used 'asyncio' so have no idea how well it would work with the framework, normal Python threads are fine.

[pipiche]

I would suspect there is a conflict between Domoticz and the plugin accessing the database simultaneously. I've successfully done database reads before but not much writing.

I've never used 'asyncio' so have no idea how well it would work with the framework, normal Python threads are fine.

But that are different databases , I'm not accessing the Domoticz DB, but a dedicated one

[pipiche]

I just did install gdb and get a better/deeper/cleaner stack trace.

Code: Select all

Aug 15 12:57:46 rasp domoticz[2468]: Current thread 0xaa3ff3a0 (most recent call first):
Aug 15 12:57:46 rasp domoticz[2468]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/appdb.py", line 54 in execute
Aug 15 12:57:46 rasp domoticz[2468]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/appdb.py", line 323 in _scan
Aug 15 12:57:46 rasp domoticz[2468]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/appdb.py", line 376 in _load_devices
Aug 15 12:57:46 rasp domoticz[2468]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/appdb.py", line 328 in load
Aug 15 12:57:46 rasp domoticz[2468]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/application.py", line 53 in _load_db
Aug 15 12:57:46 rasp domoticz[2468]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/zigpy/application.py", line 61 in new
Aug 15 12:57:46 rasp domoticz[2468]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/plugin.py", line 128 in main
Aug 15 12:57:46 rasp domoticz[2468]:   File "/usr/lib/python3.7/asyncio/events.py", line 88 in _run
Aug 15 12:57:46 rasp domoticz[2468]:   File "/usr/lib/python3.7/asyncio/base_events.py", line 1786 in _run_once
Aug 15 12:57:46 rasp domoticz[2468]:   File "/usr/lib/python3.7/asyncio/base_events.py", line 541 in run_forever
Aug 15 12:57:46 rasp domoticz[2468]:   File "/usr/lib/python3.7/asyncio/base_events.py", line 574 in run_until_complete
Aug 15 12:57:46 rasp domoticz[2468]:   File "/usr/lib/python3.7/asyncio/runners.py", line 43 in run
Aug 15 12:57:46 rasp domoticz[2468]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/plugin.py", line 177 in zigpy_thread
Aug 15 12:57:46 rasp domoticz[2468]:   File "/usr/lib/python3.7/threading.py", line 870 in run
Aug 15 12:57:46 rasp domoticz[2468]:   File "/usr/lib/python3.7/threading.py", line 926 in _bootstrap_inner
Aug 15 12:57:46 rasp domoticz[2468]:   File "/usr/lib/python3.7/threading.py", line 890 in _bootstrap
Aug 15 12:57:46 rasp domoticz[2468]: Thread 0xb504f3a0 (most recent call first):
Aug 15 12:57:46 rasp domoticz[2468]: Error: Domoticz(pid:2468, tid:2493('PluginMgr')) received fatal signal 11 (Segmentation fault)
Aug 15 12:57:46 rasp domoticz[2468]: Error: siginfo address=0x9a4, address=0xaa3fd2ac
Aug 15 12:57:51 rasp domoticz[2468]: Error: Thread 21 (Thread 0xaa3ff3a0 (LWP 2493)):
Aug 15 12:57:51 rasp domoticz[2468]: Error: #0  0xb6bdb748 in waitpid () from /lib/libpthread.so.0
Aug 15 12:57:51 rasp domoticz[2468]: Error: #1  0x002f5d7c in dumpstack_gdb(bool) ()
Aug 15 12:57:51 rasp domoticz[2468]: Error: #2  0x002f62e8 in signal_handler(int, siginfo_t*, void*) ()
Aug 15 12:57:51 rasp domoticz[2468]: Error: #3  <signal handler called>
Aug 15 12:57:51 rasp domoticz[2468]: Error: #4  0xb6bdbc44 in raise () from /lib/libpthread.so.0
Aug 15 12:57:51 rasp domoticz[2468]: Error: #5  <signal handler called>
Aug 15 12:57:51 rasp domoticz[2468]: Error: #6  0xb6a000e8 in __memcpy_neon () from /lib/libc.so.6
Aug 15 12:57:51 rasp domoticz[2468]: Error: #7  0x007557f0 in sqlite3_str_vappendf ()
Aug 15 12:57:51 rasp domoticz[2468]: Error: #8  0x00000000 in ?? ()
Aug 15 12:57:51 rasp systemd[1]: Started Process Core Dump (PID 2501/UID 0).

[pipiche]

I finally been able to duplicate the issue with a short plugin. It crashes exatly at the same place with the all zigpy library.

Code: Select all

Aug 16 19:54:07 rasp domoticz[31446]: Status: (ZigPy on RPI) Initialized version 0.0.1, author 'pipiche38'
Aug 16 19:54:07 rasp domoticz[31446]: (ZigPy on RPI) onStart called
Aug 16 19:54:07 rasp domoticz[31446]: (ZigPy on RPI) Starting the thread
Aug 16 19:54:07 rasp domoticz[31446]: Fatal Python error: Segmentation fault
Aug 16 19:54:07 rasp domoticz[31446]: Current thread 0xac9dd3a0 (most recent call first):
Aug 16 19:54:07 rasp domoticz[31446]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/plugin.py", line 89 in execute
Aug 16 19:54:07 rasp domoticz[31446]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/plugin.py", line 192 in _scan
Aug 16 19:54:07 rasp domoticz[31446]:   File "/var/lib/domoticz/plugins/Domoticz-Zigpy/plugin.py", line 207 in zigpy_thread
Aug 16 19:54:07 rasp domoticz[31446]:   File "/usr/lib/python3.8/threading.py", line 870 in run
Aug 16 19:54:07 rasp domoticz[31446]:   File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
Aug 16 19:54:07 rasp domoticz[31446]:   File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap
Aug 16 19:54:07 rasp domoticz[31446]: Thread 0xb504e3a0 (most recent call first):
Aug 16 19:54:07 rasp domoticz[31446]: <no Python frame>
Aug 16 19:54:07 rasp domoticz[31446]: Error: Domoticz(pid:31446, tid:31468('PluginMgr')) received fatal signal 11 (Segmentation fault)
Aug 16 19:54:07 rasp domoticz[31446]: Error: siginfo address=0x7ad6, address=0xac9dc10c
Aug 16 19:54:10 rasp domoticz[31446]: Error: Thread 19 (Thread 0xac9dd3a0 (LWP 31468)):
Aug 16 19:54:10 rasp domoticz[31446]: Error: #0  0xb6a46860 in wait4 () from /lib/libc.so.6
Aug 16 19:54:10 rasp domoticz[31446]: Error: #1  0x002f5d7c in dumpstack_gdb(bool) ()
Aug 16 19:54:10 rasp domoticz[31446]: Error: #2  0x002f62e8 in signal_handler(int, siginfo_t*, void*) ()
Aug 16 19:54:10 rasp domoticz[31446]: Error: #3  <signal handler called>
Aug 16 19:54:10 rasp domoticz[31446]: Error: #4  0xb6c081d8 in raise () from /lib/libpthread.so.0
Aug 16 19:54:10 rasp domoticz[31446]: Error: #5  <signal handler called>
Aug 16 19:54:10 rasp domoticz[31446]: Error: #6  0xb6a18fe0 in free () from /lib/libc.so.6
Aug 16 19:54:10 rasp domoticz[31446]: Error: #7  0x0074d5a0 in sqlite3VdbeMemGrow ()
Aug 16 19:54:10 rasp domoticz[31446]: Error: #8  0x00000000 in ?? ()
Aug 16 19:54:10 rasp systemd[1]: Started Process Core Dump (PID 31479/UID 0).

Here attached

plugin.py.zip

(3.12 KiB) Downloaded 68 times

[Dnpwwo]

Still don't know but I have a comment and a question which may be useful:

• Comment: Not sure doing all this db work in an object constructor is not good practice in general
• Question: I didn't see and commit statements anywhere, is that on purpose? I would suggest changing 'execute' to be

  Code: Select all

      def execute(self, *args, **kwargs):
      	self._cursor = self._db.cursor()
          retval = self._cursor.execute(*args, **kwargs)
          self._cursor.commit()
          return retval
  

  I use something similar in some of my code

[pipiche]

Still don't know but I have a comment and a question which may be useful:

• Comment: Not sure doing all this db work in an object constructor is not good practice in general
• Question: I didn't see and commit statements anywhere, is that on purpose? I would suggest changing 'execute' to be

I cannot really comment on why this is done as an object constructor, as this is the zigpy library implementation.
As the commit() , indeed as I focus on duplicating the problem and as the problem was found on the first select statement.

I did further investigation, and I think I found the line of code creating the issue

Code: Select all

self.execute("PRAGMA user_version = %s" % (DB_VERSION,))

Unfortunately this doesn't help in the overall code !

Code: Select all

    def execute(self, *args, **kwargs):
    	self._cursor = self._db.cursor()
        retval = self._cursor.execute(*args, **kwargs)
        self._cursor.commit()
        return retval

I use something similar in some of my code
[/list]

Did update the execute() method

Code: Select all

    def execute(self, *args, **kwargs):
        self._cursor = self._db.cursor()
        retval = self._cursor.execute(*args, **kwargs)
        self._db.commit()

What I wonder is if we don't have some conflict between the SQLITE3 used by domoticz in the C++ code and the SQLITE3 used in the Python Framework. I suspect a conflict ...

[edit]
Did further investigation and I think we need to understand why while using the PRAGMA in the domoticz code we have such issue, as if we are outside of the Python Framework there is no issue.
Most-likely PRAGMA just trigger the issue, but it is not the root cause ... as on the rea if I remove the PRAGMA part, I still get the segmentation violation. So I would consider that the PRAGMA is a good way to reproduce the problem, and if we find the root cause, we would fixe the overall issue.

[pipiche]

@Dnpwwo

For your information on the sqlite3 issue , I have managed to have a persistent database (without using sqlite3) and the plugin works pretty well .

I strongly believe that there is some conflict between the sqlite calls from Domoticz and the one from the embedded plugin framework.

In the past, I had some issue with my plugin when accessing directly the Domoticz DB (which I consider was a bit risky), so I didn't investigate much and found other ways.

But here as I demonstrated in the plugin we are using a different Database (not the domoticz one), the asyncio is not involved at.

[pipiche]

I have created an issue on github

https://github.com/domoticz/domoticz/issues/4312