Incorrect Caller ID on sip phones

EricLomm

Joined
May 19, 2009
Messages
20
Likes
0
Points
0
#1
Hello,

We have noticed in using Elastix that when we are receiving incoming calls on our SIP phones, regardless of what phone it is on, the caller ID always shows up as "home5" regardless of what number is calling us.

Is there some setting I can change so that the actual number that is calling us will be displayed?

Thanks
 

jessie

Joined
Sep 17, 2008
Messages
124
Likes
0
Points
0
#2
Hi EricLomm,

Can you send the logs when having an incoming call?

Thanks,


Jessie
 

jgutierrez

Joined
Feb 28, 2008
Messages
5,737
Likes
0
Points
0
#3
Does your problem occurs when you receive a call from an internal extension (fxs extension or sip/iax2 extension)? Or it only happens if you receive it from pstn? If that is the case, are you using analog or digital trunks?
 

EricLomm

Joined
May 19, 2009
Messages
20
Likes
0
Points
0
#4
jessie said:
Hi EricLomm,

Can you send the logs when having an incoming call?

Thanks,


Jessie
Below is the log file for an incoming call. I have changed the username and password for vitelity and the incoming phone number. But other then that this is the log from asterisk.

Code:
<------------>
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [7202575334@from-trunk:1] Set("SIP/xxxuser-xxpassword", "__FROM_DID=7202575334") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [7202575334@from-trunk:2] Gosub("SIP/xxxuser-xxpassword", "app-blacklist-check|s|1") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@app-blacklist-check:1] LookupBlacklist("SIP/xxxuser-xxpassword", "") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@app-blacklist-check:2] GotoIf("SIP/xxxuser-xxpassword", "0?blacklisted") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@app-blacklist-check:3] Return("SIP/xxxuser-xxpassword", "") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [7202575334@from-trunk:3] ExecIf("SIP/xxxuser-xxpassword", "0 |Set|CALLERID(name)=720937xxxx") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [7202575334@from-trunk:4] Set("SIP/xxxuser-xxpassword", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [7202575334@from-trunk:5] SetCallerPres("SIP/xxxuser-xxpassword", "allowed_not_screened") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [7202575334@from-trunk:6] Goto("SIP/xxxuser-xxpassword", "ivr-3|s|1") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Goto (ivr-3,s,1)
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:1] Set("SIP/xxxuser-xxpassword", "MSG=custom/360b") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:2] Set("SIP/xxxuser-xxpassword", "LOOPCOUNT=0") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:3] Set("SIP/xxxuser-xxpassword", "__DIR-CONTEXT=default") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:4] Set("SIP/xxxuser-xxpassword", "_IVR_CONTEXT_ivr-3=") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:5] Set("SIP/xxxuser-xxpassword", "_IVR_CONTEXT=ivr-3") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:6] GotoIf("SIP/xxxuser-xxpassword", "0?begin") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:7] Answer("SIP/xxxuser-xxpassword", "") in new stack
[May 28 10:54:57] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:8] Wait("SIP/xxxuser-xxpassword", "1") in new stack
[May 28 10:54:58] NOTICE[2851] chan_sip.c: -- Re-registration for xxxuser@inbound2.vitelity.net
[May 28 10:54:58] DEBUG[2851] chan_sip.c: >>> Re-using Auth data for xxxuser@inbound2.vitelity.net
[May 28 10:54:58] NOTICE[2851] chan_sip.c: Outbound Registration: Expiry for inbound2.vitelity.net is 60 sec (Scheduling reregistration in 45 s)
[May 28 10:54:58] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:9] Set("SIP/xxxuser-xxpassword", "TIMEOUT(digit)=3") in new stack
[May 28 10:54:58] VERBOSE[24097] logger.c: -- Digit timeout set to 3
[May 28 10:54:58] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:10] Set("SIP/xxxuser-xxpassword", "TIMEOUT(response)=10") in new stack
[May 28 10:54:58] VERBOSE[24097] logger.c: -- Response timeout set to 10
[May 28 10:54:58] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:11] Set("SIP/xxxuser-xxpassword", "__IVR_RETVM=") in new stack
[May 28 10:54:58] VERBOSE[24097] logger.c: -- Executing [s@ivr-3:12] ExecIf("SIP/xxxuser-xxpassword", "1|Background|custom/360b") in new stack
[May 28 10:54:58] VERBOSE[24097] logger.c: -- <SIP/xxxuser-xxpassword> Playing 'custom/360b' (language 'en')
[May 28 10:55:01] VERBOSE[2709] logger.c: -- Remote UNIX connection
[May 28 10:55:02] VERBOSE[24101] logger.c: -- Remote UNIX connection disconnected
[May 28 10:55:08] VERBOSE[24097] logger.c: == CDR updated on SIP/xxxuser-xxpassword
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [1023@ivr-3:1] ExecIf("SIP/xxxuser-xxpassword", "0|dbDel|") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [1023@ivr-3:2] Set("SIP/xxxuser-xxpassword", "__NODEST=") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [1023@ivr-3:3] Goto("SIP/xxxuser-xxpassword", "from-did-direct|1023|1") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Goto (from-did-direct,1023,1)
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [1023@from-did-direct:1] Macro("SIP/xxxuser-xxpassword", "exten-vm|1023|1023") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-exten-vm:1] Macro("SIP/xxxuser-xxpassword", "user-callerid") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:1] Set("SIP/xxxuser-xxpassword", "AMPUSER=720937xxxx") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/xxxuser-xxpassword", "0?report") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: GotoIf
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/xxxuser-xxpassword", "1|Set|REALCALLERIDNUM=720937xxxx") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: ExecIf
[May 28 10:55:08] DEBUG[24097] func_db.c: DB: DEVICE/720937xxxx/user not found in database.
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:4] Set("SIP/xxxuser-xxpassword", "AMPUSER=") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/xxxuser-xxpassword", "AMPUSERCIDNAME=Home5") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/xxxuser-xxpassword", "0?report") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: GotoIf
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:7] Set("SIP/xxxuser-xxpassword", "AMPUSERCID=") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:8] Set("SIP/xxxuser-xxpassword", "CALLERID(all)="Home5" <>") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] DEBUG[24097] func_db.c: DB: DEVICE/720937xxxx/user not found in database.
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:9] Set("SIP/xxxuser-xxpassword", "REALCALLERIDNUM=") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] DEBUG[24097] func_db.c: DB: AMPUSER//language not found in database.
[May 28 10:55:08] DEBUG[24097] func_db.c: DB: AMPUSER//language not found in database.
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:10] ExecIf("SIP/xxxuser-xxpassword", "0|Set|CHANNEL(language)=") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: ExecIf
[May 28 10:55:08] DEBUG[24097] func_db.c: DB: AMPUSER//language not found in database.
[May 28 10:55:08] DEBUG[24097] func_db.c: DB: AMPUSER//language not found in database.
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:11] GotoIf("SIP/xxxuser-xxpassword", "0?continue") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: GotoIf
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:12] Set("SIP/xxxuser-xxpassword", "__TTL=64") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:13] GotoIf("SIP/xxxuser-xxpassword", "1?continue") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Goto (macro-user-callerid,s,20)
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: GotoIf
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:20] NoOp("SIP/xxxuser-xxpassword", "Using CallerID "Home5" <>") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Noop
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Macro
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-exten-vm:2] Set("SIP/xxxuser-xxpassword", "RingGroupMethod=none") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-exten-vm:3] Set("SIP/xxxuser-xxpassword", "VMBOX=1023") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-exten-vm:4] Set("SIP/xxxuser-xxpassword", "EXTTOCALL=1023") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] DEBUG[24097] func_db.c: DB: CFU/1023 not found in database.
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-exten-vm:5] Set("SIP/xxxuser-xxpassword", "CFUEXT=") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] DEBUG[24097] func_db.c: DB: CFB/1023 not found in database.
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-exten-vm:6] Set("SIP/xxxuser-xxpassword", "CFBEXT=") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-exten-vm:7] Set("SIP/xxxuser-xxpassword", "RT=15") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-exten-vm:8] Macro("SIP/xxxuser-xxpassword", "record-enable|1023|IN") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/xxxuser-xxpassword", "1?check") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Goto (macro-record-enable,s,4)
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: GotoIf
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-record-enable:4] AGI("SIP/xxxuser-xxpassword", "recordingcheck|20090528-105508|1243529697.301") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[May 28 10:55:08] VERBOSE[24097] logger.c: recordingcheck|20090528-105508|1243529697.301: Inbound recording not enabled
[May 28 10:55:08] VERBOSE[24097] logger.c: -- AGI Script recordingcheck completed, returning 0
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: AGI
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-record-enable:5] MacroExit("SIP/xxxuser-xxpassword", "") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Macro
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-exten-vm:9] Macro("SIP/xxxuser-xxpassword", "dial|15|tr|1023") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-dial:1] GotoIf("SIP/xxxuser-xxpassword", "1?dial") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Goto (macro-dial,s,3)
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: GotoIf
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-dial:3] AGI("SIP/xxxuser-xxpassword", "dialparties.agi") in new stack
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[May 28 10:55:09] VERBOSE[24097] logger.c: dialparties.agi: Starting New Dialparties.agi
[May 28 10:55:09] VERBOSE[24106] logger.c: == Parsing '/etc/asterisk/manager.conf': [May 28 10:55:09] VERBOSE[24106] logger.c: Found
[May 28 10:55:09] VERBOSE[24106] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [May 28 10:55:09] VERBOSE[24106] logger.c: Found
[May 28 10:55:09] VERBOSE[24106] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [May 28 10:55:09] VERBOSE[24106] logger.c: Found
[May 28 10:55:09] WARNING[24106] config.c: Unknown directive '#permit=192.168.1.0/255.255.255.0' at line 18 of /etc/asterisk/manager_custom.conf
[May 28 10:55:09] VERBOSE[24106] logger.c: == Manager 'admin' logged on from 127.0.0.1
[May 28 10:55:09] VERBOSE[24097] logger.c: dialparties.agi: Caller ID name is 'Home5' number is 'unknown'
[May 28 10:55:09] VERBOSE[24097] logger.c: dialparties.agi: Methodology of ring is 'none'
[May 28 10:55:09] VERBOSE[24097] logger.c: -- dialparties.agi: Added extension 1023 to extension map
[May 28 10:55:09] VERBOSE[24097] logger.c: -- dialparties.agi: Extension 1023 cf is disabled
[May 28 10:55:09] VERBOSE[24097] logger.c: -- dialparties.agi: Extension 1023 do not disturb is disabled
[May 28 10:55:09] VERBOSE[24097] logger.c: dialparties.agi: Extension 1023 has ExtensionState: 0
[May 28 10:55:09] VERBOSE[24097] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 1023
[May 28 10:55:09] VERBOSE[24097] logger.c: -- dialparties.agi: DbDel CALLTRACE/1023 - Caller ID is not defined
[May 28 10:55:09] VERBOSE[24097] logger.c: -- dialparties.agi: Filtered ARG3: 1023
[May 28 10:55:09] VERBOSE[24106] logger.c: == Manager 'admin' logged off from 127.0.0.1
[May 28 10:55:09] VERBOSE[24097] logger.c: -- AGI Script dialparties.agi completed, returning 0
[May 28 10:55:09] DEBUG[24097] app_macro.c: Executed application: AGI
[May 28 10:55:09] VERBOSE[24097] logger.c: -- Executing [s@macro-dial:7] Dial("SIP/xxxuser-xxpassword", "SIP/1023|15|tr") in new stack
[May 28 10:55:09] NOTICE[24097] app_dial.c: Hey! chan SIP/xxxuser-xxpassword's context='macro-dial', and exten='s'
[May 28 10:55:09] DEBUG[24097] chan_sip.c: Call to peer '1023' is 1 out of 50
[May 28 10:55:09] VERBOSE[24097] logger.c: Audio is at 10.0.1.20 port 10374
[May 28 10:55:09] VERBOSE[24097] logger.c: Adding codec 0x4 (ulaw) to SDP
[May 28 10:55:09] VERBOSE[24097] logger.c: Adding codec 0x8 (alaw) to SDP
[May 28 10:55:09] VERBOSE[24097] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[May 28 10:55:09] VERBOSE[24097] logger.c: Reliably Transmitting (NAT) to 10.0.1.90:5061:
INVITE sip:1023@10.0.1.90:5061 SIP/2.0
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK66998904;rport
From: "Home5" <sip:Unknown@10.0.1.20>;tag=as0fcc7b50
To: <sip:1023@10.0.1.90:5061>
Contact: <sip:Unknown@10.0.1.20>
Call-ID: 067f639d218630b040b217a107f4ecf2@10.0.1.20
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Thu, 28 May 2009 16:55:09 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Type: application/sdp
Content-Length: 256

v=0
o=root 2689 2689 IN IP4 10.0.1.20
s=session
c=IN IP4 10.0.1.20
t=0 0
m=audio 10374 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

---
[May 28 10:55:09] VERBOSE[24097] logger.c: -- Called 1023
[May 28 10:55:09] VERBOSE[2851] logger.c:
<--- SIP read from 10.0.1.90:5061 --->
SIP/2.0 100 Trying
To: <sip:1023@10.0.1.90:5061>
From: "Home5" <sip:Unknown@10.0.1.20>;tag=as0fcc7b50
Call-ID: 067f639d218630b040b217a107f4ecf2@10.0.1.20
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK66998904
Server: Sipura/SPA841-3.1.3(a)
Content-Length: 0


<------------->
[May 28 10:55:09] VERBOSE[2851] logger.c: --- (8 headers 0 lines) ---
[May 28 10:55:09] VERBOSE[2851] logger.c:
<--- SIP read from 10.0.1.90:5061 --->
SIP/2.0 180 Ringing
To: <sip:1023@10.0.1.90:5061>;tag=25d31cf8c339d404i1
From: "Home5" <sip:Unknown@10.0.1.20>;tag=as0fcc7b50
Call-ID: 067f639d218630b040b217a107f4ecf2@10.0.1.20
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK66998904
Server: Sipura/SPA841-3.1.3(a)
Content-Length: 0


