Closed icegas closed 3 months ago
here is as log from asyncari:
DEBUG:asyncio:Using selector: EpollSelector DEBUG:asyncswagger11.client:Loading from http://0.0.0.0:8088/ari/api-docs/resources.json DEBUG:asyncswagger11.client:eventWebsocket?'app=hello' DEBUG:asyncswagger11.client:GET http://0.0.0.0:8088/ari/events({'app': 'hello'}) DEBUG:asyncari.client:ADD StasisStart DEBUG:asyncari.client:DISP ***** Dispatch:<EventMessage StasisStart> {'_client': <Client:ARI.c65.66a5f9d6e67>, '_orig_msg': {'application': 'hello', 'args': [], 'asterisk_id': '06:20:f3:13:90:23', 'channel': {'accountcode': '', 'caller': {'name': '', 'number': '****'}, 'connected': {'name': '', 'number': ''}, 'creationtime': '2024-07-28T07:57:17.531+0000', 'dialplan': {'app_data': 'hello', 'app_name': 'Stasis', 'context': 'internal', 'exten': '*****', 'priority': 2}, 'id': '1722153437.28', 'language': 'en', 'name': 'SIP/****-0000000f', 'protocol_id': 'bAW64J7vrC', 'state': 'Ring'}, 'timestamp': '2024-07-28T07:57:17.531+0000', 'type': 'StasisStart'}, 'application': 'hello', 'args': [], 'asterisk_id': '06:20:f3:13:90:23', 'channel': Channel(1722153437.28), 'timestamp': '2024-07-28T07:57:17.531+0000', 'type': 'StasisStart'} /home/ubuntu/agi/voice_assistant.py:52: RuntimeWarning: coroutine 'BaseObject._get_enriched.<locals>.enrich_operation' was never awaited channel.answer() RuntimeWarning: Enable tracemalloc to get the object allocation traceback DEBUG:asyncswagger11.client:create?'type=mixing' DEBUG:asyncswagger11.client:POST http://0.0.0.0:8088/ari/bridges({'type': 'mixing'}) DEBUG:asyncari.model:resp={'id': '8233ada8-7c4d-42c0-9da1-b89da801bc90', 'technology': 'simple_bridge', 'bridge_type': 'mixing', 'bridge_class': 'stasis', 'creator': 'Stasis', 'name': '', 'channels': [], 'creationtime': '2024-07-28T07:57:17.546+0000', 'video_mode': 'talker'} DEBUG:asyncswagger11.client:externalMedia?'channelId=ARI.c65.66a5f9d6e67.1&app=hello&external_host=127.0.0.1%3A9998&format=ulaw' DEBUG:asyncswagger11.client:POST http://0.0.0.0:8088/ari/channels/externalMedia({'channelId': 'ARI.c65.66a5f9d6e67.1', 'app': 'hello', 'external_host': '127.0.0.1:9998', 'format': 'ulaw'}) DEBUG:asyncari.model:resp={'id': 'ARI.c65.66a5f9d6e67.1', 'name': 'UnicastRTP/127.0.0.1:9998-0x7e117400c100', 'state': 'Down', 'protocol_id': '', 'caller': {'name': '', 'number': ''}, 'connected': {'name': '', 'number': ''}, 'accountcode': '', 'dialplan': {'context': 'default', 'exten': 's', 'priority': 1, 'app_name': 'AppDial2', 'app_data': '(Outgoing Line)'}, 'creationtime': '2024-07-28T07:57:17.553+0000', 'language': 'en', 'channelvars': {'UNICASTRTP_LOCAL_PORT': '14510', 'UNICASTRTP_LOCAL_ADDRESS': '127.0.0.1'}} DEBUG:asyncari.model:Issuing command addChannel {'channel': ['ARI.c65.66a5f9d6e67.1', '1722153437.28'], 'bridgeId': '8233ada8-7c4d-42c0-9da1-b89da801bc90'} DEBUG:asyncswagger11.client:addChannel?'channel=%5B%27ARI.c65.66a5f9d6e67.1%27%2C+%271722153437.28%27%5D&bridgeId=8233ada8-7c4d-42c0-9da1-b89da801bc90' DEBUG:asyncswagger11.client:POST http://0.0.0.0:8088/ari/bridges/8233ada8-7c4d-42c0-9da1-b89da801bc90/addChannel({'channel': 'ARI.c65.66a5f9d6e67.1,1722153437.28'}) DEBUG:asyncari.client:DISP ***** Dispatch:<EventMessage DialStart> {'_client': <Client:ARI.c65.66a5f9d6e67>, '_orig_msg': {'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'dialstatus': '', 'dialstring': '127.0.0.1:9998/c(ulaw)', 'forward': '', 'peer': {'accountcode': '', 'caller': {'name': '', 'number': ''}, 'connected': {'name': '', 'number': ''}, 'creationtime': '2024-07-28T07:57:17.553+0000', 'dialplan': {'app_data': '(Outgoing Line)', 'app_name': 'AppDial2', 'context': 'default', 'exten': 's', 'priority': 1}, 'id': 'ARI.c65.66a5f9d6e67.1', 'language': 'en', 'name': 'UnicastRTP/127.0.0.1:9998-0x7e117400c100', 'protocol_id': '', 'state': 'Down'}, 'timestamp': '2024-07-28T07:57:17.553+0000', 'type': 'Dial'}, 'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'dialstatus': '', 'dialstring': '127.0.0.1:9998/c(ulaw)', 'forward': '', 'peer': Channel(ARI.c65.66a5f9d6e67.1), 'timestamp': '2024-07-28T07:57:17.553+0000', 'type': 'DialStart'} WARNING:asyncari.model:Event not recognized: <EventMessage DialStart> for Channel(ARI.c65.66a5f9d6e67.1) DEBUG:asyncari.client:DISP ***** Dispatch:<EventMessage ChannelStateChange> {'_client': <Client:ARI.c65.66a5f9d6e67>, '_orig_msg': {'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'channel': {'accountcode': '', 'caller': {'name': '', 'number': ''}, 'connected': {'name': '', 'number': ''}, 'creationtime': '2024-07-28T07:57:17.553+0000', 'dialplan': {'app_data': '(Outgoing Line)', 'app_name': 'AppDial2', 'context': 'default', 'exten': 's', 'priority': 1}, 'id': 'ARI.c65.66a5f9d6e67.1', 'language': 'en', 'name': 'UnicastRTP/127.0.0.1:9998-0x7e117400c100', 'protocol_id': '', 'state': 'Up'}, 'timestamp': '2024-07-28T07:57:17.553+0000', 'type': 'ChannelStateChange'}, 'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'channel': Channel(ARI.c65.66a5f9d6e67.1), 'timestamp': '2024-07-28T07:57:17.553+0000', 'type': 'ChannelStateChange'} DEBUG:asyncari.model:State:Up Channel(ARI.c65.66a5f9d6e67.1) DEBUG:asyncari.client:DISP ***** Dispatch:<EventMessage DialResult> {'_client': <Client:ARI.c65.66a5f9d6e67>, '_orig_msg': {'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'dialstatus': 'ANSWER', 'dialstring': '127.0.0.1:9998/c(ulaw)', 'forward': '', 'peer': {'accountcode': '', 'caller': {'name': '', 'number': ''}, 'connected': {'name': '', 'number': ''}, 'creationtime': '2024-07-28T07:57:17.553+0000', 'dialplan': {'app_data': '(Outgoing Line)', 'app_name': 'AppDial2', 'context': 'default', 'exten': 's', 'priority': 1}, 'id': 'ARI.c65.66a5f9d6e67.1', 'language': 'en', 'name': 'UnicastRTP/127.0.0.1:9998-0x7e117400c100', 'protocol_id': '', 'state': 'Up'}, 'timestamp': '2024-07-28T07:57:17.553+0000', 'type': 'Dial'}, 'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'dialstatus': 'ANSWER', 'dialstring': '127.0.0.1:9998/c(ulaw)', 'forward': '', 'peer': Channel(ARI.c65.66a5f9d6e67.1), 'timestamp': '2024-07-28T07:57:17.553+0000', 'type': 'DialResult'} WARNING:asyncari.model:Event not recognized: <EventMessage DialResult> for Channel(ARI.c65.66a5f9d6e67.1) DEBUG:asyncari.model:resp=<Response 204 No Content> DEBUG:asyncari.client:DISP ***** Dispatch:<EventMessage StasisStart> {'_client': <Client:ARI.c65.66a5f9d6e67>, '_orig_msg': {'application': 'hello', 'args': [], 'asterisk_id': '06:20:f3:13:90:23', 'channel': {'accountcode': '', 'caller': {'name': '', 'number': ''}, 'connected': {'name': '', 'number': ''}, 'creationtime': '2024-07-28T07:57:17.553+0000', 'dialplan': {'app_data': 'hello', 'app_name': 'Stasis', 'context': 'default', 'exten': 's', 'priority': 1}, 'id': 'ARI.c65.66a5f9d6e67.1', 'language': 'en', 'name': 'UnicastRTP/127.0.0.1:9998-0x7e117400c100', 'protocol_id': '', 'state': 'Up'}, 'timestamp': '2024-07-28T07:57:17.553+0000', 'type': 'StasisStart'}, 'application': 'hello', 'args': [], 'asterisk_id': '06:20:f3:13:90:23', 'channel': Channel(ARI.c65.66a5f9d6e67.1), 'timestamp': '2024-07-28T07:57:17.553+0000', 'type': 'StasisStart'} DEBUG:asyncari.client:DISP ***** Dispatch:<EventMessage ChannelEnteredBridge> {'_client': <Client:ARI.c65.66a5f9d6e67>, '_orig_msg': {'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'bridge': {'bridge_class': 'stasis', 'bridge_type': 'mixing', 'channels': ['ARI.c65.66a5f9d6e67.1'], 'creationtime': '2024-07-28T07:57:17.546+0000', 'creator': 'Stasis', 'id': '8233ada8-7c4d-42c0-9da1-b89da801bc90', 'name': '', 'technology': 'simple_bridge', 'video_mode': 'talker'}, 'channel': {'accountcode': '', 'caller': {'name': '', 'number': ''}, 'connected': {'name': '', 'number': ''}, 'creationtime': '2024-07-28T07:57:17.553+0000', 'dialplan': {'app_data': 'hello', 'app_name': 'Stasis', 'context': 'default', 'exten': 's', 'priority': 1}, 'id': 'ARI.c65.66a5f9d6e67.1', 'language': 'en', 'name': 'UnicastRTP/127.0.0.1:9998-0x7e117400c100', 'protocol_id': '', 'state': 'Up'}, 'timestamp': '2024-07-28T07:57:17.565+0000', 'type': 'ChannelEnteredBridge'}, 'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'bridge': Bridge(8233ada8-7c4d-42c0-9da1-b89da801bc90), 'channel': Channel(ARI.c65.66a5f9d6e67.1), 'timestamp': '2024-07-28T07:57:17.565+0000', 'type': 'ChannelEnteredBridge'} DEBUG:asyncari.client:DISP ***** Dispatch:<EventMessage ChannelEnteredBridge> {'_client': <Client:ARI.c65.66a5f9d6e67>, '_orig_msg': {'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'bridge': {'bridge_class': 'stasis', 'bridge_type': 'mixing', 'channels': ['1722153437.28', 'ARI.c65.66a5f9d6e67.1'], 'creationtime': '2024-07-28T07:57:17.546+0000', 'creator': 'Stasis', 'id': '8233ada8-7c4d-42c0-9da1-b89da801bc90', 'name': '', 'technology': 'simple_bridge', 'video_mode': 'talker'}, 'channel': {'accountcode': '', 'caller': {'name': '', 'number': '****'}, 'connected': {'name': '', 'number': ''}, 'creationtime': '2024-07-28T07:57:17.531+0000', 'dialplan': {'app_data': 'hello', 'app_name': 'Stasis', 'context': 'internal', 'exten': '****', 'priority': 2}, 'id': '1722153437.28', 'language': 'en', 'name': 'SIP/****-0000000f', 'protocol_id': 'bAW64J7vrC', 'state': 'Ring'}, 'timestamp': '2024-07-28T07:57:17.565+0000', 'type': 'ChannelEnteredBridge'}, 'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'bridge': Bridge(8233ada8-7c4d-42c0-9da1-b89da801bc90), 'channel': Channel(1722153437.28), 'timestamp': '2024-07-28T07:57:17.565+0000', 'type': 'ChannelEnteredBridge'} DEBUG:asyncari.client:DISP ***** Dispatch:<EventMessage ChannelConnectedLine> {'_client': <Client:ARI.c65.66a5f9d6e67>, '_orig_msg': {'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'channel': {'accountcode': '', 'caller': {'name': '', 'number': ''}, 'connected': {'name': '', 'number': '****'}, 'creationtime': '2024-07-28T07:57:17.553+0000', 'dialplan': {'app_data': 'hello', 'app_name': 'Stasis', 'context': 'default', 'exten': 's', 'priority': 1}, 'id': 'ARI.c65.66a5f9d6e67.1', 'language': 'en', 'name': 'UnicastRTP/127.0.0.1:9998-0x7e117400c100', 'protocol_id': '', 'state': 'Up'}, 'timestamp': '2024-07-28T07:57:17.566+0000', 'type': 'ChannelConnectedLine'}, 'application': 'hello', 'asterisk_id': '06:20:f3:13:90:23', 'channel': Channel(ARI.c65.66a5f9d6e67.1), 'timestamp': '2024-07-28T07:57:17.566+0000', 'type': 'ChannelConnectedLine'}
if using this diaplan code
exten => 4,1,Answer() same = n,Stasis(hello-world) same = n,Hangup()
And of course changing app to hello-world in the code, it is answering, but after 30 seconds hanging up, and rtp packets not being send also.
super strange, but when i've added this:
await bridge.play(media="sound:hello-world")
everything started working.
Looks like problems related to asterisk
rtp_handler method is not being called for rtp packets. i also turn on rtp packets debug on asterisk and don't see any rtp packets, call just not answering. log from asterisk:
Using SIP RTP CoS mark 5 -- Executing [****@internal:1] NoOp("SIP/****-0000000d", "") in new stack -- Executing [****@internal:2] Stasis("SIP/****-0000000d", "hello") in new stack -- Called 127.0.0.1:9998/c(ulaw) -- UnicastRTP/127.0.0.1:9998-0x7e11b80c4820 answered -- Channel UnicastRTP/127.0.0.1:9998-0x7e11b80c4820 joined 'simple_bridge' stasis-bridge <e4c12d81 -82f8-4670-89a2-e9833816e5c9> -- Channel SIP/*****-0000000d joined 'simple_bridge' stasis-bridge <e4c12d81-82f8-4670-89a2-e983381 6e5c9>
Python 3.10.14 asterisk 18 asyncari=0.10.8 anyio=3.7.1 aioudp=0.1.1