Spontaneous Reboot Due To MySQL Lookups ? (Jonas Kellens)

Home » Asterisk Users » Spontaneous Reboot Due To MySQL Lookups ? (Jonas Kellens)
Asterisk Users No Comments

Hi Jonas

We have more or less this behaviour with 1.8.32.3 when writing CDRs to ODBC on Percona 5.6 (MySQL drop-in replacement with some optimisations and extra features.)

In our case the system does NOT reboot, but Asterisk itself crashes with a segfault inside unixODBC itself.

We’re running on CentOS 7, so the first thing we tried was to upgrade the ODBC drivers to the most recent version, and also use the most recent MySQL ODBC connector.

This did not solve the problem, and the spontaneous shutdowns (and then restarts via CentOS 7 systemd) of the 1.8.32.3 instances continued.

Eventually we traced this to contention on the CDR table itself in the associated MySQL / Percona instance. We had a stored procedure running on the CDR table at set intervals via a MySQL timed event that was converting the Asterisk CDR data into another table we use for our own purposes. This was effectively locking the CDR table in ways that wasn’t allowing Asterisk 1.8.32.3 to enter CDRs when it wanted to.

The practical effect in real-world terms was that people could make a call, but then NOT do another call on that same extension, for up to five or ten minutes at a time. This was because the Asterisk 1.8.32.3 instance was waiting to get access to the CDR table to write that extensions most-recent CDR record in, and was holding onto the extension to prevent a new call when it hadn’t yet managed to write into the CDR table for the previous call.

Also, if pushed hard enough with concurrent calls, the Asterisk instance would get segfaulted due to a segfault in the ODBC drivers, due to this contention and waiting for access to the CDR table.

All I can recommend is to upgrade to, for example, Asterisk 13.22.0 which is relatively painless to upgrade to if you’re on 1.8.32.3 or the 1.8 series (at least in our experience) – OR remove contention on the CDR table.

We eventually removed the extra SP we had running on the MySQL / Percona CDR table, as the contention problems persisted with 13.22.0, BUT IT DOES NOT CRASH LIKE 1.8.32.3 – while running against the same Percona 5.6 MySQL version, with the same level of MySQL DB contention taking place.

E. g. look for contention on the MySQL tables you use, or just SQL contention in general – generate enough contention (with tables locked when Asterisk tries to write to them) and it does seem that 1.8 series Asterisk instances will segfault in the ODBC driver, if the concurrent call count goes high enough.

Or (the better option) upgrade to at least Asterisk 13 (in our experience).

Even with the same contention on MySQL db’s accessed with unixODBC 2.3.6, and our same table-access killer SP running, Asterisk 13.22.0 doesn’t crash at all when writing with the same version unixODBC driver to the contentious tables in MySQL. (We still had the same problem with people only being capable of making one call and then waiting up to five minutes post-hangup before being able to make the next call, but we solved that by not running the SP on schedule anymore against the CDR and CEL tables.)

E.g. effectively we solved the crashes by upgrading from 1.8.32.3 to 13.22.0 – the rest is incidentals unique to our usage case.

Hope this helps.

Date: Thu, 4 Oct 2018 17:10:01 +0200
From: Jonas Kellens
To: Asterisk Users Mailing List – Non-Commercial Discussion

Subject: [asterisk-users] Spontaneous reboot due to MySQL lookups ?
Message-ID:
Content-Type: text/plain; charset=”utf-8″; Format=”flowed”

Hello

using Asterisk 1.8.32.

I notice that there is a spontaneous reboot of the Asterisk system from time to time.

When I look in the logs (verbose file) I noticed that every time this occurs it’s at a moment that there is a MySQL action, be it a lookup or an insert/update/delete.

I must say I do have some MySQL queries that occur in my dialplan when a call comes in, to look up different actions to perform on this call.

An idea how to overcome this problem ? Seems a “performance” issue, no ?!

Is it better to have these MySQL queries to be done by an external script (like a php script that I call with the System()-command or a SHELL()-command) ?

Here are some examples from the verbose file.

[Aug 22 15:19:10] VERBOSE[2977] pbx.c: [Aug 22 15:19:10] —
Executing [s@sub-GetAlertInfo:3] MYSQL(“SIP/SipAgenT01-0000317d”,
“Connect connid localhost myuser mypwd myDB”) in new stack
[Aug 22 15:19:10] VERBOSE[2977] pbx.c: [Aug 22 15:19:10] —
Executing [s@sub-GetAlertInfo:5] MYSQL(“SIP/SipAgenT01-0000317d”, “Query resultid 1 SELECT uri, callinfo FROM distringtone WHERE onoff=’1′”) in new stack
[Aug 22 15:19:18] VERBOSE[3306] config.c: [Aug 22 15:19:18] == Parsing
‘/etc/asterisk/logger.conf’: [Aug 22 15:19:18] VERBOSE[3306] config.c:
[Aug 22 15:19:18] == Found
[Aug 22 15:19:18] VERBOSE[3306] config.c: [Aug 22 15:19:18] == Parsing
‘/etc/asterisk/asterisk.conf’: [Aug 22 15:19:18] VERBOSE[3306] config.c:
[Aug 22 15:19:18] == Found
[Aug 22 15:19:18] VERBOSE[3306] manager.c: [Aug 22 15:19:18] == Manager registered action DataGet
[Aug 22 15:19:18] VERBOSE[3306] config.c: [Aug 22 15:19:18] == Parsing
‘/etc/asterisk/codecs.conf’: [Aug 22 15:19:18] VERBOSE[3306] config.c:
[Aug 22 15:19:18] == Found
[Aug 22 15:19:18] VERBOSE[3306] loader.c: [Aug 22 15:19:18] Asterisk Dynamic Loader Starting:
[Aug 22 15:19:18] VERBOSE[3306] config.c: [Aug 22 15:19:18] == Parsing
‘/etc/asterisk/modules.conf’: [Aug 22 15:19:18] VERBOSE[3306] config.c:
[Aug 22 15:19:18] == Found
[Aug 22 15:19:18] VERBOSE[3306] config.c: [Aug 22 15:19:18] == Parsing
‘/etc/asterisk/res_config_mysql.conf’: [Aug 22 15:19:18] VERBOSE[3306]
config.c: [Aug 22 15:19:18] == Found
[Aug 22 15:19:18] VERBOSE[3306] res_config_mysql.c: [Aug 22 15:19:18]
== MySQL RealTime driver loaded.
[Aug 22 15:19:18] VERBOSE[3306] loader.c: [Aug 22 15:19:18]
res_config_mysql.so => (MySQL RealTime Configuration Driver)

[Aug 22 16:23:25] VERBOSE[24283] pbx.c: [Aug 22 16:23:25] —
Executing [s@sub-GetSipAccountdetails:3]
MYSQL(“SIP/SipAgenT01-00004184”, “Connect connid localhost myuser mypwd myDB”) in new stack
[Aug 22 16:23:25] VERBOSE[24283] pbx.c: [Aug 22 16:23:25] —
Executing [s@sub-GetSipAccountdetails:4]
MYSQL(“SIP/SipAgenT01-00004184”, “Query resultid 1 SELECT SIPusername, currstatus, available FROM tbl_SIP WHERE ID=”800″”) in new stack
[Aug 22 16:23:32] VERBOSE[24309] config.c: [Aug 22 16:23:32] == Parsing
‘/etc/asterisk/logger.conf’: [Aug 22 16:23:32] VERBOSE[24309] config.c:
[Aug 22 16:23:32] == Found
[Aug 22 16:23:32] VERBOSE[24309] config.c: [Aug 22 16:23:32] == Parsing
‘/etc/asterisk/asterisk.conf’: [Aug 22 16:23:32] VERBOSE[24309]
config.c: [Aug 22 16:23:32] == Found
[Aug 22 16:23:32] VERBOSE[24309] manager.c: [Aug 22 16:23:32] == Manager registered action DataGet
[Aug 22 16:23:32] VERBOSE[24309] config.c: [Aug 22 16:23:32] == Parsing
‘/etc/asterisk/codecs.conf’: [Aug 22 16:23:32] VERBOSE[24309] config.c:
[Aug 22 16:23:32] == Found
[Aug 22 16:23:32] VERBOSE[24309] loader.c: [Aug 22 16:23:32] Asterisk Dynamic Loader Starting:
[Aug 22 16:23:32] VERBOSE[24309] config.c: [Aug 22 16:23:32] == Parsing
‘/etc/asterisk/modules.conf’: [Aug 22 16:23:32] VERBOSE[24309] config.c:
[Aug 22 16:23:32] == Found
[Aug 22 16:23:32] VERBOSE[24309] config.c: [Aug 22 16:23:32] == Parsing
‘/etc/asterisk/res_config_mysql.conf’: [Aug 22 16:23:32] VERBOSE[24309]
config.c: [Aug 22 16:23:32] == Found
[Aug 22 16:23:32] VERBOSE[24309] res_config_mysql.c: [Aug 22 16:23:32]
== MySQL RealTime driver loaded.
[Aug 22 16:23:32] VERBOSE[24309] loader.c: [Aug 22 16:23:32]
res_config_mysql.so => (MySQL RealTime Configuration Driver)

