Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Audio gets cut off #1

Open
sanderversluys opened this issue Aug 17, 2023 · 9 comments
Open

Audio gets cut off #1

sanderversluys opened this issue Aug 17, 2023 · 9 comments

Comments

@sanderversluys
Copy link

Tried to run it myself with my rotary phone and grandstream 801 but audio gets cut off when picking off the phone and also generated audio is downloaded, put on queue but not played.

API keys etc are set just fine.

Any idea based on my log?

debug.log

@tcz
Copy link
Owner

tcz commented Aug 17, 2023

Hey, first of all, it's awesome that you picked this up!

audio gets cut off

You mean the greeting audio and the audio generated with Polly? Does it play to some extent?

Based on the logs everything looks fine. I leave here my HT801 config for comparison. I think most if them should have the default values, perhaps the jitter buffer size is higher, but I'm not 100% sure because I bought it a long time ago.

Let me know if this helps, if not we can dig deeper.

image image

@sanderversluys
Copy link
Author

sanderversluys commented Aug 21, 2023

Thank you for your response.

It seems I got some additional config options but most where similar as yours or the default options. I guess the firmware version may be slightly different.

Screenshot 2023-08-21 at 15 45 25

@tcz
Copy link
Owner

tcz commented Aug 21, 2023

Both the software and the hardware version actually:

image

Yet it doesn't really explain the issue.

What I'd suggest is to enable the debug on HT801 and look at what's happening there. I made video on how to do that:
https://www.loom.com/share/a480ec34037944649282994a1a42cf4a?sid=ce15ddba-bb28-4d7d-abea-d701c5e14cba

This was referenced Sep 12, 2023
@tcz
Copy link
Owner

tcz commented Oct 14, 2023

Can you test if the latest version works better?
See #2 (comment)

@lundstrom14
Copy link

Hi @tcz. I have the same problem.

Audio typically gets cut of at "Hello". I have the same issue with new patch with shared sockets unfortunately.

I'll post the HT801 (newer hardware and software versions) logs, maybe you can spot something that's off regarding RTP negotiation?

Super thanks!

@tcz
Copy link
Owner

tcz commented Oct 22, 2023

Yeah logs might help although they didn't really reveal much for the share socket issue.

@lundstrom14
Copy link

lundstrom14 commented Oct 22, 2023

Sometime's I've been able to hear the full greeting message, but very rarely. Could there be something else than RTP negotiation or socket issues?

ht801.log

