Wrong CALLERID(num) when using macro

Asterisk Asterisk Support
1

Hi,
I have an extensions table with the following:

±----±---------±------±---------±-------±------------------------------------------+
| id | context | exten | priority | app | appdata |
±----±---------±------±---------±-------±------------------------------------------+
| 348 | incoming | _. | 1 | Macro | main-gcm-redial,${EXTEN},${CALLERID(num)} |
±----±---------±------±---------±-------±------------------------------------------+

My problem is that sometimes callerId(num) is getting wrong when entering function. Here are the logs:

[Nov 11 08:25:48] DEBUG[30967][C-0000023f] chan_sip.c: build_route: Record-Route hop: sip:sip1.rounds.com;lr;ftag=1889300186;did=8b2.667940f4
[Nov 11 08:25:48] VERBOSE[30967][C-0000023f] chan_sip.c: list_route: hop: sip:sip1.rounds.com;lr;ftag=1889300186;did=8b2.667940f4
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] chan_sip.c: SIP/US_62.219.142.171_39297-00000461: New call is still down… Trying…
[Nov 11 08:25:48] VERBOSE[30967][C-0000023f] chan_sip.c:
<— Transmitting (NAT) to 23.22.36.93:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP sip1.rounds.com;branch=z9hG4bK2888.b4455a3.0;received=23.22.36.93;rport=5060
Via: SIP/2.0/UDP 192.168.1.120:60404;received=62.219.142.171;branch=z9hG4bK1402140869;rport=8454
Record-Route: sip:sip1.rounds.com;lr;ftag=1889300186;did=8b2.667940f4
From: sip:[b][u]20000001[/u][/b]@sip1.rounds.com:5060;tag=1889300186
To: sip:20000080@xmpp1.rounds.com:5060
Call-ID: eefe1c17-23d7-f97c-b76d-66a4c2e91261
CSeq: 1128974289 INVITE
Server: PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:20000080@54.242.147.102:5060
Content-Length: 0

