Nick Heinemans
2005-Jun-10 08:48 UTC
[Asterisk-Users] AAH 1.1 cannot call between extensions (xten lite softphones)
Hello all,
I've installed AAH 1.1 on my VIA C3 powered mini PC. I've made the
necessary
changes to the * makefile, so the compilation went well. The first thing I
did was configuring two extensions from AMP, namely 200 and 201. Then I
installed X-lite on two PC's and configured them with one of the extensions:
System settings - SIP proxy - Default:
Username: 200
Authorisation user: 200
Password: ****
Domain/Realm: babbelbox
SIP Proxy: babbelbox
Babbelbox is the hostname of my * server and DNS is working properly. Now
here's my problem, I can't call from one extension to the other. I tried
both ways, but after about 5 seconds of silence, I get the voicemail (which
works by the way). Also, I can make outbound calls (after configuring a SIP
trunk to my ITSP), but I cannot receive calls through this trunk. Something
makes me believe there is something wrong with the configuration of my
X-lite softphones...
Here's the logfile output:
Jun 10 11:47:38 DEBUG[18503]: Expression is '0'
Jun 10 11:47:38 VERBOSE[18503]: -- Executing
GotoIf("SIP/201-1fe7",
"0?4:3") in new stack
Jun 10 11:47:38 VERBOSE[18503]: -- Goto (macro-dial,s,3)
Jun 10 11:47:38 VERBOSE[18503]: -- Executing
SetCIDName("SIP/201-1fe7",
"Test") in new stack
Jun 10 11:47:38 VERBOSE[18503]: -- Executing AGI("SIP/201-1fe7",
"dialparties.agi") in new stack
Jun 10 11:47:38 VERBOSE[18503]: -- Launched AGI Script
/var/lib/asterisk/agi-bin/dialparties.agi
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: request dialparties.agi
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: priority = 4
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: extension = s
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: language = en
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: accountcode Jun 10
11:47:38 VERBOSE[18503]: -- dialparties.agi: uniqueid 1118418458.50
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: channel SIP/201-1fe7
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: callerid = Test
<201>
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: context macro-dial
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: type = SIP
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: rdnis = unknown
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: enhanced = 0.0
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: dnid = 200
Jun 10 11:47:38 VERBOSE[18503]: dialparties.agi: Caller ID name is
'Test'
number is '201'
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: Added extension 200
to extension map
Jun 10 11:47:38 DEBUG[18503]: Unable to find key '200' in family
'CF'
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: Extension 200 cf is
disabled
Jun 10 11:47:38 DEBUG[18503]: Unable to find key '200' in family
'DND'
Jun 10 11:47:38 VERBOSE[18503]: -- dialparties.agi: Extension 200 do
not disturb is disabled
Jun 10 11:47:49 VERBOSE[18503]: -- AGI Script dialparties.agi completed,
returning 0
Jun 10 11:47:49 VERBOSE[18503]: -- Executing NoOp("SIP/201-1fe7",
"Returned from dialparties with no extensions to call") in new stack
Jun 10 11:47:49 VERBOSE[18503]: -- Executing
SetVar("SIP/201-1fe7",
"DIALSTATUS=BUSY") in new stack
Jun 10 11:47:49 DEBUG[18503]: Expression is '0'
Jun 10 11:47:49 VERBOSE[18503]: -- Executing
GotoIf("SIP/201-1fe7",
"0?s-BUSY|1") in new stack
Jun 10 11:47:49 DEBUG[18503]: Not taking any branch
Jun 10 11:47:49 DEBUG[18503]: Expression is '0'
Jun 10 11:47:49 VERBOSE[18503]: -- Executing
GotoIf("SIP/201-1fe7",
"0?s-BUSY|1") in new stack
Jun 10 11:47:49 DEBUG[18503]: Not taking any branch
Jun 10 11:47:49 VERBOSE[18503]: -- Executing NoOp("SIP/201-1fe7",
"Sending to Voicemail box 200@default") in new stack
Jun 10 11:47:49 VERBOSE[18503]: -- Executing Macro("SIP/201-1fe7",
"vm|200@default|BUSY") in new stack
Jun 10 11:47:49 VERBOSE[18503]: -- Executing Goto("SIP/201-1fe7",
"s-BUSY|1") in new stack
Jun 10 11:47:49 VERBOSE[18503]: -- Goto (macro-vm,s-BUSY,1)
Jun 10 11:47:49 VERBOSE[18503]: -- Executing
VoiceMail("SIP/201-1fe7",
"b200@default") in new stack
Jun 10 11:47:49 DEBUG[18503]: voicemail/default/200/busy doesn't exist,
doing what we can
Jun 10 11:47:49 DEBUG[18503]: Ooh, format changed from unknown to ulaw
Jun 10 11:47:49 DEBUG[18503]: Scheduling timer at 160 sample intervals
Jun 10 11:47:49 VERBOSE[18503]: -- Playing 'vm-theperson' (language
'en')
Jun 10 11:47:49 DEBUG[1720]: Stopping retransmission on
'8ECC1CE1-BD90-43A3-BC30-D763C5DC0A6F@10.168.193.20' of Response 52707:
Found
Jun 10 11:47:51 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:47:51 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:47:51 DEBUG[18503]: Scheduling timer at 160 sample intervals
Jun 10 11:47:51 VERBOSE[18503]: -- Playing 'digits/2' (language
'en')
Jun 10 11:47:51 DEBUG[1720]: Auto destroying call
'7ECA836B-78B2-408E-BEAA-3E41363921F5@10.168.193.31'
Jun 10 11:47:51 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:47:51 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:47:51 DEBUG[18503]: Scheduling timer at 160 sample intervals
Jun 10 11:47:51 VERBOSE[18503]: -- Playing 'digits/0' (language
'en')
Jun 10 11:47:52 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:47:52 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:47:52 DEBUG[18503]: Scheduling timer at 160 sample intervals
Jun 10 11:47:52 VERBOSE[18503]: -- Playing 'digits/0' (language
'en')
Jun 10 11:47:53 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:47:53 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:47:53 DEBUG[18503]: Scheduling timer at 160 sample intervals
Jun 10 11:47:53 VERBOSE[18503]: -- Playing 'vm-isonphone' (language
'en')
Jun 10 11:47:54 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:47:54 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:47:54 DEBUG[18503]: Scheduling timer at 160 sample intervals
Jun 10 11:47:54 VERBOSE[18503]: -- Playing 'vm-intro' (language
'en')
Jun 10 11:48:00 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:48:00 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:48:00 DEBUG[18503]: Scheduling timer at 160 sample intervals
Jun 10 11:48:00 VERBOSE[18503]: -- Playing 'beep' (language
'en')
Jun 10 11:48:00 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:48:00 DEBUG[18503]: Scheduling timer at 0 sample intervals
Jun 10 11:48:00 DEBUG[18503]: Locked path
'/var/spool/asterisk/voicemail/default/200/INBOX'
Jun 10 11:48:00 VERBOSE[18503]: -- Recording the message
Jun 10 11:48:00 DEBUG[18503]: play_and_record: <None>,
/var/spool/asterisk/voicemail/default/200/INBOX/msg0001, 'wav49|wav'
Jun 10 11:48:00 DEBUG[18503]: Recording Formats: sfmts=wav49
Jun 10 11:48:00 VERBOSE[18503]: -- x=0, open writing:
/var/spool/asterisk/voicemail/default/200/INBOX/msg0001 format: wav49,
0x9515ed8
Jun 10 11:48:00 VERBOSE[18503]: -- x=1, open writing:
/var/spool/asterisk/voicemail/default/200/INBOX/msg0001 format: wav,
0x9515b18
Jun 10 11:48:00 DEBUG[18503]: Unlocked path
'/var/spool/asterisk/voicemail/default/200/INBOX'
Jun 10 11:48:02 VERBOSE[18503]: -- User hung up
Jun 10 11:48:02 VERBOSE[18503]: -- Recording was 1 seconds long but
needs to be at least 3 - abandoning
Jun 10 11:48:02 VERBOSE[18503]: == Spawn extension (macro-vm, s-BUSY, 1)
exited non-zero on 'SIP/201-1fe7' in macro 'vm'
Jun 10 11:48:02 VERBOSE[18503]: == Spawn extension (macro-exten-vm, s, 7)
exited non-zero on 'SIP/201-1fe7' in macro 'exten-vm'
Jun 10 11:48:02 VERBOSE[18503]: == Spawn extension (from-internal, 200, 1)
exited non-zero on 'SIP/201-1fe7'
Jun 10 11:48:02 VERBOSE[18503]: -- Executing Macro("SIP/201-1fe7",
"hangupcall") in new stack
Jun 10 11:48:02 VERBOSE[18503]: -- Executing
ResetCDR("SIP/201-1fe7",
"w") in new stack
Jun 10 11:48:02 DEBUG[18503]: cdr_mysql: inserting a CDR record.
Jun 10 11:48:02 DEBUG[18503]: cdr_mysql: SQL command as follows: INSERT
INTO cdr
(calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration
,billsec,disposition,amaflags,accountcode) VALUES ('2005-06-10
11:47:38','\"Test\"
<201>','201','200','from-internal',
'SIP/201-1fe7','','ResetCDR','w',24,13,'ANSWERED',3,'')
Jun 10 11:48:02 VERBOSE[18503]: -- Executing NoCDR("SIP/201-1fe7",
"")
in new stack
Jun 10 11:48:02 WARNING[18503]: CDR on channel 'SIP/201-1fe7' not posted
Jun 10 11:48:02 WARNING[18503]: CDR on channel 'SIP/201-1fe7' lacks end
Jun 10 11:48:02 VERBOSE[18503]: -- Executing Wait("SIP/201-1fe7",
"5")
in new stack
Jun 10 11:48:02 VERBOSE[18503]: == Spawn extension (macro-hangupcall, s,
3) exited non-zero on 'SIP/201-1fe7' in macro 'hangupcall'
Jun 10 11:48:02 VERBOSE[18503]: == Spawn extension (from-internal, h, 1)
exited non-zero on 'SIP/201-1fe7'
Jun 10 11:48:02 DEBUG[18503]: update_user_counter(201) - decrement inUse
counter
TIA, Nick
Possibly Parallel Threads
Wisdom of the Ancients
