Here are my logs from the point that the auto attendant forwards the call to the extension:
[7] 2008/09/29 14:12:48: SIP Rx tcp:172.16.116.104:5065:
REFER sip:999@172.16.116.105:1181;transport=tcp SIP/2.0
FROM: <sip:999@172.16.116.104;user=phone>;epid=06A5C4BC0B;tag=c19311cfd
TO: <sip:999@172.16.116.104;user=phone>;tag=53059
CSEQ: 1 REFER
CALL-ID: 88725d22@pbx
MAX-FORWARDS: 70
VIA: SIP/2.0/TCP 172.16.116.104:5065;branch=z9hG4bK6d898cb2
CONTACT: <sip:OBSRNDVMMX01.obsrnd.obsglobal.com:5065;transport=Tcp;maddr=172.16.116.104
;ms-opaque=ede52a3158c87bd0>;automata
CONTENT-LENGTH: 0
REFER-TO: <sip:212@172.16.116.105:1181;transport=tcp;user=phone>
REFERRED-BY: <sip:999@172.16.116.104;user=phone>
USER-AGENT: RTCC/3.0.0.0
[7] 2008/09/29 14:12:48: SIP Tx tcp:172.16.116.104:5065:
SIP/2.0 202 Accepted
Via: SIP/2.0/TCP 172.16.116.104:5065;branch=z9hG4bK6d898cb2
From: <sip:999@172.16.116.104;user=phone>;tag=c19311cfd;epid=06A5C4BC0B
To: <sip:999@172.16.116.104;user=phone>;tag=53059
Call-ID: 88725d22@pbx
CSeq: 1 REFER
Contact: <sip:999@172.16.116.105:1181;transport=tcp>
User-Agent: pbxnsip-PBX/3.0.0.2998
Content-Length: 0
[5] 2008/09/29 14:12:48: Redirecting call to 212
[5] 2008/09/29 14:12:48: Call 88725d22@pbx#53059: Last request not finished
[7] 2008/09/29 14:12:48: SIP Tx tcp:172.16.116.104:5065:
BYE sip:OBSRNDVMMX01.obsrnd.obsglobal.com:5065;transport=Tcp;maddr=172.16.116.104 SIP/2.0
Via: SIP/2.0/TCP 172.16.116.105:1181;branch=z9hG4bK-d1b5d0ea5696fcc1fcaf23c8260956a0;rport
From: "OBS Global" <sip:999@172.16.116.104;user=phone>;tag=53059
To: <sip:999@172.16.116.104;user=phone>;tag=c19311cfd
Call-ID: 88725d22@pbx
CSeq: 25625 BYE
Max-Forwards: 70
Contact: <sip:999@172.16.116.105:1181;transport=tcp>
RTP-RxStat: Dur=15,Pkt=528,Oct=90816,Underun=0
RTP-TxStat: Dur=14,Pkt=699,Oct=117264
Content-Length: 0
[5] 2008/09/29 14:12:48: Dialplan ThinkTel: 212 goes to extension
[8] 2008/09/29 14:12:48: Play audio_moh/noise.wav
[7] 2008/09/29 14:12:48: UDP: Opening socket on port 54846
[7] 2008/09/29 14:12:48: UDP: Opening socket on port 54847
[7] 2008/09/29 14:12:48: SIP Tx tcp:172.16.116.102:5060:
INVITE sip:+12049759212@172.16.116.102;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 172.16.116.105:1182;branch=z9hG4bK-c6c4c5fff867991162b4cdac8dfdb667;rport
From: "Chris Deacon" <sip:2049820218@159.18.161.101:5060;transport=udp;user=phone>;tag=62205
To: "OBS Global" <sip:999@obsrnd.obsglobal.com>
Call-ID: 9b698194@pbx
CSeq: 11279 INVITE
Max-Forwards: 70
Contact: <sip:212@172.16.116.105:1182;transport=tcp>
Supported: 100rel, replaces, norefersub
Allow-Events: refer
Allow: INVITE, ACK, CANCEL, BYE, REFER, PRACK, INFO, UPDATE
Accept: application/sdp
User-Agent: pbxnsip-PBX/3.0.0.2998
Alert-Info: <http://127.0.0.1/Bellcore-dr2>
P-Asserted-Identity: "OBS Global" <sip:999@obsrnd.obsglobal.com>
Content-Type: application/sdp
Content-Length: 294
v=0
o=- 14904 14904 IN IP4 172.16.116.105
s=-
c=IN IP4 172.16.116.105
t=0 0
m=audio 54846 RTP/AVP 0 8 9 2 3 101
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:9 g722/8000
a=rtpmap:2 g726-32/8000
a=rtpmap:3 gsm/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sendrecv
[7] 2008/09/29 14:12:48: UDP: Opening socket on port 51212
[7] 2008/09/29 14:12:48: UDP: Opening socket on port 51213
[7] 2008/09/29 14:12:48: SIP Tx udp:172.16.116.200:2051:
INVITE sip:212@172.16.116.200:2051;line=rpwp3qf5 SIP/2.0
Via: SIP/2.0/UDP 172.16.116.105:5060;branch=z9hG4bK-6b60059434809ee17999ff5b626bdef1;rport
From: "Chris Deacon" <sip:2049820218@159.18.161.101:5060;transport=udp;user=phone>;tag=11559
To: "OBS Global" <sip:999@obsrnd.obsglobal.com>
Call-ID: 7ec7d03a@pbx
CSeq: 22046 INVITE
Max-Forwards: 70
Contact: <sip:212@172.16.116.105:5060;transport=udp>
Supported: 100rel, replaces, norefersub
Allow-Events: refer
Allow: INVITE, ACK, CANCEL, BYE, REFER, PRACK, INFO, UPDATE
Accept: application/sdp
User-Agent: pbxnsip-PBX/3.0.0.2998
Alert-Info: <http://127.0.0.1/Bellcore-dr2>
P-Asserted-Identity: "OBS Global" <sip:999@obsrnd.obsglobal.com>
Content-Type: application/sdp
Content-Length: 294
v=0
o=- 54913 54913 IN IP4 172.16.116.105
s=-
c=IN IP4 172.16.116.105
t=0 0
m=audio 51212 RTP/AVP 0 8 9 2 3 101
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:9 g722/8000
a=rtpmap:2 g726-32/8000
a=rtpmap:3 gsm/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sendrecv
[7] 2008/09/29 14:12:48: 1B9E0136@159.18.161.101#b6d60dcb50: Media-aware pass-through mode
[7] 2008/09/29 14:12:48: SIP Rx tcp:172.16.116.102:5060:
SIP/2.0 100 Trying
FROM: "Chris Deacon"<sip:2049820218@159.18.161.101:5060;transport=udp;user=phone>;tag=62205
TO: "OBS Global"<sip:999@obsrnd.obsglobal.com>
CSEQ: 11279 INVITE
CALL-ID: 9b698194@pbx
VIA: SIP/2.0/TCP 172.16.116.105:1182;branch=z9hG4bK-c6c4c5fff867991162b4cdac8dfdb667;rport
CONTENT-LENGTH: 0
[7] 2008/09/29 14:12:48: SIP Rx udp:172.16.116.200:2051:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 172.16.116.105:5060;branch=z9hG4bK-6b60059434809ee17999ff5b626bdef1;rport=5060
From: "Chris Deacon" <sip:2049820218@159.18.161.101:5060;transport=udp;user=phone>;tag=11559
To: "OBS Global" <sip:999@obsrnd.obsglobal.com>;tag=yv82uxv0iq
Call-ID: 7ec7d03a@pbx
CSeq: 22046 INVITE
Contact: <sip:212@172.16.116.200:2051;line=rpwp3qf5>;flow-id=1
Require: 100rel
RSeq: 1
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO
Allow-Events: talk, hold, refer, call-info
Content-Length: 0
[7] 2008/09/29 14:12:48: SIP Tx udp:172.16.116.200:2051:
PRACK sip:212@172.16.116.200:2051;line=rpwp3qf5 SIP/2.0
Via: SIP/2.0/UDP 172.16.116.105:5060;branch=z9hG4bK-636dea0941850e26b19f08a829dc50f9;rport
From: "Chris Deacon" <sip:2049820218@159.18.161.101:5060;transport=udp;user=phone>;tag=11559
To: "OBS Global" <sip:999@obsrnd.obsglobal.com>;tag=yv82uxv0iq
Call-ID: 7ec7d03a@pbx
CSeq: 22047 PRACK
Max-Forwards: 70
Contact: <sip:212@172.16.116.105:5060;transport=udp>
RAck: 1 22046 INVITE
P-Asserted-Identity: "OBS Global" <sip:999@obsrnd.obsglobal.com>
Content-Length: 0
[8] 2008/09/29 14:12:48: Play audio_en/ringback.wav
[8] 2008/09/29 14:12:48: Call 88725d22@pbx#53059: Response does not correspond to open request
[7] 2008/09/29 14:12:48: SIP Rx udp:172.16.116.200:2051:
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 172.16.116.105:5060;branch=z9hG4bK-636dea0941850e26b19f08a829dc50f9;rport=5060
From: "Chris Deacon" <sip:2049820218@159.18.161.101:5060;transport=udp;user=phone>;tag=11559
To: "OBS Global" <sip:999@obsrnd.obsglobal.com>;tag=yv82uxv0iq
Call-ID: 7ec7d03a@pbx
CSeq: 22047 PRACK
Contact: <sip:212@172.16.116.200:2051;line=rpwp3qf5>;flow-id=1
Content-Length: 0
[7] 2008/09/29 14:12:48: Call 7ec7d03a@pbx#11559: Clear last request
[7] 2008/09/29 14:12:48: SIP Rx tcp:172.16.116.102:5060:
SIP/2.0 183 Session Progress
FROM: "Chris Deacon"<sip:2049820218@159.18.161.101:5060;transport=udp;user=phone>;tag=62205
TO: OBS Global<sip:999@obsrnd.obsglobal.com>;epid=4414844359;tag=389ae44573
CSEQ: 11279 INVITE
CALL-ID: 9b698194@pbx
VIA: SIP/2.0/TCP 172.16.116.105:1182;branch=z9hG4bK-c6c4c5fff867991162b4cdac8dfdb667;rport
CONTENT-LENGTH: 0
SERVER: RTCC/3.0.0.0 MediationServer
[7] 2008/09/29 14:12:49: SIP Rx tcp:172.16.116.104:5065:
SIP/2.0 200 OK
FROM: "OBS Global"<sip:999@172.16.116.104;user=phone>;tag=53059
TO: <sip:999@172.16.116.104;user=phone>;tag=c19311cfd;epid=06A5C4BC0B
CSEQ: 25625 BYE
CALL-ID: 88725d22@pbx
VIA: SIP/2.0/TCP 172.16.116.105:1181;branch=z9hG4bK-d1b5d0ea5696fcc1fcaf23c8260956a0;rport
CONTENT-LENGTH: 0
SERVER: RTCC/3.0.0.0
[8] 2008/09/29 14:12:49: Call 88725d22@pbx#53059: Response does not correspond to open request
[5] 2008/09/29 14:12:49: BYE Response: Terminate 88725d22@pbx
[7] 2008/09/29 14:12:49: Other Ports: 3
[7] 2008/09/29 14:12:49: Call Port: 1B9E0136@159.18.161.101#b6d60dcb50
[7] 2008/09/29 14:12:49: Call Port: 7ec7d03a@pbx#11559
[7] 2008/09/29 14:12:49: Call Port: 9b698194@pbx#62205
[7] 2008/09/29 14:12:49: SIP Rx tcp:172.16.116.102:5060:
SIP/2.0 180 Ringing
FROM: "Chris Deacon"<sip:2049820218@159.18.161.101:5060;transport=udp;user=phone>;tag=62205
TO: OBS Global<sip:999@obsrnd.obsglobal.com>;epid=4414844359;tag=389ae44573
CSEQ: 11279 INVITE
CALL-ID: 9b698194@pbx
VIA: SIP/2.0/TCP 172.16.116.105:1182;branch=z9hG4bK-c6c4c5fff867991162b4cdac8dfdb667;rport
CONTENT-LENGTH: 0
SERVER: RTCC/3.0.0.0 MediationServer
[7] 2008/09/29 14:12:50: SIP Tr udp:159.18.161.67:5060:
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 159.18.161.67;branch=z9hG4bK8751.c2ab7894.0
Via: SIP/2.0/UDP 159.18.161.101:5060;rport=5060;branch=z9hG4bK-0c26c6f69825fcf9328601343cba48ea-159.18.161.101-1
Record-Route: <sip:2049758698@159.18.161.67;ftag=159.18.161.101+1+1ba2d9+59b98b75;lr=on>
From: Chris Deacon <sip:2049820218@159.18.161.101:5060;transport=udp>;tag=159.18.161.101+1+1ba2d9+59b98b75;isup-oli=00
To: <sip:2049758698@205.200.204.5>;tag=b6d60dcb50
Call-ID: 1B9E0136@159.18.161.101
CSeq: 684567237 INVITE
Contact: <sip:2049758698@172.16.116.105:5060;transport=udp>
Supported: 100rel, replaces, norefersub
Allow-Events: refer
Allow: INVITE, ACK, CANCEL, BYE, REFER, PRACK, INFO, UPDATE
Accept: application/sdp
User-Agent: pbxnsip-PBX/3.0.0.2998
Content-Type: application/sdp
Content-Length: 208
v=0
o=- 38924 38924 IN IP4 172.16.116.105
s=-
c=IN IP4 172.16.116.105
t=0 0
m=audio 62836 RTP/AVP 0 101
a=rtpmap:0 pcmu/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrec