Incorrect Caller ID on sip phones

Discussion in 'General' started by EricLomm, May 27, 2009.

  1. EricLomm

    Joined:
    May 19, 2009
    Messages:
    20
    Likes Received:
    0
    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
     
  2. jessie

    Joined:
    Sep 17, 2008
    Messages:
    124
    Likes Received:
    0
    Hi EricLomm,

    Can you send the logs when having an incoming call?

    Thanks,


    Jessie
     
  3. jgutierrez

    Joined:
    Feb 28, 2008
    Messages:
    5,737
    Likes Received:
    0
    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?
     
  4. EricLomm

    Joined:
    May 19, 2009
    Messages:
    20
    Likes Received:
    0
    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
     
  5. EricLomm

    Joined:
    May 19, 2009
    Messages:
    20
    Likes Received:
    0
    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.
     
  6. dicko

    Joined:
    Oct 24, 2008
    Messages:
    4,099
    Likes Received:
    0
    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
     
  7. EricLomm

    Joined:
    May 19, 2009
    Messages:
    20
    Likes Received:
    0
    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.
     
  8. dicko

    Joined:
    Oct 24, 2008
    Messages:
    4,099
    Likes Received:
    0
    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?.
     

Share This Page