[Home]

Summary:ASTERISK-28566: CDR backend unload problem during active call(s)
Reporter:Marian Piater (maikyp)Labels:patch
Date Opened:2019-10-04 15:22:09Date Closed:2019-10-08 07:30:15
Priority:MajorRegression?
Status:Closed/CompleteComponents:CDR/General
Versions:16.5.1 Frequency of
Occurrence		Constant
Related
Issues:
Environment:Debian Wheeze 64bit, Asterisk compiled from source.Attachments:( 0) 0001-cdr_mysql-Don-t-clean-up-on-unload-unless-we-can-unr.patch
Description:When I have upgraded from version 11.25.3 to 16.5.1 our PBX crashed during next five days. I found, that problem starts when our cron unload and load cdr_mysql.so module. I have to unload/load this module, because our pbx using special national characters and sometimes happen after few days, that cdr_mysql stored text not in utf8. But when I unloaded/loaded module every day, than connection in utf8 worked. That was problem in 11.25.3 and now I now, that I can use module reload.

But back to the problem, because it is maybe related to the other cdr backend such as odbc, psql etc...

When I try to unload cdr_mysql.so module during active call(s) then I see this message from cdr.c

{code}
[Oct  4 20:36:48] WARNING[99120]: cdr.c:2974 ast_cdr_generic_unregister: Unable to unregister CDR backend mysql; 5 CDRs are still active
[Oct  4 20:36:48] WARNING[99120]: loader.c:1264 ast_unload_resource: Firm unload failed for cdr_mysql.so
{code}

Module was not unregistered, but the command "cdr mysql status" disappear from CLI.

MySQL backend is still registered as I can see in cdr show status:

{code}
Call Detail Record (CDR) settings
----------------------------------
 Logging:                    Enabled
 Mode:                       Simple
 Log unanswered calls:       Yes
 Log congestion:             No

* Registered Backends
 -------------------
   mysql
{code}

After disconnect active calls, I see this error:
{code}
[Oct  4 20:36:55] ERROR[98837]: cdr_mysql.c:212 mysql_log: Cannot connect to database server >�: (2005) Unknown MySQL server host '>�' (-5)
[Oct  4 20:37:00] ERROR[98837]: cdr_mysql.c:212 mysql_log: Cannot connect to database server >�: (2005) Unknown MySQL server host '>�' (-5)
{code}

Or during last test (same server, same configuration):
{code}
[Oct  4 21:53:58] ERROR[123001]: cdr_mysql.c:212 mysql_log: Cannot connect to database server r show s: (2005) Unknown MySQL server host 'r show s' (-5)
[Oct  4 21:53:59] ERROR[123001]: cdr_mysql.c:212 mysql_log: Cannot connect to database server r show s: (2005) Unknown MySQL server host 'r show s' (-5)
[Oct  4 21:54:00] ERROR[123001]: cdr_mysql.c:212 mysql_log: Cannot connect to database server r show s: (2005) Unknown MySQL server host 'r show s' (-5)
{code}

Server host is a localhost, but in a console I see "r show s" or other strange text from dialplan or CLI command (cdr show status   = r show s)

In this case, values from dialplan:

{code}
[Oct  4 06:53:18] ERROR[25236] cdr_mysql.c: Cannot connect to database server XTENSION: (2005) Unknown MySQL server host 'XTENSION' (-2)
[Oct  4 06:57:41] ERROR[25236] cdr_mysql.c: Cannot connect to database server XTENSION: (2005) Unknown MySQL server host 'XTENSION' (-2)
{code}

I also tried connect to mysql using socket:
{code}
[Oct  4 07:47:48] ERROR[25236] cdr_mysql.c: Cannot connect to database server : (2002) Can't connect to local MySQL server through socket 'ng_calls' (2 "No such file or directory")

[Oct  4 07:49:12] ERROR[25236] cdr_mysql.c: Cannot connect to database server : (2002) Can't connect to local MySQL server through socket 'ng_calls' (2 "No such file or directory")
[Oct  4 07:49:54] ERROR[25236] cdr_mysql.c: Cannot connect to database server : (2002) Can't connect to local MySQL server through socket 'ng_calls' (2 "No such file or directory")
{code}

