[asterisk-bugs] [JIRA] (ASTERISK-27020) ARI breaks and doesn't send websocket messages when any party hangsup a call that is in a bridge
Asterisk Team (JIRA)
noreply at issues.asterisk.org
Tue Jun 13 12:01:58 CDT 2017
[ https://issues.asterisk.org/jira/browse/ASTERISK-27020?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=237422#comment-237422 ]
Asterisk Team commented on ASTERISK-27020:
------------------------------------------
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
> ARI breaks and doesn't send websocket messages when any party hangsup a call that is in a bridge
> ------------------------------------------------------------------------------------------------
>
> Key: ASTERISK-27020
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-27020
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Resources/res_ari
> Affects Versions: 14.4.0
> Environment: CentOS 6.6 - FreePBX
> Reporter: Bruce
> Assignee: Bruce
>
> This is an incoming call from SIP trunk PSTN:
> When 2 channels created by ARI are in a bridge which is created by ARI, and the one of the channels hangs up, ARI breaks websocket without returning any response to it. This only happens when the *first* party hangs up (essentially leaving the bridge). If the second party hangs up then websocket is re-initiated and the second channel leaves the bridge, and ARI behaves normally.
> The following is snippet of what happens. Everything start line 49 is wrong and not normal behavior. Line 49 should be something else. This is something else on Asterisk version 14.0.2.
> [2017-05-26 16:40:02] DEBUG[2292]: chan_sip.c:27401 handle_request_bye: Received bye, issuing owner hangup
> [2017-05-26 16:40:02] DEBUG[2292]: chan_sip.c:3759 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 205.205.205.205:5060
> [2017-05-26 16:40:02] DEBUG[2255]: cdr.c:1296 cdr_object_finalize: Finalized CDR for SIP/9053341207-out-0000005c - start 1495831181.347010 answer 1495831183.717176 end 1495831202.874313 dispo ANSWERED
> [2017-05-26 16:40:02] DEBUG[2259]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0xb76021ec from class 'asteriskcdrdb'
> [2017-05-26 16:40:02] DEBUG[2259]: cel_odbc.c:759 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype, eventtime, cid_name, cid_num, cid_ani, cid_rdnis, cid_dnid, exten, context, channame, appname, appdata, amaflags, accountcode, uniqueid, linkedid, peer, userdeftype, extra) VALUES ('HANGUP', {ts '2017-05-26 16:40:02.874350'}, '', '', '', '', '', '', 'from-pstn', 'SIP/9053341207-out-0000005c', '', '', 3, '', '4999-out', '4999-in', '', '', '{"dialstatus":"","hangupcause":16,"hangupsource":"SIP/9053341207-out-0000005c"}')]
> [2017-05-26 16:40:02] DEBUG[2259]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0xb76021ec into pool
> [2017-05-26 16:40:02] DEBUG[2884]: manager.c:5911 match_filter: Examining AMI event:
> Event: Hangup
> Privilege: call,all
> Channel: SIP/9053341207-out-0000005c
> ChannelState: 6
> ChannelStateDesc: Up
> CallerIDNum: <unknown>
> CallerIDName: <unknown>
> ConnectedLineNum: 4158889999
> ConnectedLineName: asdf
> Language: en
> AccountCode:
> Context: from-pstn
> Exten:
> Priority: 1
> Uniqueid: 4999-out
> Linkedid: 4999-in
> Cause: 16
> Cause-txt: Normal Clearing
>
>
> [2017-05-26 16:40:02] DEBUG[3451]: manager.c:5911 match_filter: Examining AMI event:
> Event: Hangup
> Privilege: call,all
> Channel: SIP/9053341207-out-0000005c
> ChannelState: 6
> ChannelStateDesc: Up
> CallerIDNum: <unknown>
> CallerIDName: <unknown>
> ConnectedLineNum: 4158889999
> ConnectedLineName: asdf
> Language: en
> AccountCode:
> Context: from-pstn
> Exten:
> Priority: 1
> Uniqueid: 4999-out
> Linkedid: 4999-in
> Cause: 16
> Cause-txt: Normal Clearing
>
>
> [2017-05-26 16:40:02] DEBUG[2255]: cdr.c:1124 cdr_object_create_public_records: CDR for SIP/9053341207-out-0000005c is dialed and has no Party B; discarding
> [2017-05-26 16:40:02] DEBUG[2255]: cdr.c:1124 cdr_object_create_public_records: CDR for SIP/9053341207-out-0000005c is dialed and has no Party B; discarding
> [2017-05-26 16:40:02] DEBUG[2245]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for SIP - 9053341207-out
> [2017-05-26 16:40:02] DEBUG[2245]: chan_sip.c:30320 sip_devicestate: Checking device state for peer 9053341207-out
> [2017-05-26 16:40:02] DEBUG[2245]: devicestate.c:474 do_state_change: Changing state for SIP/9053341207-out - state 1 (Not in use)
> [2017-05-26 16:40:02] DEBUG[2292]: chan_sip.c:6600 sip_pvt_dtor: Destroying SIP dialog 120b301f23f017d639de2d1034176836 at 65.65.65.65:5160
> [2017-05-26 16:40:02] DEBUG[2292]: rtp_engine.c:397 instance_destructor: Destroyed RTP instance '0xb46b3ff4'
> [2017-05-26 16:40:02] DEBUG[2259]: res_odbc.c:869 _ast_odbc_request_obj2: Reusing ODBC handle 0xb76021ec from class 'asteriskcdrdb'
> [2017-05-26 16:40:02] DEBUG[2259]: cel_odbc.c:759 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype, eventtime, cid_name, cid_num, cid_ani, cid_rdnis, cid_dnid, exten, context, channame, appname, appdata, amaflags, accountcode, uniqueid, linkedid, peer, userdeftype, extra) VALUES ('CHAN_END', {ts '2017-05-26 16:40:02.875377'}, '', '', '', '', '', '', 'from-pstn', 'SIP/9053341207-out-0000005c', '', '', 3, '', '4999-out', '4999-in', '', '', '')]
> [2017-05-26 16:40:02] DEBUG[2259]: res_odbc.c:718 ast_odbc_release_obj: Releasing ODBC handle 0xb76021ec into pool
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 530
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 530
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 574
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 574
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 589
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 589
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 657
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 657
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 672
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 672
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 642
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 642
> [2017-05-26 16:40:02] DEBUG[3193]: utils.c:1347 wait_for_output: Timed out trying to write
> [2017-05-26 16:40:02] DEBUG[3193]: res_http_websocket.c:396 __ast_websocket_write: Closing WS with 1011 because we can't fulfill a write request
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 657
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 657
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 523
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 523
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 538
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 538
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 444
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 444
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 461
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 461
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 466
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 466
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 606
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 606
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 422
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 422
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 470
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 470
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:1437 __ast_websocket_write_string: Writing websocket string of length 470
> [2017-05-26 16:40:03] DEBUG[3193]: res_http_websocket.c:356 __ast_websocket_write: Writing websocket text frame, length 470
> [2017-05-26 16:40:03] NOTICE[3193]: ari/ari_websockets.c:180 ast_ari_websocket_session_write: Problem occurred during websocket write to 172.65.41.2:35618, websocket closed
> [2017-05-26 16:40:03] DEBUG[3193]: stasis/app.c:1295 unsubscribe: channel '4999-out': is 0 interested in customapp
> [2017-05-26 16:40:03] DEBUG[3193]: stasis/app.c:1298 unsubscribe: channel '4999-out' unsubscribed from customapp
> [2017-05-26 16:40:03] DEBUG[6003]: ari/ari_websockets.c:135 ast_ari_websocket_session_read: WebSocket closed
> [2017-05-26 16:40:03] DEBUG[6080]: http.c:1931 httpd_helper_thread: HTTP opening session. Top level
> [2017-05-26 16:40:03] DEBUG[6080]: http.c:1407 handle_uri: HTTP Request URI is /ari/events?app=customapp&api_key=TxMjGn230K3ys:fhR7uV49z7zatAh5
> [2017-05-26 16:40:03] DEBUG[6080]: http.c:1462 handle_uri: match request [ari/events] with handler [httpstatus] len 10
> [2017-05-26 16:40:03] DEBUG[6080]: http.c:1462 handle_uri: match request [ari/events] with handler [static] len 6
> [2017-05-26 16:40:03] DEBUG[6080]: http.c:1462 handle_uri: match request [ari/events] with handler [ari] len 3
> [2017-05-26 16:40:03] DEBUG[6080]: http.c:1478 handle_uri: Match made with [ari]
> [2017-05-26 16:40:03] DEBUG[6080]: res_ari.c:514 ast_ari_invoke: Finding handler for events
> [2017-05-26 16:40:03] DEBUG[6080]: res_ari.c:519 ast_ari_invoke: Checking endpoints
> [2017-05-26 16:40:03] DEBUG[6080]: res_ari.c:519 ast_ari_invoke: Checking recordings
> [2017-05-26 16:40:03] DEBUG[6080]: res_ari.c:519 ast_ari_invoke: Checking channels
> [2017-05-26 16:40:03] DEBUG[6080]: res_ari.c:519 ast_ari_invoke: Checking bridges
> [2017-05-26 16:40:03] DEBUG[6080]: res_ari.c:519 ast_ari_invoke: Checking asterisk
> [2017-05-26 16:40:03] DEBUG[6080]: res_ari.c:519 ast_ari_invoke: Checking sounds
> [2017-05-26 16:40:03] DEBUG[6080]: res_ari.c:519 ast_ari_invoke: Checking applications
> [2017-05-26 16:40:03] DEBUG[6080]: res_ari.c:519 ast_ari_invoke: Checking events
> [2017-05-26 16:40:03] DEBUG[6080]: res_ari.c:539 ast_ari_invoke: Got it!
> [2017-05-26 16:40:03] DEBUG[6080]: ari/resource_events.c:483 ast_ari_websocket_events_event_websocket_attempted: /events WebSocket attempted
> [2017-05-26 16:40:03] DEBUG[6080]: ari/resource_events.c:498 ast_ari_websocket_events_event_websocket_established: /events WebSocket established
> [2017-05-26 16:40:03] DEBUG[2884]: manager.c:5911 match_filter: Examining AMI event:
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list