[asterisk-bugs] [JIRA] (ASTERISK-29187) stasis.c: FRACK!, Failed assertion bad magic number 0x0 for object in publish_msg

Mauri de Souza Meneguzzo (3CPlus) (JIRA) noreply at issues.asterisk.org
Mon Nov 30 22:24:16 CST 2020


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

Mauri de Souza Meneguzzo (3CPlus) edited comment on ASTERISK-29187 at 11/30/20 10:23 PM:
-----------------------------------------------------------------------------------------

It happens two or three times per day, almost every day. Every asterisk instance runs inside a container so the environment is consistent between then. Different instances crash randomly, it's not always the same instance or instances running on the same node etc.

Heres the contents of pjsip.conf

{noformat}
[system]
type=system
threadpool_initial_size=50
threadpool_auto_increment=10
threadpool_idle_timeout=120
threadpool_max_size=500
timer_t1=150
timer_b=9600

[global]
type=global
mwi_tps_queue_high=5000

;================================ TRANSPORTS ==
; Our primary transport definition for UDP communication behind NAT.
[transport-external]
type = transport
protocol = udp
bind = 0.0.0.0
; NAT settings
local_net = 10.0.0.0/8
external_media_address = 10.142.0.49
external_signaling_address = 10.142.0.49

[transport-udp]
type = transport
protocol = udp
bind = 0.0.0.0:5061

[transport-tcp]
type = transport
protocol = tcp
bind = 0.0.0.0:5061
{noformat}

The contents of the log before the crash including the crash itself:

{noformat}
[Nov 30 13:08:27] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000b356' for lack of audio RTP activity in 15 seconds
[Nov 30 13:08:30] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cc3b' for lack of audio RTP activity in 15 seconds
[Nov 30 13:08:56] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cb1b' for lack of audio RTP activity in 15 seconds
[Nov 30 13:08:58] WARNING[23472]: res_pjsip_pubsub.c:787 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo from kamailio_endpoint
[Nov 30 13:10:39] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cccb' for lack of audio RTP activity in 15 seconds
[Nov 30 13:11:06] ERROR[346332]: channel.c:724 does_id_conflict: Channel Unique ID '6KZBoSNqME' already in use by channel PJSIP/kamailio_endpoint_tls-0000cbbe(0x7fa25c102160)
[Nov 30 13:11:17] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-00009b44' for lack of audio RTP activity in 15 seconds
[Nov 30 13:11:42] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000c6a6' for lack of audio RTP activity in 15 seconds
[Nov 30 13:12:20] WARNING[108989]: res_pjsip_pubsub.c:787 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo from kamailio_endpoint
[Nov 30 13:14:27] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cde5' for lack of audio RTP activity in 15 seconds
[Nov 30 13:16:17] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000b392' for lack of audio RTP activity in 15 seconds
[Nov 30 13:16:26] WARNING[108989]: res_pjsip_pubsub.c:787 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo from kamailio_endpoint
[Nov 30 13:17:08] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cc63' for lack of audio RTP activity in 15 seconds
[Nov 30 13:20:10] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cf01' for lack of audio RTP activity in 15 seconds
[Nov 30 13:20:16] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cf64' for lack of audio RTP activity in 15 seconds
[Nov 30 13:20:44] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cfb9' for lack of audio RTP activity in 15 seconds
[Nov 30 13:21:21] WARNING[23472]: res_pjsip_pubsub.c:787 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo from kamailio_endpoint
[Nov 30 13:22:00] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cfe3' for lack of audio RTP activity in 15 seconds
[Nov 30 13:22:07] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000c5f2' for lack of audio RTP activity in 15 seconds
[Nov 30 13:22:39] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000ced5' for lack of audio RTP activity in 15 seconds
[Nov 30 13:23:23] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-000099b1' for lack of audio RTP activity in 15 seconds
[Nov 30 13:26:08] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000d024' for lack of audio RTP activity in 15 seconds
[Nov 30 13:26:55] WARNING[350449][C-0000cd30]: res_rtp_asterisk.c:2932 dtls_srtp_setup: Fingerprint provided by remote party does not match that of peer certificate on RTP instance '0x7fa26c2daf30'
[Nov 30 13:26:55] WARNING[350449][C-0000cd30]: res_rtp_asterisk.c:7422 ast_rtp_read: RTP Read error: Unspecified.  Hanging up.
[Nov 30 13:26:55] WARNING[350449][C-0000cd30]: res_stasis_playback.c:276 playback_final_update: 10.8.9.18-1606753614.53586: Playback failed for sound:login
FRACK!, Failed assertion bad magic number 0x0 for object 0x7fa328020c60 (0) at line 1474 in publish_msg of stasis.c
[Nov 30 13:27:27] ERROR[350426][C-0000cd2c]: stasis.c:1474 publish_msg: FRACK!, Failed assertion bad magic number 0x0 for object 0x7fa328020c60 (0)
[Nov 30 13:27:27] ERROR[350426][C-0000cd2c]:   Got 21 backtrace records
FRACK!, Failed assertion bad magic number 0x0 for object 0x7fa328020c60 (0) at line 1478 in publish_msg of stasis.c
# 0: asterisk __ast_assert_failed()
# 1: asterisk <unknown>()
# 2: asterisk __ao2_ref()
# 3: asterisk <unknown>()
# 4: asterisk stasis_publish()
# 5: asterisk bridge_topics_destroy()
# 6: asterisk <unknown>()
# 7: asterisk __ao2_ref()
# 8: asterisk <unknown>()
# 9: asterisk __ao2_ref()
#10: asterisk ast_bridge_depart()
#11: [0x7fa33f7c16c0] res_stasis.so res_stasis.c:1567 stasis_app_exec()
#12: [0x7fa33f02e310] app_stasis.so app_stasis.c:105 app_exec()
#13: asterisk pbx_exec()
#14: asterisk <unknown>()
#15: asterisk ast_spawn_extension()
#16: asterisk <unknown>()
#17: asterisk <unknown>()
#18: asterisk <unknown>()
#19: [0x7fa350359ea7] libpthread.so.0 pthread_create.c:478 start_thread()
#20: [0x7fa34ffb0d4f] libc.so.6 clone.S:97 __GI___clone()
[Nov 30 13:27:27] ERROR[350426][C-0000cd2c]: stasis.c:1478 publish_msg: FRACK!, Failed assertion bad magic number 0x0 for object 0x7fa328020c60 (0)
[Nov 30 13:27:27] ERROR[350426][C-0000cd2c]:   Got 21 backtrace records
# 0: asterisk __ast_assert_failed()
# 1: asterisk <unknown>()
# 2: asterisk __ao2_lock()
# 3: asterisk <unknown>()
# 4: asterisk stasis_publish()
# 5: asterisk bridge_topics_destroy()
# 6: asterisk <unknown>()
# 7: asterisk __ao2_ref()
# 8: asterisk <unknown>()
# 9: asterisk __ao2_ref()
#10: asterisk ast_bridge_depart()
#11: [0x7fa33f7c16c0] res_stasis.so res_stasis.c:1567 stasis_app_exec()
#12: [0x7fa33f02e310] app_stasis.so app_stasis.c:105 app_exec()
#13: asterisk pbx_exec()
#14: asterisk <unknown>()
#15: asterisk ast_spawn_extension()
#16: asterisk <unknown>()
#17: asterisk <unknown>()
#18: asterisk <unknown>()
#19: [0x7fa350359ea7] libpthread.so.0 pthread_create.c:478 start_thread()
#20: [0x7fa34ffb0d4f] libc.so.6 clone.S:97 __GI___clone()
/usr/bin/entrypoint.sh: line 104:    26 Segmentation fault      (core dumped) asterisk -fg
{noformat}


was (Author: mauri de souza meneguzzo (3cplus)):
It happens two or three times per day, almost every day. Every asterisk instance runs inside a container so the environment is consistent between then. Different instances crash randomly, it's not always the same instance or instances running on the same node etc.

Heres the contents of pjsip.conf

{noformat}
[system]
type=system
threadpool_initial_size=50
threadpool_auto_increment=10
threadpool_idle_timeout=120
threadpool_max_size=500
timer_t1=150
timer_b=9600

[global]
type=global
mwi_tps_queue_high=5000

;================================ TRANSPORTS ==
; Our primary transport definition for UDP communication behind NAT.
[transport-external]
type = transport
protocol = udp
bind = 0.0.0.0
; NAT settings
local_net = 10.0.0.0/8
external_media_address = 10.142.0.49
external_signaling_address = 10.142.0.49

[transport-udp]
type = transport
protocol = udp
bind = 0.0.0.0:5061

[transport-tcp]
type = transport
protocol = tcp
bind = 0.0.0.0:5061
{noformat}

The contents of the log before the crash:

{noformat}
[Nov 30 13:08:27] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000b356' for lack of audio RTP activity in 15 seconds
[Nov 30 13:08:30] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cc3b' for lack of audio RTP activity in 15 seconds
[Nov 30 13:08:56] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cb1b' for lack of audio RTP activity in 15 seconds
[Nov 30 13:08:58] WARNING[23472]: res_pjsip_pubsub.c:787 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo from kamailio_endpoint
[Nov 30 13:10:39] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cccb' for lack of audio RTP activity in 15 seconds
[Nov 30 13:11:06] ERROR[346332]: channel.c:724 does_id_conflict: Channel Unique ID '6KZBoSNqME' already in use by channel PJSIP/kamailio_endpoint_tls-0000cbbe(0x7fa25c102160)
[Nov 30 13:11:17] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-00009b44' for lack of audio RTP activity in 15 seconds
[Nov 30 13:11:42] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000c6a6' for lack of audio RTP activity in 15 seconds
[Nov 30 13:12:20] WARNING[108989]: res_pjsip_pubsub.c:787 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo from kamailio_endpoint
[Nov 30 13:14:27] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cde5' for lack of audio RTP activity in 15 seconds
[Nov 30 13:16:17] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000b392' for lack of audio RTP activity in 15 seconds
[Nov 30 13:16:26] WARNING[108989]: res_pjsip_pubsub.c:787 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo from kamailio_endpoint
[Nov 30 13:17:08] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cc63' for lack of audio RTP activity in 15 seconds
[Nov 30 13:20:10] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cf01' for lack of audio RTP activity in 15 seconds
[Nov 30 13:20:16] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cf64' for lack of audio RTP activity in 15 seconds
[Nov 30 13:20:44] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cfb9' for lack of audio RTP activity in 15 seconds
[Nov 30 13:21:21] WARNING[23472]: res_pjsip_pubsub.c:787 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo from kamailio_endpoint
[Nov 30 13:22:00] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000cfe3' for lack of audio RTP activity in 15 seconds
[Nov 30 13:22:07] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000c5f2' for lack of audio RTP activity in 15 seconds
[Nov 30 13:22:39] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000ced5' for lack of audio RTP activity in 15 seconds
[Nov 30 13:23:23] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-000099b1' for lack of audio RTP activity in 15 seconds
[Nov 30 13:26:08] NOTICE[131]: res_pjsip_sdp_rtp.c:149 rtp_check_timeout: Disconnecting channel 'PJSIP/kamailio_endpoint_tls-0000d024' for lack of audio RTP activity in 15 seconds
[Nov 30 13:26:55] WARNING[350449][C-0000cd30]: res_rtp_asterisk.c:2932 dtls_srtp_setup: Fingerprint provided by remote party does not match that of peer certificate on RTP instance '0x7fa26c2daf30'
[Nov 30 13:26:55] WARNING[350449][C-0000cd30]: res_rtp_asterisk.c:7422 ast_rtp_read: RTP Read error: Unspecified.  Hanging up.
[Nov 30 13:26:55] WARNING[350449][C-0000cd30]: res_stasis_playback.c:276 playback_final_update: 10.8.9.18-1606753614.53586: Playback failed for sound:login
FRACK!, Failed assertion bad magic number 0x0 for object 0x7fa328020c60 (0) at line 1474 in publish_msg of stasis.c
[Nov 30 13:27:27] ERROR[350426][C-0000cd2c]: stasis.c:1474 publish_msg: FRACK!, Failed assertion bad magic number 0x0 for object 0x7fa328020c60 (0)
[Nov 30 13:27:27] ERROR[350426][C-0000cd2c]:   Got 21 backtrace records
FRACK!, Failed assertion bad magic number 0x0 for object 0x7fa328020c60 (0) at line 1478 in publish_msg of stasis.c
...
{noformat}