Application logs.
2023-10-22 17:07:08 MainThread [DEBUG]: Registered function weather__get_weather_today
2023-10-22 17:07:08 MainThread [DEBUG]: Registered function accent__change_accent
2023-10-22 17:07:08 SIP server [INFO]: SIP server started on 0.0.0.0:5060
2023-10-22 17:07:11 SIP server [INFO]: Incoming SIP request b'INVITE'
2023-10-22 17:07:11 SIP server [DEBUG]: b'INVITE sip:192.168.1.98:5060 SIP/2.0\r\nVia: SIP/2.0/UDP 192.168.220.60:5060;branch=z9hG4bK1676250581;rport\r\nFrom: "Mattias" sip:IPCall@192.168.220.60:5060;tag=1370303268\r\nTo: sip:192.168.1.98:5060\r\nCall-ID: 1158434412-5060-16@BJC.BGI.CCA.GA\r\nCSeq: 150 INVITE\r\nContact: sip:IPCall@192.168.220.60:5060\r\nMax-Forwards: 70\r\nUser-Agent: Grandstream HT801 1.0.43.11\r\nSupported: replaces, path, timer, eventlist\r\nAllow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE\r\nContent-Type: application/sdp\r\nAccept: application/sdp, application/dtmf-relay\r\nContent-Length: 482\r\n\r\nv=0\r\no=IPCall 8000 8000 IN IP4 192.168.220.60\r\ns=SIP Call\r\nc=IN IP4 192.168.220.60\r\nt=0 0\r\nm=audio 5004 RTP/AVP 0 8 4 18 2 97 123 9 101\r\na=sendrecv\r\na=rtpmap:0 PCMU/8000\r\na=ptime:50\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:4 G723/8000\r\na=rtpmap:18 G729/8000\r\na=fmtp:18 annexb=no\r\na=rtpmap:2 G726-32/8000\r\na=rtpmap:97 iLBC/8000\r\na=fmtp:97 mode=20\r\na=rtpmap:123 opus/48000/2\r\na=fmtp:123 maxplaybackrate=16000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-16,32-36,54\r\n'
2023-10-22 17:07:11 SIP server [INFO]: SIP response sent 200
2023-10-22 17:07:11 SIP server [DEBUG]: b'SIP/2.0 200 OK\r\nVia: SIP/2.0/UDP 192.168.220.60:5060;branch=z9hG4bK1676250581;rport\r\nTo: sip:192.168.1.98:5060\r\nFrom: "Mattias" sip:IPCall@192.168.220.60:5060;tag=1370303268\r\nContact: sip:192.168.1.98:5060\r\nCall-ID: 1158434412-5060-16@BJC.BGI.CCA.GA\r\nCSeq: 150 INVITE\r\nContent-type: application/sdp\r\nContent-Length: 151\r\n\r\nv=0\no=RotaryGPT 1 1 IN IP4 192.168.1.98\ns=SIP Call\nc=IN IP4 192.168.1.98\r\nt=0 0\r\nm=audio 5004 RTP/AVP 0\r\na=sendrecv\r\na=rtpmap:0 PCMU/8000\r\na=ptime:20\r\n'
2023-10-22 17:07:11 SIP server [DEBUG]: Calling incoming call callbacks with client RTP address 192.168.220.60:5004
2023-10-22 17:07:11 RTP receiver [INFO]: RTP receiver started on 0.0.0.0:5004
2023-10-22 17:07:11 RTP sender [INFO]: RTP sender started with peer 192.168.220.60:5004
2023-10-22 17:07:11 Conversation [INFO]: Conversation started
2023-10-22 17:07:11 Conversation [DEBUG]: Sending greeting
2023-10-22 17:07:11 SIP server [DEBUG]: Finished incoming call callbacks
2023-10-22 17:07:11 SIP server [INFO]: Incoming SIP request b'ACK'
2023-10-22 17:07:11 SIP server [DEBUG]: b'ACK sip:192.168.1.98:5060 SIP/2.0\r\nVia: SIP/2.0/UDP 192.168.220.60:5060;branch=z9hG4bK1083392993;rport\r\nFrom: "Mattias" sip:IPCall@192.168.220.60:5060;tag=1370303268\r\nTo: sip:192.168.1.98:5060\r\nCall-ID: 1158434412-5060-16@BJC.BGI.CCA.GA\r\nCSeq: 150 ACK\r\nContact: sip:192.168.220.60:5060\r\nMax-Forwards: 70\r\nSupported: replaces, path, timer, eventlist\r\nUser-Agent: Grandstream HT801 1.0.43.11\r\nAllow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE\r\nContent-Length: 0\r\n\r\n'
2023-10-22 17:07:11 RTP sender [DEBUG]: New talkspurt, marker bit set
2023-10-22 17:07:16 Conversation [DEBUG]: Sending greeting
2023-10-22 17:07:17 Conversation [DEBUG]: Starting Whisper request
2023-10-22 17:07:17 RTP sender [DEBUG]: New talkspurt, marker bit set
2023-10-22 17:07:17 Conversation [DEBUG]: Receiving audio
2023-10-22 17:07:19 Conversation [DEBUG]: Silence detected
2023-10-22 17:07:19 Conversation [DEBUG]: Sending Whisper request
2023-10-22 17:07:19 Conversation [DEBUG]: Whisper returned
2023-10-22 17:07:19 Conversation [INFO]: User message: Hello, what is your name?
2023-10-22 17:07:19 Conversation [DEBUG]: Sending GPT request
2023-10-22 17:07:21 Conversation [INFO]: Agent message: My name is Phone Agent. How can I assist you today?
2023-10-22 17:07:21 Conversation [DEBUG]: Sending Polly request
b'HTTP/1.1 200 OK\r\nx-amzn-RequestId: d605cec1-6b32-4855-8c8e-8fdfd297bc26\r\nx-amzn-RequestCharacters: 51\r\nContent-Type: audio/pcm\r\nTransfer-Encoding: chunked\r\nDate: Sun, 22 Oct 2023 15:07:20 GMT\r\nConnection: close'
2023-10-22 17:07:21 Conversation [DEBUG]: Polly chunk arrived, sending to RTP
2023-10-22 17:07:21 RTP sender [DEBUG]: New talkspurt, marker bit set
2023-10-22 17:07:21 Conversation [DEBUG]: Polly chunk arrived, sending to RTP
2023-10-22 17:07:22 Conversation [DEBUG]: Polly chunk arrived, sending to RTP
2023-10-22 17:07:22 Conversation [DEBUG]: Polly chunk arrived, sending to RTP
2023-10-22 17:07:22 Conversation [DEBUG]: Polly chunk arrived, sending to RTP
2023-10-22 17:07:22 Conversation [DEBUG]: Polly chunk arrived, sending to RTP
2023-10-22 17:07:22 Conversation [DEBUG]: Polly chunk arrived, sending to RTP
2023-10-22 17:07:22 Conversation [DEBUG]: Polly chunk arrived, sending to RTP
2023-10-22 17:07:22 Conversation [DEBUG]: Polly chunk arrived, sending to RTP
2023-10-22 17:07:22 Conversation [DEBUG]: Polly fully returned, waiting for audio out queue to be consumed
2023-10-22 17:07:25 Conversation [DEBUG]: Audio out queue empty
2023-10-22 17:07:25 Conversation [DEBUG]: Starting Whisper request
2023-10-22 17:07:25 Conversation [DEBUG]: Receiving audio
2023-10-22 17:07:31 Conversation [DEBUG]: Silence detected
2023-10-22 17:07:31 Conversation [DEBUG]: Sending Whisper request
2023-10-22 17:07:31 SIP server [INFO]: Incoming SIP request b'BYE'
2023-10-22 17:07:31 SIP server [DEBUG]: b'BYE sip:192.168.1.98:5060 SIP/2.0\r\nVia: SIP/2.0/UDP 192.168.220.60:5060;branch=z9hG4bK1294677366;rport\r\nFrom: "Mattias" sip:IPCall@192.168.220.60:5060;tag=1370303268\r\nTo: sip:192.168.1.98:5060\r\nCall-ID: 1158434412-5060-16@BJC.BGI.CCA.GA\r\nCSeq: 151 BYE\r\nContact: sip:192.168.220.60:5060\r\nMax-Forwards: 70\r\nSupported: replaces, path, timer, eventlist\r\nUser-Agent: Grandstream HT801 1.0.43.11\r\nAllow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE\r\nContent-Length: 0\r\n\r\n'
2023-10-22 17:07:31 SIP server [INFO]: SIP response sent 200
2023-10-22 17:07:31 SIP server [DEBUG]: b'SIP/2.0 200 OK\r\nVia: SIP/2.0/UDP 192.168.220.60:5060;branch=z9hG4bK1294677366;rport\r\nTo: sip:192.168.1.98:5060\r\nFrom: "Mattias" sip:IPCall@192.168.220.60:5060;tag=1370303268\r\nContact: sip:192.168.1.98:5060\r\nCall-ID: 1158434412-5060-16@BJC.BGI.CCA.GA\r\nCSeq: 151 BYE\r\nContent-Length: 0\r\n\r\n'
2023-10-22 17:07:31 SIP server [DEBUG]: Calling call ended callbacks
2023-10-22 17:07:31 RTP sender [INFO]: RTP sender stopped
Exception in thread RTP receiver:
Traceback (most recent call last):
File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner
self.run()
File "/usr/lib/python3.7/threading.py", line 865, in run
self._target(*self._args, **self._kwargs)
File "/home/pi/git/rotary-gpt/rotarygpt/rtp.py", line 24, in start
self._receive_audio()
File "/home/pi/git/rotary-gpt/rotarygpt/rtp.py", line 34, in _receive_audio
chunk, address = self.shared_socket.recvfrom(160 + 12) # 20ms is 160 8bit samples plus header
File "/home/pi/git/rotary-gpt/rotarygpt/rtp.py", line 125, in recvfrom
return self.socket.recvfrom(size)
OSError: [Errno 9] Bad file descriptor

2023-10-22 17:07:31 Conversation [DEBUG]: Whisper returned
2023-10-22 17:07:31 Conversation [INFO]: Conversation ended
2023-10-22 17:07:31 SIP server [DEBUG]: Finished call ended callbacks

@tcz
Copy link
Owner

tcz commented Oct 22, 2023 via email

@lundstrom14
Copy link

Thanks for your reply.

Posted the HT801 logs above.

Hmm. I don't think the exception above "OSError: [Errno 9] Bad file descriptor" is the issue, at least it was not the exception that I was trying to highlight. Think that part is just race conditions when BYE since there's no mutex on shared socket?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants