Transfer of outbound calls fails

Asterisk Asterisk Support
1

Environment:

CentOS 5.8
Asterisk 1.8.11.0
FreePBX 2.10.1.1
Phones: SNOM 870 Firmware: snom870-SIP 8.7.3.10
Asterisk General Outbound Dial settings: tTwW

Scenario:

Internal extension A calls external sip number C then wants to transfer the call to internal sip extension B. Extension B rings once and then is told to cancel as shown below. We can transfer inbound calls with no issue just the outbound calls won’t work.

Results:

Internal sip extension B log shows:

Received from udp:172.16.1.34:5060 at 7/9/2012 15:46:08:469 (886 bytes):

INVITE sip:250@192.168.88.165:5060;line=4p72ym7m SIP/2.0
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK13daa177
Max-Forwards: 70
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as56c3f3a3
To: sip:250@192.168.88.165:5060;line=4p72ym7m
Contact: sip:2212726@172.16.1.34:5060
Call-ID: 2669a4b8236d956e02317aa73ac0bc34@172.16.1.34:5060
CSeq: 102 INVITE
User-Agent: FPBX-2.10.1(1.8.11.0)
Date: Fri, 07 Sep 2012 19:46:08 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 282

v=0
o=root 2093085221 2093085221 IN IP4 172.16.1.34
s=Asterisk PBX 1.8.11.0
c=IN IP4 172.16.1.34
t=0 0
m=audio 11060 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

Sent to udp:172.16.1.34:5060 at 7/9/2012 15:46:08:480 (369 bytes):

SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK13daa177
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as56c3f3a3
To: sip:250@192.168.88.165:5060;line=4p72ym7m;tag=b5qhpkt9ys
Call-ID: 2669a4b8236d956e02317aa73ac0bc34@172.16.1.34:5060
CSeq: 102 INVITE
Contact: sip:250@192.168.88.165:5060;line=4p72ym7m;reg-id=1
Content-Length: 0

Sent to udp:172.16.1.34:5060 at 7/9/2012 15:46:08:498 (512 bytes):

SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK13daa177
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as56c3f3a3
To: sip:250@192.168.88.165:5060;line=4p72ym7m;tag=b5qhpkt9ys
Call-ID: 2669a4b8236d956e02317aa73ac0bc34@172.16.1.34:5060
CSeq: 102 INVITE
Contact: sip:250@192.168.88.165:5060;line=4p72ym7m;reg-id=1
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE
Allow-Events: talk, hold, refer, call-info
Content-Length: 0

Received from udp:172.16.1.34:5060 at 7/9/2012 15:46:08:724 (382 bytes):

CANCEL sip:250@192.168.88.165:5060;line=4p72ym7m SIP/2.0
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK13daa177
Max-Forwards: 70
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as56c3f3a3
To: sip:250@192.168.88.165:5060;line=4p72ym7m
Call-ID: 2669a4b8236d956e02317aa73ac0bc34@172.16.1.34:5060
CSeq: 102 CANCEL
User-Agent: FPBX-2.10.1(1.8.11.0)
Content-Length: 0

Asterisk log shows:

[Sep 7 15:46:08] VERBOSE[4035] pbx.c: – Executing [s@macro-dial-one:42] Dial(“SIP/fpbx-1-0edad64d-000001b8”, “SIP/250,trw”) in new stack
[Sep 7 15:46:08] VERBOSE[4035] netsock2.c: == Using SIP RTP TOS bits 184
[Sep 7 15:46:08] VERBOSE[4035] netsock2.c: == Using SIP RTP CoS mark 5
[Sep 7 15:46:08] VERBOSE[4035] app_dial.c: – Called SIP/250
[Sep 7 15:46:08] VERBOSE[4035] app_dial.c: – SIP/250-000001ba is ringing
[Sep 7 15:46:08] VERBOSE[4035] app_dial.c: – SIP/fpbx-1-0edad64d-000001b8 requested special control 20, passing it to SIP/250-000001ba
[Sep 7 15:46:08] VERBOSE[4035] app_macro.c: == Spawn extension (macro-dial-one, s, 42) exited non-zero on ‘SIP/fpbx-1-0edad64d-000001b8’ in macro ‘dial-one’
[Sep 7 15:46:08] VERBOSE[4035] app_macro.c: == Spawn extension (macro-exten-vm, s, 14) exited non-zero on ‘SIP/fpbx-1-0edad64d-000001b8’ in macro ‘exten-vm’
[Sep 7 15:46:08] VERBOSE[4035] pbx.c: == Spawn extension (from-internal-xfer, 250, 2) exited non-zero on ‘SIP/fpbx-1-0edad64d-000001b8’

