Calls not routing to inbound routes properly

xptpa2020 · February 16, 2012, 8:49pm

Hello all,

I am running into a wall here (and it isn’t moving). I’ve got a sip trunk provided by a local Broadsoft company that I am registering our Asterisk box to to make and receive phone calls. I have 3 DID’s assigned: (I’ve made all DID’s, providers, IP address, and cell phones fictitious, to protect our security):

9991112222
9991113333
9991114444

I’ve got 1) pointing to our main IVR I created, 2) is a direct inward DID for extension 114 and 3) is our fax to email DID at extension 201.

I’ve got 3 inbound routes created:

9991112222 / AnyCID - IVR
9991113333 / ANYCID - 114
9991114444 / AnyCID - 201 (with fax detection at the extension)

No matter what happens, all calls to any DID will go only to 9991112222 (the IVR). I am only using 1 trunk that registers as:

[email protected]:authpass:[email protected]/9991112222

and in sip_registrations_custom.conf I also have:

[email protected]:authpass:[email protected]/9991113333
[email protected]:authpass:[email protected]/9991114444

I see in our status page that 1 trunk is online and 3 are registered (as I believe it should be), and in Broadsoft, I can see 3 registrations for that one trunk as well - one for each DID. I created Shared Call Appearances in Broadsoft for each DID to make this all possible for me. However, I’m having problems with the routing at Asterisk.

I can see in the sip debug log file that calls first come in at the DID I called from my cell phone, but it always ends up at the IVR.

I also attached my sip log that will explain better than I can what is happening.

Does anybody have a clear idea what could be the issue? I’ve read the FreePBX article (http://www.freepbx.org/support/documentation/howtos/how-to-get-the-did-of-a-sip-trunk-when-the-provider-doesnt-send-it-and-) and about 15 others with other providers and Asterisk systems, but I cannot find anything relevant to my scenario.

So now I’m consulting with the experts. What is my problem?

Many many many thanks.

alan · February 17, 2012, 1:23am

Please post console output of a call to your system.

xptpa2020 · February 19, 2012, 5:03am

Via: SIP/2.0/UDP 192.168.96.1:5060;branch=z9hG4bK394aa3a6
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as39c3e146
To: sip:[email protected]:5060
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 NOTIFY
User-Agent: FPBX-2.10.0rc1(1.8.8.0)
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 93

Messages-Waiting: yes
Message-Account: sip:*[email protected]:5060
Voice-Message: 1/1 (0/0)

[2012-02-16 15:22:12] VERBOSE[20260] config.c: == Parsing ‘/etc/asterisk/dahdi-channels.conf’: [2012-02-16 15:22:12] VERBOSE[20260] config.c: == Found
[2012-02-16 15:22:12] VERBOSE[20260] config.c: == Parsing ‘/etc/asterisk/chan_dahdi_additional.conf’: [2012-02-16 15:22:12] VERBOSE[20260] config.c: == Found
[2012-02-16 15:22:12] WARNING[20260] chan_dahdi.c: Ignoring any changes to ‘signalling’ (on reload) at line 12.
[2012-02-16 15:22:12] WARNING[20260] chan_dahdi.c: Ignoring any changes to ‘rxwink’ (on reload) at line 13.
[2012-02-16 15:22:12] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:192.168.96.109:5060 —>
SIP/2.0 200 OK
To: sip:[email protected]:5060;tag=814f32dd9951d91bi0
From: “Unknown” sip:[email protected];tag=as39c3e146
Call-ID: [email protected]:5060
CSeq: 102 NOTIFY
Via: SIP/2.0/UDP 192.168.96.1:5060;branch=z9hG4bK394aa3a6
Server: Cisco/SPA525G-7.4.8
Content-Length: 0

<------------->
[2012-02-16 15:22:12] VERBOSE[19698] chan_sip.c: — (8 headers 0 lines) —
[2012-02-16 15:22:12] VERBOSE[19698] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: NOTIFY
[2012-02-16 15:22:12] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
SIP/2.0 404 Not found
Via:SIP/2.0/UDP 11.111.111.111:5060;received=12.12.12.12;branch=z9hG4bK7dae7883;rport
From:sip:[email protected];tag=as5dd3a8a6
To:sip:[email protected];tag=1433813424-1329423732627
Call-ID:[email protected]
CSeq:4229 REGISTER
Content-Length:0

<------------->
[2012-02-16 15:22:12] VERBOSE[19698] chan_sip.c: — (7 headers 0 lines) —
[2012-02-16 15:22:13] VERBOSE[19681] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]:5060’ in 13568 ms (Method: NOTIFY)
[2012-02-16 15:22:13] VERBOSE[19681] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.96.109:5060:
NOTIFY sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.96.1:5060;branch=z9hG4bK0a3217c5
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as3e97453b
To: sip:[email protected]:5060
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 NOTIFY
User-Agent: FPBX-2.10.0rc1(1.8.8.0)
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 93

Messages-Waiting: yes
Message-Account: sip:*[email protected]:5060
Voice-Message: 1/1 (0/0)

[2012-02-16 15:22:13] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:192.168.96.109:5060 —>
SIP/2.0 200 OK
To: sip:[email protected]:5060;tag=814f32dd9951d91bi0
From: “Unknown” sip:[email protected];tag=as3e97453b
Call-ID: [email protected]:5060
CSeq: 102 NOTIFY
Via: SIP/2.0/UDP 192.168.96.1:5060;branch=z9hG4bK0a3217c5
Server: Cisco/SPA525G-7.4.8
Content-Length: 0

<------------->
[2012-02-16 15:22:13] VERBOSE[19698] chan_sip.c: — (8 headers 0 lines) —
[2012-02-16 15:22:13] VERBOSE[19698] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: NOTIFY
[2012-02-16 15:22:14] VERBOSE[19681] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]:5060’ in 13440 ms (Method: NOTIFY)
[2012-02-16 15:22:14] VERBOSE[19681] chan_sip.c: Reliably Transmitting (NAT) to 192.168.96.101:5061:
NOTIFY sip:[email protected]:5061 SIP/2.0
Via: SIP/2.0/UDP 192.168.96.1:5060;branch=z9hG4bK4f6c0525;rport
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as538cf400
To: sip:[email protected]:5061
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 NOTIFY
User-Agent: FPBX-2.10.0rc1(1.8.8.0)
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 92

Messages-Waiting: no
Message-Account: sip:*[email protected]:5060
Voice-Message: 0/1 (0/0)

