[asterisk-bugs] [JIRA] (ASTERISK-30210) func_frame_trace: Channel masquerade triggers assertion
Richard Mudgett (JIRA)
noreply at issues.asterisk.org
Thu Sep 8 08:06:09 CDT 2022
[ https://issues.asterisk.org/jira/browse/ASTERISK-30210?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=260038#comment-260038 ]
Richard Mudgett commented on ASTERISK-30210:
--------------------------------------------
I did not think it would happen with frame trace. However, frame trace is attached to a channel by frame hooks and thus can legitimately get it before it is passed to the channel driver. The case should be changed to decode the frame like the other cases.
> 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
> Assignee: Unassigned
>
> 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 "®lock", type = 368649216, odd_even_indicator = 140 '214', valid = 85 'U'}, tag = 0x558c15ed1933 "®lock"}, 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 "®lock", type = 368649216, odd_even_indicator = 140 '214', valid = 85 'U'}, tag = 0x558c15ed1933 "®lock"}, 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 "®lock", type = 368649216, odd_even_indicator = 140 '214', valid = 85 'U'}, tag = 0x558c15ed1933 "®lock"}, 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