Since this errors, CDRs are not stored in database and few calls later (maybe 50 calls), asterisk have an other issue when dialplan execution stops, during set value to CDR variables:

For example:
{code}
[Oct  4 08:40:59] VERBOSE[17778][C-00002325] pbx.c: Executing [0728733844@in_extensions_72:2] Set("SIP/6196-0000430f", "CDR(call_id)=1570171260790723829-0@192.168.222.243") in new stack
{code}
That was the last executed application in a dialplan.

The issue replication is simple. Just try to unload cdr_mysql.so (or maybe also other cdr sql backends) during at least one active call.

Thank you.
Best regards
Marian
Comments:By: Asterisk Team (asteriskteam) 2019-10-04 15:22:10.812-0500

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.

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.
By: Sean Bright (seanbright) 2019-10-04 15:27:21.018-0500

My guess is that [this fix that went in about two years ago|https://github.com/asterisk/asterisk/commit/898b3b080afda038153c4046d4ebbeea02edcc9f#diff-9247ae39c65642794b09a51670aba7b4] for ASTERISK-27366 makes it unnecessary to unload/load the module. Regardless, it should not end up in an inconsistent state when you try to unload it.
By: Sean Bright (seanbright) 2019-10-04 15:35:21.814-0500

[~maikyp], can you try the attached patch [^0001-cdr_mysql-Don-t-clean-up-on-unload-unless-we-can-unr.patch] and let us know if it resolves the problem for you?
By: Marian Piater (maikyp) 2019-10-04 15:36:00.754-0500

Thanks for your reply. I will disable reloading module in a crontab.
By: Marian Piater (maikyp) 2019-10-04 15:36:59.219-0500

Of course!
By: Marian Piater (maikyp) 2019-10-04 15:44:32.894-0500

Compile error:

{code}
  [CC] cdr_mysql.c -> cdr_mysql.o
cdr_mysql.c: In function ‘my_unload_module’:
cdr_mysql.c:383:17: warning: unused variable ‘entry’ [-Wunused-variable]
 struct column *entry;
                ^~~~~
cdr_mysql.c: At top level:
cdr_mysql.c:392:52: error: expected ‘)’ before ‘sizeof’
 ast_cli_unregister_multiple(cdr_mysql_status_cli, sizeof(cdr_mysql_status_cli) / sizeof(struct ast_cli_entry));
                                                   ^~~~~~