[2012-02-16 15:22:14] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:192.168.96.101:5061 —>
SIP/2.0 200 OK
To: sip:[email protected]:5061;tag=2d3af22b8b0979c3i1
From: “Unknown” sip:[email protected];tag=as538cf400
Call-ID: [email protected]:5060
CSeq: 102 NOTIFY
Via: SIP/2.0/UDP 192.168.96.1:5060;branch=z9hG4bK4f6c0525
Server: Cisco/SPA504G-7.4.8
Content-Length: 0

<------------->
[2012-02-16 15:22:14] VERBOSE[19698] chan_sip.c: — (8 headers 0 lines) —
[2012-02-16 15:22:14] VERBOSE[19698] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: NOTIFY
[2012-02-16 15:22:14] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
SIP/2.0 404 Not found
Via:SIP/2.0/UDP 11.111.111.111:5060;received=12.12.12.12;branch=z9hG4bK7dae7883;rport
From:sip:[email protected];tag=as5dd3a8a6
To:sip:[email protected];tag=778785685-1329423734627
Call-ID:[email protected]
CSeq:4229 REGISTER
Content-Length:0

<------------->
[2012-02-16 15:22:14] VERBOSE[19698] chan_sip.c: — (7 headers 0 lines) —
[2012-02-16 15:22:16] VERBOSE[19681] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]:5060’ in 13376 ms (Method: NOTIFY)
[2012-02-16 15:22:16] VERBOSE[19681] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.96.102:5060:
NOTIFY sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.96.1:5060;branch=z9hG4bK756344a0
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as55f8821d
To: sip:[email protected]:5060
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 NOTIFY
User-Agent: FPBX-2.10.0rc1(1.8.8.0)
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 92

Messages-Waiting: no
Message-Account: sip:*[email protected]:5060
Voice-Message: 0/1 (0/0)

[2012-02-16 15:22:16] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:192.168.96.102:5060 —>
SIP/2.0 200 OK
To: sip:[email protected]:5060;tag=b671089a79c1400ai2
From: “Unknown” sip:[email protected];tag=as55f8821d
Call-ID: [email protected]:5060
CSeq: 102 NOTIFY
Via: SIP/2.0/UDP 192.168.96.1:5060;branch=z9hG4bK756344a0
Server: Cisco/SPA509G-7.4.9c
Content-Length: 0

<------------->
[2012-02-16 15:22:16] VERBOSE[19698] chan_sip.c: — (8 headers 0 lines) —
[2012-02-16 15:22:16] VERBOSE[19698] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: NOTIFY
[2012-02-16 15:22:17] ERROR[19717] app_voicemail_imapstorage.c: Couldn’t find mailbox 201 in context device
[2012-02-16 15:22:17] NOTICE[20284] manager.c: 192.168.96.1 failed to pass IP ACL as ‘admin’
[2012-02-16 15:22:17] NOTICE[20284] manager.c: 192.168.96.1 failed to authenticate as ‘admin’
[2012-02-16 15:22:18] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
BYE sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65675215-1596339304-1329423728538-
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1596339304-1329423728538-
To:"MyCompany Line"sip:[email protected];tag=as757735f5
Call-ID:[email protected]
CSeq:65675215 BYE
Max-Forwards:70
Content-Length:0

<------------->
[2012-02-16 15:22:18] VERBOSE[19698] chan_sip.c: — (8 headers 0 lines) —
[2012-02-16 15:22:18] VERBOSE[19698] chan_sip.c: Sending to 12.134.122.121:1029 (NAT)
[2012-02-16 15:22:18] VERBOSE[19698] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: BYE)
[2012-02-16 15:22:18] VERBOSE[19698] chan_sip.c:
<— Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65675215-1596339304-1329423728538-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1596339304-1329423728538-
To: "MyCompany Line"sip:[email protected];tag=as757735f5
Call-ID: [email protected]
CSeq: 65675215 BYE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
[2012-02-16 15:22:18] VERBOSE[20281] pbx.c: == Spawn extension (ivr-1, s, 11) exited non-zero on ‘SIP/MyCompany-0000001c’
[2012-02-16 15:22:18] VERBOSE[20281] pbx.c: – Executing [h@ivr-1:1] Hangup(“SIP/MyCompany-0000001c”, “”) in new stack
[2012-02-16 15:22:18] VERBOSE[20281] pbx.c: == Spawn extension (ivr-1, h, 1) exited non-zero on ‘SIP/MyCompany-0000001c’
[2012-02-16 15:22:18] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
SIP/2.0 404 Not found
Via:SIP/2.0/UDP 11.111.111.111:5060;received=12.12.12.12;branch=z9hG4bK7dae7883;rport
From:sip:[email protected];tag=as5dd3a8a6
To:sip:[email protected];tag=2043836720-1329423738627
Call-ID:[email protected]
CSeq:4229 REGISTER
Content-Length:0

<------------->
[2012-02-16 15:22:18] VERBOSE[19698] chan_sip.c: — (7 headers 0 lines) —
[2012-02-16 15:22:22] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
SIP/2.0 404 Not found
Via:SIP/2.0/UDP 11.111.111.111:5060;received=12.12.12.12;branch=z9hG4bK7dae7883;rport
From:sip:[email protected];tag=as5dd3a8a6
To:sip:[email protected];tag=892014371-1329423742654
Call-ID:[email protected]
CSeq:4229 REGISTER
Content-Length:0

<------------->
[2012-02-16 15:22:22] VERBOSE[19698] chan_sip.c: — (7 headers 0 lines) —
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
SIP/2.0 404 Not found
Via:SIP/2.0/UDP 11.111.111.111:5060;received=12.12.12.12;branch=z9hG4bK7dae7883;rport
From:sip:[email protected];tag=as5dd3a8a6
To:sip:[email protected];tag=1029955262-1329423746627
Call-ID:[email protected]
CSeq:4229 REGISTER
Content-Length:0

<------------->
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: — (7 headers 0 lines) —
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
INVITE sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1753273721-1329423746882-
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1753273721-1329423746882-
To:"MyCompany Line"sip:[email protected]
Call-ID:[email protected]
CSeq:65684386 INVITE
Contact:sip:12.134.122.121:5060
Supported:100rel
Allow:ACK,BYE,CANCEL,INFO,INVITE,OPTIONS,PRACK,REFER,NOTIFY,UPDATE
Call-Info:sip:12.134.122.121;appearance-index=1
Accept:application/media_control+xml,application/sdp,multipart/mixed
Max-Forwards:70
Content-Type:application/sdp
Content-Disposition:session;handling=required
Content-Length:290

v=0
o=BroadWorks 25699660 1 IN IP4 63.135.224.139
s=-
c=IN IP4 12.134.122.121
t=0 0
m=audio 56338 RTP/AVP 18 0 8 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=maxptime:20
<------------->
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: — (15 headers 14 lines) —
[2012-02-16 15:22:26] VERBOSE[19698] netsock.c: == Using UDPTL TOS bits 184
[2012-02-16 15:22:26] VERBOSE[19698] netsock.c: == Using UDPTL CoS mark 5
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Sending to 12.134.122.121:1029 (NAT)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Using INVITE request as basis request - [email protected]
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found peer ‘MyCompany’ for ‘5551234564’ from 12.134.122.121:1029
[2012-02-16 15:22:26] VERBOSE[19698] netsock2.c: == Using SIP RTP TOS bits 184
[2012-02-16 15:22:26] VERBOSE[19698] netsock2.c: == Using SIP RTP CoS mark 5
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 18
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 0
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 8
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 101
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format G729 for ID 18
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format PCMU for ID 0
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format PCMA for ID 8
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format telephone-event for ID 101
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Peer audio RTP is at port 12.134.122.121:56338
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Looking for 9991113333 in from-trunk-sip-MyCompany (domain 12.12.12.12:5060)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: list_route: hop: sip:12.134.122.121:5060
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1753273721-1329423746882-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1753273721-1329423746882-
To: "MyCompany Line"sip:[email protected]
Call-ID: [email protected]
CSeq: 65684386 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
INVITE sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1040203140-1329423746883-
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1040203140-1329423746883-
To:"MyCompany Line"sip:[email protected]
Call-ID:[email protected]
CSeq:65684386 INVITE
Contact:sip:12.134.122.121:5060
Supported:100rel
Allow:ACK,BYE,CANCEL,INFO,INVITE,OPTIONS,PRACK,REFER,NOTIFY,UPDATE
Call-Info:sip:12.134.122.121;appearance-index=1
Accept:application/media_control+xml,application/sdp,multipart/mixed
Max-Forwards:70
Content-Type:application/sdp
Content-Disposition:session;handling=required
Content-Length:290

v=0
o=BroadWorks 25699662 1 IN IP4 63.135.224.139
s=-
c=IN IP4 12.134.122.121
t=0 0
m=audio 56338 RTP/AVP 18 0 8 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=maxptime:20
<------------->
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: — (15 headers 14 lines) —
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [9991113333@from-trunk-sip-MyCompany:1] Set(“SIP/MyCompany-0000001d”, “GROUP()=OUT_2”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [9991113333@from-trunk-sip-MyCompany:2] Goto(“SIP/MyCompany-0000001d”, “from-trunk,9991113333,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (from-trunk,9991113333,1)
[2012-02-16 15:22:26] VERBOSE[19698] netsock.c: == Using UDPTL TOS bits 184
[2012-02-16 15:22:26] VERBOSE[19698] netsock.c: == Using UDPTL CoS mark 5
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [9991113333@from-trunk:1] Set(“SIP/MyCompany-0000001d”, “__FROM_DID=9991113333”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [9991113333@from-trunk:2] Gosub(“SIP/MyCompany-0000001d”, “app-blacklist-check,s,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Sending to 12.134.122.121:1029 (NAT)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Using INVITE request as basis request - [email protected]
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found peer ‘MyCompany’ for ‘5551234564’ from 12.134.122.121:1029
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/MyCompany-0000001d”, “0?blacklisted”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/MyCompany-0000001d”, “CALLED_BLACKLIST=1”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] netsock2.c: == Using SIP RTP TOS bits 184
[2012-02-16 15:22:26] VERBOSE[19698] netsock2.c: == Using SIP RTP CoS mark 5
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/MyCompany-0000001d”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 18
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 0
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [9991113333@from-trunk:3] Set(“SIP/MyCompany-0000001d”, “CDR(did)=9991113333”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 8
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 101
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format G729 for ID 18
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format PCMU for ID 0
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [9991113333@from-trunk:4] ExecIf(“SIP/MyCompany-0000001d”, “0 ?Set(CALLERID(name)=5551234564)”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format PCMA for ID 8
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format telephone-event for ID 101
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [9991113333@from-trunk:5] Set(“SIP/MyCompany-0000001d”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Peer audio RTP is at port 12.134.122.121:56338
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [9991113333@from-trunk:6] Set(“SIP/MyCompany-0000001d”, “CALLERPRES()=allowed_not_screened”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Looking for 9991114444 in from-trunk-sip-MyCompany (domain 12.12.12.12:5060)
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [9991113333@from-trunk:7] Goto(“SIP/MyCompany-0000001d”, “from-did-direct,114,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (from-did-direct,114,1)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: list_route: hop: sip:12.134.122.121:5060
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:1] GotoIf(“SIP/MyCompany-0000001d”, “0?ext-local,114,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1040203140-1329423746883-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1040203140-1329423746883-
To: "MyCompany Line"sip:[email protected]
Call-ID: [email protected]
CSeq: 65684386 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:2] Macro(“SIP/MyCompany-0000001d”, “user-callerid,”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
INVITE sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684387-1786302999-1329423746884-
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1786302999-1329423746884-
To:"MyCompany Line"sip:[email protected]
Call-ID:[email protected]
CSeq:65684387 INVITE
Contact:sip:12.134.122.121:5060
Supported:100rel
Allow:ACK,BYE,CANCEL,INFO,INVITE,OPTIONS,PRACK,REFER,NOTIFY,UPDATE
Call-Info:sip:12.134.122.121;appearance-index=1
Accept:application/media_control+xml,application/sdp,multipart/mixed
Max-Forwards:70
Content-Type:application/sdp
Content-Disposition:session;handling=required
Content-Length:290

v=0
o=BroadWorks 25699658 1 IN IP4 63.135.224.139
s=-
c=IN IP4 63.135.224.139
t=0 0
m=audio 56338 RTP/AVP 18 0 8 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=maxptime:20
<------------->
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: — (15 headers 14 lines) —
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/MyCompany-0000001d”, “AMPUSER=5551234564”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/MyCompany-0000001d”, “0?report”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [9991114444@from-trunk-sip-MyCompany:1] Set(“SIP/MyCompany-0000001e”, “GROUP()=OUT_2”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [9991114444@from-trunk-sip-MyCompany:2] Goto(“SIP/MyCompany-0000001e”, “from-trunk,9991114444,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/MyCompany-0000001d”, “1?Set(REALCALLERIDNUM=5551234564)”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] netsock.c: == Using UDPTL TOS bits 184
[2012-02-16 15:22:26] VERBOSE[19698] netsock.c: == Using UDPTL CoS mark 5
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Sending to 12.134.122.121:1029 (NAT)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Using INVITE request as basis request - [email protected]
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/MyCompany-0000001d”, “AMPUSER=”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found peer ‘MyCompany’ for ‘5551234564’ from 12.134.122.121:1029
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/MyCompany-0000001d”, “AMPUSERCIDNAME=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (from-trunk,9991114444,1)
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/MyCompany-0000001d”, “1?report”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (macro-user-callerid,s,13)
[2012-02-16 15:22:26] VERBOSE[19698] netsock2.c: == Using SIP RTP TOS bits 184
[2012-02-16 15:22:26] VERBOSE[19698] netsock2.c: == Using SIP RTP CoS mark 5
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [9991114444@from-trunk:1] Set(“SIP/MyCompany-0000001e”, “__FROM_DID=9991114444”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:13] GotoIf(“SIP/MyCompany-0000001d”, “0?continue”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [9991114444@from-trunk:2] Gosub(“SIP/MyCompany-0000001e”, “app-blacklist-check,s,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/MyCompany-0000001e”, “0?blacklisted”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:14] Set(“SIP/MyCompany-0000001d”, “__TTL=64”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 18
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 0
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 8
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:15] GotoIf(“SIP/MyCompany-0000001d”, “1?continue”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found RTP audio format 101
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (macro-user-callerid,s,26)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format G729 for ID 18
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/MyCompany-0000001e”, “CALLED_BLACKLIST=1”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format PCMU for ID 0
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:26] Set(“SIP/MyCompany-0000001d”, “CALLERID(number)=5551234564”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/MyCompany-0000001e”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format PCMA for ID 8
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Found audio description format telephone-event for ID 101
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [9991114444@from-trunk:3] Set(“SIP/MyCompany-0000001e”, “CDR(did)=9991114444”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [9991114444@from-trunk:4] ExecIf(“SIP/MyCompany-0000001e”, “0 ?Set(CALLERID(name)=5551234564)”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Peer audio RTP is at port 63.135.224.139:56338
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Looking for 9991112222 in from-trunk-sip-MyCompany (domain 12.12.12.12:5060)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [9991114444@from-trunk:5] Set(“SIP/MyCompany-0000001e”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: list_route: hop: sip:12.134.122.121:5060
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [9991114444@from-trunk:6] Set(“SIP/MyCompany-0000001e”, “CALLERPRES()=allowed_not_screened”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [9991114444@from-trunk:7] Goto(“SIP/MyCompany-0000001e”, “from-did-direct,201,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684387-1786302999-1329423746884-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1786302999-1329423746884-
To: "MyCompany Line"sip:[email protected]
Call-ID: [email protected]
CSeq: 65684387 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (from-did-direct,201,1)
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:27] Set(“SIP/MyCompany-0000001d”, “CALLERID(name)=WIRELESS CALLER”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [201@from-did-direct:1] Set(“SIP/MyCompany-0000001e”, “__RINGTIMER=15”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/MyCompany-0000001d”, “CHANNEL(language)=en”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [201@from-did-direct:2] Macro(“SIP/MyCompany-0000001e”, “exten-vm,novm,201,0,0,0”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:3] Set(“SIP/MyCompany-0000001d”, “__EXTTOCALL=114”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:4] Set(“SIP/MyCompany-0000001d”, “__PICKUPMARK=114”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:1] Macro(“SIP/MyCompany-0000001e”, “user-callerid,”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [9991112222@from-trunk-sip-MyCompany:1] Set(“SIP/MyCompany-0000001f”, “GROUP()=OUT_2”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [9991112222@from-trunk-sip-MyCompany:2] Goto(“SIP/MyCompany-0000001f”, “from-trunk,9991112222,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Goto (from-trunk,9991112222,1)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/MyCompany-0000001e”, “AMPUSER=5551234564”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:5] Macro(“SIP/MyCompany-0000001d”, “blkvm-setifempty,”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/MyCompany-0000001e”, “0?report”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/MyCompany-0000001d”, “1?init”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (macro-blkvm-setifempty,s,4)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/MyCompany-0000001e”, “1?Set(REALCALLERIDNUM=5551234564)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [9991112222@from-trunk:1] Set(“SIP/MyCompany-0000001f”, “__FROM_DID=9991112222”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [9991112222@from-trunk:2] Gosub(“SIP/MyCompany-0000001f”, “app-blacklist-check,s,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/MyCompany-0000001f”, “0?blacklisted”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/MyCompany-0000001e”, “AMPUSER=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/MyCompany-0000001f”, “CALLED_BLACKLIST=1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-blkvm-setifempty:4] Set(“SIP/MyCompany-0000001d”, “__BLKVM_CHANNEL=SIP/MyCompany-0000001d”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-blkvm-setifempty:5] Set(“SIP/MyCompany-0000001d”, “SHARED(BLKVM,SIP/MyCompany-0000001d)=TRUE”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/MyCompany-0000001e”, “AMPUSERCIDNAME=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-blkvm-setifempty:6] Set(“SIP/MyCompany-0000001d”, “GOSUB_RETVAL=TRUE”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/MyCompany-0000001d”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/MyCompany-0000001e”, “1?report”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/MyCompany-0000001f”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (macro-user-callerid,s,13)
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [9991112222@from-trunk:3] Set(“SIP/MyCompany-0000001f”, “CDR(did)=9991112222”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [9991112222@from-trunk:4] ExecIf(“SIP/MyCompany-0000001f”, “0 ?Set(CALLERID(name)=5551234564)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:13] GotoIf(“SIP/MyCompany-0000001e”, “0?continue”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [9991112222@from-trunk:5] Set(“SIP/MyCompany-0000001f”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [9991112222@from-trunk:6] Set(“SIP/MyCompany-0000001f”, “CALLERPRES()=allowed_not_screened”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:6] GotoIf(“SIP/MyCompany-0000001d”, “1?skipov”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:14] Set(“SIP/MyCompany-0000001e”, “__TTL=64”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (from-did-direct,114,9)
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:9] Set(“SIP/MyCompany-0000001d”, “RRNODEST=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:10] Set(“SIP/MyCompany-0000001d”, “__NODEST=114”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [9991112222@from-trunk:7] Goto(“SIP/MyCompany-0000001f”, “ivr-1,s,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Goto (ivr-1,s,1)
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:1] Set(“SIP/MyCompany-0000001f”, “TIMEOUT_LOOPCOUNT=0”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:11] GosubIf(“SIP/MyCompany-0000001d”, “0?sub-fmsetcid,s,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:2] Set(“SIP/MyCompany-0000001f”, “INVALID_LOOPCOUNT=0”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:12] Set(“SIP/MyCompany-0000001d”, “RecordMethod=Group”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:3] Set(“SIP/MyCompany-0000001f”, “_IVR_CONTEXT_ivr-1=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:13] Gosub(“SIP/MyCompany-0000001d”, “sub-record-check,s,1(exten,114,)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:4] Set(“SIP/MyCompany-0000001f”, “_IVR_CONTEXT=ivr-1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:5] Set(“SIP/MyCompany-0000001f”, “__IVR_RETVM=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/MyCompany-0000001d”, “1?check”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (sub-record-check,s,3)
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:6] GotoIf(“SIP/MyCompany-0000001f”, “0?start”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:7] Answer(“SIP/MyCompany-0000001f”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:3] Set(“SIP/MyCompany-0000001d”, “MON_FMT=wav”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:4] GotoIf(“SIP/MyCompany-0000001d”, “1?next”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:15] GotoIf(“SIP/MyCompany-0000001e”, “1?continue”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (sub-record-check,s,7)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (macro-user-callerid,s,26)
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:7] ExecIf(“SIP/MyCompany-0000001d”, “0?Return()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:26] Set(“SIP/MyCompany-0000001e”, “CALLERID(number)=5551234564”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:8] GotoIf(“SIP/MyCompany-0000001d”, “0?exten,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] chan_sip.c: Audio is at 5060
[2012-02-16 15:22:26] VERBOSE[20287] chan_sip.c: Adding codec 0x4 (ulaw) to SDP
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:9] Set(“SIP/MyCompany-0000001d”, “__REC_STATUS=INITIALIZED”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:10] ExecIf(“SIP/MyCompany-0000001d”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20287] chan_sip.c:
<— Reliably Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684387-1786302999-1329423746884-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1786302999-1329423746884-
To: "MyCompany Line"sip:[email protected];tag=as5e481750
Call-ID: [email protected]
CSeq: 65684387 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Type: application/sdp
Content-Length: 240

v=0
o=root 1183281754 1183281754 IN IP4 12.12.12.12
s=Asterisk PBX 1.8.8.0
c=IN IP4 12.12.12.12
t=0 0
m=audio 11232 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

<------------>
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:11] Set(“SIP/MyCompany-0000001d”, “NOW=1329423746”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:27] Set(“SIP/MyCompany-0000001e”, “CALLERID(name)=WIRELESS CALLER”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/MyCompany-0000001d”, “__DAY=16”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/MyCompany-0000001e”, “CHANNEL(language)=en”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:13] Set(“SIP/MyCompany-0000001d”, “__MONTH=02”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:2] Set(“SIP/MyCompany-0000001e”, “RingGroupMethod=none”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/MyCompany-0000001d”, “__YEAR=2012”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:3] Set(“SIP/MyCompany-0000001e”, “__EXTTOCALL=201”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/MyCompany-0000001d”, “__TIMESTR=20120216-152226”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:4] Set(“SIP/MyCompany-0000001e”, “__PICKUPMARK=201”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/MyCompany-0000001d”, “__FROMEXTEN=5551234564”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:5] Set(“SIP/MyCompany-0000001e”, “RT=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/MyCompany-0000001d”, “__CALLFILENAME=exten-114-5551234564-20120216-152226-1329423746.29”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@sub-record-check:18] Goto(“SIP/MyCompany-0000001d”, “exten,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:6] Gosub(“SIP/MyCompany-0000001e”, “sub-record-check,s,1(exten,201,)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (sub-record-check,exten,1)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/MyCompany-0000001e”, “1?check”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [exten@sub-record-check:1] GotoIf(“SIP/MyCompany-0000001d”, “0?callee”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (sub-record-check,s,3)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:3] Set(“SIP/MyCompany-0000001e”, “MON_FMT=wav”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [exten@sub-record-check:2] Set(“SIP/MyCompany-0000001d”, “__REC_POLICY_MODE=dontcare”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:4] GotoIf(“SIP/MyCompany-0000001e”, “1?next”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [exten@sub-record-check:3] GotoIf(“SIP/MyCompany-0000001d”, “1?caller”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (sub-record-check,s,7)
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (sub-record-check,exten,10)
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [exten@sub-record-check:10] Set(“SIP/MyCompany-0000001d”, “REC_POLICY_MODE=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:7] ExecIf(“SIP/MyCompany-0000001e”, “0?Return()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [exten@sub-record-check:11] GosubIf(“SIP/MyCompany-0000001d”, “0?record,1(exten,114,5551234564)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [exten@sub-record-check:12] Return(“SIP/MyCompany-0000001d”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:8] GotoIf(“SIP/MyCompany-0000001e”, “0?exten,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:14] Set(“SIP/MyCompany-0000001d”, “RingGroupMethod=ringallv2”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:9] Set(“SIP/MyCompany-0000001e”, “__REC_STATUS=INITIALIZED”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:15] Set(“SIP/MyCompany-0000001d”, “_FMGRP=114”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:16] GotoIf(“SIP/MyCompany-0000001d”, “1?doconfirm”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:10] ExecIf(“SIP/MyCompany-0000001e”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (from-did-direct,114,19)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:11] Set(“SIP/MyCompany-0000001e”, “NOW=1329423746”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [114@from-did-direct:19] Macro(“SIP/MyCompany-0000001d”, “dial-confirm,22,tr,114-8136798117#,114”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/MyCompany-0000001e”, “__DAY=16”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-dial-confirm:1] Set(“SIP/MyCompany-0000001d”, “DB(RG/114/SIP/MyCompany-0000001d)=RINGING”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:13] Set(“SIP/MyCompany-0000001e”, “__MONTH=02”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-dial-confirm:2] Set(“SIP/MyCompany-0000001d”, “__UNIQCHAN=SIP/MyCompany-0000001d”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/MyCompany-0000001e”, “__YEAR=2012”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-dial-confirm:3] Set(“SIP/MyCompany-0000001d”, “USE_CONFIRMATION=TRUE”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-dial-confirm:4] Set(“SIP/MyCompany-0000001d”, “RINGGROUP_INDEX=114”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/MyCompany-0000001e”, “__TIMESTR=20120216-152226”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-dial-confirm:5] Set(“SIP/MyCompany-0000001d”, “FORCE_CONFIRM=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-dial-confirm:6] Set(“SIP/MyCompany-0000001d”, “ARG4=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/MyCompany-0000001e”, “__FROMEXTEN=5551234564”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-dial-confirm:7] Macro(“SIP/MyCompany-0000001d”, “dial,22,tr,114-8136798117#”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/MyCompany-0000001e”, “__CALLFILENAME=exten-201-5551234564-20120216-152226-1329423746.30”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@sub-record-check:18] Goto(“SIP/MyCompany-0000001e”, “exten,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/MyCompany-0000001d”, “1?dial”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (sub-record-check,exten,1)
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Goto (macro-dial,s,3)
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/MyCompany-0000001d”, “dialparties.agi”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [exten@sub-record-check:1] GotoIf(“SIP/MyCompany-0000001e”, “0?callee”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [exten@sub-record-check:2] Set(“SIP/MyCompany-0000001e”, “__REC_POLICY_MODE=dontcare”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [exten@sub-record-check:3] GotoIf(“SIP/MyCompany-0000001e”, “1?caller”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (sub-record-check,exten,10)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [exten@sub-record-check:10] Set(“SIP/MyCompany-0000001e”, “REC_POLICY_MODE=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [exten@sub-record-check:11] GosubIf(“SIP/MyCompany-0000001e”, “0?record,1(exten,201,5551234564)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [exten@sub-record-check:12] Return(“SIP/MyCompany-0000001e”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:7] GotoIf(“SIP/MyCompany-0000001e”, “1?macrodial”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (macro-exten-vm,s,13)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:13] GosubIf(“SIP/MyCompany-0000001e”, “0?clrheader,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:14] Macro(“SIP/MyCompany-0000001e”, “dial-one,tr,201”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:1] Set(“SIP/MyCompany-0000001e”, “DEXTEN=201”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:2] Set(“SIP/MyCompany-0000001e”, “DIALSTATUS_CW=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:3] GosubIf(“SIP/MyCompany-0000001e”, “0?screen,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:4] GosubIf(“SIP/MyCompany-0000001e”, “0?cf,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:5] GotoIf(“SIP/MyCompany-0000001e”, “1?skip1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (macro-dial-one,s,8)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:8] GotoIf(“SIP/MyCompany-0000001e”, “0?nodial”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:9] GotoIf(“SIP/MyCompany-0000001e”, “0?continue”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:10] Set(“SIP/MyCompany-0000001e”, “EXTHASCW=ENABLED”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:11] GotoIf(“SIP/MyCompany-0000001e”, “0?next1:cwinusebusy”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (macro-dial-one,s,23)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:23] GotoIf(“SIP/MyCompany-0000001e”, “1?next3:continue”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (macro-dial-one,s,24)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:24] ExecIf(“SIP/MyCompany-0000001e”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:25] GotoIf(“SIP/MyCompany-0000001e”, “0?nodial”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:26] GosubIf(“SIP/MyCompany-0000001e”, “1?dstring,1():dlocal,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:1] Set(“SIP/MyCompany-0000001e”, “DSTRING=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:2] Set(“SIP/MyCompany-0000001e”, “DEVICES=201”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:3] ExecIf(“SIP/MyCompany-0000001e”, “0?Return()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:4] ExecIf(“SIP/MyCompany-0000001e”, “0?Set(DEVICES=01)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:5] Set(“SIP/MyCompany-0000001e”, “LOOPCNT=1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:6] Set(“SIP/MyCompany-0000001e”, “ITER=1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:7] Set(“SIP/MyCompany-0000001e”, “THISDIAL=SIP/201”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:8] GosubIf(“SIP/MyCompany-0000001e”, “1?zap2dahdi,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/MyCompany-0000001e”, “0?Return()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/MyCompany-0000001e”, “NEWDIAL=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/MyCompany-0000001e”, “LOOPCNT2=1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/MyCompany-0000001e”, “ITER2=1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/MyCompany-0000001e”, “THISPART2=SIP/201”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/MyCompany-0000001e”, “0?Set(THISPART2=DAHDI/201)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/MyCompany-0000001e”, “NEWDIAL=SIP/201&”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/MyCompany-0000001e”, “ITER2=2”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/MyCompany-0000001e”, “0?begin2”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/MyCompany-0000001e”, “THISDIAL=SIP/201”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/MyCompany-0000001e”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:9] Set(“SIP/MyCompany-0000001e”, “DSTRING=SIP/201&”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:10] Set(“SIP/MyCompany-0000001e”, “ITER=2”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:11] GotoIf(“SIP/MyCompany-0000001e”, “0?begin”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:12] Set(“SIP/MyCompany-0000001e”, “DSTRING=SIP/201”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [dstring@macro-dial-one:13] Return(“SIP/MyCompany-0000001e”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:27] GotoIf(“SIP/MyCompany-0000001e”, “0?nodial”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:28] GotoIf(“SIP/MyCompany-0000001e”, “1?skiptrace”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (macro-dial-one,s,30)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:30] Set(“SIP/MyCompany-0000001e”, “D_OPTIONS=tr”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“SIP/MyCompany-0000001e”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“SIP/MyCompany-0000001e”, “0?SIPAddHeader()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“SIP/MyCompany-0000001e”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“SIP/MyCompany-0000001e”, “0?qwait,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:35] Set(“SIP/MyCompany-0000001e”, “__CWIGNORE=”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:36] Set(“SIP/MyCompany-0000001e”, “__KEEPCID=TRUE”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:37] GotoIf(“SIP/MyCompany-0000001e”, “0?usegoto,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:38] GotoIf(“SIP/MyCompany-0000001e”, “1?godial”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (macro-dial-one,s,42)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:42] Dial(“SIP/MyCompany-0000001e”, “SIP/201,tr”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] netsock.c: == Using UDPTL TOS bits 184
[2012-02-16 15:22:26] VERBOSE[20286] netsock.c: == Using UDPTL CoS mark 5
[2012-02-16 15:22:26] VERBOSE[20286] chan_sip.c: Really destroying SIP dialog ‘[email protected]:5060’ Method: INVITE
[2012-02-16 15:22:26] WARNING[20286] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Unknown)
[2012-02-16 15:22:26] VERBOSE[20286] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:43] ExecIf(“SIP/MyCompany-0000001e”, “0?Set(DIALSTATUS=)”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:44] GosubIf(“SIP/MyCompany-0000001e”, “0?s-CHANUNAVAIL,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-dial-one:45] MacroExit(“SIP/MyCompany-0000001e”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:15] Set(“SIP/MyCompany-0000001e”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:16] GosubIf(“SIP/MyCompany-0000001e”, “0?docfu,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:17] GosubIf(“SIP/MyCompany-0000001e”, “0?docfb,1()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:18] Set(“SIP/MyCompany-0000001e”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:19] ExecIf(“SIP/MyCompany-0000001e”, “0?MacroExit()”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-exten-vm:20] GotoIf(“SIP/MyCompany-0000001e”, “1?s-CHANUNAVAIL,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (macro-exten-vm,s-CHANUNAVAIL,1)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s-CHANUNAVAIL@macro-exten-vm:1] GotoIf(“SIP/MyCompany-0000001e”, “0?exit,1”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s-CHANUNAVAIL@macro-exten-vm:2] PlayTones(“SIP/MyCompany-0000001e”, “congestion”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s-CHANUNAVAIL@macro-exten-vm:3] Congestion(“SIP/MyCompany-0000001e”, “10”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] chan_sip.c:
<— Reliably Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1040203140-1329423746883-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1040203140-1329423746883-
To: "MyCompany Line"sip:[email protected];tag=as4689919a
Call-ID: [email protected]
CSeq: 65684386 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
X-Asterisk-HangupCause: Unknown
X-Asterisk-HangupCauseCode: 20
Content-Length: 0

<------------>
[2012-02-16 15:22:26] VERBOSE[20286] app_macro.c: == Spawn extension (macro-exten-vm, s-CHANUNAVAIL, 3) exited non-zero on ‘SIP/MyCompany-0000001e’ in macro ‘exten-vm’
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: == Spawn extension (from-did-direct, 201, 2) exited non-zero on ‘SIP/MyCompany-0000001e’
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [h@from-did-direct:1] Macro(“SIP/MyCompany-0000001e”, “hangupcall,”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/MyCompany-0000001e”, “1?theend”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Goto (macro-hangupcall,s,3)
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: – Executing [s@macro-hangupcall:3] Hangup(“SIP/MyCompany-0000001e”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[20286] app_macro.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on ‘SIP/MyCompany-0000001e’ in macro ‘hangupcall’
[2012-02-16 15:22:26] VERBOSE[20286] pbx.c: == Spawn extension (from-did-direct, h, 1) exited non-zero on ‘SIP/MyCompany-0000001e’
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
CANCEL sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1040203140-1329423746883-
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1040203140-1329423746883-
To:"MyCompany Line"sip:[email protected]
Call-ID:[email protected]
CSeq:65684386 CANCEL
Reason:SIP;text=“Call completed elsewhere”;cause=200
Max-Forwards:70
Content-Length:0

<------------->
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: — (9 headers 0 lines) —
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Sending to 12.134.122.121:1029 (NAT)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: CANCEL)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— Reliably Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1040203140-1329423746883-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1040203140-1329423746883-
To: "MyCompany Line"sip:[email protected];tag=as4689919a
Call-ID: [email protected]
CSeq: 65684386 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1040203140-1329423746883-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1040203140-1329423746883-
To: "MyCompany Line"sip:[email protected];tag=as4689919a
Call-ID: [email protected]
CSeq: 65684386 CANCEL
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
CANCEL sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1753273721-1329423746882-
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1753273721-1329423746882-
To:"MyCompany Line"sip:[email protected]
Call-ID:[email protected]
CSeq:65684386 CANCEL
Reason:SIP;text=“Call completed elsewhere”;cause=200
Max-Forwards:70
Content-Length:0

<------------->
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: — (9 headers 0 lines) —
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Sending to 12.134.122.121:1029 (NAT)
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— Reliably Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1753273721-1329423746882-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1753273721-1329423746882-
To: "MyCompany Line"sip:[email protected];tag=as416c912c
Call-ID: [email protected]
CSeq: 65684386 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1753273721-1329423746882-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1753273721-1329423746882-
To: "MyCompany Line"sip:[email protected];tag=as416c912c
Call-ID: [email protected]
CSeq: 65684386 CANCEL
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
[2012-02-16 15:22:26] VERBOSE[20285] res_agi.c: – <SIP/MyCompany-0000001d>AGI Script dialparties.agi completed, returning 4
[2012-02-16 15:22:26] VERBOSE[20285] app_macro.c: == Spawn extension (macro-dial, s, 3) exited non-zero on ‘SIP/MyCompany-0000001d’ in macro ‘dial’
[2012-02-16 15:22:26] VERBOSE[20285] app_macro.c: == Spawn extension (macro-dial-confirm, s, 7) exited non-zero on ‘SIP/MyCompany-0000001d’ in macro ‘dial-confirm’
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: == Spawn extension (from-did-direct, 114, 19) exited non-zero on ‘SIP/MyCompany-0000001d’
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [h@from-did-direct:1] Macro(“SIP/MyCompany-0000001d”, “hangupcall,”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/MyCompany-0000001d”, “0?theend”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-hangupcall:2] NoOp(“SIP/MyCompany-0000001d”, “Deleting: RG/114/SIP/MyCompany-0000001d RINGING”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: – Executing [s@macro-hangupcall:3] Hangup(“SIP/MyCompany-0000001d”, “”) in new stack
[2012-02-16 15:22:26] VERBOSE[20285] app_macro.c: == Spawn extension (macro-hangupcall, s, 3) exited non-zero on ‘SIP/MyCompany-0000001d’ in macro ‘hangupcall’
[2012-02-16 15:22:26] VERBOSE[20285] pbx.c: == Spawn extension (from-did-direct, h, 1) exited non-zero on ‘SIP/MyCompany-0000001d’
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
ACK sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1040203140-1329423746883-;rport=1029
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1040203140-1329423746883-
To:"MyCompany Line"sip:[email protected];tag=as4689919a
Call-ID:[email protected]
CSeq:65684386 ACK
Max-Forwards:70
Content-Length:0

<------------->
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: — (8 headers 0 lines) —
[2012-02-16 15:22:26] VERBOSE[19698] chan_sip.c: Really destroying SIP dialog ‘[email protected]’ Method: ACK
[2012-02-16 15:22:27] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
ACK sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1040203140-1329423746883-;rport=1029
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1040203140-1329423746883-
To:"MyCompany Line"sip:[email protected];tag=as4689919a
Call-ID:[email protected]
CSeq:65684386 ACK
Max-Forwards:70
Content-Length:0

<------------->
[2012-02-16 15:22:27] VERBOSE[19698] chan_sip.c: — (8 headers 0 lines) —
[2012-02-16 15:22:27] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
ACK sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684386-1753273721-1329423746882-;rport=1029
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1753273721-1329423746882-
To:"MyCompany Line"sip:[email protected];tag=as416c912c
Call-ID:[email protected]
CSeq:65684386 ACK
Max-Forwards:70
Content-Length:0

<------------->
[2012-02-16 15:22:27] VERBOSE[19698] chan_sip.c: — (8 headers 0 lines) —
[2012-02-16 15:22:27] VERBOSE[19698] chan_sip.c: Really destroying SIP dialog ‘[email protected]’ Method: ACK
[2012-02-16 15:22:27] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
ACK sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684387A1786302999-1329423746884-
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1786302999-1329423746884-
To:"MyCompany Line"sip:[email protected];tag=as5e481750
Call-ID:[email protected]
CSeq:65684387 ACK
Contact:sip:12.134.122.121:5060
Max-Forwards:70
Content-Length:0

<------------->
[2012-02-16 15:22:27] VERBOSE[19698] chan_sip.c: — (9 headers 0 lines) —
[2012-02-16 15:22:27] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:8] Wait(“SIP/MyCompany-0000001f”, “1”) in new stack
[2012-02-16 15:22:28] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:9] Set(“SIP/MyCompany-0000001f”, “IVR_MSG=custom/MyCompany-main-ivr”) in new stack
[2012-02-16 15:22:28] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:10] Set(“SIP/MyCompany-0000001f”, “TIMEOUT(digit)=3”) in new stack
[2012-02-16 15:22:28] VERBOSE[20287] func_timeout.c: – Digit timeout set to 3.000
[2012-02-16 15:22:28] VERBOSE[20287] pbx.c: – Executing [s@ivr-1:11] ExecIf(“SIP/MyCompany-0000001f”, “1?Background(custom/MyCompany-main-ivr)”) in new stack
[2012-02-16 15:22:28] VERBOSE[20287] file.c: – <SIP/MyCompany-0000001f> Playing ‘custom/MyCompany-main-ivr.slin’ (language ‘en’)
[2012-02-16 15:22:30] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
SIP/2.0 404 Not found
Via:SIP/2.0/UDP 11.111.111.111:5060;received=12.12.12.12;branch=z9hG4bK7dae7883;rport
From:sip:[email protected];tag=as5dd3a8a6
To:sip:[email protected];tag=265631734-1329423750627
Call-ID:[email protected]
CSeq:4229 REGISTER
Content-Length:0

<------------->
[2012-02-16 15:22:30] VERBOSE[19698] chan_sip.c: — (7 headers 0 lines) —
[2012-02-16 15:22:30] ERROR[19718] app_voicemail_imapstorage.c: Couldn’t find mailbox 201 in context device
[2012-02-16 15:22:31] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
SIP/2.0 404 Not found
Via:SIP/2.0/UDP 11.111.111.111:5060;received=12.12.12.12;branch=z9hG4bK134b2425;rport
From:sip:[email protected];tag=as0801d354
To:sip:[email protected];tag=1841940262-1329423751127
Call-ID:[email protected]
CSeq:4230 REGISTER
Content-Length:0

<------------->
[2012-02-16 15:22:31] VERBOSE[19698] chan_sip.c: — (7 headers 0 lines) —
[2012-02-16 15:22:31] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
SIP/2.0 404 Not found
Via:SIP/2.0/UDP 11.111.111.111:5060;received=12.12.12.12;branch=z9hG4bK134b2425;rport
From:sip:[email protected];tag=as0801d354
To:sip:[email protected];tag=1677729592-1329423751627
Call-ID:[email protected]
CSeq:4230 REGISTER
Content-Length:0

<------------->
[2012-02-16 15:22:31] VERBOSE[19698] chan_sip.c: — (7 headers 0 lines) —
[2012-02-16 15:22:32] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
SIP/2.0 404 Not found
Via:SIP/2.0/UDP 11.111.111.111:5060;received=12.12.12.12;branch=z9hG4bK134b2425;rport
From:sip:[email protected];tag=as0801d354
To:sip:[email protected];tag=2067007163-1329423752627
Call-ID:[email protected]
CSeq:4230 REGISTER
Content-Length:0

<------------->
[2012-02-16 15:22:32] VERBOSE[19698] chan_sip.c: — (7 headers 0 lines) —
[2012-02-16 15:22:34] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
SIP/2.0 404 Not found
Via:SIP/2.0/UDP 11.111.111.111:5060;received=12.12.12.12;branch=z9hG4bK134b2425;rport
From:sip:[email protected];tag=as0801d354
To:sip:[email protected];tag=1042446419-1329423754627
Call-ID:[email protected]
CSeq:4230 REGISTER
Content-Length:0

<------------->
[2012-02-16 15:22:34] VERBOSE[19698] chan_sip.c: — (7 headers 0 lines) —
[2012-02-16 15:22:36] VERBOSE[19698] chan_sip.c:
<— SIP read from UDP:12.134.122.121:1029 —>
BYE sip:[email protected]:5060 SIP/2.0
Via:SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684388-1786302999-1329423746884-
From:"WIRELESS CALLER"sip:[email protected];user=phone;tag=1786302999-1329423746884-
To:"MyCompany Line"sip:[email protected];tag=as5e481750
Call-ID:[email protected]
CSeq:65684388 BYE
Max-Forwards:70
Content-Length:0

<------------->
[2012-02-16 15:22:36] VERBOSE[19698] chan_sip.c: — (8 headers 0 lines) —
[2012-02-16 15:22:36] VERBOSE[19698] chan_sip.c: Sending to 12.134.122.121:1029 (NAT)
[2012-02-16 15:22:36] VERBOSE[19698] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: BYE)
[2012-02-16 15:22:36] VERBOSE[19698] chan_sip.c:
<— Transmitting (NAT) to 12.134.122.121:1029 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 12.134.122.121;branch=z9hG4bKBroadWorks.2pp4ea-12.12.12.12V5060-0-65684388-1786302999-1329423746884-;received=12.134.122.121;rport=1029
From: "WIRELESS CALLER"sip:[email protected];user=phone;tag=1786302999-1329423746884-
To: "MyCompany Line"sip:[email protected];tag=as5e481750
Call-ID: [email protected]
CSeq: 65684388 BYE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0

<------------>
[2012-02-16 15:22:36] VERBOSE[20287] pbx.c: == Spawn extension (ivr-1, s, 11) exited non-zero on ‘SIP/MyCompany-0000001f’
[2012-02-16 15:22:36] VERBOSE[20287] pbx.c: – Executing [h@ivr-1:1] Hangup(“SIP/MyCompany-0000001f”, “”) in new stack
[2012-02-16 15:22:36] VERBOSE[20287] pbx.c: == Spawn extension (ivr-1, h, 1) exited non-zero on ‘SIP/MyCompany-0000001f’