<------------->
[May 28 10:55:09] VERBOSE[2851] logger.c: --- (8 headers 0 lines) ---
[May 28 10:55:09] VERBOSE[24097] logger.c: -- SIP/1023-b7500468 is ringing
[May 28 10:55:10] VERBOSE[2851] logger.c: Reliably Transmitting (NAT) to 10.0.1.90:5060:
OPTIONS sip:23@10.0.1.90:5060 SIP/2.0
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK626aeb5e;rport
From: "Unknown" <sip:Unknown@10.0.1.20>;tag=as2095875b
To: <sip:23@10.0.1.90:5060>
Contact: <sip:Unknown@10.0.1.20>
Call-ID: 0adc848b4c80e71d501d601b28b0e9c7@10.0.1.20
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Thu, 28 May 2009 16:55:10 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


---
[May 28 10:55:10] VERBOSE[2851] logger.c:
<--- SIP read from 10.0.1.90:5060 --->
SIP/2.0 200 OK
To: <sip:23@10.0.1.90:5060>;tag=12fb9d37aad3e05di0
From: "Unknown" <sip:Unknown@10.0.1.20>;tag=as2095875b
Call-ID: 0adc848b4c80e71d501d601b28b0e9c7@10.0.1.20
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK626aeb5e
Server: Sipura/SPA841-3.1.3(a)
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER


