Summary:	ASTERISK-30341: cdr_adaptive_odbc: fails to write CDRs after database reload
Reporter:	Gregory Massel (gmza)	Labels:
Date Opened:	2022-12-07 03:43:09.000-0600	Date Closed:
Priority:	Major	Regression?
Status:	Open/New	Components:	CDR/cdr_adaptive_odbc
Versions:	18.15.1	Frequency of Occurrence
Related Issues:
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.	Attachments:
Description:	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@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.
Comments:	By: Asterisk Team (asteriskteam) 2022-12-07 03:43:13.066-0600 Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. Please note that log messages and other files should not be sent to the Sangoma Asterisk Team unless explicitly asked for. All files should be placed on this issue in a sanitized fashion as needed. A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report. Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process]. Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur. Please note that by submitting data, code, or documentation to Sangoma through JIRA, you accept the Terms of Use present at [https://www.asterisk.org/terms-of-use/|https://www.asterisk.org/terms-of-use/]. By: Joshua C. Colp (jcolp) 2022-12-07 03:52:54.727-0600 You state that reloading both res_odbc and cdr_adaptive_odbc fixes the issue. Does merely reloading the CDR module fix it? Can you attach a complete debug log as well? You've also stated "a frozen state". What does that mean? Are you just referring to not being able to post the CDRs or is Asterisk freezing? There is also no cache in CDR modules. The CDR core provides a batching mechanism which batch posts, that is the extent of what is implemented. By: Asterisk Team (asteriskteam) 2022-12-21 12:00:32.539-0600 Suspended due to lack of activity. This issue will be automatically re-opened if the reporter posts a comment. If you are not the reporter and would like this re-opened please create a new issue instead. If the new issue is related to this one a link will be created during the triage process. Further information on issue tracker usage can be found in the Asterisk Issue Guidlines [1]. [1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines By: Gregory Massel (gmza) 2023-01-26 16:07:43.288-0600 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. By: Asterisk Team (asteriskteam) 2023-01-26 16:07:43.730-0600 This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable. By: ben kolodny (benphone) 2023-03-09 10:36:36.631-0600 look like i got his also, just with a lack of being able to connect to db ! if more info is needed i would try to help i do just a "reload" and it works and it starts working again . maybe there should be some kind of mechanism to retest a erroneous connection after a X amount of seconds ?