[Home]

Summary:ASTERISK-28160: Asterisk was failed down and restarted again.
Reporter:Cao Minh Hiep (hiepcm)Labels:pjsip sip
Date Opened:2018-11-11 21:06:50.000-0600Date Closed:2019-05-15 08:01:46
Priority:MajorRegression?
Status:Closed/CompleteComponents:. I did not set the category correctly.
Versions:13.12.0 Frequency of
Occurrence		One Time
Related
Issues:
Environment:Attachments:
Description:Hello,
We are using Asterisk v13.12.0. We don't know what happened and how to reproduce this issue. But "cdr.c: CDR simple logging enabled" and "loader.c: 302 modules will be loaded " were shown out at the Asterisk logs. It means the Asterisk has been failed down and restarted.

We know that you only support us if it happens at the newest version.
But I would like to ask you that have you seen the issue like that before? and patch to solve this problem?.

Please let us know if you need more infomation.

Here are the logs when the issue occurred:

" [Nov  8 16:12:56] NOTICE[14997][C-00002f89] app_queue.c: Delaying member connect for 1 seconds
[Nov  8 16:13:14] WARNING[15526][C-00002f89] bridge_basic.c: Unexpected stimulus 'Transfer Target Answer' received in attended transfer state 'Blond Non-Final'
[Nov  8 16:13:14] ERROR[15526][C-00002f89] astobj2.c: FRACK!, Failed assertion user_data is NULL (0)
[Nov  8 16:13:14] ERROR[15526][C-00002f89] astobj2.c: FRACK!, Failed assertion user_data is NULL (0)
[Nov  8 16:13:42] NOTICE[16858] cdr.c: CDR simple logging enabled.
[Nov  8 16:13:42] NOTICE[16858] loader.c: 302 modules will be loaded.
[Nov  8 16:13:43] WARNING[16858] res_xmpp.c: Entity ID is not set. The distributing device state or MWI will not work.
[Nov  8 16:13:43] WARNING[16858] res_phoneprov.c: Unable to find a valid server address or name.
[Nov  8 16:13:43] ERROR[16858] ari/config.c: No configured users for ARI
[Nov  8 16:13:43] ERROR[16858] res_pjsip_publish_asterisk.c: Entity ID is not set.
[Nov  8 16:13:43] WARNING[16858] res_config_pgsql.c: Possibly unsupported column type 'numeric' on column 'regseconds' "

---------


CORE:
"Core was generated by `/usr/sbin/asterisk -f -g'.
Program terminated with signal 11, Segmentation fault.
#0  ast_channel_internal_bridge_channel (chan=chan@entry=0x0) at channel_internal_api.c:1410
1410            return chan->bridge_channel;

-------

bt:

(gdb) bt
#0  ast_channel_internal_bridge_channel (chan=chan@entry=0x0) at channel_internal_api.c:1410
#1  0x00000000004c5696 in ast_channel_get_bridge_channel (chan=chan@entry=0x0) at channel.c:10492
#2  0x000000000047ae9c in ringing (chan=0x0) at bridge_basic.c:1804
#3  blond_enter (props=props@entry=0x7f84b402e2c8) at bridge_basic.c:2315
#4  0x000000000047afda in blond_nonfinal_enter (props=0x7f84b402e2c8) at bridge_basic.c:2329
#5  0x00000000004778ab in attended_transfer_monitor_thread (data=data@entry=0x7f84b402e2c8) at bridge_basic.c:3047
#6  0x00000000005ecdee in dummy_start (data=<optimized out>) at utils.c:1235
#7  0x00007f8533bbfdc5 in start_thread () from /lib64/libpthread.so.0
#8  0x00007f85331a173d in clone () from /lib64/libc.so.6 "

---------
Best regards.
Comments:By: Asterisk Team (asteriskteam) 2018-11-11 21:06:52.206-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.

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].
By: Joshua C. Colp (jcolp) 2018-11-12 04:31:46.374-0600

Nothing comes to mind immediately, but you could also search JIRA yourself to see if you find anything.

I'm also requesting feedback on this as it does require a new version if we are to look at it as you mention.
By: Cao Minh Hiep (hiepcm) 2018-11-13 19:22:53.535-0600

Thanks for your feedback.

Yes, We are also searching JIRA the subject related to the bug.
But, Please let us know if you have any solutions for the bug.
Thank you.

By: Asterisk Team (asteriskteam) 2018-11-28 12:00:02.114-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: Cao Minh Hiep (hiepcm) 2019-05-12 22:21:16.922-0500

Hi,
I would like to ask you the causing of Asterisk restart problem that happened in another server.
This time, the output logs differ from the logs of last time that I have reported before.

In our system, the sip will be checked at every one minute by a script. At these logs. SIP was checked at '2019/5/7  9:15:01'. After about 10seconds If there is no response from Asterisk (response timeout), It will restart the Asterisk.

At these logs, We found the following log, before the SIP was checked. Is this a Network problem?
"[May  7 09:14:23] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/192.168.120.60-0001a42d' for lack of RTP activity in 11 seconds
[May  7 09:14:23] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/100232-0001a45c' for lack of RTP activity in 11 seconds"

Here is the detail logs:

"[May  7 09:13:37] NOTICE[2060] res_rtp_asterisk.c: Unknown RTP codec 95 received from '(null)'
[May  7 09:13:37] NOTICE[581] app_queue.c: Delaying member connect for 1 seconds
[May  7 09:13:38] NOTICE[2115] res_rtp_asterisk.c: Unknown RTP codec 95 received from '192.168.181.64:8000'
[May  7 09:13:44] NOTICE[2327] res_rtp_asterisk.c: Unknown RTP codec 95 received from '192.168.68.143:8000'
[May  7 09:13:44] NOTICE[2327] res_rtp_asterisk.c: Unknown RTP codec 95 received from '192.168.68.143:8000'
[May  7 09:13:50] WARNING[2762] channel.c: Prodding channel 'Local/66104@a_context_01-0251;2' failed
[May  7 09:13:52] NOTICE[2760] res_rtp_asterisk.c: Unknown RTP codec 95 received from '(null)'
[May  7 09:13:52] NOTICE[2712] res_rtp_asterisk.c: Unknown RTP codec 95 received from '192.168.142.51:8000'
[May  7 09:13:52] NOTICE[2467] app_queue.c: Delaying member connect for 1 seconds
[May  7 09:14:06] NOTICE[3482] res_rtp_asterisk.c: Unknown RTP codec 95 received from '192.168.142.79:8000'
[May  7 09:14:08] NOTICE[2712] res_rtp_asterisk.c: Unknown RTP codec 95 received from '192.168.142.51:8000'
[May  7 09:14:10] NOTICE[3413] res_rtp_asterisk.c: Unknown RTP codec 95 received from '(null)'
[May  7 09:14:11] NOTICE[3230] app_queue.c: Delaying member connect for 1 seconds
[May  7 09:14:21] WARNING[3919] channel.c: Exceptionally long voice queue length queuing to Local/9918@a_context_01-3293;2
[May  7 09:14:22] WARNING[3919] channel.c: Exceptionally long voice queue length queuing to Local/9918@a_context_01-3293;2
[May  7 09:14:23] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/192.168.120.60-0001a42d' for lack of RTP activity in 11 seconds
[May  7 09:14:23] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/100232-0001a45c' for lack of RTP activity in 11 seconds
[May  7 09:14:34] NOTICE[3787] res_rtp_asterisk.c: Unknown RTP codec 95 received from '192.168.68.143:8000'
[May  7 09:14:34] NOTICE[3787] res_rtp_asterisk.c: Unknown RTP codec 95 received from '192.168.68.143:8000'
[May  7 09:14:55] NOTICE[2417] chan_sip.c:    -- Registration for '55773673@kwus.sip.0038.net' timed out, trying again (Attempt #3)
[May  7 09:14:55] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/192.168.120.60-0001a4a1' for lack of RTP activity in 15 seconds
[May  7 09:14:55] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/GW99998-0001a4a0' for lack of RTP activity in 16 seconds
[May  7 09:14:55] NOTICE[2417] chan_sip.c:    -- Registration for '55773674@kwus.sip.0038.net' timed out, trying again (Attempt #3)
[May  7 09:14:55] NOTICE[2417] chan_sip.c:    -- Registration for '55773675@kwus.sip.0038.net' timed out, trying again (Attempt #2)
[May  7 09:14:56] WARNING[3919] channel.c: Exceptionally long voice queue length queuing to Local/9918@a_context_01-3293;2
[May  7 09:14:58] WARNING[3919] channel.c: Exceptionally long voice queue length queuing to Local/9918@a_context_01-3293;2
[May  7 09:14:59] WARNING[3919] channel.c: Exceptionally long voice queue length queuing to Local/9918@a_context_01-3293;2

[May  7 09:15:05] NOTICE[2417] chan_sip.c:    -- Registration for '55782299@kwus.sip.0038.net' timed out, trying again (Attempt #2)
[May  7 09:15:10] NOTICE[2417] chan_sip.c:    -- Registration for '52131464@kwus.sip.0038.net' timed out, trying again (Attempt #2)
[May  7 09:15:15] NOTICE[2417] chan_sip.c:    -- Registration for '55773672@kwus.sip.0038.net' timed out, trying again (Attempt #3)
[May  7 09:15:15] WARNING[2417] chan_sip.c: Retransmission timeout reached on transmission iPtntQvneOx8i9svY83jKw.. for seqno 2 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 36252ms with no response
[May  7 09:15:15] WARNING[2417] chan_sip.c: Retransmission timeout reached on transmission 521a4f72179e3a5d7719334d45edb2985060@192.168.120.11 for seqno 1 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 35745ms with no response
[May  7 09:15:15] WARNING[2417] chan_sip.c: Retransmission timeout reached on transmission Fb-7nwzGiaEtBWUHhrrwrQ.. for seqno 2 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 41418ms with no response
[May  7 09:15:15] WARNING[2417] chan_sip.c: Hanging up call Fb-7nwzGiaEtBWUHhrrwrQ.. - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[May  7 09:15:15] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/GW99995-0001a42f' for lack of RTP activity in 30 seconds
[May  7 09:15:15] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/100335-0001a45e' for lack of RTP activity in 16 seconds
[May  7 09:15:15] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/GW99998-0001a49e' for lack of RTP activity in 13 seconds
[May  7 09:15:15] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/100053-0001a498' for lack of RTP activity in 19 seconds
[May  7 09:15:15] NOTICE[2417] chan_sip.c: Disconnecting call 'SIP/100412-0001a44e' for lack of RTP activity in 21 seconds
[May  7 09:15:16] NOTICE[2417] chan_sip.c:    -- Registration for '55773673@kwus.sip.0038.net' timed out, trying again (Attempt #4) "
By: Asterisk Team (asteriskteam) 2019-05-12 22:21:18.087-0500

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: George Joseph (gjoseph) 2019-05-13 11:28:32.510-0500

Offhand, it looks like there were network issues or your system may have been  under attack and overloaded.

By: Cao Minh Hiep (hiepcm) 2019-05-13 20:05:36.029-0500

Hi George.
We have reproduced this issue, the causing of the issue is the network connection problem.
Thanks for your advice.