<------------->
[May 28 10:55:10] VERBOSE[2851] logger.c: --- (9 headers 0 lines) ---
[May 28 10:55:10] VERBOSE[2851] logger.c: Really destroying SIP dialog '0adc848b4c80e71d501d601b28b0e9c7@10.0.1.20' Method: OPTIONS
[May 28 10:55:10] VERBOSE[2851] logger.c: Reliably Transmitting (NAT) to 10.0.1.90:5061:
OPTIONS sip:1023@10.0.1.90:5061 SIP/2.0
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK78a91c8a;rport
From: "Unknown" <sip:Unknown@10.0.1.20>;tag=as45c83703
To: <sip:1023@10.0.1.90:5061>
Contact: <sip:Unknown@10.0.1.20>
Call-ID: 1484db3e1caed1af05d621586ea71416@10.0.1.20
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Thu, 28 May 2009 16:55:10 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


---
[May 28 10:55:10] VERBOSE[2851] logger.c:
<--- SIP read from 10.0.1.90:5061 --->
SIP/2.0 200 OK
To: <sip:1023@10.0.1.90:5061>;tag=a033a667777fe8edi1
From: "Unknown" <sip:Unknown@10.0.1.20>;tag=as45c83703
Call-ID: 1484db3e1caed1af05d621586ea71416@10.0.1.20
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK78a91c8a
Server: Sipura/SPA841-3.1.3(a)
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER


<------------->
[May 28 10:55:10] VERBOSE[2851] logger.c: --- (9 headers 0 lines) ---
[May 28 10:55:10] VERBOSE[2851] logger.c: Really destroying SIP dialog '1484db3e1caed1af05d621586ea71416@10.0.1.20' Method: OPTIONS
[May 28 10:55:12] VERBOSE[2851] logger.c:
<--- SIP read from 10.0.1.90:5060 --->
NOTIFY sip:10.0.1.20 SIP/2.0
Via: SIP/2.0/UDP 10.0.1.90:5060;branch=z9hG4bK-ce18189f
From: "Eric" <sip:23@10.0.1.20>;tag=a919076f1dcebb85o0
To: <sip:10.0.1.20>
Call-ID: 4d8d3c2f-3f7a0dc5@10.0.1.90
CSeq: 6368 NOTIFY
Max-Forwards: 70
Event: keep-alive
User-Agent: Sipura/SPA841-3.1.3(a)
Content-Length: 0


<------------->
[May 28 10:55:12] VERBOSE[2851] logger.c: --- (10 headers 0 lines) ---
[May 28 10:55:12] VERBOSE[2851] logger.c: Sending to 10.0.1.90 : 5060 (no NAT)
[May 28 10:55:12] VERBOSE[2851] logger.c:
<--- Transmitting (no NAT) to 10.0.1.90:5060 --->
SIP/2.0 489 Bad event
Via: SIP/2.0/UDP 10.0.1.90:5060;branch=z9hG4bK-ce18189f;received=10.0.1.90
From: "Eric" <sip:23@10.0.1.20>;tag=a919076f1dcebb85o0
To: <sip:10.0.1.20>;tag=as495171f5
Call-ID: 4d8d3c2f-3f7a0dc5@10.0.1.90
CSeq: 6368 NOTIFY
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


<------------>
[May 28 10:55:13] DEBUG[24097] chan_sip.c: Call to peer '1023' removed from call limit 50
[May 28 10:55:13] VERBOSE[24097] logger.c: Scheduling destruction of SIP dialog '067f639d218630b040b217a107f4ecf2@10.0.1.20' in 6400 ms (Method: INVITE)
[May 28 10:55:13] VERBOSE[24097] logger.c: Reliably Transmitting (NAT) to 10.0.1.90:5061:
CANCEL sip:1023@10.0.1.90:5061 SIP/2.0
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK66998904;rport
From: "Home5" <sip:Unknown@10.0.1.20>;tag=as0fcc7b50
To: <sip:1023@10.0.1.90:5061>
Call-ID: 067f639d218630b040b217a107f4ecf2@10.0.1.20
CSeq: 102 CANCEL
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


---
[May 28 10:55:13] VERBOSE[24097] logger.c: Scheduling destruction of SIP dialog '067f639d218630b040b217a107f4ecf2@10.0.1.20' in 6400 ms (Method: INVITE)
[May 28 10:55:13] VERBOSE[24097] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on 'SIP/xxxuser-xxpassword' in macro 'dial'
[May 28 10:55:13] VERBOSE[24097] logger.c: == Spawn extension (macro-exten-vm, s, 9) exited non-zero on 'SIP/xxxuser-xxpassword' in macro 'exten-vm'
[May 28 10:55:13] VERBOSE[24097] logger.c: == Spawn extension (from-did-direct, 1023, 1) exited non-zero on 'SIP/xxxuser-xxpassword'
[May 28 10:55:13] VERBOSE[24097] logger.c: -- Executing [h@macro-dial:1] Macro("SIP/xxxuser-xxpassword", "hangupcall") in new stack
[May 28 10:55:13] VERBOSE[24097] logger.c: -- Executing [s@macro-hangupcall:1] ResetCDR("SIP/xxxuser-xxpassword", "vw") in new stack
[May 28 10:55:13] DEBUG[24097] app_macro.c: Executed application: ResetCDR
[May 28 10:55:13] VERBOSE[24097] logger.c: -- Executing [s@macro-hangupcall:2] NoCDR("SIP/xxxuser-xxpassword", "") in new stack
[May 28 10:55:13] DEBUG[24097] app_macro.c: Executed application: NoCDR
[May 28 10:55:13] VERBOSE[24097] logger.c: -- Executing [s@macro-hangupcall:3] GotoIf("SIP/xxxuser-xxpassword", "1?skiprg") in new stack
[May 28 10:55:13] VERBOSE[24097] logger.c: -- Goto (macro-hangupcall,s,6)
[May 28 10:55:13] DEBUG[24097] app_macro.c: Executed application: GotoIf
[May 28 10:55:13] VERBOSE[24097] logger.c: -- Executing [s@macro-hangupcall:6] GotoIf("SIP/xxxuser-xxpassword", "1?skipblkvm") in new stack
[May 28 10:55:13] VERBOSE[24097] logger.c: -- Goto (macro-hangupcall,s,9)
[May 28 10:55:13] DEBUG[24097] app_macro.c: Executed application: GotoIf
[May 28 10:55:13] VERBOSE[24097] logger.c: -- Executing [s@macro-hangupcall:9] GotoIf("SIP/xxxuser-xxpassword", "1?theend") in new stack
[May 28 10:55:13] VERBOSE[24097] logger.c: -- Goto (macro-hangupcall,s,11)
[May 28 10:55:13] DEBUG[24097] app_macro.c: Executed application: GotoIf
[May 28 10:55:13] VERBOSE[24097] logger.c: -- Executing [s@macro-hangupcall:11] Hangup("SIP/xxxuser-xxpassword", "") in new stack
[May 28 10:55:13] VERBOSE[24097] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/xxxuser-xxpassword' in macro 'hangupcall'
[May 28 10:55:13] VERBOSE[24097] logger.c: == Spawn extension (macro-dial, h, 1) exited non-zero on 'SIP/xxxuser-xxpassword'
[May 28 10:55:13] VERBOSE[2851] logger.c:
<--- SIP read from 10.0.1.90:5061 --->
SIP/2.0 487 Request Terminated
To: <sip:1023@10.0.1.90:5061>;tag=25d31cf8c339d404i1
From: "Home5" <sip:Unknown@10.0.1.20>;tag=as0fcc7b50
Call-ID: 067f639d218630b040b217a107f4ecf2@10.0.1.20
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK66998904
Server: Sipura/SPA841-3.1.3(a)
Content-Length: 0


<------------->
[May 28 10:55:13] VERBOSE[2851] logger.c: --- (8 headers 0 lines) ---
[May 28 10:55:13] VERBOSE[2851] logger.c: Transmitting (NAT) to 10.0.1.90:5061:
ACK sip:1023@10.0.1.90:5061 SIP/2.0
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK66998904;rport
From: "Home5" <sip:Unknown@10.0.1.20>;tag=as0fcc7b50
To: <sip:1023@10.0.1.90:5061>;tag=25d31cf8c339d404i1
Contact: <sip:Unknown@10.0.1.20>
Call-ID: 067f639d218630b040b217a107f4ecf2@10.0.1.20
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


---
[May 28 10:55:13] DEBUG[2851] chan_sip.c: Call to peer '1023' removed from call limit 50
[May 28 10:55:13] VERBOSE[2851] logger.c:
<--- SIP read from 10.0.1.90:5061 --->
SIP/2.0 200 OK
To: <sip:1023@10.0.1.90:5061>;tag=25d31cf8c339d404i1
From: "Home5" <sip:Unknown@10.0.1.20>;tag=as0fcc7b50
Call-ID: 067f639d218630b040b217a107f4ecf2@10.0.1.20
CSeq: 102 CANCEL
Via: SIP/2.0/UDP 10.0.1.20:5060;branch=z9hG4bK66998904
Server: Sipura/SPA841-3.1.3(a)
Content-Length: 0


<------------->
[May 28 10:55:13] VERBOSE[2851] logger.c: --- (8 headers 0 lines) ---
[May 28 10:55:13] VERBOSE[2851] logger.c: Really destroying SIP dialog '067f639d218630b040b217a107f4ecf2@10.0.1.20' Method: INVITE
[May 28 10:55:27] VERBOSE[2851] logger.c:
<--- SIP read from 10.0.1.90:5060 --->
NOTIFY sip:10.0.1.20 SIP/2.0
Via: SIP/2.0/UDP 10.0.1.90:5060;branch=z9hG4bK-bab13be1
From: "Eric" <sip:23@10.0.1.20>;tag=a919076f1dcebb85o0
To: <sip:10.0.1.20>
Call-ID: 4d8d3c2f-3f7a0dc5@10.0.1.90
CSeq: 6369 NOTIFY
Max-Forwards: 70
Event: keep-alive
User-Agent: Sipura/SPA841-3.1.3(a)
Content-Length: 0


<------------->
[May 28 10:55:27] VERBOSE[2851] logger.c: --- (10 headers 0 lines) ---
[May 28 10:55:27] VERBOSE[2851] logger.c: Sending to 10.0.1.90 : 5060 (no NAT)
[May 28 10:55:27] VERBOSE[2851] logger.c:
<--- Transmitting (no NAT) to 10.0.1.90:5060 --->
SIP/2.0 489 Bad event
Via: SIP/2.0/UDP 10.0.1.90:5060;branch=z9hG4bK-bab13be1;received=10.0.1.90
From: "Eric" <sip:23@10.0.1.20>;tag=a919076f1dcebb85o0
To: <sip:10.0.1.20>;tag=as3047f1cc
Call-ID: 4d8d3c2f-3f7a0dc5@10.0.1.90
CSeq: 6369 NOTIFY
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


<------------>
[May 28 10:55:29] VERBOSE[24109] logger.c: == Parsing '/etc/asterisk/manager.conf': [May 28 10:55:29] VERBOSE[24109] logger.c: Found
[May 28 10:55:29] VERBOSE[24109] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [May 28 10:55:29] VERBOSE[24109] logger.c: Found
[May 28 10:55:29] VERBOSE[24109] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [May 28 10:55:29] VERBOSE[24109] logger.c: Found
[May 28 10:55:29] WARNING[24109] config.c: Unknown directive '#permit=192.168.1.0/255.255.255.0' at line 18 of /etc/asterisk/manager_custom.conf
[May 28 10:55:29] VERBOSE[24109] logger.c: == Manager 'admin' logged on from 127.0.0.1
[May 28 10:55:29] VERBOSE[24109] logger.c: == Manager 'admin' logged off from 127.0.0.1
[May 28 10:55:31] VERBOSE[24111] logger.c: == Parsing '/etc/asterisk/manager.conf': [May 28 10:55:31] VERBOSE[24111] logger.c: Found
[May 28 10:55:31] VERBOSE[24111] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [May 28 10:55:31] VERBOSE[24111] logger.c: Found
[May 28 10:55:31] VERBOSE[24111] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [May 28 10:55:31] VERBOSE[24111] logger.c: Found
[May 28 10:55:31] WARNING[24111] config.c: Unknown directive '#permit=192.168.1.0/255.255.255.0' at line 18 of /etc/asterisk/manager_custom.conf
[May 28 10:55:31] VERBOSE[24111] logger.c: == Manager 'admin' logged on from 127.0.0.1
 

