What triggers "sipsorcery[0] Set remote track (audio - index=0) SSRC to 1758487334."?

[tmakaro]

Happy Father's Day to all you fathers out there!

I wrote this really nice answering machine detection that works off of the OnRtpPacketReceived event. When I test it on my computer using FreePBX and voip.ms, it works great. As soon as the call is connected, I get "sipsorcery[0] Set remote track (audio - index=0) SSRC to 1758487334" and then RTP packets start coming in immediately after that.

However, I just tried my test program on another server that uses an older asterisk server and Thinktel and it doesn't work.

What I discovered was the "sipsorcery[0] Set remote track (audio - index=0) SSRC to 1758487334" does not happen immediately after the call connection and thus I don't receive any RTP packets.

It's not until I play a file that "sipsorcery[0] Set remote track (audio - index=0) SSRC to 1758487334" happens and then RTP packets start coming in.

Is there any way to force "sipsorcery[0] Set remote track" to occur immediately after the call-out connection?

Working log snippet:
`

12:39:07 dbug: sipsorcery[0] Response received: udp:192.168.3.193:5062<-udp:192.168.3.34:5060 INVITE 183 Session Progress
12:39:07 dbug: sipsorcery[0] Information response 183 Session Progress for sip:##########@192.168.3.34:5060.
12:39:07 dbug: sipsorcery[0] Setting audio source format to 0:PCMU 8000 (RTP clock rate 8000).
12:39:07 dbug: sipsorcery[0] Set remote description for early media result OK.
12:39:07 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] Ringing
12:39:07 dbug: sipsorcery[0] Set remote track (audio - index=0) SSRC to 1758487334.
12:39:09 dbug: sipsorcery[0] Response received: udp:192.168.3.193:5062<-udp:192.168.3.34:5060 INVITE 200 OK
12:39:09 dbug: sipsorcery[0] Request sent: udp:192.168.3.193:5062->udp:192.168.3.34:5060 ACK sip:192.168.3.34:5060 SIP/2.0
12:39:09 dbug: sipsorcery[0] Response 200 OK for sip:##########@192.168.3.34:5060.
12:39:09 dbug: sipsorcery[0] Setting audio source format to 0:PCMU 8000 (RTP clock rate 8000).
12:39:09 info: sipsorcery[0] Call attempt to sip:##########@192.168.3.34:5060 was answered.
12:39:09 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] Answered
12:39:09 info: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] Dial call duration: 00:00:13.1629497
12:39:09 dbug: sipsorcery[0] Set remote track (audio - index=0) SSRC to 1758487334.
12:39:10 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] OnRtpPacketReceived!
12:39:10 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] OnRtpPacketReceived!
12:39:10 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] OnRtpPacketReceived!

`

Failed snippet:
`

12:24:58 dbug: sipsorcery[0] Response received: udp:10.143.105.20:5060<-udp:10.143.105.253:65477 INVITE 183 Session Progress
12:24:58 dbug: sipsorcery[0] Information response 183 Session Progress for [sip:##########@10.143.102.41:5060](http://sip/##########@10.143.102.41:5060).
12:24:58 dbug: sipsorcery[0] Setting audio source format to 0:PCMU 8000 (RTP clock rate 8000).
12:24:58 dbug: sipsorcery[0] Set remote description for early media result OK.
12:24:58 dbug: sipsorcery[0] Starting RTCP session for 04bb87a5-ffac-4151-90db-43e7588d67bc.
12:24:58 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] Ringing
12:25:00 dbug: sipsorcery[0] Response received: udp:10.143.105.20:5060<-udp:10.143.105.253:65477 INVITE 200 OK
12:25:00 dbug: sipsorcery[0] Request sent: udp:10.143.105.20:5060->udp:10.143.105.253:65477 ACK [sip:##########@10.143.105.253:65477](http://sip/##########@10.143.105.253:65477) SIP/2.0
12:25:00 dbug: sipsorcery[0] Response 200 OK for [sip:##########@10.143.102.41:5060](http://sip/##########@10.143.102.41:5060).
12:25:00 dbug: sipsorcery[0] Setting audio source format to 0:PCMU 8000 (RTP clock rate 8000).
12:25:00 info: sipsorcery[0] Call attempt to [sip:##########@10.143.102.41:5060](http://sip/##########@10.143.102.41:5060) was answered.
12:25:00 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] Answered
12:25:00 info: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] Dial call duration: 00:00:06.8515361
12:25:00 dbug: ivrToolkit.Core.Util.LineWrapper[0] CallAnalysis is: Connected
12:25:00 dbug: ivrToolkit.Core.Util.LineWrapper[0] PlayFileAsync(Voice Files/Person.wav)
12:25:00 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] PlayFile(Voice Files/Person.wav) - _digitPressed = False
12:25:00 dbug: sipsorcery[0] Sending audio stream length 36000.
12:25:00 dbug: sipsorcery[0] Set remote track (audio - index=0) SSRC to 2147179012.
12:25:00 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] OnRtpPacketReceived!
12:25:00 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] OnRtpPacketReceived!
12:25:00 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] OnRtpPacketReceived!
12:25:00 dbug: ivrToolkit.Plugin.SipSorcery.SipSorceryLine[0] OnRtpPacketReceived!

`

[sipsorcery]

My guess would be that the Set remote track is a red herring. All it's doing is responding once the first RTP packet is received to connect the local RTP stream with the remote one.

Is there a NAT present in the second failure case? If it can be fixed by sending RTP to the remote Asterisk server it could be because that's punching a hole in your NAT.