> stasis.c: FRACK!, Failed assertion bad magic number 0x0 for object in publish_msg
> ---------------------------------------------------------------------------------
>
>                 Key: ASTERISK-29187
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-29187
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Resources/res_stasis
>    Affects Versions: 17.8.0, 18.0.1
>         Environment: Kubernetes pod running on a Container Optimized OS (GCE) instance
>            Reporter: Mauri de Souza Meneguzzo (3CPlus)
>            Assignee: Unassigned
>         Attachments: ast-coredumper-files.tar.gz
>
>
> This is a follow up for ASTERISK-28931, which we opened some time ago. Seems like the same problem is happening again.
> This problem occurs in versions as old as Asterisk 17.3.0 and is happening in every version onwards. We are currently running version 18.0.1 and the segfault still occurs.
> Our Asterisk instances are crashing at least one time per day and in some cases even multiple times, with the following backtrace being displayed:
> FRACK!, Failed assertion bad magic number 0x0 for object 0x7fa328020c60 (0) at line 1474 in publish_msg of stasis.c
> {noformat}
> #0: asterisk __ast_assert_failed()
> #1: asterisk <unknown>()
> #2: asterisk __ao2_ref() 
> #3: asterisk <unknown>() 
> #4: asterisk stasis_publish() 
> #5: asterisk bridge_topics_destroy() 
> #6: asterisk <unknown>() 
> #7: asterisk __ao2_ref() 
> #8: asterisk <unknown>() 
> #9: asterisk __ao2_ref() 
> #10: asterisk ast_bridge_depart() 
> #11: [0x7fa33f7c16c0] res_stasis.so res_stasis.c:1567 stasis_app_exec() 
> #12: [0x7fa33f02e310] app_stasis.so app_stasis.c:105 app_exec() 
> #13: asterisk pbx_exec() 
> #14: asterisk <unknown>() 
> #15: asterisk ast_spawn_extension() 
> #16: asterisk <unknown>() 
> #17: asterisk <unknown>() 
> #18: asterisk <unknown>() 
> #19: [0x7fa350359ea7] libpthread.so.0 pthread_create.c:478 start_thread() 
> #20: [0x7fa34ffb0d4f] libc.so.6 clone.S:97 __GI___clone() 
> 26 Segmentation fault (core dumped) asterisk  -fg
> {noformat}
> GDB's "bt" output:
> {noformat}
> (gdb) bt
> #0  0x000055d23a2f787a in dispatch_message (sub=0x30ec8348e5894855,
>     message=0x7fa2740b6fd8, synchronous=0) at stasis.c:1335
> #1  0x000055d23a2f7d63 in publish_msg (topic=0x7fa328020c60,
>     message=0x7fa2740b6fd8, sync_sub=0x0) at stasis.c:1484
> #2  0x000055d23a2f7df6 in stasis_publish (topic=0x7fa328020c60,
>     message=0x7fa2740b6fd8) at stasis.c:1509
> #3  0x000055d23a2fc765 in bridge_topics_destroy (bridge=0x7fa32807af10)
>     at stasis_bridges.c:344
> #4  0x000055d23a1c2afc in destroy_bridge (obj=0x7fa32807af10) at bridge.c:666
> #5  0x000055d23a1b41d8 in __ao2_ref (user_data=0x7fa32807af10, delta=-1,
>     tag=0x0,
>     file=0x55d23a3c7960 "\r\n<title>%d %s</title>\r\n</head><body>\r\n<h1>%s</h1>\r\n<p>%s</p>\r\n<hr />\r\n%s</body></html>\r\n", line=3105,
>     func=0x55d23a3c8f00 <__PRETTY_FUNCTION__.8> "playtones_generator")
>     at astobj2.c:614
> #6  0x000055d23a1e3ef1 in bridge_channel_destroy (obj=0x7fa274023ce0)
>     at bridge_channel.c:3105
> #7  0x000055d23a1b41d8 in __ao2_ref (user_data=0x7fa274023ce0, delta=-1,
>     tag=0x0, file=0x55d23a3c2bd9 "", line=1984,
>     func=0x55d23a3c4d60 <__PRETTY_FUNCTION__.130> "ent call progress message %d\n") at astobj2.c:614
> #8  0x000055d23a1c70ac in ast_bridge_depart (chan=0x7fa26c11da60)
>     at bridge.c:1984
> {noformat}



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



More information about the asterisk-bugs mailing list