TUTORIAL: Analyze data from a CLIR report
CLIR (Command Line Interface Report) is used to display Asterisk debugging information.
To obtain the CLIR for a call:
- Log in to the system administration.
- Go to Reports > CDR
- Select a call by clicking the check box check corresponding
- Click the button CLIR .
The output information is used to identify the problem; for example, if the call does not reach its destination. Please read the instructions below to learn how to interpret the debug information:
The first part of a CLIR report consists of variables that are sent to us by Asterisk. It basically gives information about who is calling whom, the caller ID, the account code, the channel type, etc.
Analysis of Asterisk variables
We have the channel type. It can be a channel SIP, IAX2 or Zap depending on the incoming transport.
VAR variables
The first part of the CLIR report shows you the declaration of the Asterisk variables; this is the part colored in blue on the report.
19:05:51 VAR: agi\_channel: SIP/1001-08185a40 The line below represents an important figure. It tells us the unique identifier of the call. Each call has a unique number which consists of the current timestamp of the call. Recordings, CDRs and CLIRs are all stored and linked to this key.
It is important to remember that on certain actions, such as leaving a queue and certain types of transfers, this number is retained. This means that 3 or 4 separate calls can have only 1 unique ID. This is how we link them on the CDR page in the latest versions.
19:05:51 VAR: agi\_uniqueid: 1173377151.6 The line below tells us the caller ID.
19:05:51 VAR: agi\_callerid:1001 Another important field is the context we are in. If the context is 'default', it means it is a local call (extension to extension, extension to the outside).
If the context is the name of the trunk, it means that it is an incoming call. In such contexts, only DIDs are allowed. This is why you may have CLIRs indicating “Destination not found” because we do not allow anything other than DIDs.
There are several other contexts that essentially tell PBXware which limitations should be applied.
When we are in a « transfer » context, there are no limitations for the destinations.
19:05:51 VAR: agi\_callingpres: 0 19:05:51 VAR: agi\_callingani2: 0 19:05:51 VAR: agi\_callington: 0 19:05:51 VAR: agi\_callingtns: 0 19:05:51 VAR: agi\_dnid: \*149 19:05:51 VAR: agi\_rdnis: unknown 19:05:51 VAR: agi\_context: default This line indicates the extension called. Here, it tells us that it is *149:
19:05:51 VAR: agi\_extension: \*149 This variable will be used to identify local extensions.
Commands
We are now going to identify the second part of the CLIR characterized by a yellow-colored background on the report. It consists of three parts:
The TIME command to be executed results from Asterisk
The command to be performed can be of two types:
- If it begins with APP: this means we are telling Asterisk to perform an action.
- If not, this means we simply return debugging information so that we can easily track what is happening in case of a problem.
result-from-asterisk generally consists of result=[value], and it is only really useful for APP inputs, because that is when we would like to read a result from Asterisk.
Here, we ask Asterisk for the variable TRANSFER_PARENT. As you can see, Asterisk stated result = 0, which means there is no such variable. If the result were, for example result = 1131023912.1, this means the variable is set.
This variable tells us that we are part of a transferred call or that we are basically a new call. This only works for blind transfers and normal transfers. Supervised transfers are displayed as new calls and therefore TRANSFER_PARENT equals 0 here.
19:05:51 APP: get variable TRANSFER\_PARENT 200 result=0 Here, we define the variable TRANSFER_PARENT with our current unique identifier. Note the __ variable prefix: this means that Asterisk must copy this variable into all calls that follow it.
19:05:51 APP: set variable \_\_TRANSFER\_PARENT 1173377151.6 200 result=1 The following line means that we detected account code 1001 from agi_accountcode.
19:05:51 Detected accountcode '1001' ... 200 result=1 Blind transfer check. If someone has transferred a third party, it means we need to force a "transfer" context that will allow that party to be transferred to any extension. This can pose a security risk, but it is the only way to successfully transfer a third party.
19:05:51 APP: get variable BLINDTRANSFER 200 result=0 Now we check whether *149 is in the DID database, for two reasons:
- Sometimes, we need to use the “default” context for SIP calls because there are many SIP Trunks that send calls from different IP addresses. This way, we detect the DID and block it immediately.
- If local extensions call a local DID, it means that we will not really dial, but in fact we will simply dial the local extension. Example: suppose we have a DID 09 74 10 10 10, if local extensions call this number, we will not dial via our Trunk, but we would in fact translate this number to extension 100.
19:05:51 '\*149' is not in DID database, continuing ... 200 result=1 Here we set a limit at the global PBXware level. For now, this indicates that we have set a limit of 246 worldwide calls.
19:05:51 Set limit - 246 200 result=1 This line shows us that Asterisk compares the global limit to the current number of calls. If the limit had been reached, the call could not have been progressed and would have failed from that point.
19:05:51 Limit not exceeded (1 < 246) for localextensions 200 result=1 Incoming/outgoing limits also exist at the extension level. For this extension, the limit is set at 3 calls:
19:05:51 Set limit - 3 200 result=1 As with the PBXware limit, the values are compared with the current number of outbound calls for extension 1001. This is the first call, so everything is fine, the limit is not exceeded:
19:05:51 Limit not exceeded (1 < 3) for 1001\_out 200 result=1 We check whether the Last Caller service (*149) is enabled for this particular extension. The service is enabled, so we proceed.
19:05:51 Lastcaller enabled 200 result=1 The call is now answered:
19:05:51 APP: answer 200 result=0 Now, the report informs us that we will play a file to the other party.
19:05:51 Playing macro 'last-num-to-call' ... 200 result=1 We are broadcasting the file.
19:05:53 APP: stream file last-num-to-call 200 result=0 endpos=19040 The report shows us the execution of the SayDigits application, which makes it possible to have the digits of a number spoken aloud.
Here, this will not work because SayDigits can only say numbers and here the variable used is “unknown”.
19:05:53 APP: exec SayDigits unknown 200 result=0 The report shows us here that we have set wait timeouts. After pressing the key, we wait an additional 3 seconds for the next digit. It also says that the overall response timeout is 6 seconds, meaning that if nothing is entered within 6 seconds, we consider this the end of the input:
19:05:53 APP: exec Set TIMEOUT(digit)=3 200 result=0 19:05:53 APP: exec Set TIMEOUT(response)=6 200 result=0 19:05:53 APP: answer 200 result=0 Now, the system plays another file:
19:05:53 Playing macro 'to-call-this-number' ... 200 result=1 19:05:55 APP: stream file to-call-this-number 200 result=0 endpos=11040 The system resets this limit again:
19:05:55 APP: exec Set TIMEOUT(response)=5 200 result=0 19:05:55 APP: exec Set TIMEOUT(digit)=3 200 result=0 Now, the report tells us to run the READ application and we tell Asterisk to read the ‘press_one’ file:
19:05:59 APP: exec read dtmfdata|press\_one 200 result=0 Now, the system will check whether the DTMF key 1 is pressed. If it is indeed pressed, the call continues. As you can see, 1 is in parentheses (1), which means that the key is indeed pressed:
19:05:59 APP: get variable dtmfdata 200 result=1 (1) Now, the system checks whether there is another network prefix assigned with the “unknown” extension:
19:05:59 Checking for 'Other Network' prefix ... 200 result=1 Since we are not another network, the system now takes the route:
19:05:59 Detecting destination for '0033501020304' ... 200 result=1 In simple routing, we can see that the route taken is the international route:
Looking for range in Simple Routing table ... 200 result=1 Found Destination 'International' (RouteID: 6) ... 200 result=1 Now, the system sets a timeout, here the timeout is one hour (3600s).
19:05:59 APP: exec Set TIMEOUT(absolute)=3600 200 result=0 19:05:59 Setting AbsoluteTimeout to 3600 seconds ... 200 result=1 Here, the system looks for a Trunk and finds a main Trunk 032445231 for this particular destination:
19:05:59 Found primary trunk '032445231' ... 200 result=1 Since there were no other Trunks, PBXware skips the secondary & tertiary trunks:
19:06:00 Secondary trunk set as '-- None --', skipping it ... 200 result=1 19:06:00 Tertiary trunk set as '-- None --', skipping it ... 200 result=1 Now, the system will try to retrieve the LCR data from the global LCR table or from the LCR table in the extensions.
19:06:00 Detecting LCR data ... 200 result=1 Once again, the system checks the local extension limits.
Set limit - 246 200 result=1 Limit not exceeded (1 < 246) for localextensions 200 result=1 The system saves our previous CallerID.
19:06:00 APP: get variable CALLERID 200 result=1 ("gloCOM" ) 19:06:00 Setting backup CallerID to 'gloCOM' ... 200 result=1 The line below highlights an important piece of information. It tells us that the Trunk is not set to make calls in E164, so there will be a number translation.
19:06:00 Trunk does not support E164 ... 200 result=1 The options below define recording elements. As we can see, "automon" is enabled, that is, "instant recording" in our interface (when you are on a call and want to start recording by entering the access code).
All variables starting with TOUCH_MONITOR_*.
For example:
- TOUCH_MONITOR_SILENT informs you that recording has started and that it is not in silent mode.
- TOUCH_MONITOR_STOP_SOUND informs us that a beep will be emitted when the recording is stopped.
The system will also save the file as wav49 and under our current unique ID (1173377151.6).
MONITOR_EXEC is a global recording variable and is not tied to ‘Instant Recording’ but rather to the ‘Record Calls’ option in Extension. Pay attention to this for additional options. For now, as you can see, it is empty, which means recording is set to “off”.
19:06:00 Dialing over PJSIP protocol ... 200 result=1 19:06:00 APP: set variable DYNAMIC_FEATURES automon 200 result=1 19:06:00 APP: set variable TOUCH_MONITOR_SILENT FALSE 200 result=1 19:06:00 APP: exec Set MONITOR_EXEC=|g 200 result=0 19:06:00 APP: set variable TOUCH_MONITOR_ARGS wav49|1173377151.6|m 200 result=1 19:06:00 APP: set variable TOUCH_MONITOR_START_SOUND recorded 200 result=1 19:06:00 APP: set variable TOUCH_MONITOR_STOP_SOUND beep 200 result=1 Now, let's make a call.
exec Dial PJSIP/101/sip:101@70.210.41.14:6654,32,trixj The system checks the state of the call (is it ANSWERED, BUSY…) and if it is ANSWERED, it checks how long the call lasted.
19:06:06 APP: get variable DIALSTATUS 200 result=1 (ANSWER) 19:06:06 APP: get variable ANSWEREDTIME 200 result=1 (4) Finally, the system shows us the total conversation time.
19:06:06 Total time: 4 200 result=1 Common issues
Some call issues related to your PBXware configuration can be resolved easily by looking at Asterisk's CLIR report, particularly the lines colored in white; here are some examples.
- Example 1: Active closing hours
If a call arrives while schedules are configured, this will appear clearly in the CLIR report.
Here, we can see that the system is retrieving the data contained in the operating hours settings.
Fetching Operation Times data ...
We can see that the schedules are enabled on the called destination:
Operation Times enabled, checking ...
Here, the system informs us that the call was made during closing hours:
Closed day/time period in effect ..
From now on, the call will be forwarded to the default destination configured in the operating times, here the voicemail of extension 108:
Returning operator '108' as new destination .. Forcing destination type to 'voicemail' (via Operation Times) ... No limit for voicemail exec Set CDR(userfield)=108 get variable CBUNIQUEID Dialing Voicemail 108 ... - Example 2: Unauthorized route
In the example below, the extension cannot make outbound calls and it is indicated that the user is not authorized to call this destination.
In the CLIR report, the error also appears:
Detecting destination for '0601020304' ... Looking for range in Simple Routing table ... Found Destination 'Mobile' (RouteID: 3) ... Loading Default Operation Times ... Skipped Operation Times ...
However, the report shows us that the extension is not authorized to go through the Mobile route, so the call will not go any further, as shown by the line "answer 200 result=0"; the following line informs us that the sound file "not_authorized" is played to the caller.
Destination 'Mobile' not allowed ... answer 200 result=0 Playing macro 'not_authorized' ..
In order to resolve the problem, all you have to do is authorize the Mobile destination in the extension concerned.
- Example 3 : DND enabled
If a call is made to an extension and that extension is in DND mode (do not disturb), this will appear in the CLIR report:
'Do Not Disturb' is enabled ... Enabling permament Do Not Disturb ... exec Answer 200 result=0 Dialing Voicemail 108 ...
The call will not go any further, as shown by the line "exec answer 200 result=0", and the call will be forwarded to the extension's voicemail as shown by the last line.
- Example 4 : Channel limit exceeded
When an incoming call arrives and all channels are already occupied, the CLIR report shows that this limit is exceeded.
First of all, Asterisk does set the channel limit to 8 (this is the configuration you specified in your PBXware settings), and a ninth call then comes in, so we can see that the limit is exceeded with the last line:
Set limit - 8 Decrementing limit for '990.lmt_localextensions' ... Limit exceeded (9 > 8) for localextensions 