This was original asked in a thread about log files.
I have one phone that will not call out to any extension. The display says unknown caller then call failed with a busy signal. I have a aastra 57CT phone. Using x-lite I can make a call to the aastra phone but not back to the x-lite phone.
Is there a log file that will track or give me more information to help me trouble shoot this issue? Where would the file be located?
Without any clues given about your installation I could say “I don’t know” but I will give it a shot.
Asterisk logs are in /var/log/asterisk and are called full, full.0, full.1 etc etc.
To get a full log you will need to type in the asterisk cli:
logger rotate
set verbose 5
Make the call then turn back the verbosity level to what it was before ( 3 or 0).
And Patrick do not forget to include info on the setup
phones local or remote?
Firewall?? God I hope so…
Right Ports / protocol forwarded to the box??
BLAH… BLAH…
This is my first real attempt at posting trouble issues. I usually prefer searching and finding someone with the same issues that I am having it usually works out for me. I have set up file servers with samba in linux without having to ask, not in this case.
The asterisk version is 1.4.21.2 should be 64 bit version running on a Dell 1430SC rack server. The network I am running is 10.10.10.0 class c network. The firewall is ip 10.10.10.1 my asterisk server is 10.10.10.166. I plan on using the last 50 IP numbers as the extensions. For instance IP 210 is extension 2100. The web based administration tool says asterisk 2.5.0.0 if that helps.
All phones are on the 10.10.10.2xx segment except the softphone it is on computer with 10.10.10.89. So far I am only trying two phone the aastra 57 CT which I purchased for the extra handset, I will not purchase another one like it because the phone handset doesn’t work under our conditions. And the softphone is x-lite. I need to find a hardphone that will make calls. At this point I haven’t set up any inbound or outbound routes because I am unable to make internal calls from a hardphone to the softphone.
I did find the logs prior to this post in the /var/log/asterisk directory and the softphone was logging information but the hardphone wasn’t logging information. I changed the verbose as suggested and the softphone is logging to the full file and the hardphone does the same thing as before not logging anything. Does that suggest that the aastra isnt seeing the PBX?
On the FreePBX extension panel the aastra phone lines so green, they go off hook it I answer in fact I can put the call on hold and call another line from the softphone both show offhook. When the aastra hardphone makes a call the phone in the panel doesn’t do anything.
Thanks for the help and if this sheds any light on the issue please let me know.
Patrick
Made a change to the firewall setting port 5060 to forward to PBX. Now I can see changes made to full from that extension. I am still unable to make a call.
Any idea what I should be looking for now?
There are two primary ways to debug: cli and log files. The cli is accessed from a linux terminal (i.e. putty) by typping asterisk -r, the logfiles can be asccesed using the log file module in FreePBX.
IN EITHER CASE there is some logging/debuging that needs to be enabled from the cli. core set verbose 3 is the absolute minimum to be useful. There is also core set debug 3 which can sometimes be helpful, but sometimes clutters things up un-nesesraly. There is also sip set debug
I hope that helps
Thanks for the tips it set the verbose back to 3. Then initiated a call from extension 210 to 289. I found a comment about not found in database will append the lines. Is this help full, did I incorrectly set up the extensions in freepbx? Also something to note in the Panel on freepbx the phone sometimes dims to light green.
[Mar 16 17:19:21] DEBUG[23296] func_db.c: DB: CFU/289 not found in database.
[Mar 16 17:19:21] VERBOSE[23296] logger.c: – Executing [s@macro-exten-vm:5] Set(“SIP/210-b002b7b0”, “CFUEXT=”) in new stack
[Mar 16 17:19:21] DEBUG[23296] app_macro.c: Executed application: Set
[Mar 16 17:19:21] DEBUG[23296] func_db.c: DB: CFB/289 not found in database.
Patrick you’ll need to post a lot more of the log as a call will be 50-60 lines not 3 or 4. CFU means call forward unconditional, CFB means call forward if busy. The two lines showing these are a very small part of a call transaction. it’s when a call comes it it’s checking the state variables so it knows what to do when it talks to the phone.
Let’s start work some more basic debug info as it looks like the Aastra phone is not properly configured to register to the phone system.
For Aastra phones you need to set the following values: proxy server, Registrar server, proxy and registrar port defaults to 5060 so unless you changed it, it should be fine. Authentication name should be the extension number, and password should be the secret you defined for the extension.
You have provided no information as to how you’ve setup the phones so I can’t help with specific details about where to go and how to change these for your setup but Aastra phones by default boot looking for a tftp server (that is defined in dhcp) that then serves the phones a config file that is named using it’s mac address in upper case followed by .cfg (000851A21E.cfg for example).
For a quick crash course on how to help us help you, read http://freepbx.org/forum/freepbx/installation/so-you-have-a-problem-and-want-help
The fun is all in the details, small things can mean big differences, like one phone being on a different network or remote to the phone system. So please help us a bit more so we can help you.
Thanks for trying to help. Using putty and logging in as Root I get the following information. I hope this helps with all the versions and updates. Some more the network and hardware setup was posted earlier.
I made some of the changes to the aastra phone and it appears to not log anything in the full file again. I made a call from extension 289 xlite softphone to the aastra hard phone 210. I must have a config issue with the aastra because it now says that it has no service. Attached is the log file from full for the call from extension 289 to 210. I will continue to mess around with the aastra to find out what I have set incorrectly.
Hopefully it is something small and easy to setup. I cant wait to get this thing running because I plan to use it in our small business we currently are limping along on an old Keysystem no voice mail.
PBX in a Flash Version 1.3 Daemon Status
pbx.local on 10.10.10.166 - eth0
CentOS release 5.2 (Final) :64 Bit Kernel: 2.6.18-92.1.6.el5
For help on PBX commands than you can run type help-pbx *
[Mar 17 17:48:23] VERBOSE[27711] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [210@from-internal:1] Macro(“SIP/289-b002b7b0”, “exten-vm|novm|210”) in new stack
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-exten-vm:1] Macro(“SIP/289-b002b7b0”, “user-callerid”) in new stack
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/289-b002b7b0”, “AMPUSER=289”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/289-b002b7b0”, “0?report”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: GotoIf
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/289-b002b7b0”, “1|Set|REALCALLERIDNUM=289”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: ExecIf
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/289-b002b7b0”, “AMPUSER=289”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/289-b002b7b0”, “AMPUSERCIDNAME=Patrick”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/289-b002b7b0”, “0?report”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: GotoIf
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/289-b002b7b0”, “AMPUSERCID=289”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/289-b002b7b0”, “CALLERID(all)=“Patrick” <289>”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:9] Set(“SIP/289-b002b7b0”, “REALCALLERIDNUM=289”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/289-b002b7b0”, “0?continue”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: GotoIf
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:11] Set(“SIP/289-b002b7b0”, “__TTL=64”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/289-b002b7b0”, “1?continue”) in new stack
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Goto (macro-user-callerid,s,19)
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: GotoIf
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-user-callerid:19] NoOp(“SIP/289-b002b7b0”, “Using CallerID “Patrick” <289>”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Noop
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Macro
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-exten-vm:2] Set(“SIP/289-b002b7b0”, “RingGroupMethod=none”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-exten-vm:3] Set(“SIP/289-b002b7b0”, “VMBOX=novm”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-exten-vm:4] Set(“SIP/289-b002b7b0”, “EXTTOCALL=210”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] DEBUG[27713] func_db.c: DB: CFU/210 not found in database.
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-exten-vm:5] Set(“SIP/289-b002b7b0”, “CFUEXT=”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] DEBUG[27713] func_db.c: DB: CFB/210 not found in database.
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-exten-vm:6] Set(“SIP/289-b002b7b0”, “CFBEXT=”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-exten-vm:7] Set(“SIP/289-b002b7b0”, “RT=”"") in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Set
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-exten-vm:8] Macro(“SIP/289-b002b7b0”, “record-enable|210|IN”) in new stack
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/289-b002b7b0”, “1?check”) in new stack
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Goto (macro-record-enable,s,4)
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: GotoIf
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-record-enable:4] AGI(“SIP/289-b002b7b0”, “recordingcheck|20090317-174824|1237330104.71”) in new stack
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Mar 17 17:48:24] VERBOSE[27713] logger.c: recordingcheck|20090317-174824|1237330104.71: Inbound recording not enabled
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – AGI Script recordingcheck completed, returning 0
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: AGI
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-record-enable:5] MacroExit(“SIP/289-b002b7b0”, “”) in new stack
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: Macro
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-exten-vm:9] Macro(“SIP/289-b002b7b0”, “dial||tr|210”) in new stack
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-dial:1] GotoIf(“SIP/289-b002b7b0”, “1?dial”) in new stack
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Goto (macro-dial,s,3)
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: GotoIf
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-dial:3] AGI(“SIP/289-b002b7b0”, “dialparties.agi”) in new stack
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[Mar 17 17:48:24] VERBOSE[27713] logger.c: dialparties.agi: Starting New Dialparties.agi
[Mar 17 17:48:24] VERBOSE[27716] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 17 17:48:24] VERBOSE[27716] logger.c: Found
[Mar 17 17:48:24] VERBOSE[27716] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 17 17:48:24] VERBOSE[27716] logger.c: Found
[Mar 17 17:48:24] VERBOSE[27716] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 17 17:48:24] VERBOSE[27716] logger.c: Found
[Mar 17 17:48:24] VERBOSE[27716] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 17 17:48:24] VERBOSE[27713] logger.c: dialparties.agi: Caller ID name is ‘Patrick’ number is ‘289’
[Mar 17 17:48:24] VERBOSE[27713] logger.c: dialparties.agi: Methodology of ring is ‘none’
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – dialparties.agi: Added extension 210 to extension map
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – dialparties.agi: Extension 210 cf is disabled
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – dialparties.agi: Extension 210 do not disturb is disabled
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – dialparties.agi: dbset CALLTRACE/210 to 289
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – dialparties.agi: Filtered ARG3: 210
[Mar 17 17:48:24] VERBOSE[27716] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – AGI Script dialparties.agi completed, returning 0
[Mar 17 17:48:24] DEBUG[27713] app_macro.c: Executed application: AGI
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Executing [s@macro-dial:7] Dial(“SIP/289-b002b7b0”, “SIP/210||tr”) in new stack
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – Called 210
[Mar 17 17:48:24] VERBOSE[27713] logger.c: – SIP/210-141d6b30 is ringing
[Mar 17 17:48:24] VERBOSE[27711] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 17 17:48:28] VERBOSE[27723] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 17 17:48:28] VERBOSE[27723] logger.c: Found
[Mar 17 17:48:28] VERBOSE[27723] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 17 17:48:28] VERBOSE[27723] logger.c: Found
[Mar 17 17:48:28] VERBOSE[27723] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 17 17:48:28] VERBOSE[27723] logger.c: Found
[Mar 17 17:48:28] VERBOSE[27723] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Mar 17 17:48:28] VERBOSE[27723] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Mar 17 17:48:30] VERBOSE[27713] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/289-b002b7b0’ in macro ‘dial’
[Mar 17 17:48:30] VERBOSE[27713] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/289-b002b7b0’ in macro ‘exten-vm’
[Mar 17 17:48:30] VERBOSE[27713] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/289-b002b7b0’
[Mar 17 17:48:30] VERBOSE[27713] logger.c: – Executing [h@macro-dial:1] Macro(“SIP/289-b002b7b0”, “hangupcall”) in new stack
[Mar 17 17:48:30] VERBOSE[27713] logger.c: – Executing [s@macro-hangupcall:1] ResetCDR(“SIP/289-b002b7b0”, “w”) in new stack
[Mar 17 17:48:30] DEBUG[27713] app_macro.c: Executed application: ResetCDR
[Mar 17 17:48:30] VERBOSE[27713] logger.c: – Executing [s@macro-hangupcall:2] NoCDR(“SIP/289-b002b7b0”, “”) in new stack
[Mar 17 17:48:30] DEBUG[27713] app_macro.c: Executed application: NoCDR
[Mar 17 17:48:30] VERBOSE[27713] logger.c: – Executing [s@macro-hangupcall:3] GotoIf(“SIP/289-b002b7b0”, “1?skiprg”) in new stack
[Mar 17 17:48:30] VERBOSE[27713] logger.c: – Goto (macro-hangupcall,s,6)
[Mar 17 17:48:30] DEBUG[27713] app_macro.c: Executed application: GotoIf
[Mar 17 17:48:30] VERBOSE[27713] logger.c: – Executing [s@macro-hangupcall:6] GotoIf(“SIP/289-b002b7b0”, “1?skipblkvm”) in new stack
[Mar 17 17:48:30] VERBOSE[27713] logger.c: – Goto (macro-hangupcall,s,9)
[Mar 17 17:48:30] DEBUG[27713] app_macro.c: Executed application: GotoIf
[Mar 17 17:48:30] VERBOSE[27713] logger.c: – Executing [s@macro-hangupcall:9] GotoIf(“SIP/289-b002b7b0”, “1?theend”) in new stack
[Mar 17 17:48:30] VERBOSE[27713] logger.c: – Goto (macro-hangupcall,s,11)
[Mar 17 17:48:30] DEBUG[27713] app_macro.c: Executed application: GotoIf
[Mar 17 17:48:30] VERBOSE[27713] logger.c: – Executing [s@macro-hangupcall:11] Hangup(“SIP/289-b002b7b0”, “”) in new stack
[Mar 17 17:48:30] VERBOSE[27713] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/289-b002b7b0’ in macro ‘hangupcall’
[Mar 17 17:48:30] VERBOSE[27713] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/289-b002b7b0’
[Mar 17 17:48:31] VERBOSE[27726] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Mar 17 17:48:31] VERBOSE[27726] logger.c: Found
[Mar 17 17:48:31] VERBOSE[27726] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Mar 17 17:48:31] VERBOSE[27726] logger.c: Found
[Mar 17 17:48:31] VERBOSE[27726] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Mar 17 17:48:31] VERBOSE[27726] logger.c: Found
[Mar 17 17:48:31] VERBOSE[27726] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
A phone will not answer if it is not registered with the phone system. And if it is not registering with the phone system then it’s config file is not setup properly.
at the asterisk cli type sip show peers and look at the extension 210.
you’ll get a output something like this:
Name/username Host Dyn Nat ACL Port Status
789/789 172.18.1.82 D N 5060 Unmonitored
420/420 172.18.1.152 D N 5060 OK (141 ms)
414/414 (Unspecified) D N 0 UNKNOWN
extension 789 and 420 are ok, 414 is a problem it’s not registered (and in my case has not been plugged for 5 months).
There are many good documents out on how to configure the Aastra phones on the web. also check out http://voip-info.org
Thanks again, I will hunt down some more documentation using the link provided. Am I correct in assuming that I am really having trouble with the x-lite softphone extension 289 and not the aastra phone?
pbx*CLI> sip show peers
Name/username Host Dyn Nat ACL Port Status
289 10.10.10.89 N 5060 UNREACHABLE
211 10.10.10.210 N 5060 OK (43 ms)
210 10.10.10.210 N 5060 OK (44 ms)
Error 403 Forbidden comes up on the xlite phone if I check the box asking for server registration.
I found that this response indicates that the server has received and understood the request but will not provide the service.
Is this something that I need to address in the extensions page?
yes that seems to be saying that 289 is the issue.
Do you have a firewall on the xlite workstation. make sure that UDP port 5060 is open.