[asterisk-bugs] [JIRA] (ASTERISK-29296) ari: Bridge is partially invalid when it shouldn't be
Joshua C. Colp (JIRA)
noreply at issues.asterisk.org
Fri Jul 9 09:02:40 CDT 2021
[ https://issues.asterisk.org/jira/browse/ASTERISK-29296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=255584#comment-255584 ]
Joshua C. Colp edited comment on ASTERISK-29296 at 7/9/21 9:02 AM:
-------------------------------------------------------------------
We were "fortunate" enough to have a crash/core dump occur on one of our 18.2 QA instances this afternoon. Full log leading up attached.
was (Author: bweschke):
We were "fortunate" enough to have a crash/core dump occur on one of our 18.2 QA instances this afternoon. This was the full log leading up to it....
[2021-07-08 16:40:32] DEBUG[21324] channel.c: Channel 0x7efd440141f0 'Recorder/ARI-00000037;2' allocated
[2021-07-08 16:40:32] DEBUG[21324] channel_internal_api.c: Recorder/ARI-00000037;2: Formats: (slin)
[2021-07-08 16:40:32] DEBUG[21324] channel_internal_api.c: New topology set
[2021-07-08 16:40:32] DEBUG[21324] bridge_roles.c: Set role 'recorder'
[2021-07-08 16:40:32] ERROR[21324] stasis.c: FRACK!, Failed assertion bad magic number 0x0 for object 0x7efd4806d2e0 (0)
[2021-07-08 16:40:32] DEBUG[21325] http.c: HTTP Request URI is /asterisk/ari/channels?api_key=admin:MASKED&endpoint=Local%2F3154474827%40preferredcallerid&priority=1&app=ari-queue-1&appArgs=agentconnected%2Cbridge.SKTOBD.kchen.9154474827&callerId=outboundcall&timeout=8&channelId=SKTOBD.9154474827.kchen&otherChannelId=SKTOBD.9154474827.kchen.native
[2021-07-08 16:40:32] DEBUG[21325] http.c: match request [ari/channels] with handler [httpstatus] len 10
[2021-07-08 16:40:32] DEBUG[21325] http.c: match request [ari/channels] with handler [phoneprov] len 9
[2021-07-08 16:40:32] DEBUG[21325] http.c: match request [ari/channels] with handler [metrics] len 7
[2021-07-08 16:40:32] DEBUG[21325] http.c: match request [ari/channels] with handler [static] len 6
[2021-07-08 16:40:32] DEBUG[21325] http.c: match request [ari/channels] with handler [ari] len 3
[2021-07-08 16:40:32] DEBUG[21325] http.c: Match made with [ari]
[2021-07-08 16:40:32] DEBUG[21325] http.c: HTTP consuming request body
[2021-07-08 16:40:32] DEBUG[21325] res_ari.c: Finding handler for channels
[2021-07-08 16:40:32] DEBUG[21325] res_ari.c: Finding handler for channels
[2021-07-08 16:40:32] DEBUG[21325] res_ari.c: Checking ari channels: Explicit match with channels
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: <initializing>: Formats: (none)
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: Channel is being initialized or destroyed
[2021-07-08 16:40:32] DEBUG[21325] stasis.c: Creating topic. name: channel:SKTOBD.9154474827.kchen, detail:
[2021-07-08 16:40:32] DEBUG[21325] stasis.c: Topic 'channel:SKTOBD.9154474827.kchen': 0x7efd40005070 created
[2021-07-08 16:40:32] DEBUG[21325] channel.c: Channel 0x7efd40006510 'Local/9154474827 at preferredcallerid-00000038;1' allocated
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: Local/3154474827 at preferredcallerid-00000038;1: MultistreamFormats: (slin192)
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: Set native formats but not topology
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: Local/3154474827 at preferredcallerid-00000038;1: <0:audio-0:audio:sendrecv (slin192)>
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: Used provided topology
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: <initializing>: Formats: (none)
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: Channel is being initialized or destroyed
[2021-07-08 16:40:32] DEBUG[21325] stasis.c: Creating topic. name: channel:SKTOBD.9154474827.kchen.native, detail:
[2021-07-08 16:40:32] DEBUG[21325] stasis.c: Topic 'channel:SKTOBD.9154474827.kchen.native': 0x7efd4000e340 created
[2021-07-08 16:40:32] DEBUG[21325] channel.c: Channel 0x7efd4000b690 'Local/9154474827 at preferredcallerid-00000038;2' allocated
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: Local/3154474827 at preferredcallerid-00000038;2: MultistreamFormats: (slin192)
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: Set native formats but not topology
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: Local/3154474827 at preferredcallerid-00000038;2: <0:audio-0:audio:sendrecv (slin192)>
[2021-07-08 16:40:32] DEBUG[21325] channel_internal_api.c: Used provided topology
[2021-07-08 16:40:32] DEBUG[21325] res_stasis.c: ari-queue-1: Subscribing to SKTOBD.9154474827.kchen
[2021-07-08 16:40:32] DEBUG[21325] stasis/app.c: Channel 'SKTOBD.9154474827.kchen' is 1 interested in ari-queue-1
[2021-07-08 16:40:32] DEBUG[21325] res_stasis.c: ari-queue-1: Subscribing to SKTOBD.9154474827.kchen.native
[2021-07-08 16:40:32] DEBUG[21325] stasis/app.c: Channel 'SKTOBD.9154474827.kchen.native' is 1 interested in ari-queue-1
[2021-07-08 16:40:32] DEBUG[21325] http.c: HTTP closing session. status_code:200
[2021-07-08 16:40:32] DEBUG[21325] http.c: HTTP closing session. Top level
[2021-07-08 16:40:32] DEBUG[21325] tcptls.c: ast_tcptls_close_session_file invoked on session instance without file or file descriptor
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 739
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 739
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 719
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 719
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 739
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 739
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 727
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 727
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 739
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 739
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 710
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 710
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 788
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 788
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 698
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 698
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 780
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 780
[2021-07-08 16:40:32] VERBOSE[21326] dial.c: Called 9154474827 at preferredcallerid
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'AGENT' is 'kchen'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx.c: Launching 'Set'
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx.c: Executing [3154474827 at preferredcallerid:1] Set("Local/9154474827 at preferredcallerid-00000038;2", "GROUP()=kchen") in new stack
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 774
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 774
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'RID' is '3ea52c4b-5d2e-11e8-bcbc-0a634134f3e0'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'PreferredCallerId' is '8047633908'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'AGENT' is 'kchen'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'UID' is 'f2460a95-92ab-4733-836b-29c366ab5868'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'EXTEN' is '9154474827'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx.c: Launching 'Verbose'
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx.c: Executing [3154474827 at preferredcallerid:2] Verbose("Local/3154474827 at preferredcallerid-00000038;2", "Setting restaurant rid 3ea52c4b-5d2e-11e8-bcbc-0a634134f3e0 with preferred caller id 8047633908 for kchen (f2460a95-92ab-4733-836b-29c366ab5868) outbound call to 9154474827") in new stack
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 1100
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 1100
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] app_verbose.c: Setting restaurant rid 3ea52c4b-5d2e-11e8-bcbc-0a634134f3e0 with preferred caller id 8047633908 for kchen (f2460a95-92ab-4733-836b-29c366ab5868) outbound call to 9154474827
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARIGLOBALHOLDINGSERVLET' is '1'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx.c: Launching 'Set'
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx.c: Executing [9154474827 at preferredcallerid:3] Set("Local/9154474827 at preferredcallerid-00000038;2", "ARIHOLDINGSERVLET=1") in new stack
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 786
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 786
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 764
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 764
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'UID' is 'f2460a95-92ab-4733-836b-29c366ab5868'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'EXTEN' is '3154474827'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'RID' is '3ea52c4b-5d2e-11e8-bcbc-0a634134f3e0'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx.c: Launching 'Gosub'
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx.c: Executing [9154474827 at preferredcallerid:4] Gosub("Local/9154474827 at preferredcallerid-00000038;2", "startOutboundCall,,1(f2460a95-92ab-4733-836b-29c366ab5868,9154474827,3ea52c4b-5d2e-11e8-bcbc-0a634134f3e0,SIP)") in new stack
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 972
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 972
[2021-07-08 16:40:32] DEBUG[21320] bridge_roles.c: Roles did not exist on channel PJSIP/ariqueue_ob_endpoint-00000037
[2021-07-08 16:40:32] DEBUG[21320] stasis/control.c: SKTOBD.kchen.3154474827: Adding to bridge bridge.SKTOBD.kchen.9154474827
[2021-07-08 16:40:32] ERROR[21320] stasis.c: FRACK!, Failed assertion bad magic number 0x0 for object 0x7efd4806d2e0 (0)
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_lua.c: Looking up 9154474827 at startOutboundCall:1
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] app_stack.c: Channel Local/9154474827 at preferredcallerid-00000038;2 has no datastore, so we're allocating one.
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 886
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 886
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] app_stack.c: Setting 'ARG1' to 'f2460a95-92ab-4733-836b-29c366ab5868'
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 860
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 860
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] app_stack.c: Setting 'ARG2' to '3154474827'
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 886
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 886
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] app_stack.c: Setting 'ARG3' to '3ea52c4b-5d2e-11e8-bcbc-0a634134f3e0'
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 853
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 853
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] app_stack.c: Setting 'ARG4' to 'SIP'
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 851
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 851
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_lua.c: Looking up 3154474827 at startOutboundCall:1
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_lua.c: Looking up 3154474827 at startOutboundCall:1
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARG1' is 'f2460a95-92ab-4733-836b-29c366ab5868'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARG1' is 'f2460a95-92ab-4733-836b-29c366ab5868'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARG2' is '9154474827'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARG2' is '9154474827'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARG3' is '3ea52c4b-5d2e-11e8-bcbc-0a634134f3e0'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARG3' is '3ea52c4b-5d2e-11e8-bcbc-0a634134f3e0'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARG4' is 'SIP'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARG4' is 'SIP'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'CID' is '92d10f7f-b837-4742-8df7-b57c3770f3bc'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'CID' is '92d10f7f-b837-4742-8df7-b57c3770f3bc'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARIHOLDINGSERVLET' is '1'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'ARIHOLDINGSERVLET' is '1'
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx_lua.c: Executing [9154474827 at startOutboundCall:1] log("Local/9154474827 at preferredcallerid-00000038;2", ",Start outbound call request: '{"uid":"f2460a95-92ab-4733-836b-29c366ab5868","userAgent":"SIP","rid":"3ea52c4b-5d2e-11e8-bcbc-0a634134f3e0","ariholdingservlet":"1","regulatedPhone":"9154474827","cid":"92d10f7f-b837-4742-8df7-b57c3770f3bc"}'")
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 1280
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 1280
[2021-07-08 16:40:32] ERROR[21327][C-0000001e] app_verbose.c: Unknown log level: ''
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'CALLCTRAPIBASEURL' is 'https://qa.letsdochinese.com'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'CALLCTRAPIBASEURL' is 'https://qa.letsdochinese.com'
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx_lua.c: Executing [9154474827 at startOutboundCall:1] log("Local/9154474827 at preferredcallerid-00000038;2", ",Start outbound call response: {
cid = "92d10f7f-b837-4742-8df7-b57c3770f3bc"
}")
[2021-07-08 16:40:32] ERROR[21327][C-0000001e] app_verbose.c: Unknown log level: ''
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx_lua.c: Executing [9154474827 at startOutboundCall:1] log("Local/9154474827 at preferredcallerid-00000038;2", ",Setting CID to 92d10f7f-b837-4742-8df7-b57c3770f3bc")
[2021-07-08 16:40:32] ERROR[21327][C-0000001e] app_verbose.c: Unknown log level: ''
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx_lua.c: Executing [9154474827 at startOutboundCall:1] log("Local/9154474827 at preferredcallerid-00000038;2", ",Setting USERAGENT to SIP for 92d10f7f-b837-4742-8df7-b57c3770f3bc")
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 818
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 818
[2021-07-08 16:40:32] ERROR[21327][C-0000001e] app_verbose.c: Unknown log level: ''
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx_lua.c: Executing [9154474827 at startOutboundCall:1] Return("Local/9154474827 at preferredcallerid-00000038;2", "")
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 805
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 805
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_lua.c: Goto detected: context changed from startOutboundCall to preferredcallerid
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 734
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 734
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 734
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 734
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 734
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 734
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 734
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 734
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 734
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 734
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 742
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 742
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'CHANNEL' is 'Local/9154474827 at preferredcallerid-00000038;2'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx.c: Launching 'Set'
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx.c: Executing [3154474827 at preferredcallerid:5] Set("Local/9154474827 at preferredcallerid-00000038;2", "CUTCHANNAME=Local/9154474827 at preferredcallerid-00000038") in new stack
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx_variables.c: Result of 'CUTCHANNAME' is 'Local/9154474827 at preferredcallerid-00000038'
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx.c: Launching 'Verbose'
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx.c: Executing [3154474827 at preferredcallerid:6] Verbose("Local/9154474827 at preferredcallerid-00000038;2", "CHANNEL NAME IS Local/9154474827 at preferredcallerid-00000038") in new stack
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] app_verbose.c: CHANNEL NAME IS Local/3154474827 at preferredcallerid-00000038
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx.c: Launching 'Set'
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx.c: Executing [3154474827 at preferredcallerid:7] Set("Local/9154474827 at preferredcallerid-00000038;2", "_SKTCALLTYPE=outbound") in new stack
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] pbx.c: Launching 'Answer'
[2021-07-08 16:40:32] VERBOSE[21327][C-0000001e] pbx.c: Executing [3154474827 at preferredcallerid:8] Answer("Local/9154474827 at preferredcallerid-00000038;2", "") in new stack
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 858
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 858
[2021-07-08 16:40:32] DEBUG[21327][C-0000001e] core_unreal.c: Blocked indication -1
[2021-07-08 16:40:32] VERBOSE[21326] dial.c: Local/9154474827 at preferredcallerid-00000038;1 answered
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 836
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 836
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 874
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 874
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 790
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 790
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 768
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 768
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 754
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 754
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 700
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 700
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 710
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 710
[2021-07-08 16:40:32] VERBOSE[21326] ari/resource_channels.c: Launching Stasis(ari-queue-1,agentconnected,bridge.SKTOBD.kchen.9154474827) on Local/9154474827 at preferredcallerid-00000038;1
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 784
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 784
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket string of length 790
[2021-07-08 16:40:32] DEBUG[6805] res_http_websocket.c: Writing websocket text frame, length 790
[2021-07-08 16:40:32] DEBUG[6735] devicestate.c: No provider found, checking channel drivers for Local - 9154474827 at preferredcallerid
[2021-07-08 16:40:32] DEBUG[6735] devicestate.c: Changing state for Local/3154474827 at preferredcallerid - state 2 (In use)
[2021-07-08 16:40:32] DEBUG[6735] devicestate.c: No provider found, checking channel drivers for Local - 9154474827 at preferredcallerid
[2021-07-08 16:40:32] DEBUG[6735] devicestate.c: Changing state for Local/9154474827 at preferredcallerid - state 2 (In use)
[2021-07-08 16:40:32] DEBUG[6799] app_queue.c: Device 'Local/3154474827 at preferredcallerid' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2021-07-08 16:40:32] DEBUG[6799] app_queue.c: Device 'Local/3154474827 at preferredcallerid' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2021-07-08 16:40:32] DEBUG[6760] res_pjsip_registrar.c: Woke up at 1625776832 Interval: 30
[2021-07-08 16:40:32] DEBUG[6760] res_pjsip_registrar.c: Expiring 0 contacts
[2021-07-08 16:40:32] ERROR[21324] : Got 13 backtrace records
# 0: [0x5b9690] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x45e08f] asterisk astobj2.c:511 __ao2_ref()
# 2: [0x583968] asterisk stasis.c:1596 stasis_forward_all()
# 3: [0x7efd0892203c] res_ari_bridges.so resource_bridges.c:673 ast_ari_bridges_record()
# 4: [0x7efd08920a75] res_ari_bridges.so res_ari_bridges.c:1463 ast_ari_bridges_record_cb()
# 5: [0x7efd0bc050fd] res_ari.so res_ari.c:588 ast_ari_invoke()
# 6: [0x7efd0bc068c6] res_ari.so res_ari.c:1058 ast_ari_callback()
# 7: [0x5fca70] asterisk http.c:1494 handle_uri()
# 8: [inlined] asterisk http.c:1928 httpd_process_request()
# 9: [0x5fcf8b] asterisk http.c:1991 httpd_helper_thread()
#10: [0x5b50cc] asterisk utils.c:1301 dummy_start()
#11: [0x7efd716666ba] libpthread.so.0 :0 __pthread_get_minstack()
#12: [0x7efd708fb4dd] libc.so.6 clone.S:111 clone()
[2021-07-08 16:40:32] ERROR[21324] stasis.c: FRACK!, Failed assertion bad magic number 0x7ef for object 0x7efd4806d2e0 (0)
[2021-07-08 16:40:32] ERROR[21320] : Got 15 backtrace records
[2021-07-08 16:40:32] ERROR[21320] : Got 15 backtrace records
# 0: [0x5b9690] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x45e08f] asterisk astobj2.c:511 __ao2_ref()
# 2: [0x583944] asterisk stasis.c:1595 stasis_forward_all()
# 3: [0x7efd26102f00] res_stasis.so app.c:181 forwards_create_bridge()
# 4: [inlined] res_stasis.so app.c:1453 app_subscribe_bridge()
# 5: [0x7efd26107d3a] res_stasis.so control.c:1328 control_swap_channel_in_bridge()
# 6: [0x7efd261053c6] res_stasis.so command.c:105 command_invoke()
# 7: [0x7efd26108866] res_stasis.so control.c:1507 control_dispatch_all()
# 8: [0x7efd260fd47e] res_stasis.so res_stasis.c:1559 stasis_app_exec()
# 9: [0x7efd0ab98bb7] app_stasis.so app_stasis.c:111 app_exec()
#10: [0x5399dd] asterisk pbx_app.c:493 pbx_exec()
#11: [0x7efd0afacea7] res_ari_channels.so resource_channels.c:1030 ari_originate_dial()
#12: [0x5b50cc] asterisk utils.c:1301 dummy_start()
#13: [0x7efd716666ba] libpthread.so.0 :0 __pthread_get_minstack()
#14: [0x7efd708fb4dd] libc.so.6 clone.S:111 clone()
[2021-07-08 16:40:32] ERROR[21320] stasis.c: FRACK!, Failed assertion bad magic number 0x7ef for object 0x7efd4806d2e0 (0)
[2021-07-08 16:40:32] ERROR[21324] : Got 14 backtrace records
# 0: [0x5b9690] asterisk utils.c:2454 __ast_assert_failed()
# 1: [0x45d86e] asterisk astobj2.c:219 log_bad_ao2()
# 2: [inlined] asterisk astobj2.c:224 __ao2_lock()
# 3: [0x5839b7] asterisk stasis.c:1598 stasis_forward_all()
# 4: [0x7efd0892203c] res_ari_bridges.so resource_bridges.c:673 ast_ari_bridges_record()
# 5: [0x7efd08920a75] res_ari_bridges.so res_ari_bridges.c:1463 ast_ari_bridges_record_cb()
# 6: [0x7efd0bc050fd] res_ari.so res_ari.c:588 ast_ari_invoke()
# 7: [0x7efd0bc068c6] res_ari.so res_ari.c:1058 ast_ari_callback()
# 8: [0x5fca70] asterisk http.c:1494 handle_uri()
# 9: [inlined] asterisk http.c:1928 httpd_process_request()
#10: [0x5fcf8b] asterisk http.c:1991 httpd_helper_thread()
#11: [0x5b50cc] asterisk utils.c:1301 dummy_start()
#12: [0x7efd716666ba] libpthread.so.0 :0 __pthread_get_minstack()
#13: [0x7efd708fb4dd] libc.so.6 clone.S:111 clone()
[2021-07-08 16:41:25] Asterisk 18.2.0 built by root @ rhino on a x86_64 running Linux on 2021-03-11 13:03:47 UTC
> ari: Bridge is partially invalid when it shouldn't be
> -----------------------------------------------------
>
> Key: ASTERISK-29296
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-29296
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Resources/res_stasis
> Affects Versions: 18.2.0, 18.4.0
> Environment: Ubuntu 18
> Reporter: BJ Weschke
> Assignee: Unassigned
> Attachments: asterisk-18-2-frack-core-dump-20210708.tar.bz2, ASTERISK-29296-full.txt, asterisk-frack.log.bz2
>
>
> Upon trying to add a channel to a bridge while testing Asterisk 18.2 in our QA environment, we started seeing these messages (see in attached log beginning at 14:09:42) in the full log, and after that point, anything related to the channel or the bridge in question seems to stream these errors into the log. The testers than gracefully shut down the Asterisk instance to clear the issue. We've not been able to reproduce this by doing the same use case that caused the issue in the first place.
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list