localhost*CLI> <-- SIP read from 82.101.62.99:5060: Cirpack KeepAlive Packet --- (1 headers 0 lines) --- localhost*CLI> <-- SIP read from 82.101.62.99:5060: Cirpack KeepAlive Packet --- (1 headers 0 lines) --- Destroying call 'Njg5YWNjMGJiMTA4NGNkYTFmYjEzYjgwNGFjM2JlZWI.' localhost*CLI> <-- SIP read from 82.101.62.99:5060: Cirpack KeepAlive Packet --- (1 headers 0 lines) --- localhost*CLI> sip debug SIP Debugging re-enabled localhost*CLI> <-- SIP read from 192.168.7.81:18910: INVITE sip:00615088947@192.168.7.10 SIP/2.0 Via: SIP/2.0/UDP 192.168.7.81:18910;branch=z9hG4bK-d8754z-7b061e0b9d3bbc41-1---d8754z-;rport Max-Forwards: 70 Contact: To: "00615088947" From: "Wayne Wilson";tag=a20e5a0c Call-ID: NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE. CSeq: 1 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 1013t stamp 43069 Content-Length: 571 v=0 o=- 9 2 IN IP4 192.168.7.81 s=CounterPath eyeBeam 1.5 c=IN IP4 192.168.7.81 t=0 0 m=audio 46628 RTP/AVP 107 100 106 6 0 105 8 18 3 5 101 a=alt:1 3 : 767AuR/e bd2k8hYJ 192.168.7.81 46628 a=alt:2 2 : HDeK9YHN 9XEktJgV 192.168.198.1 46628 a=alt:3 1 : CQ2d9Us2 md5//JTn 192.168.200.1 46628 a=fmtp:18 annexb=yes a=fmtp:101 0-15 a=rtpmap:107 BV32/16000 a=rtpmap:100 SPEEX/16000 a=rtpmap:106 SPEEX-FEC/16000 a=rtpmap:105 SPEEX-FEC/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:EB58722E7304487FAC960C220268F22D --- (12 headers 19 lines) --- Using INVITE request as basis request - NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE. Sending to 192.168.7.81 : 18910 (NAT) Reliably Transmitting (NAT) to 192.168.7.81:18910: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.7.81:18910;branch=z9hG4bK-d8754z-7b061e0b9d3bbc41-1---d8754z-;received=192.168.7.81;rport=18910 From: "Wayne Wilson";tag=a20e5a0c To: "00615088947";tag=as52efa280 Call-ID: NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE. CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Proxy-Authenticate: Digest algorithm=MD5, realm="voipnow", nonce="64898988" Content-Length: 0 --- Scheduling destruction of call 'NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE.' in 15000 ms Found user '0003*501' localhost*CLI> <-- SIP read from 192.168.7.81:18910: ACK sip:00615088947@192.168.7.10 SIP/2.0 Via: SIP/2.0/UDP 192.168.7.81:18910;branch=z9hG4bK-d8754z-7b061e0b9d3bbc41-1---d8754z-;rport To: "00615088947";tag=as52efa280 From: "Wayne Wilson";tag=a20e5a0c Call-ID: NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE. CSeq: 1 ACK Content-Length: 0 --- (7 headers 0 lines) --- localhost*CLI> <-- SIP read from 192.168.7.81:18910: INVITE sip:00615088947@192.168.7.10 SIP/2.0 Via: SIP/2.0/UDP 192.168.7.81:18910;branch=z9hG4bK-d8754z-4a277e40281b385f-1---d8754z-;rport Max-Forwards: 70 Contact: To: "00615088947" From: "Wayne Wilson";tag=a20e5a0c Call-ID: NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE. CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Proxy-Authorization: Digest username="0003*501",realm="voipnow",nonce="64898988",uri="sip:00615088947@192.168.7.10",response="073caf6c2405b414095de457720e943b",algorithm=MD5 User-Agent: eyeBeam release 1013t stamp 43069 Content-Length: 571 v=0 o=- 9 2 IN IP4 192.168.7.81 s=CounterPath eyeBeam 1.5 c=IN IP4 192.168.7.81 t=0 0 m=audio 46628 RTP/AVP 107 100 106 6 0 105 8 18 3 5 101 a=alt:1 3 : 767AuR/e bd2k8hYJ 192.168.7.81 46628 a=alt:2 2 : HDeK9YHN 9XEktJgV 192.168.198.1 46628 a=alt:3 1 : CQ2d9Us2 md5//JTn 192.168.200.1 46628 a=fmtp:18 annexb=yes a=fmtp:101 0-15 a=rtpmap:107 BV32/16000 a=rtpmap:100 SPEEX/16000 a=rtpmap:106 SPEEX-FEC/16000 a=rtpmap:105 SPEEX-FEC/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:EB58722E7304487FAC960C220268F22D --- (13 headers 19 lines) --- Using INVITE request as basis request - NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE. Sending to 192.168.7.81 : 18910 (NAT) Found user '0003*501' Found RTP audio format 107 Found RTP audio format 100 Found RTP audio format 106 Found RTP audio format 6 Found RTP audio format 0 Found RTP audio format 105 Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 3 Found RTP audio format 5 Found RTP audio format 101 Peer audio RTP is at port 192.168.7.81:46628 Found description format BV32 Found description format SPEEX Found description format SPEEX-FEC Found description format SPEEX-FEC Found description format G729 Found description format telephone-event Capabilities: us - 0x8 (alaw), peer - audio=0x32e (gsm|ulaw|alaw|adpcm|g729|speex)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Looking for 00615088947 in from-internal (domain 192.168.7.10) list_route: hop: Transmitting (NAT) to 192.168.7.81:18910: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.7.81:18910;branch=z9hG4bK-d8754z-4a277e40281b385f-1---d8754z-;received=192.168.7.81;rport=18910 From: "Wayne Wilson";tag=a20e5a0c To: "00615088947" Call-ID: NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE. CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- -- Executing GotoIf("SIP/0003*501-086622d0", "0?200:2") in new stack -- Goto (from-internal,00615088947,2) -- Executing Set("SIP/0003*501-086622d0", "TIMEOUT(absolute)=7200") in new stack -- Channel will hangup at 2008-02-21 16:12:32 UTC. -- Executing GotoIf("SIP/0003*501-086622d0", "1?4:10") in new stack -- Goto (from-internal,00615088947,4) -- Executing GotoIf("SIP/0003*501-086622d0", "1?15:5") in new stack -- Goto (from-internal,00615088947,15) -- Executing Set("SIP/0003*501-086622d0", "CALLERCHAN=0003*501") in new stack -- Executing Set("SIP/0003*501-086622d0", "__ORIGINEXT=0003*501") in new stack -- Executing Macro("SIP/0003*501-086622d0", "mappublic|0003*501|00615088947") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Connect connid") in new stack -- SIP Seeding peer from astdb: '0003*501' at 0003*501@192.168.7.81:18910 for 3600 12 headers, 0 lines Reliably Transmitting (NAT) to 192.168.7.81:18910: OPTIONS sip:0003*501@192.168.7.81:18910;rinstance=8c9794050344db06 SIP/2.0 Via: SIP/2.0/UDP 192.168.7.10:5060;branch=z9hG4bK56233ebc;rport From: "Anonymous" ;tag=as594dc43d To: Contact: Call-ID: 2d601a947be0054b1b3c78922f8d8569@192.168.7.10 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 21 Feb 2008 14:12:32 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- -- Executing VMYSQL("SIP/0003*501-086622d0", "Query resultid 1 SELECT get_external_mapping("00615088947") AS localextno") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Fetch foundRow 2 localextno") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Clear 2") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Disconnect 1") in new stack -- Executing GotoIf("SIP/0003*501-086622d0", "1?100:7") in new stack -- Goto (macro-mappublic,s,100) -- Executing NoOp("SIP/0003*501-086622d0", "") in new stack -- Executing Macro("SIP/0003*501-086622d0", "check-screening|0003*501|00615088947") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Connect connid") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Query resultid 1 CALL get_screening_prefs("0003*501")") in new stack -- Executing Set("SIP/0003*501-086622d0", "screen_behavior=") in new stack -- Executing Set("SIP/0003*501-086622d0", "allow_list=") in new stack -- Executing Set("SIP/0003*501-086622d0", "deny_list=") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Fetch foundRow 2 screen_behavior allow_list deny_list") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Clear 2") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Disconnect 1") in new stack -- Executing GotoIf("SIP/0003*501-086622d0", "1?10:101") in new stack -- Goto (macro-check-screening,s,10) -- Executing Set("SIP/0003*501-086622d0", "CLIENTID=0003") in new stack -- Executing AGI("SIP/0003*501-086622d0", "callscreen|00615088947|||") in new stack -- Launched AGI Script /var/lib/asterisk/agi-bin/callscreen localhost*CLI> <-- SIP read from 192.168.7.81:18910: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.7.10:5060;branch=z9hG4bK56233ebc;rport=5060 Contact: To: ;tag=bc703e27 From: "Anonymous";tag=as594dc43d Call-ID: 2d601a947be0054b1b3c78922f8d8569@192.168.7.10 CSeq: 102 OPTIONS Accept: application/sdp Accept-Language: en Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO User-Agent: eyeBeam release 1013t stamp 43069 Content-Length: 0 --- (12 headers 0 lines) --- Destroying call '2d601a947be0054b1b3c78922f8d8569@192.168.7.10' localhost*CLI> <-- SIP read from 192.168.102.2:5060: OPTIONS sip:192.168.7.10 SIP/2.0 Via: SIP/2.0/UDP 192.168.102.2:5060;branch=z9hG4bK1ab645dd;rport From: "Anonymous" ;tag=as398d5db7 To: Contact: Call-ID: 526e5d2f10ff79c66cad65ef6d812896@192.168.102.2 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 21 Feb 2008 13:25:52 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- (12 headers 0 lines) --- Looking for s in from-sip-external (domain 192.168.7.10) Transmitting (no NAT) to 192.168.102.2:5060: SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.102.2:5060;branch=z9hG4bK1ab645dd;received=192.168.102.2;rport=5060 From: "Anonymous" ;tag=as398d5db7 To: ;tag=as7b667bb2 Call-ID: 526e5d2f10ff79c66cad65ef6d812896@192.168.102.2 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Accept: application/sdp Content-Length: 0 --- Destroying call '526e5d2f10ff79c66cad65ef6d812896@192.168.102.2' callscreen|00615088947|||: Start:... callscreen|00615088947|||: Get number: 00615088947 -- callscreen|00615088947|||: Permit category id list: callscreen|00615088947|||: Get mode = none callscreen|00615088947|||: Permit the call without checking anything callscreen|00615088947|||: You are authorized to dial number: 00615088947 callscreen|00615088947|||: End -- AGI Script callscreen completed, returning 0 -- Executing Macro("SIP/0003*501-086622d0", "billingplay|0003*501") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Connect connid") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Query resultid 1 CALL get_nocredit_sounds("0003*501")") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Fetch foundRow 2 nocredit_extension nocredit_client nocredit_reseller") in new stack -- Executing Set("SIP/0003*501-086622d0", "PLAYONNOCREDIT_EXTENSION=not-enough-credit") in new stack -- Executing Set("SIP/0003*501-086622d0", "PLAYONNOCREDIT_CLIENT=not-enough-credit") in new stack -- Executing Set("SIP/0003*501-086622d0", "PLAYONNOCREDIT_RESELLER=not-enough-credit") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Clear 2") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Disconnect 1") in new stack -- Executing Set("SIP/0003*501-086622d0", "PLAYONSECONDSLEFT=this-call-will-end-in,digits/30,seconds") in new stack -- Executing Set("SIP/0003*501-086622d0", "PLAYONLIMITLEFT=not-enough-credit,call-terminated") in new stack -- Executing Macro("SIP/0003*501-086622d0", "extisactive|0003*501") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Connect connid") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Query resultid 1 SELECT status FROM vw_extension_all WHERE extension_number="0003*501"") in new stack -- Executing Set("SIP/0003*501-086622d0", "status=") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Fetch foundRow 2 status") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Clear 2") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Disconnect 1") in new stack -- Executing GotoIf("SIP/0003*501-086622d0", "0?10") in new stack -- Executing Macro("SIP/0003*501-086622d0", "setdialoptions|out|0003*501") in new stack -- Executing GotoIf("SIP/0003*501-086622d0", "0?2:4") in new stack -- Goto (macro-setdialoptions,s,4) -- Executing Set("SIP/0003*501-086622d0", "OUTDIALOPT=") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Connect connid") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Query resultid 1 SELECT get_recorded_status("0003*501") as recorded_status") in new stack -- Executing Set("SIP/0003*501-086622d0", "recorded_status=") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Fetch foundRow 2 recorded_status") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Clear 2") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Disconnect 1") in new stack -- Executing GotoIf("SIP/0003*501-086622d0", "0?12:30") in new stack -- Goto (macro-setdialoptions,s,30) -- Executing GotoIf("SIP/0003*501-086622d0", "0?31:40") in new stack -- Goto (macro-setdialoptions,s,40) -- Executing Set("SIP/0003*501-086622d0", "OUTDIALOPT=T") in new stack -- Executing Goto("SIP/0003*501-086622d0", "50") in new stack -- Goto (macro-setdialoptions,s,50) -- Executing GotoIf("SIP/0003*501-086622d0", "0?51:101") in new stack -- Goto (macro-setdialoptions,s,101) -- Executing NoOp("SIP/0003*501-086622d0", "") in new stack -- Executing Macro("SIP/0003*501-086622d0", "billperm|outbound|0003*501") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Connect connid") in new stack -- Executing GotoIf("SIP/0003*501-086622d0", "1?10:20") in new stack -- Goto (macro-billperm,s,10) -- Executing VMYSQL("SIP/0003*501-086622d0", "Query resultid 1 SELECT allow_out as billing_perm FROM vw_extension_all| billing_plan WHERE extension_number="0003*501" AND vw_extension_all.billing_plan_id=billing_plan.id") in new stack -- Executing Goto("SIP/0003*501-086622d0", "s|40") in new stack -- Goto (macro-billperm,s,40) -- Executing Set("SIP/0003*501-086622d0", "billing_perm=") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Fetch foundRow 2 billing_perm") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Clear 2") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Disconnect 1") in new stack -- Executing GotoIf("SIP/0003*501-086622d0", "0?101") in new stack -- Executing Macro("SIP/0003*501-086622d0", "set-callerid|outbound") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Connect connid") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Query resultid 1 CALL get_callerid_name_number("0003*501"| "outbound")") in new stack -- Executing Set("SIP/0003*501-086622d0", "worldno=") in new stack -- Executing Set("SIP/0003*501-086622d0", "worldno_name=") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Fetch foundRow 2 worldno worldno_name") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Clear 2") in new stack -- Executing VMYSQL("SIP/0003*501-086622d0", "Disconnect 1") in new stack -- Executing GotoIf("SIP/0003*501-086622d0", "1?16:101") in new stack -- Goto (macro-set-callerid,s,16) -- Executing GotoIf("SIP/0003*501-086622d0", "0?17:26") in new stack -- Goto (macro-set-callerid,s,26) -- Executing GotoIf("SIP/0003*501-086622d0", "1?27:35") in new stack -- Goto (macro-set-callerid,s,27) -- Executing GotoIf("SIP/0003*501-086622d0", "1?28:30") in new stack -- Goto (macro-set-callerid,s,28) -- Executing Set("SIP/0003*501-086622d0", "CALLERID(name)=") in new stack -- Executing Set("SIP/0003*501-086622d0", "CLIENTID=0003") in new stack -- Executing AGI("SIP/0003*501-086622d0", "record|0003*501|out||") in new stack -- Launched AGI Script /var/lib/asterisk/agi-bin/record -- AGI Script record completed, returning 0 -- Executing Set("SIP/0003*501-086622d0", "__RETURNPARKDIALOPTS=Twt") in new stack -- Executing Billing("SIP/0003*501-086622d0", "Dial|00615088947||T") in new stack 2008-02-21 15:12:33 NOTICE[13312]: provider.c:178 chan_isavail: Asterisk channel 3 seems available. Channel can be used for outgoing calls. 2008-02-21 15:12:33 NOTICE[13312]: provider.c:178 chan_isavail: Asterisk channel 3 seems available. Channel can be used for outgoing calls. 2008-02-21 15:12:33 NOTICE[13312]: provider.c:178 chan_isavail: Asterisk channel 3 seems available. Channel can be used for outgoing calls. 2008-02-21 15:12:33 WARNING[13312]: routing.c:544 _find_cost_for: Could not get cost for prefix 0615088947 2008-02-21 15:12:33 ERROR[13312]: call.c:608 pre_call_data_set: 4PSA VoipNow channel 3 contains no cost for an area code matching 0615088947 (number can be modified by routing rules). Setup your channel as peer or upload costs. 2008-02-21 15:12:33 ERROR[13312]: call.c:563 pre_call_data_set: Your routing rules do not contain a route that matches dialed number 00615088947. Add a routing rule for number in order to be able to make the call. 2008-02-21 15:12:33 ERROR[13312]: app_billing.c:519 billing_exec: Could not process call information due to earlier errors. Call can not continue. == Spawn extension (from-internal, 00615088947, 27) exited non-zero on 'SIP/0003*501-086622d0' Scheduling destruction of call 'NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE.' in 32000 ms Reliably Transmitting (NAT) to 192.168.7.81:18910: SIP/2.0 603 Declined Via: SIP/2.0/UDP 192.168.7.81:18910;branch=z9hG4bK-d8754z-4a277e40281b385f-1---d8754z-;received=192.168.7.81;rport=18910 From: "Wayne Wilson";tag=a20e5a0c To: "00615088947";tag=as09c6ff52 Call-ID: NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE. CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- localhost*CLI> <-- SIP read from 192.168.7.81:18910: ACK sip:00615088947@192.168.7.10 SIP/2.0 Via: SIP/2.0/UDP 192.168.7.81:18910;branch=z9hG4bK-d8754z-4a277e40281b385f-1---d8754z-;rport To: "00615088947";tag=as09c6ff52 From: "Wayne Wilson";tag=a20e5a0c Call-ID: NDFlMDU2ZDI3YjY1MzQ4Yzc5YjAzYTBiMWIxNzUxYzE. CSeq: 2 ACK Content-Length: 0 --- (7 headers 0 lines) --- localhost*CLI> <-- SIP read from 82.101.62.99:5060: Cirpack KeepAlive Packet --- (1 headers 0 lines) --- localhost*CLI> <-- SIP read from 192.168.7.81:18910: