I’ve got my Asterisk/FreePBX setup working with two Grandstream HT-503 gateways. The two PSTN lines from Comcast do have Caller ID: it was displaying on the previous system.
I’ve seen notes to configure the HT-503s to transfer after two rings to give the caller ID info time to insert and I’ve done this.
However still no caller ID display on the phones.
Any ideas on where to look?
Caller ID normally comes in between the first and second ring on the PSTN line. Let that ring twice before you pick up to make sure the Caller ID gets processed.
Remember, the phones aren’t answering the call - Asterisk is. Your phones are answering a call from Asterisk.
Well, no. Isn’t the gateway device picking up and then forwarding the call?
I’m holding the call at the gateway – the HT503. That has a rings before forwarding setting which I’ve set to two. So the caller ID info should be there.
So what rings setting within Asterisk are you talking about? I’ll try anything and see if it’ll work.
I did a verbose packet capture on an inbound call:
Frame 7: 1152 bytes on wire (9216 bits), 1152 bytes captured (9216 bits) on interface 0
Interface id: 0 (eth0)
Encapsulation type: Ethernet (1)
Arrival Time: Apr 16, 2016 21:33:02.553337000 PDT
[Time shift for this packet: 0.000000000 seconds]
Epoch Time: 1460867582.553337000 seconds
[Time delta from previous captured frame: 2.463686000 seconds]
[Time delta from previous displayed frame: 2.463686000 seconds]
[Time since reference or first frame: 7.470175000 seconds]
Frame Number: 7
Frame Length: 1152 bytes (9216 bits)
Capture Length: 1152 bytes (9216 bits)
[Frame is marked: False]
[Frame is ignored: False]
[Protocols in frame: eth:ethertype:ip:udp:sip:sdp]
Ethernet II, Src: Grandstr_7b:04:b9 (00:0b:82:7b:04:b9), Dst: Raspberr_dc:63:0d (b8:27:eb:dc:63:0d)
Destination: Raspberr_dc:63:0d (b8:27:eb:dc:63:0d)
Address: Raspberr_dc:63:0d (b8:27:eb:dc:63:0d)
.... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
.... ...0 .... .... .... .... = IG bit: Individual address (unicast)
Source: Grandstr_7b:04:b9 (00:0b:82:7b:04:b9)
Address: Grandstr_7b:04:b9 (00:0b:82:7b:04:b9)
.... ..0. .... .... .... .... = LG bit: Globally unique address (factory default)
.... ...0 .... .... .... .... = IG bit: Individual address (unicast)
Type: IP (0x0800)
Internet Protocol Version 4, Src: 10.0.2.22 (10.0.2.22), Dst: 10.0.2.28 (10.0.2.28)
Version: 4
Header Length: 20 bytes
Differentiated Services Field: 0x68 (DSCP 0x1a: Assured Forwarding 31; ECN: 0x00: Not-ECT (Not ECN-Capable Transport))
0110 10.. = Differentiated Services Codepoint: Assured Forwarding 31 (0x1a)
.... ..00 = Explicit Congestion Notification: Not-ECT (Not ECN-Capable Transport) (0x00)
Total Length: 1138
Identification: 0x6405 (25605)
Flags: 0x00
0... .... = Reserved bit: Not set
.0.. .... = Don't fragment: Not set
..0. .... = More fragments: Not set
Fragment offset: 0
Time to live: 64
Protocol: UDP (17)
Header checksum: 0xf9dc [validation disabled]
[Good: False]
[Bad: False]
Source: 10.0.2.22 (10.0.2.22)
Destination: 10.0.2.28 (10.0.2.28)
[Source GeoIP: Unknown]
[Destination GeoIP: Unknown]
User Datagram Protocol, Src Port: 5062 (5062), Dst Port: 5060 (5060)
Source Port: 5062 (5062)
Destination Port: 5060 (5060)
Length: 1118
Checksum: 0xc807 [validation disabled]
[Good Checksum: False]
[Bad Checksum: False]
[Stream index: 1]
Session Initiation Protocol (INVITE)
Request-Line: INVITE sip:[email protected]:5060 SIP/2.0
Method: INVITE
Request-URI: sip:[email protected]:5060
Request-URI User Part: 09253139391
Request-URI Host Part: 10.0.2.28
Request-URI Host Port: 5060
[Resent Packet: False]
Message Header
Via: SIP/2.0/UDP 10.0.2.22:5062;branch=z9hG4bK868905952;rport
Transport: UDP
Sent-by Address: 10.0.2.22
Sent-by port: 5062
Branch: z9hG4bK868905952
RPort: rport
Route: <sip:10.0.2.28:5060;lr>
Route URI: sip:10.0.2.28:5060;lr
Route Host Part: 10.0.2.28
Route Host Port: 5060
Route URI parameter: lr
From: "Martinez CA" <sip:[email protected]>;tag=993770341
SIP Display info: "Martinez CA"
SIP from address: sip:[email protected]
SIP from address User Part: 9253356110
SIP from address Host Part: 10.0.2.28
SIP from tag: 993770341
To: <sip:[email protected]:5060>
SIP to address: sip:[email protected]:5060
SIP to address User Part: 09253139391
SIP to address Host Part: 10.0.2.28
SIP to address Host Port: 5060
Call-ID: [email protected]
CSeq: 220 INVITE
Sequence Number: 220
Method: INVITE
Contact: <sip:[email protected]:5062>
Contact URI: sip:[email protected]:5062
Contact URI User Part: 09253139391
Contact URI Host Part: 10.0.2.22
Contact URI Host Port: 5062
Max-Forwards: 70
User-Agent: Grandstream HT-503 V2.0A 1.0.14.100 chip V2.2
Supported: replaces, path, timer, eventlist
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE
Content-Type: application/sdp
Accept: application/sdp, application/dtmf-relay
Content-Length: 453
Message Body
Session Description Protocol
Session Description Protocol Version (v): 0
Owner/Creator, Session Id (o): 09253139391 8002 8000 IN IP4 10.0.2.22
Owner Username: 09253139391
Session ID: 8002
Session Version: 8000
Owner Network Type: IN
Owner Address Type: IP4
Owner Address: 10.0.2.22
Session Name (s): SIP Call
Connection Information (c): IN IP4 10.0.2.22
Connection Network Type: IN
Connection Address Type: IP4
Connection Address: 10.0.2.22
Time Description, active time (t): 0 0
Session Start Time: 0
Session Stop Time: 0
Media Description, name and address (m): audio 5014 RTP/AVP 0 8 4 18 2 97 102 100 101
Media Type: audio
Media Port: 5014
Media Protocol: RTP/AVP
Media Format: ITU-T G.711 PCMU
Media Format: ITU-T G.711 PCMA
Media Format: ITU-T G.723
Media Format: ITU-T G.729
Media Format: ITU-T G.721
Media Format: DynamicRTP-Type-97
Media Format: DynamicRTP-Type-102
Media Format: DynamicRTP-Type-100
Media Format: DynamicRTP-Type-101
Media Attribute (a): sendrecv
Media Attribute (a): rtpmap:0 PCMU/8000
Media Attribute Fieldname: rtpmap
Media Format: 0
MIME Type: PCMU
Sample Rate: 8000
Media Attribute (a): ptime:20
Media Attribute Fieldname: ptime
Media Attribute Value: 20
Media Attribute (a): rtpmap:8 PCMA/8000
Media Attribute Fieldname: rtpmap
Media Format: 8
MIME Type: PCMA
Sample Rate: 8000
Media Attribute (a): rtpmap:4 G723/8000
Media Attribute Fieldname: rtpmap
Media Format: 4
MIME Type: G723
Sample Rate: 8000
Media Attribute (a): rtpmap:18 G729/8000
Media Attribute Fieldname: rtpmap
Media Format: 18
MIME Type: G729
Sample Rate: 8000
Media Attribute (a): fmtp:18 annexb=no
Media Attribute Fieldname: fmtp
Media Format: 18 [G729]
Media format specific parameters: annexb=no
Media Attribute (a): rtpmap:2 G726-32/8000
Media Attribute Fieldname: rtpmap
Media Format: 2
MIME Type: G726-32
Sample Rate: 8000
Media Attribute (a): rtpmap:97 iLBC/8000
Media Attribute Fieldname: rtpmap
Media Format: 97
MIME Type: iLBC
Sample Rate: 8000
Media Attribute (a): fmtp:97 mode=20
Media Attribute Fieldname: fmtp
Media Format: 97 [iLBC]
Media format specific parameters: mode=20
Media Attribute (a): rtpmap:102 G729E/8000
Media Attribute Fieldname: rtpmap
Media Format: 102
MIME Type: G729E
Sample Rate: 8000
Media Attribute (a): rtpmap:100 AAL2-G726-16/8000
Media Attribute Fieldname: rtpmap
Media Format: 100
MIME Type: AAL2-G726-16
Sample Rate: 8000
Media Attribute (a): rtpmap:101 telephone-event/8000
Media Attribute Fieldname: rtpmap
Media Format: 101
MIME Type: telephone-event
Sample Rate: 8000
Media Attribute (a): fmtp:101 0-16,32-36,54
Media Attribute Fieldname: fmtp
Media Format: 101 [telephone-event]
Media format specific parameters: 0-16,32-36,54
And it looks like CID is being sent.
From: "Martinez CA" <sip:[email protected]>;tag=993770341
SIP Display info: "Martinez CA"
SIP from address: sip:[email protected]
SIP from address User Part: 9253356110
That looks right to me. So can anyone suggest the next step in why I am getting no display on the phone?
So I’ve confirmed that CID info is being sent from my HT503s. But still no display on my phones.
I’m playing with a couple of things.
I have two inbound routes, one for each DID. I tried going with one inbound route and leaving the DID field blank. I thought I understood that that would match any inbound call. But a call to one of my trunks yields a “This user is busy” message instead of the phones ringing. So I’ve recreated the two inbound routes.
Next thought is that each inbound route has the same ring group as it’s destination. Could that be the cause of my CID loss? Could the ring group be the problem somehow?
Any ideas would be helpful.
Thanks.
I am still really struggling with getting Caller ID to display on my phones. I’ve gotten some help over on the Asterisk forums and have been looking at Asterisk internals but have no solution yet. I’ve been pointed at trustrpid and sendrpid but those seem to be set right.
I found a posting from 2011 that said to turn on Privacy Manager on inbound routes. I’ve tried that but CNAM values are still not getting through.
Trunks do not seem to be involved here on inbound calls. My HT-503s forward calls to a configured extension and those make use of an inbound route which in turn use a ring group to ring the physical phones. The name and number of the configured extension is what is displayed on the phones.
What I need to do is turn off the rewriting of the Caller ID info and allow the Caller ID info from the PSTN to get through. Does anyone know how to do that?
Hey Kirk,
firstly I would assume that you are getting the callerid into the HT-503.
Do they have some sort of call log or debug that you can check to see if you got a valid string from the PSTN.
If it is then next step make a call and look at the asterisk logs. 200 to 1000 lines.
Just call in and ring once or twice , do not bother to answer it.
they are very detailed and you should be able to follow the call flow to see if the callerid is passed from the HT or where it maybe getting trashed.
I am no expert but that’s the first things I would do , then shout out again.
Good luck, I have actually just sorted a callerid niggle myself so I have faith that you will resolve it, it’s not that hard after all.
Oops , just read the thread from the start.!
so it is coming thru just being lost in the pbx or on the way to the phone.
paste up some normal logs without so much clutter and I shall have a stare.
Hv.
Some advancement!! It looks like privacy manager is actually doing something. For the first time I am seeing CID information in the asterisk logs:
[2016-04-21 13:38:53] NOTICE[6617][C-0000000a] chan_sip.c: Failed to authenticate device "Martinez CA" <sip:[email protected]>;tag=1389598408
Now this call did not go through. But the info did get through.
However I am not finding any information on how to configure Privacy Manager. What I need to do is whitelist everything and then blacklist what I want.
Hey K,
Not seen Privacy Manager.
Just to confirm that the DID is going to be something you dictate.
Setting it in the HT device I would guess much like the Dahdi Channel DID’s
I would say start with the basics.
Setup one trunk per device
Create a catch all inbound route
make sure it is sending a DID,
Just check the logs it will normally advise to create a route if I remember right.
if you got the DID then you can setup an incoming route per device.
The callerid stuff you can put in some debug/custom dialplans to show you any information along the way, you can fill the logs with stuff that you need to see.
Not seen a HT device so do not have any reference point to start from.
Hv.
But hv, here is what an incoming call in /var/log/asterisk/full after turning Privacy Manager off on this line looks like:
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] GotoIf("SIP/09253131111-00000029", "1?theend") in new stack
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Goto (macro-hangupcall,s,3)
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] ExecIf("SIP/09253131111-00000029", "0?Set(CDR(recordingfile)=)") in new stack
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:4] Hangup("SIP/09253131111-00000029", "") in new stack
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/09253131111-00000029' in macro 'hangupcall'
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Spawn extension (ext-group, h, 1) exited non-zero on 'SIP/09253131111-00000029'
All that is logged is the extension information.
I am just not finding any clear information on configuring Privacy Manager.
Hey Kirk,
that’s not a stares worth, more just a couple of steps.
I have no idea what is or how to configure Privacy manager,
turn it off for now till you have things working then introduce the new stuff.
Unless I am reading this wrong.
Don’t be shy, give us a chunky log to stare at.
Hang on, that sounds very strange…
No pictures, text only thanks.
Hv.
A quick way to get the log of that particular call (30414) would be to post the result of:-
grep "\[30414\]" /var/log/asterisk/full
Okay, this seems like a lot but here you go. I had to cut out some duplicate stuff about extensions to get under the posting limit size:
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] Set("SIP/09253131111-00000029",
"__DIRECTION=INBOUND") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Gosub("SIP/09253131111-00000029", "sub-
record-check,s,1(in,09253131111,dontcare)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] GotoIf("SIP/09253131111-00000029", "0?
initialized") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Set("SIP/09253131111-00000029",
"__REC_STATUS=INITIALIZED") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] Set("SIP/09253131111-00000029", "NOW=1461272941")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:4] Set("SIP/09253131111-00000029", "__DAY=21") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:5] Set("SIP/09253131111-00000029", "__MONTH=04") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:6] Set("SIP/09253131111-00000029", "__YEAR=2016") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:7] Set("SIP/09253131111-00000029",
"__TIMESTR=20160421-140901") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:8] Set("SIP/09253131111-00000029",
"__FROMEXTEN=unknown") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:9] Set("SIP/09253131111-00000029", "__MON_FMT=wav")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:10] NoOp("SIP/09253131111-00000029", "Recordings
initialized") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:11] ExecIf("SIP/09253131111-00000029", "0?Set
(ARG3=dontcare)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000029",
"REC_POLICY_MODE_SAVE=") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:13] ExecIf("SIP/09253131111-00000029", "0?Set
(REC_STATUS=NO)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:14] GotoIf("SIP/09253131111-00000029", "2?
checkaction") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (sub-record-check,s,17)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:17] GotoIf("SIP/09253131111-00000029", "1?sub-
record-check,in,1") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (sub-record-check,in,1)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] NoOp("SIP/09253131111-00000029", "Inbound
Recording Check to 09253131111") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Set("SIP/09253131111-00000029",
"FROMEXTEN=unknown") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] ExecIf("SIP/09253131111-00000029", "11?Set
(FROMEXTEN=09253131111)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:4] Gosub("SIP/09253131111-00000029",
"recordcheck,1(dontcare,in,09253131111)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] NoOp("SIP/09253131111-00000029",
"Starting recording check against dontcare") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Goto("SIP/09253131111-00000029",
"dontcare") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (sub-record-check,recordcheck,3)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] Return("SIP/09253131111-00000029", "")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:5] Return("SIP/09253131111-00000029", "") in new
stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] Set("SIP/09253131111-00000029",
"__FROM_DID=09253131111") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:4] Set("SIP/09253131111-00000029", "CDR(did)
=09253131111") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:5] ExecIf("SIP/09253131111-00000029", "0 ?Set
(CALLERID(name)=09253131111)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:6] Set("SIP/09253131111-00000029", "CHANNEL
(musicclass)=customuploaded") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:7] Set("SIP/09253131111-00000029",
"__MOHCLASS=customuploaded") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:8] Set("SIP/09253131111-00000029",
"__REVERSAL_REJECT=FALSE") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:9] GotoIf("SIP/09253131111-00000029", "1?post-
reverse-charge") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (from-trunk,09253131111,11)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:11] NoOp("SIP/09253131111-00000029", "") in new
stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000029",
"__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:13] Set("SIP/09253131111-00000029",
"__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000029", "CALLERID
(name-pres)=allowed_not_screened") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:15] Set("SIP/09253131111-00000029", "CALLERID
(num-pres)=allowed_not_screened") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:16] NoOp("SIP/09253131111-00000029", "CallerID
Entry Point") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:17] Goto("SIP/09253131111-00000029", "ext-
group,1,1") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (ext-group,1,1)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] Progress("SIP/09253131111-00000029", "") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Macro("SIP/09253131111-00000029", "user-callerid,") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] Set("SIP/09253131111-00000029",
"TOUCH_MONITOR=1461272941.41") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Set("SIP/09253131111-00000029",
"AMPUSER=09253131111") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] GotoIf("SIP/09253131111-00000029", "0?report")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:4] ExecIf("SIP/09253131111-00000029", "1?Set
(REALCALLERIDNUM=09253131111)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:5] Set("SIP/09253131111-00000029",
"AMPUSER=09253131111") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:6] GotoIf("SIP/09253131111-00000029", "0?limit")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:7] Set("SIP/09253131111-00000029",
"AMPUSERCIDNAME=Home Line") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:8] GotoIf("SIP/09253131111-00000029", "0?report")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:9] Set("SIP/09253131111-00000029",
"AMPUSERCID=09253131111") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:10] Set("SIP/09253131111-00000029",
"__DIAL_OPTIONS=Ttr") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:11] Set("SIP/09253131111-00000029", "CALLERID
(all)="Home Line" <09253131111>") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:12] GotoIf("SIP/09253131111-00000029", "0?limit")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:13] ExecIf("SIP/09253131111-00000029", "0?Set
(GROUP(concurrency_limit)=09253131111)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:14] GotoIf("SIP/09253131111-00000029", "0?
continue") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:15] Set("SIP/09253131111-00000029", "__TTL=64")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:16] GotoIf("SIP/09253131111-00000029", "1?
continue") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (macro-user-callerid,s,27)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:27] Set("SIP/09253131111-00000029", "CALLERID
(number)=09253131111") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:28] Set("SIP/09253131111-00000029", "CALLERID
(name)=Home Line") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:29] Set("SIP/09253131111-00000029", "CDR(cnum)
=09253131111") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:30] Set("SIP/09253131111-00000029", "CDR(cnam)
=Home Line") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:31] Set("SIP/09253131111-00000029", "CHANNEL
(language)=en") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] Macro("SIP/09253131111-00000029", "blkvm-setifempty,")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] GotoIf("SIP/09253131111-00000029", "1?
init") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (macro-blkvm-setifempty,s,4)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:4] Set("SIP/09253131111-00000029",
"__BLKVM_CHANNEL=SIP/09253131111-00000029") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:5] Set("SIP/09253131111-00000029", "SHARED
(BLKVM,SIP/09253131111-00000029)=TRUE") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:6] Set("SIP/09253131111-00000029",
"GOSUB_RETVAL=TRUE") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:7] MacroExit("SIP/09253131111-00000029", "")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:4] GotoIf("SIP/09253131111-00000029", "1?skipov") in new
stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (ext-group,1,7)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:7] Set("SIP/09253131111-00000029", "RRNODEST=") in new
stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:8] Set("SIP/09253131111-00000029", "__NODEST=1") in new
stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:9] GosubIf("SIP/09253131111-00000029", "0?sub-rgsetcid,s,1
()") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:10] Gosub("SIP/09253131111-00000029", "sub-record-
check,s,1(rg,1,dontcare)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] GotoIf("SIP/09253131111-00000029", "11?
initialized") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (sub-record-check,s,10)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:10] NoOp("SIP/09253131111-00000029", "Recordings
initialized") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:11] ExecIf("SIP/09253131111-00000029", "0?Set
(ARG3=dontcare)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000029",
"REC_POLICY_MODE_SAVE=") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:13] ExecIf("SIP/09253131111-00000029", "0?Set
(REC_STATUS=NO)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:14] GotoIf("SIP/09253131111-00000029", "2?
checkaction") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (sub-record-check,s,17)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:17] GotoIf("SIP/09253131111-00000029", "0?sub-
record-check,rg,1") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:18] NoOp("SIP/09253131111-00000029", "Generic rg
Recording Check - 09253131111 1") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:19] Gosub("SIP/09253131111-00000029",
"recordcheck,1(dontcare,rg,1)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] NoOp("SIP/09253131111-00000029",
"Starting recording check against dontcare") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Goto("SIP/09253131111-00000029",
"dontcare") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (sub-record-check,recordcheck,3)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] Return("SIP/09253131111-00000029", "")
in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:20] Return("SIP/09253131111-00000029", "") in new
stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:11] Set("SIP/09253131111-00000029",
"RingGroupMethod=ringall") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:12] Macro("SIP/09253131111-00000029", "dial,35,m
(customuploaded)Tt,10-11-12-13-14-15") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] NoOp("SIP/09253131111-00000029", "Blind Transfer: ,
Attended Transfer: , User: 09253131111, Alert Info: ") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] ExecIf("SIP/09253131111-00000029", "1?Set
(ALERT_INFO=)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] ExecIf("SIP/09253131111-00000029", "0?Set
(ALERT_INFO=)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:4] ExecIf("SIP/09253131111-00000029", "0?Set
(ALERT_INFO=)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:5] ExecIf("SIP/09253131111-00000029", "1?Set(CHANNEL
(musicclass)=customuploaded)") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:6] AGI("SIP/09253131111-00000029", "dialparties.agi") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: Caller ID name is 'Home Line' number is '09253131111'
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: Methodology of ring is 'ringall'
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: Added extension 15 to extension map
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: Extension 10 cf is disabled
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: Extension 15 cf is disabled
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: Extension 10 do not disturb is disabled
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: Extension 14 do not disturb is disabled
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: Extension 15 do not disturb is disabled
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: dbset CALLTRACE/14 to 09253131111
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: dbset CALLTRACE/15 to 09253131111
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: dialparties.agi: Filtered ARG3: 10-11-12-13-14-15
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_agi.c: <SIP/09253131111-00000029>AGI Script dialparties.agi completed, returning 0
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:9] NoOp("SIP/09253131111-00000029", "Returned from
dialparties with groups to dial") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:10] Set("SIP/09253131111-00000029", "LOOPCNT=6") in new
stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:11] Set("SIP/09253131111-00000029", "ITER=1") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000029", "EXTTOCALL=10") in new
stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:13] NoOp("SIP/09253131111-00000029", "Working with 10") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000029", "ITER=2") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:15] GotoIf("SIP/09253131111-00000029", "1?ndloopbegin") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (macro-dial,s,12)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000029", "EXTTOCALL=11") in new
stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:13] NoOp("SIP/09253131111-00000029", "Working with 11") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000029", "ITER=3") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:15] GotoIf("SIP/09253131111-00000029", "1?ndloopbegin") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (macro-dial,s,12)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Goto (macro-dial,s,12)
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000029", "EXTTOCALL=15") in new
stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:13] NoOp("SIP/09253131111-00000029", "Working with 15") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000029", "ITER=7") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:15] GotoIf("SIP/09253131111-00000029", "0?ndloopbegin") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:16] Macro("SIP/09253131111-00000029", "dial-ringall-
predial-hook,") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] MacroExit("SIP/09253131111-
00000029", "") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:17] Dial("SIP/09253131111-00000029",
"SIP/10&SIP/11&SIP/12&SIP/13&SIP/14&SIP/15,35,m(customuploaded)tM(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] netsock2.c: Using SIP RTP TOS bits 184
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] netsock2.c: Using SIP RTP CoS mark 5
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] netsock2.c: Using SIP RTP CoS mark 5
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] netsock2.c: Using SIP RTP TOS bits 184
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] netsock2.c: Using SIP RTP CoS mark 5
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/10-0000002a Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] NoOp("SIP/10-0000002a", "Applying SIP
Headers to channel") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Set("SIP/10-0000002a", "SIPHEADERKEYS=") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] While("SIP/10-0000002a", "0") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_while.c: Jumping to priority 7
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:8] Return("SIP/10-0000002a", "") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/10-0000002a'
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/10-0000002a Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/11-0000002b Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] NoOp("SIP/11-0000002b", "Applying SIP
Headers to channel") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Set("SIP/11-0000002b", "SIPHEADERKEYS=") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] While("SIP/11-0000002b", "0") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_while.c: Jumping to priority 7
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]rs:8] Return("SIP/11-0000002b", "") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/11-0000002b'
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/11-0000002b Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/12-0000002c Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] NoOp("SIP/12-0000002c", "Applying SIP
Headers to channel") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Set("SIP/12-0000002c", "SIPHEADERKEYS=") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] While("SIP/12-0000002c", "0") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_while.c: Jumping to priority 7
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:8] Return("SIP/12-0000002c", "") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/12-0000002c'
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/12-0000002c Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/13-0000002d Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] NoOp("SIP/13-0000002d", "Applying SIP
Headers to channel") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Set("SIP/13-0000002d", "SIPHEADERKEYS=") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] While("SIP/13-0000002d", "0") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_while.c: Jumping to priority 7
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:8] Return("SIP/13-0000002d", "") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/13-0000002d'
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/13-0000002d Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/14-0000002e Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] NoOp("SIP/14-0000002e", "Applying SIP
Headers to channel") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Set("SIP/14-0000002e", "SIPHEADERKEYS=") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] While("SIP/14-0000002e", "0") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_while.c: Jumping to priority 7
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:8] Return("SIP/14-0000002e", "") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/14-0000002e'
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/14-0000002e Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/15-0000002f Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] NoOp("SIP/15-0000002f", "Applying SIP
Headers to channel") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:2] Set("SIP/15-0000002f", "SIPHEADERKEYS=") in
new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]func-apply-sipheaders:3] While("SIP/15-0000002f", "0") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_while.c: Jumping to priority 7
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:8] Return("SIP/15-0000002f", "") in new stack
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/15-0000002f'
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_stack.c: SIP/15-0000002f Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_dial.c: Called SIP/10
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_dial.c: Called SIP/11
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_dial.c: Called SIP/15
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] res_musiconhold.c: Started music on hold, class 'customuploaded', on channel
'SIP/09253131111-00000029'
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_dial.c: SIP/15-0000002f connected line has changed. Saving it until answer for
SIP/09253131111-00000029
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_dial.c: SIP/10-0000002a connected line has changed. Saving it until answer for
SIP/09253131111-00000029
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_dial.c: SIP/11-0000002b is ringing
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_dial.c: SIP/10-0000002a is ringing
[
[2016-04-21 14:09:01] VERBOSE[30414][C-0000000c] app_dial.c: SIP/15-0000002f is ringing
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] res_musiconhold.c: Stopped music on hold on SIP/09253131111-00000029
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] app_macro.c: Spawn extension (macro-dial, s, 17) exited non-zero on 'SIP/09253131111-
00000029' in macro 'dial'
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Spawn extension (ext-group, 1, 12) exited non-zero on 'SIP/09253131111-00000029'
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] Macro("SIP/09253131111-00000029", "hangupcall,") in new
stack
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:1] GotoIf("SIP/09253131111-00000029", "1?theend") in
new stack
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Goto (macro-hangupcall,s,3)
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:3] ExecIf("SIP/09253131111-00000029", "0?Set(CDR
(recordingfile)=)") in new stack
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Executing [[email protected]:4] Hangup("SIP/09253131111-00000029", "") in new
stack
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on
'SIP/09253131111-00000029' in macro 'hangupcall'
[2016-04-21 14:09:07] VERBOSE[30414][C-0000000c] pbx.c: Spawn extension (ext-group, h, 1) exited non-zero on 'SIP/09253131111-00000029'You should notice that you truncated the relevant lines before the important bits.
Okay, well here’s a new call. I’ll post in two parts so nothing is missing. Starts with DIRECTION=INBOUND and ends with hangupcall.
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] Set("SIP/09253131111-00000037",
"__DIRECTION=INBOUND") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Gosub("SIP/09253131111-00000037", "sub-
record-check,s,1(in,09253131111,dontcare)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] GotoIf("SIP/09253131111-00000037", "0?
initialized") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Set("SIP/09253131111-00000037",
"__REC_STATUS=INITIALIZED") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] Set("SIP/09253131111-00000037", "NOW=1461296624")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:4] Set("SIP/09253131111-00000037", "__DAY=21") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:5] Set("SIP/09253131111-00000037", "__MONTH=04") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:6] Set("SIP/09253131111-00000037", "__YEAR=2016") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:7] Set("SIP/09253131111-00000037",
"__TIMESTR=20160421-204344") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:8] Set("SIP/09253131111-00000037",
"__FROMEXTEN=unknown") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:9] Set("SIP/09253131111-00000037", "__MON_FMT=wav")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:10] NoOp("SIP/09253131111-00000037", "Recordings
initialized") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:11] ExecIf("SIP/09253131111-00000037", "0?Set
(ARG3=dontcare)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000037",
"REC_POLICY_MODE_SAVE=") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:13] ExecIf("SIP/09253131111-00000037", "0?Set
(REC_STATUS=NO)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:14] GotoIf("SIP/09253131111-00000037", "2?
checkaction") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (sub-record-check,s,17)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:17] GotoIf("SIP/09253131111-00000037", "1?sub-
record-check,in,1") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (sub-record-check,in,1)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] NoOp("SIP/09253131111-00000037", "Inbound
Recording Check to 09253131111") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Set("SIP/09253131111-00000037",
"FROMEXTEN=unknown") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] ExecIf("SIP/09253131111-00000037", "11?Set
(FROMEXTEN=09253131111)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:4] Gosub("SIP/09253131111-00000037",
"recordcheck,1(dontcare,in,09253131111)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] NoOp("SIP/09253131111-00000037",
"Starting recording check against dontcare") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Goto("SIP/09253131111-00000037",
"dontcare") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (sub-record-check,recordcheck,3)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] Return("SIP/09253131111-00000037", "")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:5] Return("SIP/09253131111-00000037", "") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] Set("SIP/09253131111-00000037",
"__FROM_DID=09253131111") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:4] Set("SIP/09253131111-00000037", "CDR(did)
=09253131111") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:5] ExecIf("SIP/09253131111-00000037", "0 ?Set
(CALLERID(name)=09253131111)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:6] Set("SIP/09253131111-00000037", "CHANNEL
(musicclass)=customuploaded") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:7] Set("SIP/09253131111-00000037",
"__MOHCLASS=customuploaded") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:8] Set("SIP/09253131111-00000037",
"__REVERSAL_REJECT=FALSE") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:9] GotoIf("SIP/09253131111-00000037", "1?post-
reverse-charge") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (from-trunk,09253131111,11)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:11] NoOp("SIP/09253131111-00000037", "") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000037",
"__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:13] Set("SIP/09253131111-00000037",
"__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000037", "CALLERID
(name-pres)=allowed_not_screened") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:15] Set("SIP/09253131111-00000037", "CALLERID
(num-pres)=allowed_not_screened") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:16] NoOp("SIP/09253131111-00000037", "CallerID
Entry Point") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:17] Goto("SIP/09253131111-00000037", "ext-
group,1,1") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (ext-group,1,1)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] Progress("SIP/09253131111-00000037", "") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Macro("SIP/09253131111-00000037", "user-callerid,") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] Set("SIP/09253131111-00000037",
"TOUCH_MONITOR=1461296624.69") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Set("SIP/09253131111-00000037",
"AMPUSER=09253131111") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] GotoIf("SIP/09253131111-00000037", "0?report")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:4] ExecIf("SIP/09253131111-00000037", "1?Set
(REALCALLERIDNUM=09253131111)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:5] Set("SIP/09253131111-00000037",
"AMPUSER=09253131111") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:6] GotoIf("SIP/09253131111-00000037", "0?limit")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:7] Set("SIP/09253131111-00000037",
"AMPUSERCIDNAME=Home Line") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:8] GotoIf("SIP/09253131111-00000037", "0?report")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:9] Set("SIP/09253131111-00000037",
"AMPUSERCID=09253131111") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:10] Set("SIP/09253131111-00000037",
"__DIAL_OPTIONS=Ttr") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:11] Set("SIP/09253131111-00000037", "CALLERID
(all)="Home Line" <09253131111>") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] GotoIf("SIP/09253131111-00000037", "0?limit")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:13] ExecIf("SIP/09253131111-00000037", "0?Set
(GROUP(concurrency_limit)=09253131111)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:14] GotoIf("SIP/09253131111-00000037", "0?
continue") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:15] Set("SIP/09253131111-00000037", "__TTL=64")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:16] GotoIf("SIP/09253131111-00000037", "1?
continue") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (macro-user-callerid,s,27)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:27] Set("SIP/09253131111-00000037", "CALLERID
(number)=09253131111") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:28] Set("SIP/09253131111-00000037", "CALLERID
(name)=Home Line") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:29] Set("SIP/09253131111-00000037", "CDR(cnum)
=09253131111") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:30] Set("SIP/09253131111-00000037", "CDR(cnam)
=Home Line") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:31] Set("SIP/09253131111-00000037", "CHANNEL
(language)=en") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] Macro("SIP/09253131111-00000037", "blkvm-setifempty,")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] GotoIf("SIP/09253131111-00000037", "1?
init") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (macro-blkvm-setifempty,s,4)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:4] Set("SIP/09253131111-00000037",
"__BLKVM_CHANNEL=SIP/09253131111-00000037") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:5] Set("SIP/09253131111-00000037", "SHARED
(BLKVM,SIP/09253131111-00000037)=TRUE") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:6] Set("SIP/09253131111-00000037",
"GOSUB_RETVAL=TRUE") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:7] MacroExit("SIP/09253131111-00000037", "")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:4] GotoIf("SIP/09253131111-00000037", "1?skipov") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (ext-group,1,7)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:7] Set("SIP/09253131111-00000037", "RRNODEST=") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:8] Set("SIP/09253131111-00000037", "__NODEST=1") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:9] GosubIf("SIP/09253131111-00000037", "0?sub-rgsetcid,s,1
()") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:10] Gosub("SIP/09253131111-00000037", "sub-record-
check,s,1(rg,1,dontcare)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] GotoIf("SIP/09253131111-00000037", "11?
initialized") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (sub-record-check,s,10)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:10] NoOp("SIP/09253131111-00000037", "Recordings
initialized") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:11] ExecIf("SIP/09253131111-00000037", "0?Set
(ARG3=dontcare)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000037",
"REC_POLICY_MODE_SAVE=") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:13] ExecIf("SIP/09253131111-00000037", "0?Set
(REC_STATUS=NO)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:14] GotoIf("SIP/09253131111-00000037", "2?
checkaction") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (sub-record-check,s,17)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:17] GotoIf("SIP/09253131111-00000037", "0?sub-
record-check,rg,1") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:18] NoOp("SIP/09253131111-00000037", "Generic rg
Recording Check - 09253131111 1") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:19] Gosub("SIP/09253131111-00000037",
"recordcheck,1(dontcare,rg,1)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] NoOp("SIP/09253131111-00000037",
"Starting recording check against dontcare") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Goto("SIP/09253131111-00000037",
"dontcare") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (sub-record-check,recordcheck,3)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] Return("SIP/09253131111-00000037", "")
in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:20] Return("SIP/09253131111-00000037", "") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:11] Set("SIP/09253131111-00000037",
"RingGroupMethod=ringall") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] Macro("SIP/09253131111-00000037", "dial,35,m
(customuploaded)Tt,10-11-12-13-14-15") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] NoOp("SIP/09253131111-00000037", "Blind Transfer: ,
Attended Transfer: , User: 09253131111, Alert Info: ") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] ExecIf("SIP/09253131111-00000037", "1?Set
(ALERT_INFO=)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] ExecIf("SIP/09253131111-00000037", "0?Set
(ALERT_INFO=)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:4] ExecIf("SIP/09253131111-00000037", "0?Set
(ALERT_INFO=)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:5] ExecIf("SIP/09253131111-00000037", "1?Set(CHANNEL
(musicclass)=customuploaded)") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:6] AGI("SIP/09253131111-00000037", "dialparties.agi") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Caller ID name is 'Home Line' number is '09253131111'
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Methodology of ring is 'ringall'
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Added extension 10 to extension map
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Added extension 11 to extension map
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Added extension 12 to extension map
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Added extension 13 to extension map
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Added extension 14 to extension map
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Added extension 15 to extension map
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 10 cf is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 11 cf is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 12 cf is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 13 cf is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 14 cf is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 15 cf is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 10 do not disturb is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 11 do not disturb is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 12 do not disturb is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 13 do not disturb is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 14 do not disturb is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Extension 15 do not disturb is disabled
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: dbset CALLTRACE/10 to 09253131111
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: dbset CALLTRACE/11 to 09253131111
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: dbset CALLTRACE/12 to 09253131111
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: dbset CALLTRACE/13 to 09253131111
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: dbset CALLTRACE/14 to 09253131111
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: dbset CALLTRACE/15 to 09253131111Here’s the second half. I’m copying and pasting and setting code formatting. If there’s a better way to post these logs, let me know.
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: dialparties.agi: Filtered ARG3: 10-11-12-13-14-15
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] res_agi.c: <SIP/09253131111-00000037>AGI Script dialparties.agi completed, returning 0
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:9] NoOp("SIP/09253131111-00000037", "Returned from
dialparties with groups to dial") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:10] Set("SIP/09253131111-00000037", "LOOPCNT=6") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:11] Set("SIP/09253131111-00000037", "ITER=1") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000037", "EXTTOCALL=10") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:13] NoOp("SIP/09253131111-00000037", "Working with 10") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000037", "ITER=2") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:15] GotoIf("SIP/09253131111-00000037", "1?ndloopbegin") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (macro-dial,s,12)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000037", "EXTTOCALL=11") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:13] NoOp("SIP/09253131111-00000037", "Working with 11") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000037", "ITER=3") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:15] GotoIf("SIP/09253131111-00000037", "1?ndloopbegin") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (macro-dial,s,12)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000037", "EXTTOCALL=12") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:13] NoOp("SIP/09253131111-00000037", "Working with 12") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000037", "ITER=4") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:15] GotoIf("SIP/09253131111-00000037", "1?ndloopbegin") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (macro-dial,s,12)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000037", "EXTTOCALL=13") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:13] NoOp("SIP/09253131111-00000037", "Working with 13") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000037", "ITER=5") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:15] GotoIf("SIP/09253131111-00000037", "1?ndloopbegin") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (macro-dial,s,12)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000037", "EXTTOCALL=14") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:13] NoOp("SIP/09253131111-00000037", "Working with 14") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000037", "ITER=6") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:15] GotoIf("SIP/09253131111-00000037", "1?ndloopbegin") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Goto (macro-dial,s,12)
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:12] Set("SIP/09253131111-00000037", "EXTTOCALL=15") in new
stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:13] NoOp("SIP/09253131111-00000037", "Working with 15") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:14] Set("SIP/09253131111-00000037", "ITER=7") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:15] GotoIf("SIP/09253131111-00000037", "0?ndloopbegin") in
new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:16] Macro("SIP/09253131111-00000037", "dial-ringall-
predial-hook,") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] MacroExit("SIP/09253131111-
00000037", "") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:17] Dial("SIP/09253131111-00000037",
"SIP/10&SIP/11&SIP/12&SIP/13&SIP/14&SIP/15,35,m(customuploaded)tM(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP TOS bits 184
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP CoS mark 5
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP TOS bits 184
[2016-04-21 20:43:44] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP CoS mark 5
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP TOS bits 184
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP CoS mark 5
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP TOS bits 184
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP CoS mark 5
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP TOS bits 184
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP CoS mark 5
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP TOS bits 184
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] netsock2.c: Using SIP RTP CoS mark 5
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/10-00000038 Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] NoOp("SIP/10-00000038", "Applying SIP
Headers to channel") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Set("SIP/10-00000038", "SIPHEADERKEYS=") in
new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] While("SIP/10-00000038", "0") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_while.c: Jumping to priority 7
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:8] Return("SIP/10-00000038", "") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/10-00000038'
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/10-00000038 Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/11-00000039 Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] NoOp("SIP/11-00000039", "Applying SIP
Headers to channel") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Set("SIP/11-00000039", "SIPHEADERKEYS=") in
new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] While("SIP/11-00000039", "0") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_while.c: Jumping to priority 7
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:8] Return("SIP/11-00000039", "") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/11-00000039'
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/11-00000039 Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/12-0000003a Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] NoOp("SIP/12-0000003a", "Applying SIP
Headers to channel") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Set("SIP/12-0000003a", "SIPHEADERKEYS=") in
new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] While("SIP/12-0000003a", "0") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_while.c: Jumping to priority 7
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:8] Return("SIP/12-0000003a", "") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/12-0000003a'
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/12-0000003a Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/13-0000003b Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] NoOp("SIP/13-0000003b", "Applying SIP
Headers to channel") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Set("SIP/13-0000003b", "SIPHEADERKEYS=") in
new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] While("SIP/13-0000003b", "0") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_while.c: Jumping to priority 7
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:8] Return("SIP/13-0000003b", "") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/13-0000003b'
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/13-0000003b Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/14-0000003c Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] NoOp("SIP/14-0000003c", "Applying SIP
Headers to channel") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Set("SIP/14-0000003c", "SIPHEADERKEYS=") in
new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] While("SIP/14-0000003c", "0") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_while.c: Jumping to priority 7
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:8] Return("SIP/14-0000003c", "") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/14-0000003c'
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/14-0000003c Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/15-0000003d Internal Gosub(func-apply-sipheaders,s,1) start
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] NoOp("SIP/15-0000003d", "Applying SIP
Headers to channel") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:2] Set("SIP/15-0000003d", "SIPHEADERKEYS=") in
new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] While("SIP/15-0000003d", "0") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_while.c: Jumping to priority 7
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:8] Return("SIP/15-0000003d", "") in new stack
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'SIP/15-0000003d'
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_stack.c: SIP/15-0000003d Internal Gosub(func-apply-sipheaders,s,1) complete
GOSUB_RETVAL=
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: Called SIP/10
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: Called SIP/11
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: Called SIP/12
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: Called SIP/13
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: Called SIP/14
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: Called SIP/15
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] res_musiconhold.c: Started music on hold, class 'customuploaded', on channel
'SIP/09253131111-00000037'
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/15-0000003d connected line has changed. Saving it until answer for
SIP/09253131111-00000037
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/14-0000003c connected line has changed. Saving it until answer for
SIP/09253131111-00000037
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/13-0000003b connected line has changed. Saving it until answer for
SIP/09253131111-00000037
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/12-0000003a connected line has changed. Saving it until answer for
SIP/09253131111-00000037
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/11-00000039 connected line has changed. Saving it until answer for
SIP/09253131111-00000037
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/10-00000038 connected line has changed. Saving it until answer for
SIP/09253131111-00000037
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/12-0000003a is ringing
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/10-00000038 is ringing
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/11-00000039 is ringing
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/13-0000003b is ringing
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/14-0000003c is ringing
[2016-04-21 20:43:45] VERBOSE[16048][C-00000017] app_dial.c: SIP/15-0000003d is ringing
[2016-04-21 20:43:56] VERBOSE[16048][C-00000017] res_musiconhold.c: Stopped music on hold on SIP/09253131111-00000037
[2016-04-21 20:43:56] VERBOSE[16048][C-00000017] app_macro.c: Spawn extension (macro-dial, s, 17) exited non-zero on 'SIP/09253131111-
00000037' in macro 'dial'
[2016-04-21 20:43:56] VERBOSE[16048][C-00000017] pbx.c: Spawn extension (ext-group, 1, 12) exited non-zero on 'SIP/09253131111-00000037'
[2016-04-21 20:43:56] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] Macro("SIP/09253131111-00000037", "hangupcall,") in new
stack
[2016-04-21 20:43:56] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:1] GotoIf("SIP/09253131111-00000037", "1?theend") in
new stack
[2016-04-21 20:43:56] VERBOSE[16048][C-00000017] pbx.c: Goto (macro-hangupcall,s,3)
[2016-04-21 20:43:56] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:3] ExecIf("SIP/09253131111-00000037", "0?Set(CDR
(recordingfile)=)") in new stack
[2016-04-21 20:43:56] VERBOSE[16048][C-00000017] pbx.c: Executing [[email protected]:4] Hangup("SIP/09253131111-00000037", "") in new
stack
[2016-04-21 20:43:56] VERBOSE[16048][C-00000017] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on
'SIP/09253131111-00000037' in macro 'hangupcall'
[2016-04-21 20:43:56] VERBOSE[16048][C-00000017] pbx.c: Spawn extension (ext-group, h, 1) exited non-zero on 'SIP/09253131111-00000037'No, still missing the important bits, compare what you have posted here with what prints when you are watching it in the asterisk cli.
How are you posting the log lines?
I grep from the asterisk log file the way you said and redirect to a text file. I replace the phone number then copy and paste into the message and set the log text to code formatting. It looks like the copy process breaks the lines into two here.
How about this. I confirmed verbose mode was on:
asterisk -rx "logger set level VERBOSE on"
and generated a new call. Here is the log information on Google Drive:
File Removed
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] pbx.c: Executing [[email protected]:11] Set("SIP/09253131111-00000007", "CALLERID(all)="Home Line" <09253131111>") in new stack
and then
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] res_agi.c: dialparties.agi: Caller ID name is 'Home Line' number is '09253131111'
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] res_agi.c: dialparties.agi: Methodology of ring is 'ringall'
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] res_agi.c: dialparties.agi: Added extension 10 to extension map
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] res_agi.c: dialparties.agi: Added extension 11 to extension map
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] res_agi.c: dialparties.agi: Added extension 12 to extension map
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] res_agi.c: dialparties.agi: Added extension 13 to extension map
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] res_agi.c: dialparties.agi: Added extension 14 to extension map
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] res_agi.c: dialparties.agi: Added extension 15 to extension map
show it is being set, then
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] app_dial.c: SIP/11-00000009 is ringing
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] app_dial.c: SIP/14-0000000c is ringing
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] app_dial.c: SIP/13-0000000b is ringing
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] app_dial.c: SIP/12-0000000a is ringing
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] app_dial.c: SIP/15-0000000d is ringing
[2016-04-22 07:56:23] VERBOSE[14594][C-00000001] app_dial.c: SIP/10-00000008 is ringing
[2016-04-22 07:56:29] VERBOSE[14594][C-00000001] res_musiconhold.c: Stopped music on hold on SIP/09253131111-00000007
show it hanging up the call after 6 seconds after ringing exts. 10-15
Yes, to generate this, I made a call from my cell (actually Google Voice), let it ring a couple of times and hung up. So the six seconds sounds right. The six phones are the phones in the house. That all looks right.
So I started looking at the code that’s doing all the monkey business with caller id: macro-user-callerid. This resides in extensions_addional.conf and is clearly marked by FreePBX as do not modify.
You jumped right to the line that I saw that is setting the caller ID as the number and name of the extension receiving the call from the HT-503.
I’m not very strong with asterisk’s macro language, but I’m seeing lots of conditional language that if some piece of CNAM is missing, set caller id this way.
Maybe I could put some code in macro-user-callerid-custom which is included and put it in extensions_custom.conf. I’d have that code log whatever CNAM info is coming from the HT-503.