EricLomm

Joined
May 19, 2009
Messages
20
Likes
0
Points
0
#5
jgutierrez said:
Does your problem occurs when you receive a call from an internal extension (fxs extension or sip/iax2 extension)? Or it only happens if you receive it from pstn? If that is the case, are you using analog or digital trunks?
This problem does not occur when we are calling from an internal extenstion. This only happens when we are receiving calls from outside our organization. As far as I know our trunks are digital. in looking at the log files that we receive the incoming call information is being provided to us.
 

dicko

Joined
Oct 24, 2008
Messages
4,099
Likes
0
Points
0
#6
from your post
Code:
.
.
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:4] Set("SIP/xxxuser-xxpassword", "AMPUSER=") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/xxxuser-xxpassword", "AMPUSERCIDNAME=Home5") in new stack
[May 28 10:55:08] DEBUG[24097] app_macro.c: Executed application: Set
[May 28 10:55:08] VERBOSE[24097] logger.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/xxxuser-xxpassword", "0?report") in new stack
[May 28 10:55:08] DEBUG
.
.
and from freepbx extensions_additional.conf

[macro-user-callerid]
.
.
exten => s,n,Set(AMPUSERCIDNAME=${DB(AMPUSER/${AMPUSER}/cidname)})
exten => s,n,GotoIf($["x${AMPUSERCIDNAME:1:2}" = "x"]?report)
exten => s,n,Set(AMPUSERCID=${IF($["${DB_EXISTS(AMPUSER/${AMPUSER}/cidnum)}" = "1"]?${DB_RESULT}:${AMPUSER}
.
; end of [macro-user-callerid]

seems to show that somehow you have managed to get AMPUSER/<null>/cidname set to "home5".

rasterisk -x "database showkey Home5"

will identify the culprit(s) and then database del from the asterisk to suit. but it might well return on reloading the sql stuff at startup, do you (or your boss) remember typing home5 at any time in freepbx ?

grep -Hi home5 /etc/asterisk/ext*

will identify any freepbx file containing that string, which might help
 

EricLomm

Joined
May 19, 2009
Messages
20
Likes
0
Points
0
#7
When I type the command:

rasterisk -x "database showkey Home5"

I am getting no values returned. But if I type the command:

rasterisk -x "database show"

I am seeing the following information.

Code:
/AMPUSER//cidname                                 : Home5                    
/AMPUSER//recording                               : out=Adhoc|in=Adhoc       
/AMPUSER//ringtimer                               : 0                        
/AMPUSER//voicemail                               : novm
when tried to run the command:

database del /AMPUSER//cidname

I got an explanation of the usage of this command and nothing happened. Where or how do I get rid of this information from freepbx?

Once upon a time we did have a home5, but we removed this extension from our list of extensions.
 

dicko

Joined
Oct 24, 2008
Messages
4,099
Likes
0
Points
0
#8
Yes, I thought this might happen, as you state the explanation of "database del" is specific that it needs a space seperated (not "/" ) family and key,
the family is AMPUSER but the key here is a null value.

database del AMPUSER fred
would work but fred unfortunately is not at home(5)!.

I've never managed to create a null key before but maybe
Code:
database del AMPUSER ""
or
database del AMPUSER ''
or even
database del AMPUSER \\00 
or in desparation 
database deltree AMPUSER Home5 (but that wouldn't fix the underlying problem of an AMPUSER with a NULL value)
might be construed one way or another as a NULL and thus might work for you, if not the database is a berkeley database, and google is your friend. (to be pedantic the data is in AstDB and not FreePBX, and unfortunately you managed to set it to a NULL key, it might be hard to delete something that to asterisk is possibly invisible).
p.s.
when you had Home5 was that from your trixbox days, did you attempt to convert/import/restore trixbox to Elastix by any chance?.
 

Members online

No members online now.

Latest posts

Forum statistics

Threads
30,902
Messages
130,887
Members
17,565
Latest member
omarmenichetti
Top