2

I would assume that A hung up. Possibly it can’t cope with connected line updates.

SIP debugging from Asterisk would have been more useful.

Note that it can be difficult to debug FreePBX dialplans, although, in this case, I don’t think the problem is FreePBX related.

3

Here are the SIP trace entries from when the transfer was initiated:

INVITE sip:250@192.168.88.165:5060;line=4p72ym7m SIP/2.0
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK16fd4bc3
Max-Forwards: 70
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as487a3bff
To: sip:250@192.168.88.165:5060;line=4p72ym7m
Contact: sip:2212726@172.16.1.34:5060
Call-ID: 0901cc08286a20f7705c9b3e69b7de70@172.16.1.34:5060
CSeq: 102 INVITE
User-Agent: FPBX-2.10.1(1.8.11.0)
Date: Mon, 10 Sep 2012 19:41:58 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 280

v=0
o=root 419932477 419932477 IN IP4 172.16.1.34
s=Asterisk PBX 1.8.11.0
c=IN IP4 172.16.1.34
t=0 0
m=audio 17276 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

INVITE sip:2072212726@184.106.130.224:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 24.97.255.114:5060;branch=z9hG4bK1fbe6d6d;rport
Route: sip:pb2proxy-pro-aws03.phonebooth.net:5060;lr=on;did=8c1.4dea60c3
Max-Forwards: 70
From: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
To: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
Contact: sip:2076554742@24.97.255.114:5060
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 104 INVITE
User-Agent: FPBX-2.10.1(1.8.11.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Remote-Party-ID: “District 2” sip:250@24.97.255.114;party=calling;privacy=off;screen=no
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1781383350 1781383352 IN IP4 24.97.255.114
s=Asterisk PBX 1.8.11.0
c=IN IP4 24.97.255.114
t=0 0
m=audio 16162 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

UPDATE sip:2072212726@184.106.130.224:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 24.97.255.114:5060;branch=z9hG4bK06f72293;rport
Route: sip:pb2proxy-pro-aws03.phonebooth.net:5060;lr=on;did=8c1.4dea60c3
Max-Forwards: 70
From: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
To: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
Contact: sip:2076554742@24.97.255.114:5060
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 105 UPDATE
User-Agent: FPBX-2.10.1(1.8.11.0)
Remote-Party-ID: “-> District 2 (via 163@172.16.1.34)” sip:250@24.97.255.114;party=calling;privacy=off;screen=no
X-Asterisk-rpid-update: Yes
Content-Length: 0

SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK16fd4bc3
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as487a3bff
To: sip:250@192.168.88.165:5060;line=4p72ym7m;tag=km5jkh3fmh
Call-ID: 0901cc08286a20f7705c9b3e69b7de70@172.16.1.34:5060
CSeq: 102 INVITE
Contact: sip:250@192.168.88.165:5060;line=4p72ym7m;reg-id=1
Content-Length: 0

SIP/2.0 100 Giving a try
Via: SIP/2.0/UDP 24.97.255.114:5060;branch=z9hG4bK1fbe6d6d;rport=8070
From: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
To: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 104 INVITE
Server: Phonebooth/1.0.0
Content-Length: 0

SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK16fd4bc3
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as487a3bff
To: sip:250@192.168.88.165:5060;line=4p72ym7m;tag=km5jkh3fmh
Call-ID: 0901cc08286a20f7705c9b3e69b7de70@172.16.1.34:5060
CSeq: 102 INVITE
Contact: sip:250@192.168.88.165:5060;line=4p72ym7m;reg-id=1
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE
Allow-Events: talk, hold, refer, call-info
Content-Length: 0

SIP/2.0 200 OK
Via: SIP/2.0/UDP 24.97.255.114:5060;received=24.97.255.114;branch=z9hG4bK06f72293;rport=8070
From: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
To: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 105 UPDATE
Contact: sip:2072212726@184.106.130.224:5060;transport=udp
User-Agent: FreeSWITCH-mod_sofia/1.0.4-hacked
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: precondition, path, replaces
Content-Length: 0

SIP/2.0 200 OK
Via: SIP/2.0/UDP 24.97.255.114:5060;received=24.97.255.114;branch=z9hG4bK1fbe6d6d;rport=8070
Record-Route: sip:pb2proxy-pro-aws03.phonebooth.net:5060;lr=on
From: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
To: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 104 INVITE
Contact: sip:2072212726@184.106.130.224:5060;transport=udp
User-Agent: FreeSWITCH-mod_sofia/1.0.4-hacked
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: precondition, path, replaces
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 250

v=0
o=Sonus_UAC 22062 9057 IN IP4 67.231.0.213
s=SIP Media Capabilities
c=IN IP4 184.106.130.224
t=0 0
m=audio 16902 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20

ACK sip:2072212726@184.106.130.224:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 24.97.255.114:5060;branch=z9hG4bK25c6203f;rport
Route: sip:pb2proxy-pro-aws03.phonebooth.net:5060;lr=on;did=8c1.4dea60c3
Max-Forwards: 70
From: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
To: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
Contact: sip:2076554742@24.97.255.114:5060
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 104 ACK
User-Agent: FPBX-2.10.1(1.8.11.0)
Content-Length: 0

NOTIFY sip:163@192.168.88.181:5060;line=6fe6m62n SIP/2.0
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK284e9c04;rport
Max-Forwards: 70
From: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
To: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
Contact: sip:2212726@172.16.1.34:5060
Call-ID: 73424e50231b-uhog1amj4dab
CSeq: 102 NOTIFY
User-Agent: FPBX-2.10.1(1.8.11.0)
Event: refer;id=4
Subscription-state: active
Content-Type: message/sipfrag;version=2.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 21

SIP/2.0 180 Ringing

NOTIFY sip:163@192.168.88.181:5060;line=6fe6m62n SIP/2.0
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK6be8523c;rport
Max-Forwards: 70
From: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
To: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
Contact: sip:2212726@172.16.1.34:5060
Call-ID: 73424e50231b-uhog1amj4dab
CSeq: 103 NOTIFY
User-Agent: FPBX-2.10.1(1.8.11.0)
Event: refer;id=4
Subscription-state: terminated;reason=noresource
Content-Type: message/sipfrag;version=2.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 16

SIP/2.0 200 Ok

SIP/2.0 200 Ok
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK284e9c04;rport=5060
From: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
To: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
Call-ID: 73424e50231b-uhog1amj4dab
CSeq: 102 NOTIFY
Contact: sip:163@192.168.88.181:5060;line=6fe6m62n;reg-id=1
Content-Length: 0

INVITE sip:2076554742@24.97.255.114:5060 SIP/2.0
Via: SIP/2.0/UDP pb2proxy-pro-aws03.phonebooth.net;branch=z9hG4bK901f.bf00fd2.0
Via: SIP/2.0/UDP 184.106.130.224;received=184.106.130.224;rport=5060;branch=z9hG4bK9SQUvF75cUHtr
Max-Forwards: 68
From: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
To: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 33316995 INVITE
Contact: sip:2072212726@184.106.130.224:5060;transport=udp
User-Agent: FreeSWITCH-mod_sofia/1.0.4-hacked
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: precondition, path, replaces
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 250
X-CompanyGuid: 0edad64d
X-BWS-ALEG-CALLID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
X-BWS-GATEWAY: OLDCORE

v=0
o=Sonus_UAC 22062 9057 IN IP4 67.231.0.213
s=SIP Media Capabilities
c=IN IP4 184.106.130.224
t=0 0
m=audio 16902 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20

SIP/2.0 100 Trying
Via: SIP/2.0/UDP pb2proxy-pro-aws03.phonebooth.net;branch=z9hG4bK901f.bf00fd2.0;received=184.72.227.214;rport=5060
Via: SIP/2.0/UDP 184.106.130.224;received=184.106.130.224;rport=5060;branch=z9hG4bK9SQUvF75cUHtr
From: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
To: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 33316995 INVITE
Server: FPBX-2.10.1(1.8.11.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:2076554742@24.97.255.114:5060
Content-Length: 0

SIP/2.0 200 OK
Via: SIP/2.0/UDP pb2proxy-pro-aws03.phonebooth.net;branch=z9hG4bK901f.bf00fd2.0;received=184.72.227.214;rport=5060
Via: SIP/2.0/UDP 184.106.130.224;received=184.106.130.224;rport=5060;branch=z9hG4bK9SQUvF75cUHtr
From: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
To: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 33316995 INVITE
Server: FPBX-2.10.1(1.8.11.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:2076554742@24.97.255.114:5060
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1781383350 1781383352 IN IP4 24.97.255.114
s=Asterisk PBX 1.8.11.0
c=IN IP4 24.97.255.114
t=0 0
m=audio 16162 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

ACK sip:2076554742@24.97.255.114:5060 SIP/2.0
Via: SIP/2.0/UDP pb2proxy-pro-aws03.phonebooth.net;branch=z9hG4bK901f.bf00fd2.2
Via: SIP/2.0/UDP 184.106.130.224;received=184.106.130.224;rport=5060;branch=z9hG4bKa3gmyar9937cm
Max-Forwards: 69
From: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
To: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 33316995 ACK
Content-Length: 0

BYE sip:2076554742@24.97.255.114:5060 SIP/2.0
Via: SIP/2.0/UDP pb2proxy-pro-aws03.phonebooth.net;branch=z9hG4bK601f.ef11d313.0
Via: SIP/2.0/UDP 184.106.130.224;received=184.106.130.224;rport=5060;branch=z9hG4bKBcaD058c7cyZF
Max-Forwards: 69
From: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
To: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 33316996 BYE
Contact: sip:2072212726@184.106.130.224:5060;transport=udp
User-Agent: FreeSWITCH-mod_sofia/1.0.4-hacked
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: precondition, path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0

SIP/2.0 200 OK
Via: SIP/2.0/UDP pb2proxy-pro-aws03.phonebooth.net;branch=z9hG4bK601f.ef11d313.0;received=184.72.227.214;rport=5060
Via: SIP/2.0/UDP 184.106.130.224;received=184.106.130.224;rport=5060;branch=z9hG4bKBcaD058c7cyZF
From: sip:2072212726@trunk1.phonebooth.net;tag=QKjjj8K7c3S2j
To: “Raymond Town Office” sip:2076554742@24.97.255.114;tag=as426ec7b4
Call-ID: 2a34133e444f1cce785735ec512effcf@24.97.255.114:5060
CSeq: 33316996 BYE
Server: FPBX-2.10.1(1.8.11.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

CANCEL sip:250@192.168.88.165:5060;line=4p72ym7m SIP/2.0
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK16fd4bc3
Max-Forwards: 70
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as487a3bff
To: sip:250@192.168.88.165:5060;line=4p72ym7m
Call-ID: 0901cc08286a20f7705c9b3e69b7de70@172.16.1.34:5060
CSeq: 102 CANCEL
User-Agent: FPBX-2.10.1(1.8.11.0)
Content-Length: 0

NOTIFY sip:163@192.168.88.181:5060;line=6fe6m62n SIP/2.0
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK6be8523c;rport
Max-Forwards: 70
From: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
To: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
Contact: sip:2212726@172.16.1.34:5060
Call-ID: 73424e50231b-uhog1amj4dab
CSeq: 103 NOTIFY
User-Agent: FPBX-2.10.1(1.8.11.0)
Event: refer;id=4
Subscription-state: terminated;reason=noresource
Content-Type: message/sipfrag;version=2.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 16

SIP/2.0 200 Ok

SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK16fd4bc3
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as487a3bff
To: sip:250@192.168.88.165:5060;line=4p72ym7m;tag=km5jkh3fmh
Call-ID: 0901cc08286a20f7705c9b3e69b7de70@172.16.1.34:5060
CSeq: 102 CANCEL
Content-Length: 0

SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK16fd4bc3
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as487a3bff
To: sip:250@192.168.88.165:5060;line=4p72ym7m;tag=km5jkh3fmh
Call-ID: 0901cc08286a20f7705c9b3e69b7de70@172.16.1.34:5060
CSeq: 102 INVITE
Contact: sip:250@192.168.88.165:5060;line=4p72ym7m;reg-id=1
Content-Length: 0

ACK sip:250@192.168.88.165:5060;line=4p72ym7m SIP/2.0
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK16fd4bc3
Max-Forwards: 70
From: “CID:2076554742” sip:2212726@172.16.1.34;tag=as487a3bff
To: sip:250@192.168.88.165:5060;line=4p72ym7m;tag=km5jkh3fmh
Contact: sip:2212726@172.16.1.34:5060
Call-ID: 0901cc08286a20f7705c9b3e69b7de70@172.16.1.34:5060
CSeq: 102 ACK
User-Agent: FPBX-2.10.1(1.8.11.0)
Content-Length: 0

BYE sip:2212726@172.16.1.34:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.88.181:5060;branch=z9hG4bK-wq5d2ie12iho;rport
From: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
To: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
Call-ID: 73424e50231b-uhog1amj4dab
CSeq: 5 BYE
Max-Forwards: 70
Contact: sip:163@192.168.88.181:5060;line=6fe6m62n;reg-id=1
User-Agent: snom870/8.7.3.10
RTP-RxStat: Total_Rx_Pkts=0,Rx_Pkts=0,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0
RTP-TxStat: Total_Tx_Pkts=0,Tx_Pkts=0,Remote_Tx_Pkts=0
Content-Length: 0

SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.88.181:5060;branch=z9hG4bK-wq5d2ie12iho;received=192.168.88.181;rport=5060
From: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
To: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
Call-ID: 73424e50231b-uhog1amj4dab
CSeq: 5 BYE
Server: FPBX-2.10.1(1.8.11.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

SIP/2.0 200 Ok
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK6be8523c;rport=5060
From: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
To: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
Call-ID: 73424e50231b-uhog1amj4dab
CSeq: 103 NOTIFY
Content-Length: 0

SIP/2.0 200 Ok
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK284e9c04;rport=5060
From: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
To: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
Call-ID: 73424e50231b-uhog1amj4dab
CSeq: 102 NOTIFY
Contact: sip:163@192.168.88.181:5060;line=6fe6m62n;reg-id=1
Content-Length: 0

SIP/2.0 200 Ok
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK6be8523c;rport=5060
From: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
To: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
Call-ID: 73424e50231b-uhog1amj4dab
CSeq: 103 NOTIFY
Content-Length: 0

SIP/2.0 200 Ok
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK6be8523c;rport=5060
From: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
To: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
Call-ID: 73424e50231b-uhog1amj4dab
CSeq: 103 NOTIFY
Content-Length: 0

OPTIONS sip:250@192.168.88.165:5060;line=4p72ym7m SIP/2.0
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK3b5a4af1
Max-Forwards: 70
From: “Unknown” sip:Unknown@172.16.1.34;tag=as2a487bfb
To: sip:250@192.168.88.165:5060;line=4p72ym7m
Contact: sip:Unknown@172.16.1.34:5060
Call-ID: 46d49863097189480773c8c128743ff7@172.16.1.34:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.10.1(1.8.11.0)
Date: Mon, 10 Sep 2012 19:42:00 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK3b5a4af1
From: “Unknown” sip:Unknown@172.16.1.34;tag=as2a487bfb
To: sip:250@192.168.88.165:5060;line=4p72ym7m;tag=czq4vzo5yk
Call-ID: 46d49863097189480773c8c128743ff7@172.16.1.34:5060
CSeq: 102 OPTIONS
Contact: sip:250@192.168.88.165:5060;line=4p72ym7m;reg-id=1
User-Agent: snom870/8.7.3.10
Accept-Language: en
Accept: application/sdp
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE
Allow-Events: talk, hold, refer, call-info
Supported: timer, 100rel, replaces, from-change
Content-Length: 0

4

The trace shows NOTIFY’s that are the result of a REFER, but do not show the REFER!

Lets try again.

Edit /etc/asterisk/logger.conf, uncomment full and make sure it contains all categories.

At the CLI, type:

logger reload
core set debug 5 chan_sip
core set verbose 5
sip set debug on

Run your test case

Edit /var/log/asterisk/full to remove escape sequences and to minimally obscure sensitive data.

Post that here.

5

Sorry about that, it was a bad cut/paste, I missed the first section. Here is the the first part that immediately precedes my last post:

REFER sip:2212726@172.16.1.34:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.88.181:5060;branch=z9hG4bK-r1sy5mpkry29;rport
From: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
To: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
Call-ID: 73424e50231b-uhog1amj4dab
cseq: 4 REFER
Max-Forwards: 70
Contact: sip:163@192.168.88.181:5060;line=6fe6m62n;reg-id=1
Refer-To: sip:250@172.16.1.34;user=phone
Referred-By: sip:163@172.16.1.34
User-Agent: snom870/8.7.3.10
Content-Length: 0

SIP/2.0 202 Accepted
Via: SIP/2.0/UDP 192.168.88.181:5060;branch=z9hG4bK-r1sy5mpkry29;received=192.168.88.181;rport=5060
From: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
To: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
Call-ID: 73424e50231b-uhog1amj4dab
cseq: 4 REFER
Server: FPBX-2.10.1(1.8.11.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:2212726@172.16.1.34:5060
Content-Length: 0

Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK284e9c04;rport
Max-Forwards: 70
From: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
To: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
Contact: sip:2212726@172.16.1.34:5060
Call-ID: 73424e50231b-uhog1amj4dab
cseq: 102 NOTIFY
User-Agent: FPBX-2.10.1(1.8.11.0)
Event: refer;id=4
Subscription-state: active
Content-Type: message/sipfrag;version=2.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 21
SIP/2.0 180 ringing

NOTIFY sip:163@192.168.88.181:5060;line=6fe6m62n SIP/2.0
Via: SIP/2.0/UDP 172.16.1.34:5060;branch=z9hG4bK6be8523c;rport
Max-Forwards: 70
From: sip:2212726@172.16.1.34;user=phone;tag=as448e33e3
To: “Server Room” sip:163@172.16.1.34;tag=fbhfbs6me7
Contact: sip:2212726@172.16.1.34:5060
Call-ID: 73424e50231b-uhog1amj4dab
cseq: 103 NOTIFY
User-Agent: FPBX-2.10.1(1.8.11.0)
Event: refer;id=4
Subscription-state: terminated;reason=noresource
Content-Type: message/sipfrag;version=2.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 16
SIP/2.0 200 Ok

6

I have a trace.cap file, would you like me to attach that? If so where is the attach feature? I can’t see it anywhere.