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.

Sign up for GitHub

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

Jump to bottom

Audio Get Code off #2

Closed
maciasr opened this issue Sep 1, 2023 · 63 comments
Closed

Audio Get Code off #2

maciasr opened this issue Sep 1, 2023 · 63 comments

Comments

@maciasr
Copy link

maciasr commented Sep 1, 2023

hi there, hope all is well.
I'm trying to setup but my audio is getting cut off.
No a programmer, can you tell me where to add/edit the API key and the txt you suggested to add for GPT?

export OPENAI_API_KEY="xxxx"
export AWS_ACCESS_KEY="yyyy"
export AWS_SECRET_KEY="zzz"

Set it to the name of the city you leave. Used for weather.

export ROTARYGPT_PHYSICAL_LOCATION="Barcelona, Spain"

Getting the error below..

image
@maciasr
Copy link
Author

maciasr commented Sep 1, 2023

Thank you for your help.

@tcz
Copy link
Owner

tcz commented Sep 12, 2023

Hello,

It seems that the environmental variables are not set. Is that screenshot from a Windows machine?
If so, I believe under Windows you need to use "set" and not "export", but I'm not an expert:

https://learn.microsoft.com/en-us/windows-server/administration/windows-commands/set_1

@raulmaciascam
Copy link

Thank you the environment variable did the trick.
however I'm still facing issue with the granstream.
I opened a ticket with them, below is a copy of the trace.
I thank you very much.

rotarygpt3.zip

@raulmaciascam
Copy link

Grandstream claims that the issue since to be the RTP out port 5xxxx coming from the computer.
I tried different versions of Windows. On W7 I'm getting partial response but breaks on W10 works a little better but breaks too. On W11 does not work at all. Just bought a raspberry pi will advise how it goes..

Below is grandstream respond..

Francisco @September 14, 2023 11:19

We suspect there is some misconfiguration at the rotaryGPT.
It is sending RTP out of a port in 5xxxx, and is imposing the HT send to port 5004. The RTP port for sending and receiving ought to be the same one.

@tcz
Copy link
Owner

tcz commented Sep 15, 2023

Can you please link to the full conversation with them? I'd like to see what you sent them.

@dick-nds
Copy link

I've the same issue with the Granstream HT801 (hardware version: v6.0A / software version: v1.0.49).
Audio is (always) getting cut off during the greeting.
Only "Hello" is audible, thenafter all following receiving audio (from the RTP queue) is ignored / trashed / etc.

Voice commands back to Rotary-GTP work fine; answers are created, sent back, but again not audible.

Then i've hooked up a Gigaset E630A GO, made a direct IP call to Rotary-GTP, and everything works right out of the box....

Something with the Granstream HT801 is incorrectly set / parameterized.
Already tried several settings but without success so far.

@tcz
Copy link
Owner

tcz commented Sep 17, 2023

I'm sorry you're having a trouble here. I suspect that the hardware version might be a culprit, yours is much newer than mine.

As I wrote in #1, I think it would be useful to run debugging on the HT801:
https://www.loom.com/share/a480ec34037944649282994a1a42cf4a?sid=ce15ddba-bb28-4d7d-abea-d701c5e14cba

This might reveal some issues.

@dick-nds
Copy link

No problem. Thanks. I saw the debug option as well.

I will continue testing/debugging and/or hook up a Cisco ATA.

