Well, I thought this was working, but after more testing, it is still exhibiting the problem I had before. (Some hard-coded routing I put in was concealing the fact that it isn't handling this situation when left on its own.)
In the PSTN gateway model, SER still doesn't know how to cope when a BYE or re-INVITE arrives which has come from the PSTN gateway, and at best it makes a guess as to which is the right destination for the messages. (It usually ends up looping back to itself.) In this case with the packets that are being received, the pstn.cfg example from the documentation doesn't do the right thing, because loose_route() doesn't get triggered for the BYE and re-INVITE messages, so SER is on its own to determine where to forward the messages.
Here is a full example of the messages involved. In my earlier word example I said the original call INVITE could come from four IP addresses, but in real life the number is more like 200 sources. It is still the same problem, be it two source addresses or a million. Which address to choose in this situation?
Almost everything is correctly-relayed back to the correct IP address (66.77.88.99), EXECPT a BYE initiated by the called network (shown), or a re-INVITE initiated by the called network (not shown, but requires the same handling as called-network BYE). If one can be cured, both should start working.
Key addresses in the example: Call initiates via asterisk server at 66.77.88.99 CALL SOURCE SER is 206.33.44.55 PSTN gateway switch is 10.100.20.30 (where BYE comes from) 2.0.0-rc1 (x86_64/freebsd)
I have only included the messages between the SER and PSTN gateway switch, as that is where the trouble starts. If the others are needed, I can get them.
U 2009/10/05 17:44:48.002403 206.33.44.55:5060 -> 10.100.20.30:5060 INVITE sip:9615551212@10.100.20.30 SIP/2.0 Record-Route: sip:206.33.44.55;ftag=as33ea0360;lr=on Via: SIP/2.0/UDP 206.33.44.55;branch=z9hG4bK17e4.1b3604dc0be3614c8a5ba10b15c5c39 b.0 Via: SIP/2.0/UDP 66.77.88.99:5060;branch=z9hG4bK32448737;rport=5060 From: "TROUBLESHOOTING 1000" sip:3796661000@66.77.88.99;tag=as33ea0360 To: sip:9615551212@206.33.44.55 Contact: sip:3796661000@206.33.44.55:5060 Call-ID: 23cfb70d5362a5180aeb5048470591fc@66.77.88.99 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 16 Date: Mon, 05 Oct 2009 17:44:47 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 435
o=root 27275 27275 IN IP4 206.33.44.66 s=session c=IN IP4 206.33.44.66 t=0 0 m=audio 20366 RTP/AVP 0 3 8 112 5 10 7 97 111 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:112 AAL2-G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:10 L16/8000 a=rtpmap:7 LPC/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:111 G726-32/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv a=nortpproxy:yes
U 2009/10/05 17:44:48.004815 10.100.20.30:5060 -> 206.33.44.55:5060 SIP/2.0 100 Trying Record-Route: sip:206.33.44.55;ftag=as33ea0360;lr=on Call-ID: 23cfb70d5362a5180aeb5048470591fc@66.77.88.99 CSeq: 102 INVITE From: "TROUBLESHOOTING 1000" sip:3796661000@66.77.88.99;tag=as33ea0360 To: sip:9615551212@206.33.44.55;tag=000a0283+1+68bb002b+5fee0f2 Via: SIP/2.0/UDP 206.33.44.55;branch=z9hG4bK17e4.1b3604dc0be3614c8a5ba10b15c5c39 b.0 Via: SIP/2.0/UDP 66.77.88.99:5060;branch=z9hG4bK32448737;rport=5060 Server: DC-SIP/2.0 Supported: timer Content-Length: 0
U 2009/10/05 17:44:53.956206 10.100.20.30:5060 -> 206.33.44.55:5060 SIP/2.0 183 Session Progress Call-ID: 23cfb70d5362a5180aeb5048470591fc@66.77.88.99 CSeq: 102 INVITE From: "TROUBLESHOOTING 1000" sip:3796661000@66.77.88.99;tag=as33ea0360 To: sip:9615551212@206.33.44.55;tag=000a0283+1+68bb002b+5fee0f2 Via: SIP/2.0/UDP 206.33.44.55;branch=z9hG4bK17e4.1b3604dc0be3614c8a5ba10b15c5c39 b.0 Via: SIP/2.0/UDP 66.77.88.99:5060;branch=z9hG4bK32448737;rport=5060 Server: DC-SIP/2.0 Supported: timer Record-Route: sip:206.33.44.55;ftag=as33ea0360;lr=on Contact: sip:9615551212@10.100.20.30 Content-Type: application/sdp Content-Length: 173
v=0 o=- 3463753493 3463753549 IN IP4 10.100.20.30 s=- c=IN IP4 206.33.99.0 t=0 0 m=audio 34530 RTP/AVP 0 a=sendrecv a=ptime:20 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - -
U 2009/10/05 17:44:54.855199 10.100.20.30:5060 -> 206.33.44.55:5060 SIP/2.0 183 Session Progress Call-ID: 23cfb70d5362a5180aeb5048470591fc@66.77.88.99 CSeq: 102 INVITE From: "TROUBLESHOOTING 1000" sip:3796661000@66.77.88.99;tag=as33ea0360 To: sip:9615551212@206.33.44.55;tag=000a0283+1+68bb002b+5fee0f2 Via: SIP/2.0/UDP 206.33.44.55;branch=z9hG4bK17e4.1b3604dc0be3614c8a5ba10b15c5c39 b.0 Via: SIP/2.0/UDP 66.77.88.99:5060;branch=z9hG4bK32448737;rport=5060 Server: DC-SIP/2.0 Supported: timer Record-Route: sip:206.33.44.55;ftag=as33ea0360;lr=on Contact: sip:9615551212@10.100.20.30 Content-Type: application/sdp Content-Length: 173
v=0 o=- 3463753493 3463753549 IN IP4 10.100.20.30 s=- c=IN IP4 206.33.99.0 t=0 0 m=audio 34530 RTP/AVP 0 a=sendrecv a=ptime:20 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - -
U 2009/10/05 17:44:57.125294 10.100.20.30:5060 -> 206.33.44.55:5060 SIP/2.0 200 OK Call-ID: 23cfb70d5362a5180aeb5048470591fc@66.77.88.99 CSeq: 102 INVITE From: "TROUBLESHOOTING 1000" sip:3796661000@66.77.88.99;tag=as33ea0360 To: sip:9615551212@206.33.44.55;tag=000a0283+1+68bb002b+5fee0f2 Via: SIP/2.0/UDP 206.33.44.55;branch=z9hG4bK17e4.1b3604dc0be3614c8a5ba10b15c5c39 b.0 Via: SIP/2.0/UDP 66.77.88.99:5060;branch=z9hG4bK32448737;rport=5060 Server: DC-SIP/2.0 Supported: timer Record-Route: sip:206.33.44.55;ftag=as33ea0360;lr=on Contact: sip:9615551212@10.100.20.30 Content-Type: application/sdp Content-Length: 173
v=0 o=- 3463753493 3463753549 IN IP4 10.100.20.30 s=- c=IN IP4 206.33.99.0 t=0 0 m=audio 34530 RTP/AVP 0 a=sendrecv a=ptime:20 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - -
U 2009/10/05 17:44:57.187498 206.33.44.55:5060 -> 10.100.20.30:5060 ACK sip:9615551212@10.100.20.30:5060 SIP/2.0 Record-Route: sip:206.33.44.55;ftag=as33ea0360;lr=on Via: SIP/2.0/UDP 206.33.44.55;branch=z9hG4bK17e4.cb89b9e25754fc653a32363a1ba12e5 9.0 Via: SIP/2.0/UDP 66.77.88.99:5060;branch=z9hG4bK6a6bf681;rport=5060 From: "TROUBLESHOOTING 1000" sip:3796661000@66.77.88.99;tag=as33ea0360 To: sip:9615551212@206.33.44.55;tag=000a0283+1+68bb002b+5fee0f2 Contact: sip:3796661000@206.33.44.55:5060 Call-ID: 23cfb70d5362a5180aeb5048470591fc@66.77.88.99 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 16 Content-Length: 0
So far, everything has worked fine.
And now, the called party hangs up first, so the PSTN switch send a BYE back to SER (because of the Record-Route used in the INVITE). If the Record-Route was absent, the PSTN switch tries to send the BYE direct to 66.77.88.99 (asterisk server), cutting SER out of the loop entirely and leaving the rtpproxy for that call running for a while.
U 2009/10/05 17:45:07.356019 10.100.20.30:5060 -> 206.33.44.55:5060 BYE sip:3796661000@206.33.44.55:5060 SIP/2.0 Via: SIP/2.0/UDP 10.100.20.30;branch=z9hG4bK+ffc8b51a07f0b4336d0443eee0ed0b5e+00 0a0283+1 Max-Forwards: 70 Call-ID: 23cfb70d5362a5180aeb5048470591fc@66.77.88.99 From: sip:9615551212@206.33.44.55;tag=000a0283+1+68bb002b+5fee0f2 To: "TROUBLESHOOTING 1000" sip:3796661000@66.77.88.99;tag=as33ea0360 CSeq: 920677113 BYE Route: sip:206.33.44.55;ftag=as33ea0360;lr=on Supported: timer Content-Length: 0
So now SER has the BYE but SER doesn't know who to send it on to - loose_route() isn't triggered. So the BYE gets sent to the wrong place, no response, PSTN switch repeats BYE several times before SER tells it to stop. The place SER should send the message (66.77.88.99) is in the To: header, but nowhere else, and apparently isn't holding onto such details from the earlier messages.
U 2009/10/05 17:45:07.905334 10.100.20.30:5060 -> 206.33.44.55:5060 BYE sip:3796661000@206.33.44.55:5060 SIP/2.0 Via: SIP/2.0/UDP 10.100.20.30;branch=z9hG4bK+ffc8b51a07f0b4336d0443eee0ed0b5e+00 0a0283+1 Max-Forwards: 70 Call-ID: 23cfb70d5362a5180aeb5048470591fc@66.77.88.99 From: sip:9615551212@206.33.44.55;tag=000a0283+1+68bb002b+5fee0f2 To: "TROUBLESHOOTING 1000" sip:3796661000@66.77.88.99;tag=as33ea0360 CSeq: 920677113 BYE Route: sip:206.33.44.55;ftag=as33ea0360;lr=on Supported: timer Content-Length: 0
...
U 2009/10/05 17:45:35.038148 10.100.20.30:5060 -> 206.33.44.55:5060 BYE sip:3796661000@206.33.44.55:5060 SIP/2.0 Via: SIP/2.0/UDP 10.100.20.30;branch=z9hG4bK+ffc8b51a07f0b4336d0443eee0ed0b5e+00 0a0283+1 Max-Forwards: 70 Call-ID: 23cfb70d5362a5180aeb5048470591fc@66.77.88.99 From: sip:9615551212@206.33.44.55;tag=000a0283+1+68bb002b+5fee0f2 To: "TROUBLESHOOTING 1000" sip:3796661000@66.77.88.99;tag=as33ea0360 CSeq: 920677113 BYE Route: sip:206.33.44.55;ftag=as33ea0360;lr=on Supported: timer Content-Length: 0
U 2009/10/05 17:45:37.354456 206.33.44.55:5060 -> 10.100.20.30:5060 SIP/2.0 408 Request Timeout Via: SIP/2.0/UDP 10.100.20.30;branch=z9hG4bK+ffc8b51a07f0b4336d0443eee0ed0b5e+00 0a0283+1 Call-ID: 23cfb70d5362a5180aeb5048470591fc@66.77.88.99 From: sip:9615551212@206.33.44.55;tag=000a0283+1+68bb002b+5fee0f2 To: "TROUBLESHOOTING 1000" sip:3796661000@66.77.88.99;tag=as33ea0360 CSeq: 920677113 BYE Server: SER (2.0.0-rc1 (x86_64/freebsd)) Content-Length: 0
route{ xlog("L_ERR", "MAIN ROUTE \n method:<%rm> From URI:<%fu> From Tag:<%ft> Destination Set:<%ds> Request's R-URI:<%ru> To URI:<%tu> Received IP:<%Ri> So urce IP:<%si> Source Port:<%sp> Call ID:<%ci> Host's Hostname:<%Hn> Hosts Doma inname:<%Hd> Hosts FQDN <%Hf> Hosts IP <%Hi>");
# first do some initial sanity checks
if (!mf_process_maxfwd_header("10")) { sl_reply("483","Too Many Hops"); break; }
if (msg:len >= max_len ) { sl_reply("513", "Message too big"); break; }
if (loose_route()) { if (src_ip==10.100.20.30) { #Is it outbound? log(1, "Doing loose_route from PSTN\n"); } else { log(1, "Doing loose_route to PSTN\n"); }
t_relay(); break; }
The rest of main is determining direction if there was no loose_route() and here is where it suddenly needs to be told where exactly the BYE message should be sent because the correct destination is one of many possible call sources. Neither of the "Doing loose_route" messages get displayed when the BYE is handled.
Thanks again for suggestions.