<------------>
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] chan_sip.c: Trying to put ‘SIP/2.0 100’ onto UDP socket destined for 23.22.36.93:5060
[Nov 11 08:25:48] DEBUG[30960] devicestate.c: No provider found, checking channel drivers for SIP - US_62.219.142.171_39297
[Nov 11 08:25:48] DEBUG[30960] chan_sip.c: Checking device state for peer US_62.219.142.171_39297
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] logger.c: CALL_ID [C-0000023f] bound to thread.
[Nov 11 08:25:48] DEBUG[30960] res_config_mysql.c: MySQL RealTime: Connection okay.
[Nov 11 08:25:48] DEBUG[30960] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = ‘US_62.219.142.171_39297’ A
ND host = ‘dynamic’
[Nov 11 08:25:48] DEBUG[30960] res_config_mysql.c: MySQL RealTime: Connection okay.
[Nov 11 08:25:48] DEBUG[30960] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = ‘US_62.219.142.171_39297’
[Nov 11 08:25:48] DEBUG[30960] chan_sip.c: -REALTIME- peer built. Name: US_62.219.142.171_39297. Peer objects: 4
[Nov 11 08:25:48] DEBUG[30960] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port.
[Nov 11 08:25:48] DEBUG[30960] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port.
[Nov 11 08:25:48] DEBUG[30960] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port.
[Nov 11 08:25:48] DEBUG[30960] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port.
[Nov 11 08:25:48] DEBUG[30960] chan_sip.c: -REALTIME- loading peer from database to memory. Name: US_62.219.142.171_39297. Peer objects: 4
[Nov 11 08:25:48] DEBUG[30960] chan_sip.c: Destroying SIP peer US_62.219.142.171_39297
[Nov 11 08:25:48] DEBUG[30960] chan_sip.c: -REALTIME- peer Destroyed. Name: US_62.219.142.171_39297. Realtime Peer objects: 3
[Nov 11 08:25:48] DEBUG[30960] devicestate.c: Changing state for SIP/US_62.219.142.171_39297 - state 5 (Unavailable)
[Nov 11 08:25:48] DEBUG[30960] devicestate.c: device ‘SIP/US_62.219.142.171_39297’ state ‘5’
[Nov 11 08:25:48] DEBUG[30995] app_queue.c: Device ‘SIP/US_62.219.142.171_39297’ changed to state ‘5’ (Unavailable) but we don’t care because they’re not a member of any queue.
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] res_config_mysql.c: MySQL RealTime: Connection okay.
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = ‘20000080’ AND host = ‘dynamic’
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] res_config_mysql.c: MySQL RealTime: Connection okay.
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE defaultuser = ‘20000080’ AND host = ‘dynamic’
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] res_config_mysql.c: MySQL RealTime: Connection okay.
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = ‘20000080’
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] chan_sip.c: -REALTIME- peer built. Name: 20000080. Peer objects: 4
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] netsock2.c: Splitting ‘23.22.36.93’ into…
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] netsock2.c: …host ‘23.22.36.93’ and port ‘’.
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] netsock2.c: Splitting ‘62.219.142.171:60192’ into…
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] netsock2.c: …host ‘62.219.142.171’ and port ‘60192’.
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port.
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port.
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] chan_sip.c: -REALTIME- loading peer from database to memory. Name: US_62.219.142.171_60192. Peer objects: 4
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] chan_sip.c: Destroying SIP peer US_62.219.142.171_60192
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] chan_sip.c: -REALTIME- peer Destroyed. Name: US_62.219.142.171_60192. Realtime Peer objects: 3
[Nov 11 08:25:48] DEBUG[30967][C-0000023f] logger.c: CALL_ID [C-0000023f] being removed from thread.
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] res_config_mysql.c: MySQL RealTime: Connection okay.
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM extensions WHERE exten = ‘20000080’ AND context = ‘incoming’ AND priority = ‘1’
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] res_config_mysql.c: MySQL RealTime: Connection okay.
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM extensions WHERE exten LIKE ‘\%’ AND context = ‘incoming’ AND priority = ‘1’ ORDER BY exten
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] res_config_mysql.c: MySQL RealTime: Connection okay.
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM extensions WHERE exten = ‘20000080’ AND context = ‘incoming’ AND priority = ‘1’
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] res_config_mysql.c: MySQL RealTime: Connection okay.
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM extensions WHERE exten LIKE '\%’ AND context = ‘incoming’ AND priority = ‘1’ ORDER BY exten
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] pbx.c: Result of ‘EXTEN’ is ‘20000080’
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] pbx.c: Function result is ‘485’
[Nov 11 08:25:48] VERBOSE[2724][C-0000023f] pbx_realtime.c: – Executing [20000080@incoming:1] Macro(“SIP/US_62.219.142.171_39297-00000461”, “main-gcm-redial,20000080,485”)
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] pbx.c: Result of ‘ARG2’ is ‘485’
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] pbx.c: Result of ‘ARG1’ is ‘20000080’
[Nov 11 08:25:48] DEBUG[2724][C-0000023f] pbx.c: Launching ‘Verbose’
[Nov 11 08:25:48] VERBOSE[2724][C-0000023f] pbx.c: – Executing [s@macro-main-gcm-redial:1] Verbose(“SIP/US_62.219.142.171_39297-00000461”, "0, “485 Calling 20000080"”) in new stack

As you can see 20000001 changed to 485.

Thanks,
Gadi

2

The 485 appears before the macro call is fully parsed, so it is not related to this being a macro (although it is possibly worth noting that macros are deprecated). Asterisk does variable substitution before it invokes the application.

It is not possible to tell that the caller ID was changed to 485 as the INVITE method is missing from the trace, so it is not possible to tell what the original caller ID was.

3

Aso, you shouldn’t use “_.” as an extension pattern match as it matches the special values, like h, i, t, etc., as well as normal extension numbers.