cdr_mysql.c:394:2: error: expected identifier or ‘(’ before ‘if’
 if (connected) {
 ^~
cdr_mysql.c:400:2: warning: data definition has no type or storage class
 free_strings();
 ^~~~~~~~~~~~
cdr_mysql.c:400:2: warning: type defaults to ‘int’ in declaration of ‘free_strings’ [-Wimplicit-int]
cdr_mysql.c:400:2: warning: function declaration isn’t a prototype [-Wstrict-prototypes]
cdr_mysql.c:400:2: error: conflicting types for ‘free_strings’
cdr_mysql.c:369:13: note: previous definition of ‘free_strings’ was here
static void free_strings(void)
            ^~~~~~~~~~~~
cdr_mysql.c:402:2: error: expected identifier or ‘(’ before ‘if’
 if (!reload) {
 ^~
cdr_mysql.c:405:2: error: expected identifier or ‘(’ before ‘while’
 while ((entry = AST_RWLIST_REMOVE_HEAD(&columns, list))) {
 ^~~~~
In file included from /usr/src/asterisk-16.5.1/include/asterisk/astobj2.h:22:0,
                from /usr/src/asterisk-16.5.1/include/asterisk/strings.h:33,
                from /usr/src/asterisk-16.5.1/include/asterisk/utils.h:613,
                from /usr/src/asterisk-16.5.1/include/asterisk/config.h:30,
                from cdr_mysql.c:48:
/usr/src/asterisk-16.5.1/include/asterisk/linkedlists.h:841:3: error: expected identifier or ‘(’ before ‘)’ token
 })
  ^
/usr/src/asterisk-16.5.1/include/asterisk/linkedlists.h:843:32: note: in expansion of macro ‘AST_LIST_REMOVE_HEAD’
#define AST_RWLIST_REMOVE_HEAD AST_LIST_REMOVE_HEAD
                               ^~~~~~~~~~~~~~~~~~~~
cdr_mysql.c:405:18: note: in expansion of macro ‘AST_RWLIST_REMOVE_HEAD’
 while ((entry = AST_RWLIST_REMOVE_HEAD(&columns, list))) {
                 ^~~~~~~~~~~~~~~~~~~~~~
cdr_mysql.c:408:2: error: expected identifier or ‘(’ before ‘if’
 if (!reload) {
 ^~
cdr_mysql.c:412:2: warning: data definition has no type or storage class
 dbport = 0;
 ^~~~~~
cdr_mysql.c:412:2: warning: type defaults to ‘int’ in declaration of ‘dbport’ [-Wimplicit-int]
cdr_mysql.c:412:2: error: redefinition of ‘dbport’
cdr_mysql.c:81:12: note: previous definition of ‘dbport’ was here
static int dbport = 0;
           ^~~~~~
cdr_mysql.c:413:2: error: expected identifier or ‘(’ before ‘if’
 if (reload) {
 ^~
cdr_mysql.c:415:4: error: expected identifier or ‘(’ before ‘else’
 } else {
   ^~~~
cdr_mysql.c:419:1: error: expected identifier or ‘(’ before ‘}’ token
}
^
cdr_mysql.c: In function ‘my_unload_module’:
cdr_mysql.c:390:2: warning: control reaches end of non-void function [-Wreturn-type]
 }
 ^
At top level:
cdr_mysql.c:369:13: warning: ‘free_strings’ defined but not used [-Wunused-function]
static void free_strings(void)
            ^~~~~~~~~~~~
{code}
By: Marian Piater (maikyp) 2019-10-04 15:46:37.074-0500

you forgot {... after if (!reload)
By: Marian Piater (maikyp) 2019-10-04 15:51:00.751-0500

Now it is okay. Module is not unloaded, when there is at least one active call.

Attempt to unload module:
{code}
[Oct  4 22:44:59] WARNING[9190]: cdr.c:2974 ast_cdr_generic_unregister: Unable to unregister CDR backend mysql; 2 CDRs are still active
[Oct  4 22:44:59] WARNING[9190]: loader.c:1264 ast_unload_resource: Firm unload failed for cdr_mysql.so
{code}

Mysql backend is still registered and now I see also the mysql command.
{code}
debianpbx*CLI> cdr
mysql   set     show    submit  
{code}

After disconnect calls:
{code}
debianpbx*CLI> cdr mysql status
Connected to test_pbx@localhost, port 3306 using table cdr for 20 seconds
 Wrote 2 records since last restart.
{code}

Thank you!
By: Sean Bright (seanbright) 2019-10-04 16:01:14.073-0500

Great. Thanks for testing (sorry I didn't test compile).
By: Friendly Automation (friendly-automation) 2019-10-08 07:30:16.638-0500

Change 13010 merged by Friendly Automation:
cdr_mysql: Don't clean up on unload unless we can unregister from CDRs

[https://gerrit.asterisk.org/c/asterisk/+/13010|https://gerrit.asterisk.org/c/asterisk/+/13010]
By: Friendly Automation (friendly-automation) 2019-10-08 07:30:23.482-0500

Change 13011 merged by Friendly Automation:
cdr_mysql: Don't clean up on unload unless we can unregister from CDRs

[https://gerrit.asterisk.org/c/asterisk/+/13011|https://gerrit.asterisk.org/c/asterisk/+/13011]
By: Friendly Automation (friendly-automation) 2019-10-08 08:27:09.275-0500

Change 13008 merged by George Joseph:
cdr_mysql: Don't clean up on unload unless we can unregister from CDRs

[https://gerrit.asterisk.org/c/asterisk/+/13008|https://gerrit.asterisk.org/c/asterisk/+/13008]
By: Friendly Automation (friendly-automation) 2019-10-08 08:27:32.814-0500

Change 13009 merged by George Joseph:
cdr_mysql: Don't clean up on unload unless we can unregister from CDRs

[https://gerrit.asterisk.org/c/asterisk/+/13009|https://gerrit.asterisk.org/c/asterisk/+/13009]