As for using Rotary-GPT with home automation.... Have you ever thought about creating an interface for Home Assistant (https://developers.home-assistant.io/docs/api/rest/)? That would be great!

@tcz
Copy link
Owner

tcz commented Sep 17, 2023

I'm not familiar with Home Assistant, I only made connectors for stuff I own/use but contribs are welcome!
Let me know if I can help with the debug! It's exciting to hear you're setting up RotaryGPT!

@ShmuelCammebys ShmuelCammebys mentioned this issue Sep 19, 2023
Open
@raulmaciascam
Copy link

Grandstream Helpdesk.pdf

Attached is my interaction with Grandstream.

@raulmaciascam
Copy link

I've the same issue with the Granstream HT801 (hardware version: v6.0A / software version: v1.0.49). Audio is (always) getting cut off during the greeting. Only "Hello" is audible, thenafter all following receiving audio (from the RTP queue) is ignored / trashed / etc.

Voice commands back to Rotary-GTP work fine; answers are created, sent back, but again not audible.

Then i've hooked up a Gigaset E630A GO, made a direct IP call to Rotary-GTP, and everything works right out of the box....

Something with the Granstream HT801 is incorrectly set / parameterized. Already tried several settings but without success so far.
Same exact device.

image

@dick-nds
Copy link

So, I've done some debugging with different logging levels...
The most detailed debug logging level is quite cryptic, and no documentation for it is available anywhere.
I saw some RTCP buffer issues. Which may disrupt the RTP setup process.

I disagree with Grandstream Helpdesk's response.
Each side in a bidirectional RTP session assigns their source ports independently. Each side in a unicast session simply indicates to the other side where it wants to receive RTP packets.

Today I tested a Cisco ATA 191/192. This works instantly with factory default settings.

Also "off-hook auto dial" is possible with this ATA device.
My dial plan setting is (where xxx are ip address decimals):

(P0 <:xxx.xxx.xxx.xxx:5060>)

For now I'm happy with (the more robust) Cisco ATA.

@tusabez
Copy link

tusabez commented Sep 20, 2023 •
edited
Loading

So, I've done some debugging with different logging levels... The most detailed debug logging level is quite cryptic, and no documentation for it is available anywhere. I saw some RTCP buffer issues. Which may disrupt the RTP setup process.

I disagree with Grandstream Helpdesk's response. Each side in a bidirectional RTP session assigns their source ports independently. Each side in a unicast session simply indicates to the other side where it wants to receive RTP packets.

Today I tested a Cisco ATA 191/192. This works instantly with factory default settings.

Also "off-hook auto dial" is possible with this ATA device. My dial plan setting is (where xxx are ip address decimals):

(P0 <:xxx.xxx.xxx.xxx:5060>)

For now I'm happy with (the more robust) Cisco ATA.

Same issues with Grandstream so I tried using a Cisco ATA 192 and followed the same dial plan setting with my RPI's IP address but it doesn't seem to be calling out to my Raspberry PI. Anything else in the menu that I need to change for it to work?

@dick-nds
Copy link

Yes, i forgot to mention that you need to set "Make Call Without Reg:" to "Yes" in section "Proxy and Registration" settings for "Line 1" or "Line 2".

@raulmaciascam
Copy link

raulmaciascam commented Sep 21, 2023 via email

@dick-nds
Copy link

It's was mentioned for the Cisco ATA (in reply to @tusabez).

@tcz
Copy link
Owner

tcz commented Sep 21, 2023

I disagree with Grandstream Helpdesk's response.
Each side in a bidirectional RTP session assigns their source ports independently.

I agree with @dick-nds here, Grandstream's response is strange.

@raulmaciascam have you been able to debug HT801 as suggested in #1? I'd love to see that log.

@raulmaciascam
Copy link

raulmaciascam commented Sep 21, 2023 via email •
edited
Loading

@tusabez
Copy link

tusabez commented Sep 22, 2023

@dick-nds That did the trick! Thanks! @tcz If I wanted to change the default voice to American English and pick a server in the Western United States, would I need to make changes just in aws.py? I'm still new to this type of project so trying to figure things out.

@tcz
Copy link
Owner

tcz commented Sep 27, 2023

Yes, changing this line

self.target_host = "polly.eu-west-1.amazonaws.com"

Should change the region. I guess it could have been a parameter.

Regarding the voice, indeed, change this line:

default_voice = "Daniel"

It's important that you need to pick a voice that supports Neural Voice. Here's the full list:
https://docs.aws.amazon.com/polly/latest/dg/voicelist.html

@raulmaciascam
Copy link

raulmaciascam commented Sep 27, 2023 via email

@maciasr
Copy link
Author

maciasr commented Oct 3, 2023

Log from HT801 below..

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.485465 LIBGSDSP: CSS: RTPSTART: dec_chan=0, coderTypeDec = 46, status = 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.492825 LIBGSDSP: CSS: RTPSTART: enc_chan=1coderTypeEnc = 46, status = 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.493362 LIBGSDSP: CSS:
Value of sid_update for G711 is 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.498513 LIBGSDSP: CSS: pLineData->dwCapabilities = 3146059, pLineData->dec_chan = 0, jib_instance = 180a

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.498866 LIBGSDSP: CSS:
@@@@@ Value of pktsize 10 ms is 1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.499340 LIBGSDSP: CSS: @@ ### JB ADAPTATION TYPE is ENABLED

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.499553 LIBGSDSP: CSS: The MAX JIB value received from User space 1000

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.499748 LIBGSDSP: CSS: The ADAPTATION TYPE value received from User space 1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.504103 LIBGSDSP: CSS: The RESYNCRONISATION THRESHOLD received from User space 3

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.504476 LIBGSDSP: CSS: The TARGET PLAYOUT DELAY received from User space 20

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.507813 LIBGSDSP: CSS: The MONITORING INTERVAL value received from User space 2000

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.508364 LIBGSDSP: CSS: The ADAPTATION STEPSIZE RESET TIME value received from User space 60

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.508596 LIBGSDSP: CSS: The ADAPTATION SLOPE value received from User space 24

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.508799 LIBGSDSP: CSS: The POST ADAPTATION STEP SIZE MEDIUM value received from User space 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.509160 LIBGSDSP: CSS: The POST ADAPTATION STEP SIZE value received from User space 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.509396 LIBGSDSP: CSS: The MIN JIB value received from User space 120

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.509595 LIBGSDSP: CSS: The JIB has been initialized to this 23926b8 for line id 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.520238 LIBGSDSP: CSS: Function p_rtpapp_Start;Line 1848; STATE 2

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.520608 LIBGSDSP: CSS: Line variables: bBufSize: 160;bDecFrameSize: 80;bDecPackedFrameSize: 80;bFrameSize: 80;bPackedBufSize: 160, bPackedFrameSi

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.520748 LIBGSDSP: ze: 80

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.521155 LIBGSDSP: CSS: voice_request_start_chan returning 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.521414 LIBGSDSP: CSS: In API callback event = 281, inst = 1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.521627 LIBGSDSP: CSS: p_rtpapp_AUCCallback is getting called

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.521824 LIBGSDSP: CSS: p_rtpapp_AUCMssgHandler: Encoder chan 1 started for line 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.522176 LIBGSDSP: CSS: In API callback event = 281, inst = 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.528446 LIBGSDSP: CSS: p_rtpapp_AUCCallback is getting called

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.528730 LIBGSDSP: CSS: p_rtpapp_AUCMssgHandler: Decoder chan 0 started for line 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.529094 LIBGSDSP: CSS: p_rtpapp_SetSesionStatus: started decoder and encoder for line 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.529346 LIBGSDSP: CSS:

AUC Channel started sending COMA REPLY

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.529556 LIBGSDSP: CSS: Function create_voice_message; Sending coma response 5

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.535437 LIBGSDSP: CSS: Function p_rtpapp_SetSesionStatus;Line 703; STATE CHANGE: to 3

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.538246 LIBGSDSP: CSS: voice_request_start_rtcp:756: Calling voice_start_rtcp

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.538535 LIBGSDSP: CSS: Function p_rtpapp_RtcpStart;Line 151; Calling p_rtcp_SessionInit

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.538751 LIBGSDSP: CSS: rtcp interval 5 and opts flag 19

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.539088 LIBGSDSP: CSS: ### p_rtcp_SessionInit 5 opts 19

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.544595 LIBGSDSP: CSS: The RTCP Feedback type is '0' fb_bw '0' fb_trr_interval '0' max_rtt 0 and sizeof RTCP_config 816

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.544880 LIBGSDSP: CSS:
Session RB TYPE :: 255

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.545291 LIBGSDSP: CSS: AFTER COPY TO rtcpsession interval 5 opts 19

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.545511 LIBGSDSP: CSS:
The RTCP XR - thining 3 & gmin 16

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.546221 LIBGSDSP: CSS: p_rtcp_xr_SessionInit function called ---- Number Of SIP SESSIONS '8'

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.546483 LIBGSDSP: CSS:
p_rtcp_xr_SessionInit called with Gmin : 16 and Thining : 3 value

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.551348 LIBGSDSP: CSS: Modes of RTCP 19

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.551718 LIBGSDSP: CSS: ######## RTCP interval given from user space 5

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.552145 LIBGSDSP: CSS: p_rtcp_xr_SessionStart function called ----

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.555197 LIBGSDSP: CSS: Function create_voice_message; Sending coma response 14

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.555492 LIBGSDSP: CSS: p_rtp_SeqInit 75

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364491.560415 LIBGSDSP: CSS: p_rtp_SeqInit 77

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.645840 SigCtrl::performRegistration on acct 0, Registered: 1, proxyUrl: 254.255.107.58.site.sil6.broadviewnet.net, preferPrimary:0, perfer Primary
<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG OBP:0, obpIndex:0, failbackTimer: 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.651109 SigCtrl::performRegistration on acct 0, reset clear reachable flag to true

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.656127 SIPStack(0)::cb_snd_message, host=212232ABJJ.sil6.broadviewnet.net, original port=5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.656429 SIPStack(0)::cb_snd_message: t retry count =1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.656638 SIPStack(0)::snd_message, dst port:5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.656880 SIPStack(0)::snd_message: Copy registrarIP[] to registrarIPAddr: 216.214.56.86, port: 5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.659464 Line 452, DNS::lookup, Fetch DNS A record from preferred IP[0] for host 212232ABJJ.sil6.broadviewnet.net, IP: 216.214.56.86, port =5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.659785 SIPStack(0)::snd_message: UDP case. setNetworkConnected

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.660200 SIPStack(0)::snd_message: Present IP: 216.214.56.86, port: 5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.660427 SIPTransaction::setTargetIPandPort, host: 212232ABJJ.sil6.broadviewnet.net, IP: 216.214.56.86, port: 5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.660651 Line 452, DNS::lookup, Fetch DNS A record from preferred IP[0] for host 212232ABJJ.sil6.broadviewnet.net, IP: 216.214.56.86, port =5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.660836 SIPStack(0)::snd_message: Save registrarIP: 216.214.56.86, registrarPort: 5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.661730 SIPStack(0)::snd_message, update credential successful for server IP: 216.214.56.86

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364494.665323 SIPClientTransaction::sendRequest: Request 362 is sent

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.674130 SIPStack(0)::snd_message:(973)REGISTER sip:254.255.107.58.site.sil6.broadviewnet.net SIP/2.0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Via: SIP/2.0/UDP 254.255.107.58:5060;branch=z9hG4bK1904225867;rport
Route: sip:212232ABJJ.sil6.broadviewnet.net:5060;lr

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG From: "Tech Room" sip:3786@254.255.107.58.site.sil6.broadviewnet.net;tag=121971311

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG To: sip:3786@254.255.107.58.site.sil6.broadviewnet.net
Call-ID: 1658516088-5060-3@CFE.CFF.BAH.FI
CSeq: 2345 REGISTER

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Contact: sip:3786@254.255.107.58:5060;reg-id=1;+sip.instance="urn:uuid:00000000-0000-1000-8000-C074ADCA6F20"

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Authorization: Digest username="3786", realm="732985AAAE", nonce="297381190", uri="sip:254.255.107.58.site.sil6.broadviewnet.net", response=
<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG "0c9e743215ccd69a624519f5d9f989e7", algorithm=MD5, cnonce="08814139", qop=auth, nc=0000008e
Max-Forwards: 70

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG User-Agent: Grandstream HT801 1.0.49.2 c074adca6f20
MAC: c0:74:ad:ca:6f:20
Supported: path
Expires: 3600

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE
Content-Length: 0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364494.686741 SIPStack(0)::run: Active call dialogs: 2

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364494.687223 SIPStack(0)::run: Active transactions: 1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.697119 SIPStack(0)::receiveMessage:(936)SIP/2.0 200 OK
Via: SIP/2.0/UDP 254.255.107.58:5060;branch=z9hG4bK1904225867;rport

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Route: sip:212232ABJJ.sil6.broadviewnet.net:5060;lr
From: "Tech Room" sip:3786@254.255.107.58.site.sil6.broadviewnet.net;tag=121971311
<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG
To: sip:3786@254.255.107.58.site.sil6.broadviewnet.net
Call-ID: 1658516088-5060-3@CFE.CFF.BAH.FI
CSeq: 2345 REGISTER

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Contact: sip:3786@254.255.107.58:5060;reg-id=1;+sip.instance="urn:uuid:00000000-0000-1000-8000-C074ADCA6F20";expires=30

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Authorization: Digest username="3786", realm="732985AAAE", nonce="297381190", uri="sip:254.255.107.58.site.sil6.broadviewnet.net", response=
<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG "0c9e743215ccd69a624519f5d9f989e7", algorithm=MD5, cnonce="08814139", qop=auth, nc=0000008e
Max-Forwards: 70

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG User-Agent: Grandstream HT801 1.0.49.2 c074adca6f20
MAC: c0:74:ad:ca:6f:20
Supported: path
Expires: 30

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE
Content-Length: 0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364494.711319 SIPStack(0)::cb_rcv2xx: Received 200 response for transaction 362(REGISTER), failoverInProgress=0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.714343 EventManager::run: Dispatching event 34 (SIG_REGISTERED) on port -1:-1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.715773 SigCtrl::setRegistered, acct:0, register status:1, voltage timer 0, delay effect time 0, uptime 5238, status 0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364494.723109 SIPTransaction::waitForResponse: Request 362 got status code 200

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.723767 SigCtrl::performRegistration on acct 0, regRetries:0, retryAfter:0, regRetryWait:1

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364494.725785 SIPStack(0)::run: Active call dialogs: 2

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364494.729467 SIPStack(0)::run: Active transactions: 1

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364494.735821 SigCtrl::processSigRegistered, Account 0 Registered, tried 0; Next reg in 15 seconds (5253) on 254.255.107.58.site.sil6.broadviewnet.net

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364494.737581 SigCtrl::processSigRegistered, SIP OPTIONS/NOTIFY Keep Alive starts for account 0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364494.739260 SigCtrl::performOptionsKeepAlive, SIP OPTIONS/NOTIFY Keep Alive SIP server at account 0 is alive

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.413226 LIBGSDSP: CSS: @@@## #$$$ Sending RTCP based on TS

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.417877 GSDSP::event_handler_rtp, port = 0, event = 3 data = -969971452, detected

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.418465 GSDSP::event_handler_rtp, port = 0, event = 3 data = -969971452, detected

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.420248 LIBGSDSP: CSS: p_rtcp_xr_report function called ----

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.420600 LIBGSDSP: CSS: send Receiver ref. time block

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.420820 LIBGSDSP: CSS: Send Stat Summary RB

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.421206 LIBGSDSP: CSS: [p_rtcp_xr_StatWrite] we are having the loss packets of '200'

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.421432 LIBGSDSP: CSS: pkt_recvd '5'

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.421638 LIBGSDSP: CSS: We have exceed the size while writing the RTCP_XR_BT_LOSS_RLE

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.426661 LIBGSDSP: CSS: XR_LENGTH(wXRLen) '240' wRtcpXRSize '312'

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.427116 LIBGSDSP: CSS: ** Clear Session ***

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.429292 LIBGSDSP: CSS: ** p_rtcp_xr_ClearSession called **

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.429588 LIBGSDSP: CSS: ** sizeof(pXRSession->stat.statsummary) :: 124

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.429807 LIBGSDSP: CSS: ** sizeof(pXRSession->stat.voip_mtr) :: 28

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.430180 LIBGSDSP: CSS: ** XR built successfully **Len =312

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.430465 LIBGSDSP: CSS: Sending RTCP pkt type '200' of length '52' to user space !!!

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.430674 LIBGSDSP: CSS: Sending RTCP pkt type '202' of length '20' to user space !!!

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.434349 LIBGSDSP: CSS: Sending RTCP pkt type '207' of length '240' to user space !!!

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.434601 LIBGSDSP: CSS: we are sending the rb RTCP_XR_VOIP_RB length '8' and size = '52'

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.434804 LIBGSDSP: CSS: rtp_event_send_notification called

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.435156 LIBGSDSP: CSS: we are not sending the rb RTCP_XR_DLRR_RB !!!!!

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.438160 LIBGSDSP: CSS: we are sending the rb RTCP_XR_STAT_RB length '9' and size '56'

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.438453 LIBGSDSP: CSS: rtp_event_send_notification called

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.438668 LIBGSDSP: CSS: we are not sending the rb RTCP_XR_RECREFT_RB!!!!!

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.438872 LIBGSDSP: CSS: we are not sending the rb RTCP_XR_LOSS_RLE_RB!!!!!

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.439259 LIBGSDSP: CSS: we are not sending the rb RTCP_XR_DUPLICATE_RLE_RB!!!!!

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.439481 LIBGSDSP: CSS: we are not sending the rb RTCP_XR_PKTRT_RB!!!!!

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364496.442733 LIBGSDSP: CSS: ### Sending RTCP XR RECV pkt to user space as sGRTCPQueryFlag[line] '9c0'

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.727845 SIPStack(0)::cb_nict_kill_transaction: Kill NICT transaction 362(REGISTER)

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.728405 SIPStack(0)::run: Active call dialogs: 2

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.737217 EventManager::run: Dispatching event 5 (PHONE_ON_HOOK) on port 0:0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.738238 ATACtrl::processPhoneOnHook on port 0:0, status = CALL_COMMUNICATION/CALL_IDLE isOffHook:1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.751861 Nuvoton::stopTone, Stop tone on port 0, direction 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.761007 Nuvoton::processEvent, Phone at port 0 is on-hook

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.773427 EventManager::run: Dispatching event 28 (CALL_COMPLETED) on port 0:0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.775511 SigCtrl::processCallCompleted on port 0:0, status = CALL_HANGUP/CALL_IDLE

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.780158 SigCtrl::processCallCompleted on port 0:0, Sending BYE to dialog 4, state=2

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.783078 SIPStack(0)::cb_snd_message, host=192.168.5.118, original port=5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.783402 SIPStack(0)::cb_snd_message: t retry count =1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.785665 SIPStack(0)::snd_message: Copy registrarIP[] to registrarIPAddr: 216.214.56.86, port: 5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.786139 SIPStack(0)::snd_message: Present IP: 192.168.5.118, port: 5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.786386 SIPTransaction::setTargetIPandPort, host: 192.168.5.118, IP: 192.168.5.118, port: 5060

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.790599 SIPClientTransaction::sendRequest: Request 363 is sent

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.795557 SIPStack(0)::snd_message:(537)BYE sip:192.168.5.118:5060 SIP/2.0
Via: SIP/2.0/UDP 254.255.107.58:5060;branch=z9hG4bK553948257;rport

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG From: "Tech Room" sip:3786@192.168.5.9:5060;tag=1869409537
To: sip:192.168.5.118:5060
Call-ID: 1509639674-5060-7@CFE.CFF.BAH.FI

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG CSeq: 43 BYE
Contact: sip:3786@254.255.107.58:5060
Max-Forwards: 70
Supported: replaces, path, timer, eventlist

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG User-Agent: Grandstream HT801 1.0.49.2 c074adca6f20
MAC: c0:74:ad:ca:6f:20

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE
Content-Length: 0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.805327 SigCtrl::processCallCompleted on port 0:0, Sending BYE to dialog 6, state=2

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.806832 SIPStack(0)::run: Active call dialogs: 2

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.810390 SIPClientTransaction::sendRequest: Request 364 is sent

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.816191 SIPStack(0)::receiveMessage:(289)SIP/2.0 200 OK
Via: SIP/2.0/UDP 254.255.107.58:5060;branch=z9hG4bK553948257;rport

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG To: sip:192.168.5.118:5060
From: "Tech Room" sip:3786@192.168.5.9:5060;tag=1869409537
Contact: sip:192.168.5.118:5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Call-ID: 1509639674-5060-7@CFE.CFF.BAH.FI
CSeq: 43 BYE
Content-Length: 0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.834730 ATACtrl::processCallCompleted on port 0:0, status = CALL_IDLE/CALL_IDLE canConf:1

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.839777 SIPStack(0)::cb_rcv2xx: Received 200 response for transaction 363(BYE), failoverInProgress=0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.844227 SIPStack(0)::cb_snd_message, host=192.168.5.118, original port=5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.846323 SIPStack(0)::cb_snd_message: t retry count =1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.848142 SIPStack(0)::snd_message: Copy registrarIP[] to registrarIPAddr: 216.214.56.86, port: 5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.849376 Call(8)::processEvent, CALL_COMPLETED, port 0:0, evtPort 0:0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.849806 ### Line 2929, Call(8)::processMedia on port 0:0, stopping RTP, setting noEarlyRtpStop to false

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.850403 ATACtrl::stopRTP on 0:0, status = CALL_IDLE, force: 0, specialFeature = 100

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.851097 Call(8)::processEvent, CALL_COMPLETED, port 0:0, evtPort 0:0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.863350 GSDSP::stop RTP on port 0:0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.866674 LIBGSDSP: CSS: voice_request_stop_chan

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.868193 LIBGSDSP: CSS: voice_stop_chan

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.868509 LIBGSDSP: CSS: Sending RTCP BYE Packet

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.868731 LIBGSDSP: CSS: #### In function ByeLen reasonlen 3 pad 0 and rtcpLen 12

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.869076 LIBGSDSP: CSS: p_rtcp_ByeLen: 12

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.869325 LIBGSDSP: CSS: Sending RTCP pkt type '203' of length '12' to user space !!!

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.869526 LIBGSDSP: CSS: Function p_rtpapp_Stop;Line 2410; STATE CHANGE: to 4

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.876254 LIBGSDSP: CSS: pMember->stats.dwJibDuplicated '0' pMember->stats.dwJibDiscarded '0' pMember->stats.dwJibInvalid '0' pMember->stats.dwJib

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.876487 LIBGSDSP: Received '86', pMember->sta

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.880326 SIPStack(0)::snd_message: Present IP: 192.168.5.118, port: 5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.880671 SIPTransaction::setTargetIPandPort, host: 192.168.5.118, IP: 192.168.5.118, port: 5060

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.882150 EventPvalueChanged( :status_0_0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.885086 EventPvalueChanged( :4901 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.887183 EventPvalueChanged( :status_0_0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.890309 LIBGSDSP: dua_disconnect_voip:4643 ( 0, 0, 0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.892692 LIBGSDSP: dua_disconnect_voip:4695 ( 0, 0, 0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.894682 LIBGSDSP: dua_free_voip( 0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.907249 LIBGSDSP: dua_free_voip done

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.915894 LIBGSDSP: CSS: return value of p_rtpapp_Stopis 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.924275 EventManager::run: Dispatching event 64 (PVALUE_CHANGED) on port -1:-1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.928364 SigCtrl::processPvalueChange ( status_0_0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.930716 ATACtrl::processPvalueChange ( status_0_0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.934245 LIBGSDSP: dua_disconnect_fxs ( 0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.938595 LIBGSDSP: dua_disconnect_fxs done

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.944289 GSDSP::RTP stopped on port 0:0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.946463 RTP stop on port 0:0 local rtp port:5004 sdp:0x1d2948

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.948300 RTP::closeSocket(), Closing socket: 11, local RTP port: 5004

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.951213 RTP::closeSocket(), Closing socket: 21, local RTCP port: 5005

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.954453 Call(8)::processMedia, Call stopped on port 0:0, inTransfer = 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.955807 SIPStack(0)::snd_message:(538)BYE sip:192.168.5.118:5060 SIP/2.0
Via: SIP/2.0/UDP 254.255.107.58:5060;branch=z9hG4bK1622170837;rport

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG From: "Tech Room" sip:3786@192.168.5.9:5060;tag=1817868183
To: sip:192.168.5.118:5060
Call-ID: 955313853-5060-11@CFE.CFF.BAH.FI

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG CSeq: 81 BYE
Contact: sip:3786@254.255.107.58:5060
Max-Forwards: 70
Supported: replaces, path, timer, eventlist

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG User-Agent: Grandstream HT801 1.0.49.2 c074adca6f20
MAC: c0:74:ad:ca:6f:20

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE
Content-Length: 0

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.969386 SIPStack(0)::run: Active call dialogs: 2

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.971199 EventManager::run: Dispatching event 64 (PVALUE_CHANGED) on port -1:-1

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364499.974196 ATACtrl Loop current disconnect skipped on port 0 because of onhook

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.978520 Call(8)::processMedia call_time_total total: 9 fxs:0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.981622 SigCtrl::processPvalueChange ( 4901 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.988829 ATACtrl::processPvalueChange ( 4901 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.991133 EventManager::run: Dispatching event 64 (PVALUE_CHANGED) on port -1:-1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364499.998484 SigCtrl::processPvalueChange ( status_0_0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.004555 ATACtrl::processPvalueChange ( status_0_0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.008715 EventPvalueChanged( :call_time_total_fxs0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.011453 EventManager::run: Dispatching event 64 (PVALUE_CHANGED) on port -1:-1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.014261 SigCtrl::processPvalueChange ( call_time_total_fxs0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.015549 ATACtrl::processPvalueChange ( call_time_total_fxs0 )

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.017666 CallRecord::writeCDRFile, cdrBuf =3786,192.168.5.118:5060,N/A,2023-10-03 15:21:30,2023-10-03 15:21:31,2023-10-03 15:21:39,9,Normal,Outgoing

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG , len =106

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.022616 LIBGSDSP: CSS: In API callback event = 283, inst = 1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.026502 LIBGSDSP: CSS: p_rtpapp_AUCCallback is getting called

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.029894 LIBGSDSP: CSS: p_da_AUCChannelRelease status 0, ch 1

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.031391 LIBGSDSP: CSS: In API callback event = 283, inst = 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.038686 LIBGSDSP: CSS: p_rtpapp_AUCCallback is getting called

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.040451 LIBGSDSP: CSS: p_da_AUCChannelRelease status 0, ch 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.041792 LIBGSDSP: CSS: Function p_rtp_session_jb_stop;Line 2540; STATE CHANGE: to 5

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.044251 LIBGSDSP: CSS: p_rtp_SessionDestroy: 022e0660 - 022e3dd8

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.045826 LIBGSDSP: CSS: p_rtcp_xr_SessionStop function called ----

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.048248 LIBGSDSP: CSS: ** Stat Summary ****

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.052639 CallRecord::writeCDRFile, writing /data/cdrc074adca6f20.csv OK. cdrBuf len =106

<14> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.INFO 1696364500.055242 Deleting Call object 8 port 0:0, callCount=0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.056608 EventManager::unregisterEventListener: listener Call

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.060317 RTP::~RTP, destruct 0x1ce168

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.062648 LIBGSDSP: CSS: ** Begin Seq :: 140

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.075074 LIBGSDSP: CSS: ** End Seq :: 1ec

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.079794 LIBGSDSP: CSS: ** Lost Packet :: ad

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.086239 LIBGSDSP: CSS: ** Du Packet :: 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.092816 LIBGSDSP: CSS: ** Max. Jitter value :: 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.094861 LIBGSDSP: CSS: ** Min. Jitter value :: 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.099527 LIBGSDSP: CSS: ** Mean. Jitter value :: 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.102775 LIBGSDSP: CSS: ** Max. TTL :: 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.104787 LIBGSDSP: CSS: ** Min. TTL :: 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.108599 LIBGSDSP: CSS: ** Mean. TTL :: 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.110156 LIBGSDSP: CSS: ** p_rtcp_xr_ClearSession called **

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.113355 LIBGSDSP: CSS: ** sizeof(pXRSession->stat.statsummary) :: 124

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.118143 LIBGSDSP: CSS: ** sizeof(pXRSession->stat.voip_mtr) :: 28

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.119540 LIBGSDSP: CSS: total fb requested '0' and total removal of fb requested '0'

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.120783 LIBGSDSP: CSS: p_rtcp_SessionFree: 022e0760 - 022e12e0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.124187 LIBGSDSP: CSS: p_rtp_SessionDestroy: 022e0660 - 022e3dd8

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.128693 LIBGSDSP: CSS:

AUC Channel STOPPED sending COMA REPLY

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.130421 LIBGSDSP: CSS: Function create_voice_message; Sending coma response 7

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.131654 LIBGSDSP: CSS: create_voice_message ret 0

<15> HT801 [c0:74:ad:ca:6f:20] [1.0.49.2] GS_ATA: USER.DEBUG 1696364500.139705 LIBGSDSP: CSS: Function create_voice_message; Sending coma response 9

@maciasr
Copy link
Author

maciasr commented Oct 3, 2023

Got the Cisco device recommended no voice in either direction.
Grandstream device I got voice outgoing but not incoming.
I can see the replies from ChatGPT on the console but cant hear..

@Mikklo
Copy link

Mikklo commented Oct 4, 2023

I am having the same issue with my HT801 (Hardware version: V1.1C). The sound is cut off during the greeting. No sound on polly playback. Mic works the whole time and I can see the response in the console but no audio playback after the greeting is cut short.

I can also add that it doesn't always cut out at the same time. I have a custom greeting.pcm that is a bit longer. A few times I've got the complete message, but most of the time it cuts mid-message.

I have tried with a software phone, MicroSIP, then I can hear the full greeting every time, but I still have not managed to get it to detect silence when calling from that program, so I have not been able to verify that polly sounds works.

@tcz
Copy link
Owner

tcz commented Oct 4, 2023

@maciasr is that log from a RotaryGPT call? What's "Tech Room"

@Mikklo I'd maybe try to change the Jitter Buffer Length setting to High under the FXS PORT tab on the HT801 config but this really shouldn't be an issue.

@raulmaciascam
Copy link

raulmaciascam commented Oct 4, 2023 via email

@Mikklo
Copy link

Mikklo commented Oct 5, 2023

@tcz Yeah, already tried that. I have a bit newer software version so not all settings match your screenshots, but I have matched them as far as possible and then played around with the extra settings I have that aren't in your screenshots but no success. I was really hoping to find a solution, so I don't have to go and buy another APA.

@tcz
Copy link
Owner

tcz commented Oct 5, 2023

The reason it's so hard for me to debug this is that this seems to be an issue with the later hardware versions and it works perfectly on my earlier HT801. I looked at buying a new one but they only sell HT802 here for some reason.

I can mail you my HT801 and see if it works with that to discard other stuff like network.

@raulmaciascam
Copy link

raulmaciascam commented Oct 5, 2023 via email

@raulmaciascam
Copy link

raulmaciascam commented Oct 6, 2023 via email

@tcz
Copy link
Owner

tcz commented Oct 6, 2023

I don't think Github picks up your email attachments.

@raulmaciascam
Copy link

ip.addr==192.168.10.169.zip

@raulmaciascam
Copy link

raulmaciascam commented Oct 6, 2023 via email

@raulmaciascam
Copy link

1st_call_on_10_6_pcap_RTP_from_36383
2nd_call_on_10_6_pcap_RTP_from_49849

@raulmaciascam
Copy link

From Grandstream..

++++++++++++++++++++++++++++++++++

The screenshot you provided highlights the audio stream from HT to SIP server. This obeys the SDP negotiation.

The streams that do not obey SDP negotiation are the ones coming from 192.168.10.176 (SIP server, Raspberry...) .
Please see attached.

@tcz
Copy link
Owner

tcz commented Oct 6, 2023 •
edited
Loading

Honestly I think they somehow get confused here and want to use the same socket for both directions. It's certainly possible with UDP but it's unusual and that's not how RTP is usually implemented.

My hunch is that the source of their confusion is perhaps the fact that we suggest using the same incoming port at RotaryGPT as they use on HT801. Perhaps in the newer hardware there's some "heuristics" that if the SIP server suggests the same port as the client then it has to be the same socket for audio in and out. This would be super odd and I still don't really get how and why they "cut" the communication when this happens.

My suggestion to verify this theory is to change the port of RotaryGPT:

port_change.patch

Do these two changes and please test again. Wireshark captures are useful if it still doesn't work.

@raulmaciascam
Copy link

image

@raulmaciascam
Copy link

hi,

My apologies, don't know much about programming, getting the error above.
I'm my suppose to run the file using "python port_change.path" please see the error Im getting.
I put the files on the same directory.

image

@tcz
Copy link
Owner

tcz commented Oct 6, 2023

You need to apply the patch first:

git apply port_change.path

Then run RotaryGPT as usual.

@raulmaciascam
Copy link

raulmaciascam commented Oct 6, 2023 •
edited
Loading

Thank you, just tried with the update and encounter the same issue.
Attached are the new wireshark captures.

@raulmaciascam
Copy link

wireshark-ip.addr==192.168.10.169.zip

@tcz
Copy link
Owner

tcz commented Oct 6, 2023

Seems like this did nothing. Would you mind sending my response to Grandstream to see what they say to this?
#2 (comment)

Maybe they will suggest using the same socket, I just don't really get why. Especially because it works well on the old hardware.

@raulmaciascam
Copy link

raulmaciascam commented Oct 6, 2023 via email

@raulmaciascam
Copy link

raulmaciascam commented Oct 6, 2023 via email

@Mikklo
Copy link

Mikklo commented Oct 7, 2023 •
edited
Loading

I tried playing around with wireshark as well, looks like source port is random each time for the RTP streams from RotaryGPT to the HT801 but looks like it has destinationport always 5004.

If I test and bind the socket of the RTPSender to 5004 when starting it then the source port is 5004, and I get the full greeting message every time.
BUT
Then it cannot bind the port 5004 for the receiver and no voice is received by the application.

Would it be possible to restructure it so that sockets for RTPSender/RTPReceiver are closed and bound every time to make it possible for them to share the port? Maybe they could share socket?

@tcz
Copy link
Owner

tcz commented Oct 9, 2023

the rotary needs to send and receive audio on that port

This is just wrong. It needs to RECEIVE on that port but doesn't need to SEND it on the same port, or the same RTP session.

In the SDP RFC: https://datatracker.ietf.org/doc/html/rfc4566

Section 5.14

is the transport port to which the media stream is sent.

Sent. Not sent and received from. Just sent.

In the SIP RFC: https://datatracker.ietf.org/doc/html/rfc3261#section-14.2

Section 13.2.1

There are special rules for message bodies that contain a session
description - their corresponding Content-Disposition is "session".
SIP uses an offer/answer model where one UA sends a session
description, called the offer, which contains a proposed description
of the session. The offer indicates the desired communications means
(audio, video, games), parameters of those means (such as codec
types) and addresses for receiving media from the answerer. The
other UA responds with another session description, called the
answer, which indicates which communications means are accepted, the
parameters that apply to those means, and addresses for receiving
media from the offerer.

Again the offer contain the RECEIVING address from the ANSWER, the answer contains the RECEIVING address from the OFFERER. Two different addresses.

And perhaps more crucially in the RTP RFC: https://www.rfc-editor.org/rfc/rfc3550

Section 11

In a unicast session, both participants need to identify a port pair
for receiving RTP and RTCP packets. Both participants MAY use the
same port pair. A participant MUST NOT assume that the source port
of the incoming RTP or RTCP packet can be used as the destination
port for outgoing RTP or RTCP packets.

The reason we also know this works is that Grantstream's own hardware works like this, at least in the older version:

HT801
Hardware Version: V1.0B    
Part Number: 9610003610B
Software Version: Program -- 1.0.5.11    Bootloader -- 1.0.5.3    Core -- 1.0.5.3    Base -- 1.0.5.11  CPE -- 1.0.1.67

@raulmaciascam would you mind relaying this response to them?

@raulmaciascam
Copy link

raulmaciascam commented Oct 9, 2023 via email

@raulmaciascam
Copy link

raulmaciascam commented Oct 11, 2023 via email

@maciasr
Copy link
Author

maciasr commented Oct 12, 2023

Hi,
We are not getting very far with Grandstream.
Any recommendation or anything that we can try?
Thank you,

@maciasr
Copy link
Author

maciasr commented Oct 12, 2023

Hi,
Granstream would like a copy of packet capture of your device with working version.
Can you provide? preferably Wireshark.

@tcz
Copy link
Owner

tcz commented Oct 13, 2023

I pushed a new version of RotaryGPT that, as Grandstream suggests, uses the same socket. It's weird that they insist on this, even weirder that it works on the old hardware, but here we go.

The new version works on my device but would you please test if it solves the issue on yours?

@raulmaciascam
Copy link

raulmaciascam commented Oct 13, 2023 via email

@tcz tcz mentioned this issue Oct 14, 2023
Open
@Mikklo
Copy link

Mikklo commented Oct 14, 2023

I tested it for a couple of seconds before I had to leave home. Worked perfectly on my 1.1C hardware. Thank you so much @tcz. I tried to do this myself but didn't manage to get it all up and running. Now I will start my process to turn it into a batphone with Alfred the butler as an assistant. This is gonna be so much fun!

@raulmaciascam
Copy link

raulmaciascam commented Oct 16, 2023 via email

@maciasr
Copy link
Author

maciasr commented Oct 16, 2023

image

@tcz
Copy link
Owner

tcz commented Oct 16, 2023

Seems like you added a new function to tell the time? The error is in that function.

@tcz tcz closed this as completed Oct 16, 2023
@raulmaciascam
Copy link

raulmaciascam commented Oct 16, 2023 via email

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@tcz @Mikklo @maciasr @dick-nds @tusabez @raulmaciascam