[asterisk-bugs] [JIRA] (ASTERISK-30341) cdr_adaptive_odbc: fails to write CDRs after database reload

[Gregory Massel (JIRA)]

    [ https://issues.asterisk.org/jira/browse/ASTERISK-30341?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=261250#comment-261250 ] 

Gregory Massel commented on ASTERISK-30341:
-------------------------------------------

Apologies for the delay, however, it's been a long time since this incident recurred. It did today.

Asterisk does NOT freeze; I just mean that no CDRs can be posted to MySQL. CDRs are still written locally to cdr-csv and errors log such as:

WARNING[9319]: cdr_adaptive_odbc.c:343 generic_prepare: SQL Prepare failed![INSERT INTO cdr_vpbx [..]
WARNING[9319]: cdr_adaptive_odbc.c:347 generic_prepare: SQL Execute returned an error -1: HY000: [MySQL][ODBC 8.0(w) Driver][mysqld-8.0.31-0ubuntu0.20.04.2] (59)
WARNING[9319]: cdr_adaptive_odbc.c:766 odbc_log: cdr_adaptive_odbc: Insert failed on 'asterisk-cdr-connector:cdr_vpbx'.  CDR failed: INSERT INTO cdr_vpbx [..]

"module reload cdr_adaptive_odbc.so" on its own does NOT fix it, nor does "module reload res_odbc.so" on its own.

One has to run BOTH:
module reload res_odbc.so
[Jan 26 23:31:39] NOTICE[695081]: res_odbc.c:697 load_odbc_config: Registered ODBC class 'asterisk-cdr-connector' dsn->[asterisk-cdr-connector]
[Jan 26 23:31:39] NOTICE[695081]: res_odbc.c:697 load_odbc_config: Registered ODBC class 'clientzone-connector' dsn->[clientzone-connector]

module reload cdr_adaptive_odbc.so
Module 'cdr_adaptive_odbc.so' reloaded successfully.

There is no more debugging information that I am able to extract, however, what I did pick up here is that func_odbc.c was also throwing errors from that time (06:24:00) but then just suddenly came right all by itself after 09:34:47 (3 hours and 10 minutes later) with no specific intervention. In those three hours, it was logging errors such as:

[Jan 26 09:34:47] WARNING[232795][C-001313b7] func_odbc.c: SQL Exec Direct failed (-1)![<redacted>]
[Jan 26 09:34:47] ERROR[232795][C-001313b7] func_odbc.c: Unable to execute query [<redacted>]

I know that this triggers whenever the MySQL server shuts down. What happened this morning was that there was a package update, so the server shutdown the MySQL service, completed the 'apt upgrade' process, then restarted MySQL server. All my other systems just graciously reconnect to the MySQL server.

So it may be that the issue is actually in res_odbc.so.

I cannot explain why func_odbc comes right by itself nor why it takes so long to do so. The MySQL server was only down for a few seconds. The /var/log/apt/history.log shows that it was around 3 seconds in total and I'm confident of that because I have lots of other systems that rely on that database for other purposes that would have logged a flood of errors if it was down for any longer.

I have two Asterisk instances running on the one server (non-root), both v18.15.1, and only one was affected. Being on the same server, they'd therefore use the same unixODBC installation. However, the one that was not affected did not appear to be attempting to write any CDRs or call func_odbc at the time. So it seems that, perhaps, this issue will only occur if a CDR is being written or func_odbc called during those few seconds when the connection to the MySQL server is lost.

For one server, there were also two activate connections to MySQL, one of which showed idle for an extraordinary period of time. So it may be that res_odbc sets up a connections to the MySQL server again, however, for whatever reason still thinks that they're unusable.

> cdr_adaptive_odbc: fails to write CDRs after database reload
> ------------------------------------------------------------
>
>                 Key: ASTERISK-30341
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-30341
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: CDR/cdr_adaptive_odbc
>    Affects Versions: 18.15.1
>         Environment: Asterisk 18.15.1 on Unbuntu 18.04.1
> MySQL 8.0.31-0ubuntu0.20.04.2 on Ubuntu 20.04.2
> Both servers on same physical network and subnet.
>            Reporter: Gregory Massel
>            Severity: Major
>
> CDRs log perfectly to MySQL using cdr_adaptive_odbc up until the database shuts down and restarts.
> Occasionally Ubuntu will release an update version package for MySQL. When it does so, the database server automatically downloads the update, stops MySQL, installs the update and then restarts MySQL. When this happens, cdr_adaptive_odbc loses connection to the MySQL server and fails to ever reconnect.
> Asterisk logs countless messages like the following:
> [Dec  7 00:00:04] WARNING[28054] cdr_adaptive_odbc.c: SQL Prepare failed![INSERT INTO cdr_vpbx5 (start, clid, src, dst, dnid, dcontext, channel, dstchannel, lastapp, lastdata, duration, billsec, disposition, amaflags, accountcode, uniqueid, peeraccount, linkedid, sequence) VALUES ({ ts '2022-12-06 23:59:45' }, '"Control" <0123456789>', '0123456789', '0123456789', '0123456789', 'swvpbx-internal', 'PJSIP/xxx202-0007b59d', 'PJSIP/yyy-0007b59e', 'Dial', 'PJSIP/yyy/sip:0123456789 at 10.1.2.3:5060,120,', 18, 0, 'NO ANSWER', 3, 'xxx', '1670363985.509608', 'xxx', '1670363985.509608', 717979)]
> [Dec  7 00:00:04] WARNING[28054] cdr_adaptive_odbc.c: SQL Execute returned an error -1: HY000: [MySQL][ODBC 8.0(w) Driver][mysqld-8.0.31-0ubuntu0.20.04.1] (59)
> I do NOT believe that the issue lies with the ODBC configuration, because func_odbc continues to work perfectly.
> my res_odbc.conf file looks like:
> ;;; odbc setup file
> [asterisk-cdr-connector]
> enabled => yes
> dsn => asterisk-cdr-connector
> username => asterisk
> password => redacted
> pre-connect => yes
> sanitysql => select 1
> ;idlecheck => 180
> ;share_connections => yes
> ;limit => 20
> max_connections => 20
> [clientzone-connector]
> enabled => yes
> dsn => clientzone-connector
> username => redacted
> password => redacted
> pre-connect => yes
> sanitysql => select 1
> isolation => repeatable_read
> ;idlecheck => 180
> ;share_connections => yes
> ;limit => 20
> max_connections => 20
> My cdr_adaptive_odbc.conf file looks like:
> [db]
> connection=asterisk-cdr-connector
> table=cdr
> Restarting Asterisk solves the issue. Issuing a "module reload res_odbc.so" and "module reload cdr_adaptive_odbc.so" also solves the issue.
> It is not just updates to MySQL that will cause this. Anything that causes the database to temporarily become inaccessible, e.g. a brief connectivity glitch, will also cause it.
> This also does not affect all Asterisk servers connected to the database; it would appear that it only affects those that make/receive a call and therefore attempt to write a CDR during the time that the database is briefly inaccessible.
> The correct functionality should be to attempt reconnection ~60 seconds later and then write the CDR, not to get caught in a frozen state.



--
This message was sent by Atlassian JIRA
(v6.2#6252)