[Oct 4 10:11:25] VERBOSE[4944] pbx.c: [Oct 4 10:11:25] —
Executing [s@sub-settings:16] MYSQL(“SIP/SipAgenT01-000008cb”, “Connect connid localhost myuser mypwd myDB”) in new stack
[Oct 4 10:11:25] VERBOSE[4944] pbx.c: [Oct 4 10:11:25] —
Executing [s@sub-settings:17] MYSQL(“SIP/SipAgenT01-000008cb”, “Query resultid 1 SELECT blockID from DID where DID=987654321”) in new stack
[Oct 4 10:11:29] VERBOSE[4961] config.c: [Oct 4 10:11:29] == Parsing
‘/etc/asterisk/asterisk.conf’: [Oct 4 10:11:29] VERBOSE[4961] config.c:
[Oct 4 10:11:29] == Found
[Oct 4 10:11:29] VERBOSE[4961] manager.c: [Oct 4 10:11:29] == Manager registered action DataGet
[Oct 4 10:11:29] VERBOSE[4961] config.c: [Oct 4 10:11:29] == Parsing
‘/etc/asterisk/codecs.conf’: [Oct 4 10:11:29] VERBOSE[4961] config.c:
[Oct 4 10:11:29] == Found
[Oct 4 10:11:29] VERBOSE[4961] loader.c: [Oct 4 10:11:29] Asterisk Dynamic Loader Starting:
[Oct 4 10:11:29] VERBOSE[4961] config.c: [Oct 4 10:11:29] == Parsing
‘/etc/asterisk/modules.conf’: [Oct 4 10:11:29] VERBOSE[4961] config.c:
[Oct 4 10:11:29] == Found
[Oct 4 10:11:29] VERBOSE[4961] config.c: [Oct 4 10:11:29] == Parsing
‘/etc/asterisk/res_config_mysql.conf’: [Oct 4 10:11:29] VERBOSE[4961]
config.c: [Oct 4 10:11:29] == Found
[Oct 4 10:11:29] VERBOSE[4961] res_config_mysql.c: [Oct 4 10:11:29]
== MySQL RealTime driver loaded.
[Oct 4 10:11:29] VERBOSE[4961] loader.c: [Oct 4 10:11:29]
res_config_mysql.so => (MySQL RealTime Configuration Driver)

Kind regards

Jonas.

————– next part ————–
An HTML attachment was scrubbed… URL:

——————————

Message: 3
Date: Thu, 4 Oct 2018 17:36:08 +0200
From: Antony Stone
To: “Asterisk Users Mailing List – Non-Commercial Discussion”

Subject: Re: [asterisk-users] Spontaneous reboot due to MySQL lookups
?
Message-ID: <201810041736.08641.Antony.Stone@asterisk.open.source.it>
Content-Type: Text/Plain; charset=”iso-8859-15″

Dog is my Co-pilot

————– next part ————–
An HTML attachment was scrubbed… URL:

——————————

Subject: Digest Footer