[asterisk-bugs] [JIRA] (ASTERISK-30210) func_frame_trace: Channel masquerade triggers assertion

Joshua C. Colp (JIRA) noreply at issues.asterisk.org
Sun Sep 4 04:04:09 CDT 2022


     [ https://issues.asterisk.org/jira/browse/ASTERISK-30210?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Joshua C. Colp updated ASTERISK-30210:
--------------------------------------

    Status: Triage  (was: Open)

> func_frame_trace: Channel masquerade triggers assertion
> -------------------------------------------------------
>
>                 Key: ASTERISK-30210
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-30210
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Core/Bridging, Functions/General
>    Affects Versions: 18.14.0
>            Reporter: N A
>
> A new kind of crash/assertion that I encountered today. Whenever I transfer a call (not using Transfer, this is manually using Wait + Bridge) and a masquerade occurs, Asterisk crashes due to this assertion:
> Looking at the code, this is because AST_CONTROL_MASQUERADE_NOTIFY in func_frame_trace => assert(0);
> I sometimes use FRAME_TRACE for debugging, more so recently, so this might be why I've not seen this before.
> This reproduces consistently.
> I think this assertion is bogus, because if I comment it out in func_frame_trace, nothing happens. No crash, nothing out of the ordinary.
> What's the reason for it? If it's not really good, it should probably be removed, or changed to an error or warning instead of an assert.
> {noformat}
> Thread 1 (Thread 0x7f85e5daf700 (LWP 4265)):
> #0  0x00007f85e7f987bb in __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
>         set = {__val = {134238211, 0, 922805718333277103, 8940060396390496210, 1, 13979173243358019584, 579005069656919567, 283686952306183, 12014427501342296478, 189258333318898, 4668459621267030470, 13037061474637634319, 1559441997760, 94060151642313, 25, 0}}
>         pid = <optimized out>
>         tid = <optimized out>
> #1  0x00007f85e7f83535 in __GI_abort () at abort.c:79
>         save_stage = 1
>         act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask = {__val = {0 <repeats 11 times>, 94060152032149, 3758907856, 140213063691408, 140212966553968, 140213063691456}}, sa_flags = -402316636, sa_restorer = 0x7f85e0107970}
>         sigs = {__val = {32, 0 <repeats 15 times>}}
> #2  0x0000558c15e3e2c0 in ast_do_crash () at utils.c:2764
> #3  0x0000558c15e3e35f in __ast_assert_failed (condition=0, condition_str=0x7f85e4b71448 "0", file=0x7f85e4b7109e "func_frame_trace.c", line=348, function=0x7f85e4b71a38 <__PRETTY_FUNCTION__.15272> "print_frame") at utils.c:2793
> #4  0x00007f85e4b6f2aa in _ast_assert (condition=0, condition_str=0x7f85e4b71448 "0", file=0x7f85e4b7109e "func_frame_trace.c", line=348, function=0x7f85e4b71a38 <__PRETTY_FUNCTION__.15272> "print_frame") at /usr/src/asterisk-18.14.0/include/asterisk/utils.h:730
> #5  0x00007f85e4b703b6 in print_frame (frame=0x7f85e00b04e0) at func_frame_trace.c:348
>         __FUNCTION__ = "print_frame"
>         __PRETTY_FUNCTION__ = "print_frame"
> #6  0x00007f85e4b6f4b2 in hook_event_cb (chan=0x7f85dc064190, frame=0x7f85e00b04e0, event=AST_FRAMEHOOK_EVENT_WRITE, data=0x7f85c80a53f0) at func_frame_trace.c:150
>         i = 4
>         show_frame = 1
>         framedata = 0x7f85c80a53f0
>         __FUNCTION__ = "hook_event_cb"
> #7  0x0000558c15d4ba54 in framehook_list_push_event (framehooks=0x7f85d0053de0, frame=0x7f85e00b04e0, event=AST_FRAMEHOOK_EVENT_WRITE) at framehook.c:116
>         __list_head = 0x7f85d0053de8
>         __list_next = 0x0
>         __list_prev = 0x0
>         __list_current = 0x7f85c80a54d0
>         num = 0
>         framehook = 0x7f85c80a54d0
>         original_frame = 0x7f85e00b04e0
>         skip = 0x7f85e5daad60
>         skip_size = 4
> #8  0x0000558c15d4c34e in ast_framehook_list_write_event (framehooks=0x7f85d0053de0, frame=0x7f85e00b04e0) at framehook.c:315
> #9  0x0000558c15ce33a7 in ast_indicate_data (chan=0x7f85dc064190, _condition=34, data=0x7f85e5dab1e4, datalen=4) at channel.c:4720
>         frame = {frametype = AST_FRAME_CONTROL, subclass = {integer = 34, {format = 0x0, topology = 0x0}, frame_ending = 0}, datalen = 4, samples = 0, mallocd = 0, mallocd_hdr_len = 0, offset = 0, src = 0x0, data = {ptr = 0x7f85e5dab1e4, uint32 = 3856314852, pad = "344261332345205177000"}, delivery = {tv_sec = 0, tv_usec = 0}, frame_list = {next = 0x0}, flags = 0, ts = 0, len = 0, seqno = 0, stream_num = 0}
>         res = 0
>         awesome_frame = 0x7f85e00b04e0
>         __PRETTY_FUNCTION__ = "ast_indicate_data"
> #10 0x0000558c15ceb0d4 in channel_do_masquerade (original=0x7f85e012c960, clonechan=0x7f85dc064190) at channel.c:6975
>         x = 1
>         origstate = 21900
>         orig_disablestatecache = 367924755
>         clone_disablestatecache = 32645
>         generator_fd = -603569856
>         visible_indication = 21900
>         clone_hold_state = 32645
>         moh_is_playing = 0
>         current = 0x4
>         t = 0x0
>         t_pvt = 0x7f85dc07cbc0
>         exchange = {handlers = {first = 0x558c15f13530, last = 0x0}, dialed = {number = {str = 0x558c15f13530 "stasis_message.c", plan = 0}, subaddress = {str = 0xffffffff00000089 <error: Cannot access memory at address 0xffffffff00000089>, type = -536173824, odd_even_indicator = 133 '205', valid = 127 '177'}, transit_network_select = -603459216}, caller = {id = {name = {str = 0x558c15f13530 "stasis_message.c", char_set = 0, presentation = 0, valid = 137 '211'}, number = {str = 0x7f85e00aa300 "255ޭޭޭޭޭޭޭޭ", <incomplete sequence 336>, plan = -603459216, presentation = 32645, valid = 0 '000'}, subaddress = {str = 0x7f85dc07f170 "", type = 599622, odd_even_indicator = 0 '000', valid = 0 '000'}, tag = 0x7f85e5dab0c0 "3031355025214U"}, ani = {name = {str = 0x558c15c9793a <__ao2_unlock+237> "211E364351", <incomplete sequence 317>, char_set = -438652736, presentation = 32645, valid = 50 '2'}, number = {str = 0x22e15ca4db3 <error: Cannot access memory at address 0x22e15ca4db3>, plan = 367864744, presentation = 21900, valid = 0 '000'}, subaddress = {str = 0xe0091d00 <error: Cannot access memory at address 0xe0091d00>, type = 368649264, odd_even_indicator = 140 '214', valid = 85 'U'}, tag = 0x15f92428 <error: Cannot access memory at address 0x15f92428>}, priv = {name = {str = 0x558c15f92430 <reglock+48> "", char_set = 368649256, presentation = 21900, valid = 16 '020'}, number = {str = 0x558c15d60c3a <__ast_pthread_mutex_unlock+1072> "211E؃", <incomplete sequence 330>, plan = -438652640, presentation = 32645, valid = 58 ':'}, subaddress = {str = 0x558c15ed1933 "&reglock", type = 368649216, odd_even_indicator = 140 '214', valid = 85 'U'}, tag = 0x558c15ed1933 "&reglock"}, ani2 = 367863576}, connected = {id = {name = {str = 0x558c15f13530 "stasis_message.c", char_set = 0, presentation = 0, valid = 137 '211'}, number = {str = 0x7f85e00aa300 "255ޭޭޭޭޭޭޭޭ", <incomplete sequence 336>, plan = -603459216, presentation = 32645, valid = 0 '000'}, subaddress = {str = 0x7f85dc07f170 "", type = 599622, odd_even_indicator = 0 '000', valid = 0 '000'}, tag = 0x7f85e5dab0c0 "3031355025214U"}, ani = {name = {str = 0x558c15c9793a <__ao2_unlock+237> "211E364351", <incomplete sequence 317>, char_set = -438652736, presentation = 32645, valid = 50 '2'}, number = {str = 0x22e15ca4db3 <error: Cannot access memory at address 0x22e15ca4db3>, plan = 367864744, presentation = 21900, valid = 0 '000'}, subaddress = {str = 0xe0091d00 <error: Cannot access memory at address 0xe0091d00>, type = 368649264, odd_even_indicator = 140 '214', valid = 85 'U'}, tag = 0x15f92428 <error: Cannot access memory at address 0x15f92428>}, priv = {name = {str = 0x558c15f92430 <reglock+48> "", char_set = 368649256, presentation = 21900, valid = 16 '020'}, number = {str = 0x558c15d60c3a <__ast_pthread_mutex_unlock+1072> "211E؃", <incomplete sequence 330>, plan = -438652640, presentation = 32645, valid = 58 ':'}, subaddress = {str = 0x558c15ed1933 "&reglock", type = 368649216, odd_even_indicator = 140 '214', valid = 85 'U'}, tag = 0x558c15ed1933 "&reglock"}, ani2 = 367863576, source = 21900}, redirecting = {orig = {name = {str = 0x558c15f13530 "stasis_message.c", char_set = 0, presentation = 0, valid = 137 '211'}, number = {str = 0x7f85e00aa300 "255ޭޭޭޭޭޭޭޭ", <incomplete sequence 336>, plan = -603459216, presentation = 32645, valid = 0 '000'}, subaddress = {str = 0x7f85dc07f170 "", type = 599622, odd_even_indicator = 0 '000', valid = 0 '000'}, tag = 0x7f85e5dab0c0 "3031355025214U"}, from = {name = {str = 0x558c15c9793a <__ao2_unlock+237> "211E364351", <incomplete sequence 317>, char_set = -438652736, presentation = 32645, valid = 50 '2'}, number = {str = 0x22e15ca4db3 <error: Cannot access memory at address 0x22e15ca4db3>, plan = 367864744, presentation = 21900, valid = 0 '000'}, subaddress = {str = 0xe0091d00 <error: Cannot access memory at address 0xe0091d00>, type = 368649264, odd_even_indicator = 140 '214', valid = 85 'U'}, tag = 0x15f92428 <error: Cannot access memory at address 0x15f92428>}, to = {name = {str = 0x558c15f92430 <reglock+48> "", char_set = 368649256, presentation = 21900, valid = 16 '020'}, number = {str = 0x558c15d60c3a <__ast_pthread_mutex_unlock+1072> "211E؃", <incomplete sequence 330>, plan = -438652640, presentation = 32645, valid = 58 ':'}, subaddress = {str = 0x558c15ed1933 "&reglock", type = 368649216, odd_even_indicator = 140 '214', valid = 85 'U'}, tag = 0x558c15ed1933 "&reglock"}, priv_orig = {name = {str = 0x558c15ed2718 <__PRETTY_FUNCTION__.9272> "region_free", char_set = 0, presentation = 371, valid = 0 '000'}, number = {str = 0x0, plan = -535791248, presentation = 32645, valid = 80 'P'}, subaddress = {str = 0x558c15fc7fc0 <enddata> "033[0m", type = -536491923, odd_even_indicator = 133 '205', valid = 127 '177'}, tag = 0x7f85d403aa32 "Local/2122 at REDACTED-originate-local-00000001;2"}, priv_from = {name = {str = 0x558c15fc7fc0 <enddata> "033[0m", char_set = 365511119, presentation = 21900, valid = 208 '320'}, number = {str = 0x558c15fbc9a0 <whales> "200031345030214U", plan = 0, presentation = 0, valid = 128 '200'}, subaddress = {str = 0x7f85e5dab190 "в332345205177", type = 365512163, odd_even_indicator = 140 '214', valid = 85 'U'}, tag = 0x558c15ed2ba8 <__PRETTY_FUNCTION__.9410> "__ao2_ref"}, priv_to = {name = {str = 0x28515e08d36 <error: Cannot access memory at address 0x28515e08d36>, char_set = 367864064, presentation = 21900, valid = 96 '`'}, number = {str = 0x7f85e5dab200 "", plan = -535586608, presentation = 32645, valid = 208 '320'}, subaddress = {str = 0x558c15c9866c <__ao2_ref+1971> "351", <incomplete sequence 305>, type = 368869312, odd_even_indicator = 212 '324', valid = 5 '005'}, tag = 0x558c15f12be0 <__PRETTY_FUNCTION__.17048> "ast_channel_publish_blob"}, reason = {str = 0x558c15f11921 "stasis_channels.c", code = 0}, orig_reason = {str = 0xffffffff0000047e <error: Cannot access memory at address 0xffffffff0000047e>, code = 367228233}, count = 3656}}
>         bridged = 0x7f85e00cd580
>         rformat = 0x558c15c9793a <__ao2_unlock+237>
>         wformat = 0x7f85e0107970
>         tmp_format = 0x2a8700000000
>         tmp_cap = 0x7f85e00cd580
>         tmp_name = " 261332345205177000000z002326025214U000000063031355025214U000000000$371025214U000000063031355025214U000000030'355025214U000000 261332345k001000000311030355025214U000000062)355025214U000000260065361025214U000"
>         clone_sending_dtmf_digit = -27 '345'
>         clone_sending_dtmf_tv = {tv_sec = 140213063692560, tv_usec = 94060150129274}
>         __PRETTY_FUNCTION__ = "channel_do_masquerade"
>         __FUNCTION__ = "channel_do_masquerade"
> #11 0x0000558c15cf6ff8 in ast_channel_move (dest=0x7f85e012c960, source=0x7f85dc064190) at channel.c:10889
>         blob = 0x7f85e0107970
>         lock = 0x558c15f930c0 <channel_move_lock>
>         __PRETTY_FUNCTION__ = "ast_channel_move"
>         __FUNCTION__ = "ast_channel_move"
> #12 0x0000558c15cf6c90 in ast_channel_yank (yankee=0x7f85dc064190) at channel.c:10835
>         yanked_chan = 0x7f85e012c960
>         my_vars = {accountcode = 0x7f85e5dab420 "", exten = 0x7f85e5dab400 "s", context = 0x7f85e5dab3e0 "REDACTED-transferred", name = 0x7f85e5dab380 "Local/2123 at REDACTED-originate-local-00000005;1", amaflags = 3, priority = 4, readformat = 0x558c175080a8, writeformat = 0x558c175080a8}
>         __PRETTY_FUNCTION__ = "ast_channel_yank"
>         __FUNCTION__ = "ast_channel_yank"
> #13 0x0000558c15cae625 in ast_bridge_add_channel (bridge=0x7f85c00be270, chan=0x7f85dc064190, features=0x7f85e00fdb60, play_tone=0, xfersound=0x7f85e0092af2 "beep") at bridge.c:2515
>         chan_bridge = 0x0
>         yanked_chan = 0x0
>         __PRETTY_FUNCTION__ = "ast_bridge_add_channel"
>         __FUNCTION__ = "ast_bridge_add_channel"
> #14 0x0000558c15e84422 in bridge_exec (chan=0x7f85d4039d50, data=0x7f85e5daba30 "Local/2123 at REDACTED-originate-local-00000005;1,F(REDACTED-transferred,done,1)") at features.c:1115
>         current_dest_chan = 0x7f85dc064190
>         tmp_data = 0x7f85e5dab620 "Local/2123 at REDACTED-originate-local-00000005;1"
>         opts = {flags = 4096}
>         bconfig = {features_caller = {flags = 0}, features_callee = {flags = 0}, start_time = {tv_sec = 0, tv_usec = 0}, nexteventts = {tv_sec = 0, tv_usec = 0}, feature_start_time = {tv_sec = 0, tv_usec = 0}, feature_timer = 0, timelimit = 0, play_warning = 0, warning_freq = 0, warning_sound = 0x0, end_sound = 0x0, start_sound = 0x0, flags = 0, end_bridge_callback = 0x0, end_bridge_callback_data = 0x0, end_bridge_callback_data_fixup = 0x0, answer_topology = 0x0}
>         opt_args = {0x7f85e5dab810 "", 0x558c15f0e35f "topic", 0x7f85e5dab64f "REDACTED-transferred,done,1"}
>         calldurationlimit = {tv_sec = 0, tv_usec = 0}
>         context = 0x7f85e5dab600 "REDACTED-transferred"
>         extension = 0x7f85e5dab5a0 "Local/2123 at REDACTED-originate-local-00000005;1"
>         priority = 3
>         bridge_add_failed = 21900
>         res = -1
>         chan_features = {dtmf_hooks = 0x7f85cc4fa730, other_hooks = 0x7f85c00cf850, interval_hooks = 0x7f85e00e18d0, feature_flags = {flags = 0}, interval_sequence = 0, usable = 0, mute = 0, dtmf_passthrough = 1, inhibit_colp = 0, text_messaging = 1}
>         peer_features = 0x7f85e00fdb60
>         bridge = 0x7f85c00be270
>         xfer_cfg = 0x7f85c00ca8c0
>         args = {argc = 2, {argv = {0x7f85e5dab620 "Local/2123 at REDACTED-originate-local-00000005;1", 0x7f85e5dab64d "F(REDACTED-transferred,done,1"}, {dest_chan = 0x7f85e5dab620 "Local/2123 at REDACTED-originate-local-00000005;1", options = 0x7f85e5dab64d "F(REDACTED-transferred,done,1"}}}
>         __PRETTY_FUNCTION__ = "bridge_exec"
>         __FUNCTION__ = "bridge_exec"
> #15 0x0000558c15d986c5 in pbx_exec (c=0x7f85d4039d50, app=0x558c168b89e0, data=0x7f85e5daba30 "Local/2123 at REDACTED-originate-local-00000005;1,F(REDACTED-transferred,done,1)") at pbx_app.c:492
>         res = 21900
>         u = 0x0
>         saved_c_appl = 0x0
>         saved_c_data = 0x0
>         __PRETTY_FUNCTION__ = "pbx_exec"
> #16 0x0000558c15d82726 in pbx_extension_helper (c=0x7f85d4039d50, con=0x0, context=0x7f85d403a710 "REDACTED-transferred", exten=0x7f85d403a760 "Local/2123 at REDACTED-originate-local-00000005;1", priority=3, label=0x0, callerid=0x7f85d40460a0 "REDACTED", action=E_SPAWN, found=0x7f85e5daeccc, combined_find_spawn=1) at pbx.c:2948
>         e = 0x558c19709330
>         app = 0x558c168b89e0
>         substitute = 0x7f85e5dab9a0 "${EXTEN},F(REDACTED-transferred,done,1)"
>         q = {incstack = {0x0 <repeats 512 times>}, stacklen = 0, status = 5, swo = 0x0, data = 0x0, foundcontext = 0x7f85d403a710 "REDACTED-transferred"}
>         passdata = "Local/2123 at REDACTED-originate-local-00000005;1,F(REDACTED-transferred,done,1)", '000' <repeats 8118 times>
>         matching_action = 0
>         __PRETTY_FUNCTION__ = "pbx_extension_helper"
>         __FUNCTION__ = "pbx_extension_helper"
> #17 0x0000558c15d86a26 in ast_spawn_extension (c=0x7f85d4039d50, context=0x7f85d403a710 "REDACTED-transferred", exten=0x7f85d403a760 "Local/2123 at REDACTED-originate-local-00000005;1", priority=3, callerid=0x7f85d40460a0 "REDACTED", found=0x7f85e5daeccc, combined_find_spawn=1) at pbx.c:4203
> #18 0x0000558c15d877b5 in __ast_pbx_run (c=0x7f85d4039d50, args=0x0) at pbx.c:4377
>         digit = 0
>         invalid = 0
>         timeout = 0
>         dst_exten = '000' <repeats 56 times>, "Iu343025214U000000H016000000000000000000 at 7373025214U000000256255{272205177000000200325f340205177000000060354332345205177000000Iu343025214U000000H016000000000000000000 at 7373025214U000000~320354025214U000000200325f340205177000000 at 354332345205177000000T242343025214U000000260355332345205177000000220023371025214U000000257255{272205177000000200325f340205177000000260355332345205177000000"...
>         pos = 0
>         found = 1
>         res = 0
>         autoloopflag = 0
>         error = 0
>         pbx = 0x7f85e00d3180
>         callid = 0
>         __FUNCTION__ = "__ast_pbx_run"
>         __PRETTY_FUNCTION__ = "__ast_pbx_run"
> #19 0x0000558c15d8915e in pbx_thread (data=0x7f85d4039d50) at pbx.c:4701
>         c = 0x7f85d4039d50
> #20 0x0000558c15e3b2ac in dummy_start (data=0x558c1a8fd8b0) at utils.c:1574
>         __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {0, 1473881673984446825, 140212336045486, 140212336045487, 140213063710464, 140212898376640, 1473881674009612649, 4640862523344753001}, __mask_was_saved = 0}}, __pad = {0x7f85e5daeed0, 0x0, 0xcfb6bd8bede52c00, 0x7f85c0000bb0}}
>         __cancel_routine = 0x558c15c892f5 <ast_unregister_thread>
>         __cancel_arg = 0x7f85e5daf700
>         __not_first_call = 0
>         ret = 0x7f85e5daf700
>         a = {start_routine = 0x558c15d89139 <pbx_thread>, data = 0x7f85d4039d50, name = 0x7f85cc4f7cc0 "pbx_thread", ' ' <repeats 11 times>, "started at [ 4727] pbx.c ast_pbx_start()"}
>         lock_info = 0x7f85e00cd580
>         mutex_attr = {__size = "001000000", __align = 1}
>         __PRETTY_FUNCTION__ = "dummy_start"
> #21 0x00007f85e85c5fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
>         ret = <optimized out>
>         pd = <optimized out>
>         now = <optimized out>
>         unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140213063710464, -1477308053359619735, 140212336045486, 140212336045487, 140213063710464, 140212898376640, 1473881673973961065, 1473904819000250729}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>         not_first_call = <optimized out>
> #22 0x00007f85e8059eff in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
> {noformat}



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



More information about the asterisk-bugs mailing list