Jump to content

help! - calls not coming in!


speck

Recommended Posts

Im running PBXnSIP on a PE 1750 with dual 3.06 ghz dual core xeons

 

and several gb of ddr

 

so it has plenty of over abundance of power.

 

it connects to my POE switch, via a redundant fiber-optic connection

 

we just got the system all setup, likely ill be on the phone getting support on it here in an hr.. just wanted to see if i could fix it before then..

 

we can make calls out, however if anyone calls in, the phones do not ring

 

and then there is what sounds like someone picking up a phone, silence for around a minute

 

and then a fast busy signal

 

does anyone have any ideas of what could be causing this?

 

 

log from my grandstream

 

05/12/10 21:25:41 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Ring Start Detected, From: 906 , GWSt: 0

05/12/10 21:25:41 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (0:0)

05/12/10 21:25:41 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Set State to: Ringing, From: 992

05/12/10 21:25:41 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 *Call status* is Incoming call, From: 1716 , GWSt: 0

05/12/10 21:25:41 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] cm_task.c 1741 Port: 5 Sess: 105 fxoCallStatus old/new:0 3

05/12/10 21:25:43 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Ring Validation time: 1962 ms.

05/12/10 21:25:43 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Ring Stop Detected , From: 906 , GWSt: 1

05/12/10 21:25:43 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (1:3)

05/12/10 21:25:43 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5 Start detection, Type: BELLCORE(FSK), Alert signal(FXO_CID_ALERT_RING)

05/12/10 21:25:43 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Ring count: 1 Ring pulses: 0

05/12/10 21:25:43 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line Event triggered is: 1 Previous Event was: 2 current line Status is: 3 count: 15

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5 Finish data capture.

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5 Start cid analysis.

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5----------- CID Reporting (FSK)-----------

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5 Number: 5612093583

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5 Name: WIRELESS CALLER

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5 ---------- CID Reporting (end) ----------

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5 Capture completed. Starts @ 0x80C98580 len=0000BB80

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5 Finish cid analysis.

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 404 sip.c Sess: 1 is allocated for sip acc:5 from#: 1559

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] ------------------------- GXW setup ------------------------------

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1564 cm_utility.c Port: 5 Sess: 1 Acc:0; FullRingCounts:1 RingPulseCounts:0 FXOState:Hanging-up; Log user data: 1 StageDialing, PR Disabled; Curr.Disc. Enabled, Curr.Disc. Thres: 100; Cont'd..

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] BZ TD Disabled,Tone Cfg: Dial: F: 350 440,V: 11 11,Cad: 0 0 0,0 0 0; Ringback: F: 440 480,V: 11 11,Cad: 200 0 0,400 0 0; BZ: F: 480 620,V: 11 11,Cad: 50 0 0,50 0 0; Reorder: F: 480 620,V: 11 11,Cad: 25 0 0,25 0 0; Cont'd..

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] Caller ID Type: 1, Wait for Dial tone: 0, Dialing Cfg: ch1-8:N;, Delay2Dial: 100; FAX TD Disable, T38: Enabled, T38 Bitrate:9600, T38 Mode:1; T38 ECM:1; Echo Can.: Y, Sil. Supp.: N; Cont'd..

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] Audio Gains: RX from PSTN: 0, TX to PSTN: 1, DTMF Method: 2, SIP port: 5070, SRTP: 0,; DTMF Interkey T.O: 4, Round-robin: 1, Prefix Code: Len:2, Scheduling:99

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] ------------------------- GXW setup (end)-------------------------

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1205 sip_transport.c Sess: 1 Send SIP message: 2 To 172.169.1.5:5060

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1324 sip_message.c Port: 5 Sess: 1 0 0 11 1 WIRELESS CALLER 5612093583

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1524 sip_transport.c Sess: 1 INVITE sip:70@172.169.1.5 SIP/2.0 Via: SIP/2.0/UDP 172.169.1.110:5070;branch=z9hG4bKab11af171756cde4 From: "WIRELESS CALLER"<sip:5612093583@172.169.1.5>;tag=4be32d04b2a3e9f1 To: <sip:70@172.169.1.5> Contact: <sip:172.169.1.110:5070> Supported: replaces, timer, path Call-ID: 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110 CSeq: 30236 INVITE User-Agent: Grandstream GXW4108 (HW 1.1, Ch:1) 1.3.1.6 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Content-Type: application/sdp Content-Length: 312 v=0 o=system 8001 8000 IN IP4 172.169.1.110 s=SIP Call c=IN IP4 172.169.1.110 t=0 0 m=audio 5008 RTP/AVP 0 8 4 18 3 101 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=rtpmap:3 GSM/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11

05/12/10 21:25:46 [172.169.1.110] (user.info) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1540 sip_transport.c INVITE From="WIRELESS CALLER"<sip:5612093583@172.169.1.5>;tag=4be32d04b2a3e9f1 To=<sip:70@172.169.1.5>

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1258 sip.c Acc:5 Size:302 Received SIP message: SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.169.1.110:5070;branch=z9hG4bKab11af171756cde4 From: "WIRELESS CALLER" <sip:5612093583@172.169.1.5>;tag=4be32d04b2a3e9f1 To: <sip:70@172.169.1.5>;tag=6a07058e6b Call-ID: 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110 CSeq: 30236 INVITE Content-Length: 0

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 199 sip_dialog.c Sess: 1 Call-ID MATCHED, len&id:46 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1258 sip.c Acc:5 Size:844 Received SIP message: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 172.169.1.110:5070;branch=z9hG4bKab11af171756cde4 From: "WIRELESS CALLER" <sip:5612093583@172.169.1.5>;tag=4be32d04b2a3e9f1 To: <sip:70@172.169.1.5>;tag=6a07058e6b Call-ID: 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110 CSeq: 30236 INVITE Contact: <sip:2201@172.169.1.5:5060;transport=udp> Supported: 100rel, replaces, norefersub Allow-Events: refer Allow: INVITE, ACK, CANCEL, BYE, REFER, PRACK, INFO, UPDATE Accept: application/sdp User-Agent: pbxnsip-PBX/4.0.1.3499 Content-Type: application/sdp Content-Length: 263 v=0 o=- 49748 49748 IN IP4 172.169.1.5 s=- c=IN IP4 172.169.1.5 t=0 0 m=audio 61660 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=ptime:20 a=rtcp-xr:rcvr-rtt=all voip-metrics a=sendrecv

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 199 sip_dialog.c Sess: 1 Call-ID MATCHED, len&id:46 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 210 sdp.c Sess: 1 Acc:5 St:2 CallSt:1 rtp RTX:0 media1:0@61660-RTP payload type: 0;Port: 5 0 0 2 1 1 0 0 0 0 0 0 0;

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 569 sdp.c Port: 5 Sess: 1 rtp: 172.169.1.5:61660 0 20 101 2 0 5008 0 0 i= 5

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 735 cm_rtp.c Open VOC@ Port: 5 Sess: 1 Payload:0 Rtp 172.169.1.5:61660 0 20 101 2 5008 0 0 0 1 0 0 callSt: 5 0 0 0 1

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] VOC: Open Port: 5 with 0

05/12/10 21:25:46 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 5 Stop tone [0] from Line:1497

05/12/10 21:25:47 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Ring Start Detected, From: 906 , GWSt: 1

05/12/10 21:25:47 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (1:3)

05/12/10 21:25:47 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Ring count: 1 Ring pulses: 0

05/12/10 21:25:49 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Ring Validation time: 1962 ms.

05/12/10 21:25:49 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Ring Stop Detected , From: 906 , GWSt: 1

05/12/10 21:25:49 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (1:3)

05/12/10 21:25:49 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Ring count: 2 Ring pulses: 0

05/12/10 21:25:49 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line Event triggered is: 1 Previous Event was: 3 current line Status is: 3 count: 15

05/12/10 21:25:53 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Ring Start Detected, From: 906 , GWSt: 1

05/12/10 21:25:53 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (1:3)

05/12/10 21:25:53 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Ring count: 2 Ring pulses: 0

05/12/10 21:25:55 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Ring Validation time: 1962 ms.

05/12/10 21:25:55 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Ring Stop Detected , From: 906 , GWSt: 1

05/12/10 21:25:55 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (1:3)

05/12/10 21:25:55 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Ring count: 3 Ring pulses: 0

05/12/10 21:25:55 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line Event triggered is: 1 Previous Event was: 3 current line Status is: 3 count: 15

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1258 sip.c Acc:0 Size:967 Received SIP message: INVITE sip:840@localhost;user=phone SIP/2.0 Via: SIP/2.0/UDP 172.169.1.5:5060;branch=z9hG4bK-fa26ddcd09138673bad91dbd0aa04d33;rport From: "WIRELESS CALLER" <sip:5612093583@localhost;user=phone>;tag=25902 To: <sip:840@localhost;user=phone> Call-ID: 3480f276@pbx CSeq: 15779 INVITE Max-Forwards: 70 Contact: <sip:2201@172.169.1.5:5060;transport=udp> Supported: 100rel, replaces, norefersub Allow-Events: refer Allow: INVITE, ACK, CANCEL, BYE, REFER, PRACK, INFO, UPDATE Accept: application/sdp User-Agent: pbxnsip-PBX/4.0.1.3499 Related-Call-ID: 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110 P-Asserted-Identity: "GrandStream" <sip:2201@localhost> Content-Type: application/sdp Content-Length: 251 v=0 o=- 32832 32832 IN IP4 172.169.1.5 s=- c=IN IP4 172.169.1.5 t=0 0 m=audio 60120 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=rtcp-xr:rcvr-rtt=all voip-metrics a=sendrecv

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line is AVAILABLE, From: 1669

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 *Call status* is Incoming call, From: 1669 , GWSt: 1

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Line is AVAILABLE, From: 1669

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 *Call status* is Idle, From: 1669 , GWSt: 0

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Initiate Pick-Up, From: 1674

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] LEC: Enable Port: 4

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 404 sip.c Sess: 2 is allocated for sip acc:0 from#: 918

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1205 sip_transport.c Sess: 2 Send SIP message: 100 To 172.169.1.5:5060

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1524 sip_transport.c Sess: 2 SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.169.1.5:5060;branch=z9hG4bK-fa26ddcd09138673bad91dbd0aa04d33;rport From: "WIRELESS CALLER" <sip:5612093583@localhost;user=phone>;tag=25902 To: <sip:840@localhost;user=phone> Call-ID: 3480f276@pbx CSeq: 15779 INVITE User-Agent: Grandstream GXW4108 (HW 1.1, Ch:2) 1.3.1.6 Content-Length: 0

05/12/10 21:25:56 [172.169.1.110] (user.info) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 968 sip_handle_invite.c Sess: 2 INVITE From="WIRELESS CALLER" <sip:5612093583@localhost;user=phone>;tag=25902 To=<sip:840@localhost;user=phone>

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] ------------------------- GXW setup ------------------------------

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1073 sip_handle_invite.c Port: 4 Sess: 2 Acc:0; FullRingCounts:0 RingPulseCounts:0 FXOState:Hanging-up; Log user data: 1 StageDialing, PR Disabled; Curr.Disc. Enabled, Curr.Disc. Thres: 100; Cont'd..

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] BZ TD Disabled,Tone Cfg: Dial: F: 350 440,V: 11 11,Cad: 0 0 0,0 0 0; Ringback: F: 440 480,V: 11 11,Cad: 200 0 0,400 0 0; BZ: F: 480 620,V: 11 11,Cad: 50 0 0,50 0 0; Reorder: F: 480 620,V: 11 11,Cad: 25 0 0,25 0 0; Cont'd..

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] Caller ID Type: 1, Wait for Dial tone: 0, Dialing Cfg: ch1-8:N;, Delay2Dial: 100; FAX TD Disable, T38: Enabled, T38 Bitrate:9600, T38 Mode:1; T38 ECM:1; Echo Can.: Y, Sil. Supp.: N; Cont'd..

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] Audio Gains: RX from PSTN: 0, TX to PSTN: 1, DTMF Method: 2, SIP port: 5068, SRTP: 0,; DTMF Interkey T.O: 4, Round-robin: 1, Prefix Code: Len:2, Scheduling:99

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] ------------------------- GXW setup (end)-------------------------

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] dialplan_process: segments checked = 1, result = DIALPLAN_MATCH_SUCCESS, match_index = 0

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1205 sip_handle_invite.c Port: 4 Sess: 2 Wait Dialtone: 0 Dial: 840 When FXO is ready

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Off-Hook, From: 906 , GWSt: 1

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (1:0)

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Set State to: Settling, From: 543

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 *Call status* is Picking-up, From: 1716 , GWSt: 1

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] cm_task.c 1741 Port: 4 Sess: 2 fxoCallStatus old/new:0 2

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Line Event triggered is: 3 Previous Event was: 1 current line Status is: 3 count: 15

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Transitioning State, From: 906 , GWSt: 1

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (1:2)

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Set State to: Off-Hook, From: 1026

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 4 Enable detection: Global Mask: 8FFF DTMF: 80FF CPT: 800F

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 4 Disable detection: Global Mask: 0C00 DTMF: 80FF CPT: 8007

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 1

05/12/10 21:25:56 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (1:2)

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Transitioning State, From: 906 , GWSt: 1

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (1:2)

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 4 Disable detection: Global Mask: 0100 DTMF: 80FF CPT: 8006

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 *Call status* is Ready for Dialing, From: 1716 , GWSt: 1

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] cm_task.c 1741 Port: 4 Sess: 2 fxoCallStatus old/new:2 5

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1635 cm_utility.c Port: 4 Sess: 2 FXO_Call: 8(l:0 p:100 v:0)4(l:0 p:100 v:0)0(l:0 p:100 v:0)

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Dialing: 8

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Start tone [43] from Line:543

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Details for tone [43] f1:852 f2:1336 ON:10 OFF:10 Vol:4 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Dialing in Progress

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Stop tone [43] from Line:666

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Dialing: 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Start tone [34] from Line:622

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Details for tone [34] f1:775 f2:1209 ON:10 OFF:10 Vol:4 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Stop tone [34] from Line:666

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Dialing: 0

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Start tone [51] from Line:622

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Details for tone [51] f1:941 f2:1336 ON:10 OFF:10 Vol:4 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Stop tone [51] from Line:666

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Dialing Finished, From: 906 , GWSt: 2

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (2:5)

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Dial Finished

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1205 sip_transport.c Sess: 2 Send SIP message: 180 To 172.169.1.5:5060

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1524 sip_transport.c Sess: 2 SIP/2.0 180 Ringing Via: SIP/2.0/UDP 172.169.1.5:5060;branch=z9hG4bK-fa26ddcd09138673bad91dbd0aa04d33;rport From: "WIRELESS CALLER" <sip:5612093583@localhost;user=phone>;tag=25902 To: <sip:840@localhost;user=phone>;tag=a630d4d4dd075475 Call-ID: 3480f276@pbx CSeq: 15779 INVITE User-Agent: Grandstream GXW4108 (HW 1.1, Ch:2) 1.3.1.6 Contact: <sip:172.169.1.110:5060;transport=udp> Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Content-Length: 0

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1669 cm_utility.c Port: 4 Sess: 2 Polarity Reversal:0 101 0

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 210 sdp.c Sess: 2 Acc:0 St:4 CallSt:1 rtp RTX:0 media1:0@60120-RTP payload type: 0;Port: 4 0 0 2 1 1 0 0 0 0 0 0 0;

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 569 sdp.c Port: 4 Sess: 2 rtp: 172.169.1.5:60120 0 20 101 2 0 5012 0 0 i= 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1205 sip_transport.c Sess: 2 Send SIP message: 200 To 172.169.1.5:5060

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1524 sip_transport.c Sess: 2 SIP/2.0 200 OK Via: SIP/2.0/UDP 172.169.1.5:5060;branch=z9hG4bK-fa26ddcd09138673bad91dbd0aa04d33;rport From: "WIRELESS CALLER" <sip:5612093583@localhost;user=phone>;tag=25902 To: <sip:840@localhost;user=phone>;tag=a630d4d4dd075475 Call-ID: 3480f276@pbx CSeq: 15779 INVITE User-Agent: Grandstream GXW4108 (HW 1.1, Ch:2) 1.3.1.6 Contact: <sip:172.169.1.110:5060;transport=udp> Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Content-Type: application/sdp Supported: replaces, timer, 100rel, path Content-Length: 224 v=0 o=system 8002 8000 IN IP4 172.169.1.110 s=SIP Call c=IN IP4 172.169.1.110 t=0 0 m=audio 5012 RTP/AVP 0 8 4 18 3 101 a=sendrecv a=rtpmap:0 PCMU/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1258 sip.c Acc:0 Size:457 Received SIP message: ACK sip:172.169.1.110:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.169.1.5:5060;branch=z9hG4bK-0c71911566ef86733de7dab4cfcca9c1;rport From: "WIRELESS CALLER" <sip:5612093583@localhost;user=phone>;tag=25902 To: <sip:840@localhost;user=phone>;tag=a630d4d4dd075475 Call-ID: 3480f276@pbx CSeq: 15779 ACK Max-Forwards: 70 Contact: <sip:2201@172.169.1.5:5060;transport=udp> P-Asserted-Identity: "GrandStream" <sip:2201@localhost> Content-Length: 0

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 199 sip_dialog.c Sess: 2 Call-ID MATCHED, len&id:12 3480f276@pbx

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 137 sip_handle_ack.c Sess: 2 0 5 0 0 0 1 0 172.169.1.5:60120

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 351 sip_handle_ack.c handle ACK, (Sess: 2, st:6, est'd 1); start m:1; call st:1; sendrcv:0

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 735 cm_rtp.c Open VOC@ Port: 4 Sess: 2 Payload:0 Rtp 172.169.1.5:60120 0 20 101 2 5012 0 0 0 1 0 0 callSt: 5 0 0 1 3

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] VOC: Open Port: 4 with 0

05/12/10 21:25:57 [172.169.1.110] (user.info) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] cm_api.c 276 Start fax_detect on Port:4 Sess: 2

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Stop tone [0] from Line:1497

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1258 sip.c Acc:5 Size:830 Received SIP message: SIP/2.0 200 Ok Via: SIP/2.0/UDP 172.169.1.110:5070;branch=z9hG4bKab11af171756cde4 From: "WIRELESS CALLER" <sip:5612093583@172.169.1.5>;tag=4be32d04b2a3e9f1 To: <sip:70@172.169.1.5>;tag=6a07058e6b Call-ID: 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110 CSeq: 30236 INVITE Contact: <sip:2201@172.169.1.5:5060;transport=udp> Supported: 100rel, replaces, norefersub Allow-Events: refer Allow: INVITE, ACK, CANCEL, BYE, REFER, PRACK, INFO, UPDATE Accept: application/sdp User-Agent: pbxnsip-PBX/4.0.1.3499 Content-Type: application/sdp Content-Length: 263 v=0 o=- 49748 49748 IN IP4 172.169.1.5 s=- c=IN IP4 172.169.1.5 t=0 0 m=audio 61660 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=ptime:20 a=rtcp-xr:rcvr-rtt=all voip-metrics a=sendrecv

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 199 sip_dialog.c Sess: 1 Call-ID MATCHED, len&id:46 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] Session expire value is 0, no timer setup.

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 5 Stop tone [0] from Line:577

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 569 sdp.c Port: 5 Sess: 1 rtp: 172.169.1.5:61660 0 20 101 2 80 5008 0 0 i= 5

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1205 sip_transport.c Sess: 1 Send SIP message: 3 To 172.169.1.5:5060

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1524 sip_transport.c Sess: 1 ACK sip:2201@172.169.1.5:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.169.1.110:5070;branch=z9hG4bK3673887168170997 From: "WIRELESS CALLER"<sip:5612093583@172.169.1.5>;tag=4be32d04b2a3e9f1 To: <sip:70@172.169.1.5>;tag=6a07058e6b Contact: <sip:172.169.1.110:5070;transport=udp> Call-ID: 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110 CSeq: 30236 ACK User-Agent: Grandstream GXW4108 (HW 1.1, Ch:1) 1.3.1.6 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Content-Length: 0

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line is AVAILABLE, From: 708

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 *Call status* is Incoming call, From: 708 , GWSt: 1

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Initiate Pick-Up, From: 710

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] LEC: Enable Port: 5

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 735 cm_rtp.c Open VOC@ Port: 5 Sess: 1 Payload:0 Rtp 172.169.1.5:61660 0 20 101 2 5008 0 0 0 1 0 0 callSt: 5 0 0 1 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] VOC: Open Port: 5 with 0

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Off-Hook, From: 906 , GWSt: 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:3)

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Set State to: Settling, From: 543

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Ring count: 3 Ring pulses: 0

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 *Call status* is Picking-up, From: 1716 , GWSt: 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] cm_task.c 1741 Port: 5 Sess: 1 fxoCallStatus old/new:3 2

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 5 Stop tone [0] from Line:1497

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line Event triggered is: 3 Previous Event was: 1 current line Status is: 3 count: 15

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Transitioning State, From: 906 , GWSt: 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:2)

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Set State to: Off-Hook, From: 1026

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 5 Enable detection: Global Mask: 8DFF DTMF: 80FF CPT: 800F

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 5 Disable detection: Global Mask: 0C00 DTMF: 80FF CPT: 8003

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 *Call status* is Locally answered, From: 1716 , GWSt: 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] cm_task.c 1741 Port: 5 Sess: 1 fxoCallStatus old/new:2 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> LossOfLinePower, From: 906 , GWSt: 4

05/12/10 21:25:57 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:4)

05/12/10 21:25:58 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:25:58 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:4)

05/12/10 21:25:58 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line power has been recovered. Continue currrent call.

05/12/10 21:25:58 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line Event triggered is: 4 Previous Event was: 5 current line Status is: 4 count: 15

05/12/10 21:25:58 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Polarity Reversal, From: 906 , GWSt: 4

05/12/10 21:25:58 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:4)

05/12/10 21:25:58 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:25:58 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:4)

05/12/10 21:26:03 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:03 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:5)

05/12/10 21:26:03 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 *Call status* is Remotely answered, From: 1716 , GWSt: 4

05/12/10 21:26:03 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] cm_task.c 1741 Port: 4 Sess: 2 fxoCallStatus old/new:5 8

05/12/10 21:26:04 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:04 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:04 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:04 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:05 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:05 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:05 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:05 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:05 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 4 Disable detection: Global Mask: 0200 DTMF: 80FF CPT: 8000

05/12/10 21:26:06 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:06 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:06 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:06 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:07 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:07 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:07 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:07 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:08 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:08 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:08 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:08 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:09 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:09 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:09 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:09 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:10 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:10 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:10 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:10 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:11 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:11 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:11 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:11 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:12 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:12 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:12 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:12 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:13 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:13 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:13 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:13 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:8)

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:4)

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> LossOfLinePower, From: 906 , GWSt: 4

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:4)

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line power has been recovered. Continue currrent call.

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line Event triggered is: 3 Previous Event was: 5 current line Status is: 4 count: 15

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Polarity Reversal, From: 906 , GWSt: 4

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:4)

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> LossOfLinePower, From: 906 , GWSt: 4

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:4)

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> Line Activity Detected, From: 906 , GWSt: 4

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:4)

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Current Disconnect threshold of 100 ms reached. Begin hanging-up.

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> On-Hook, From: 906 , GWSt: 4

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (4:4)

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Set State to: On-Hook, From: 1085

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 5 Stop tone [0] from Line:837

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 5 Reset Tone Detection

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 5 Disable detection: Global Mask: FFFF DTMF: 0000 CPT: 0000

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5 Disabling detection, Type: BELLCORE

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] cm_task.c 1741 Port: 5 Sess: 1 fxoCallStatus old/new:4 0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 831 cm_utility.c Port: 5 Sess: 1, gw st: 4, gw sigtm: 0, sess st: 6, call st: 5, fxo cs: 0, from#: 1757, reason: 0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Initiate Hang-Up, From: 858

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] LEC: Disable Port: 5

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 529 cm_control.c Sess: 1 Teardown call, Sees st:6 Sees call_est'd:1 call_contol st:5 5 reason#:119 line:878

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1205 sip_transport.c Sess: 1 Send SIP message: 4 To 172.169.1.5:5060

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 704 sip_message.c Building SIP BYE, Sess: 1

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1524 sip_transport.c Sess: 1 BYE sip:2201@172.169.1.5:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.169.1.110:5070;branch=z9hG4bKd5b6553305671a15 From: "WIRELESS CALLER"<sip:5612093583@172.169.1.5>;tag=4be32d04b2a3e9f1 To: <sip:70@172.169.1.5>;tag=6a07058e6b Call-ID: 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110 CSeq: 30237 BYE User-Agent: Grandstream GXW4108 (HW 1.1, Ch:1) 1.3.1.6 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Reason: SIP ;text="FX call terminated" Content-Length: 0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 <Event> On-Hook, From: 906 , GWSt: 7

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (7:0)

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Set State to: On-Hook, From: 978

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 5 Stop tone [0] from Line:837

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1258 sip.c Acc:5 Size:383 Received SIP message: SIP/2.0 200 Ok Via: SIP/2.0/UDP 172.169.1.110:5070;branch=z9hG4bKd5b6553305671a15 From: "WIRELESS CALLER" <sip:5612093583@172.169.1.5>;tag=4be32d04b2a3e9f1 To: <sip:70@172.169.1.5>;tag=6a07058e6b Call-ID: 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110 CSeq: 30237 BYE Contact: <sip:2201@172.169.1.5:5060;transport=udp> User-Agent: pbxnsip-PBX/4.0.1.3499 Content-Length: 0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 199 sip_dialog.c Sess: 1 Call-ID MATCHED, len&id:46 72838e728fa13c91c7c23cc74aa77ff1@172.169.1.110

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 5 Stop tone [0] from Line:429

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 332 sip.c Sess: 1, Sess st:0, init'd from#:119;

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 5 Reset Tone Detection

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 5 Disable detection: Global Mask: FFFF DTMF: 0000 CPT: 0000

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 5 Disabling detection, Type: BELLCORE

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1258 sip.c Acc:0 Size:457 Received SIP message: BYE sip:172.169.1.110:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 172.169.1.5:5060;branch=z9hG4bK-f71d0b495705747feb59b14fe09b3eaa;rport From: "WIRELESS CALLER" <sip:5612093583@localhost;user=phone>;tag=25902 To: <sip:840@localhost;user=phone>;tag=a630d4d4dd075475 Call-ID: 3480f276@pbx CSeq: 15780 BYE Max-Forwards: 70 Contact: <sip:2201@172.169.1.5:5060;transport=udp> P-Asserted-Identity: "GrandStream" <sip:2201@localhost> Content-Length: 0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 185 sip_dialog.c Sess: 0 Call-ID not matched, len&id:0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 185 sip_dialog.c Sess: 1 Call-ID not matched, len&id:0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 199 sip_dialog.c Sess: 2 Call-ID MATCHED, len&id:12 3480f276@pbx

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1205 sip_transport.c Sess: 2 Send SIP message: 200 To 172.169.1.5:5060

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 1524 sip_transport.c Sess: 2 SIP/2.0 200 OK Via: SIP/2.0/UDP 172.169.1.5:5060;branch=z9hG4bK-f71d0b495705747feb59b14fe09b3eaa;rport From: "WIRELESS CALLER" <sip:5612093583@localhost;user=phone>;tag=25902 To: <sip:840@localhost;user=phone>;tag=a630d4d4dd075475 Call-ID: 3480f276@pbx CSeq: 15780 BYE User-Agent: Grandstream GXW4108 (HW 1.1, Ch:2) 1.3.1.6 Contact: <sip:172.169.1.110:5060;transport=udp> Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer, 100rel, path Content-Length: 0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 546 cm_api.c SigRemoteDisc, Port: 4 Sess: 2, sess st:6, sess orig xfr ch:0, gw st:4, gw lcs:8, gw sipch:2

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Stop tone [0] from Line:429

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 332 sip.c Sess: 2, Sess st:0, init'd from#:119;

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Initiate Hang-Up, From: 589

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] LEC: Disable Port: 4

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 <Event> On-Hook, From: 906 , GWSt: 7

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] APP: app_State:last_fxo_call_status (7:8)

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Set State to: On-Hook, From: 1085

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_GEN: Port: 4 Stop tone [0] from Line:837

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 4 Reset Tone Detection

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] TONE_DET: Port: 4 Disable detection: Global Mask: FFFF DTMF: 0000 CPT: 0000

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO_CID: Port: 4 Disabling detection, Type: BELLCORE

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] cm_task.c 1741 Port: 4 Sess: 2 fxoCallStatus old/new:8 0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 831 cm_utility.c Port: 4 Sess: 2, gw st: 7, gw sigtm: 55041, sess st: 0, call st: 1, fxo cs: 0, from#: 1757, reason: 0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 887 cm_utility.c Port: 4, sip chan:2, gw cid len:12, sip st:0

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line Event triggered is: 5 Previous Event was: 3 current line Status is: 4 count: 15

05/12/10 21:26:14 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 4 Line Event triggered is: 1 Previous Event was: 3 current line Status is: 4 count: 15

05/12/10 21:26:15 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 729 cm_utility.c Port: 4 Sess: 2, gw st:7, call st:1, rtp st:0, drv_cs:0, caller#:596, FIN !

05/12/10 21:26:15 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] FXO: Port: 5 Line Event triggered is: 1 Previous Event was: 3 current line Status is: 2 count: 15

05/12/10 21:26:16 [172.169.1.110] (user.debug) GS_LOG: [00:0B:82:21:11:43][000][9660000211A][1.3.1.6] 729 cm_utility.c Port: 5 Sess: 1, gw st:7, call st:1, rtp st:0, drv_cs:0, caller#:902, FIN !

 

 

 

log from PBXnSIP

[8] 2010/05/12 21:17:54: Last message repeated 625 times

[9] 2010/05/12 21:17:54: UDP: Opening socket on 0.0.0.0:49224

[9] 2010/05/12 21:17:54: UDP: Opening socket on 0.0.0.0:49225

[5] 2010/05/12 21:17:54: Identify trunk (IP address and DID match) 1

[9] 2010/05/12 21:17:54: Resolve 1177: aaaa udp 172.169.1.110 5070

[9] 2010/05/12 21:17:54: Resolve 1177: a udp 172.169.1.110 5070

[9] 2010/05/12 21:17:54: Resolve 1177: udp 172.169.1.110 5070

[7] 2010/05/12 21:17:54: Set packet length to 20

[6] 2010/05/12 21:17:54: Sending RTP for 15840b0650a56da395e5b7d6e7825c42@172.169.1.110#8664a79045 to 172.169.1.110:5032

[5] 2010/05/12 21:17:54: Domain trunk PSTN Gateway@localhost sends call to 72 in domain localhost

[8] 2010/05/12 21:17:54: Call state for call object 5: idle

[8] 2010/05/12 21:17:54: Play audio_moh/noise.wav

[7] 2010/05/12 21:17:54: Hunt Group 72: Moving to next stage

[7] 2010/05/12 21:17:54: Set packet length to 20

[6] 2010/05/12 21:17:54: Send codec pcmu/8000

[7] 2010/05/12 21:17:54: Hunt group 72 started 2 calls

[9] 2010/05/12 21:17:54: Resolve 1178: aaaa udp 172.169.1.110 5070

[9] 2010/05/12 21:17:54: Resolve 1178: a udp 172.169.1.110 5070

[9] 2010/05/12 21:17:54: Resolve 1178: udp 172.169.1.110 5070

[9] 2010/05/12 21:17:54: UDP: Opening socket on 0.0.0.0:53286

[9] 2010/05/12 21:17:54: UDP: Opening socket on 0.0.0.0:53287

[9] 2010/05/12 21:17:54: Using outbound proxy sip:172.169.1.60:1059;transport=tls because of flow-label

[9] 2010/05/12 21:17:54: UDP: Opening socket on 0.0.0.0:53300

[9] 2010/05/12 21:17:54: UDP: Opening socket on 0.0.0.0:53301

[9] 2010/05/12 21:17:54: Using outbound proxy sip:172.169.1.61:1042;transport=tls because of flow-label

[7] 2010/05/12 21:17:54: Call f1132ae1@pbx#52871: Clear last INVITE

[5] 2010/05/12 21:17:54: INVITE Response 486 Busy Here: Terminate f1132ae1@pbx

[8] 2010/05/12 21:17:54: CSTA: leg=12, device=100@localhost, inbound=false, Calling=5612093583@localhost, Called=70@localhost, State=terminated, call id = [f1132ae1@pbx#52871]

[7] 2010/05/12 21:17:54: Call 14990e1e@pbx#35898: Clear last INVITE

[5] 2010/05/12 21:17:54: INVITE Response 486 Busy Here: Terminate 14990e1e@pbx

[8] 2010/05/12 21:17:54: CSTA: leg=13, device=101@localhost, inbound=false, Calling=5612093583@localhost, Called=70@localhost, State=terminated, call id = [14990e1e@pbx#35898]

[8] 2010/05/12 21:17:56: Packet authenticated by transport layer

[8] 2010/05/12 21:18:04: Last message repeated 25 times

[7] 2010/05/12 21:18:04: Hunt Group 72: Moving to next stage

[7] 2010/05/12 21:18:04: Hunt group 72 started 0 calls

[7] 2010/05/12 21:18:04: Hunt Group 72: Moving to next stage

[7] 2010/05/12 21:18:04: Hunt group 72 started 0 calls

[7] 2010/05/12 21:18:04: Hunt Group 72: Moving to next stage

[9] 2010/05/12 21:18:04: Dialplan: Evaluating !^(\+?[0-9]*)@.*!sip:\1@\r;user=phone!i against 840@localhost

[5] 2010/05/12 21:18:04: Dialplan Standard Dialplan: Match 840@localhost to <sip:840@localhost;user=phone> on trunk PSTN Gateway

[5] 2010/05/12 21:18:04: Using "WIRELESS CALLER" <sip:5612093583@localhost;user=phone> as redirect source address

[8] 2010/05/12 21:18:04: Play audio_moh/noise.wav

[9] 2010/05/12 21:18:04: UDP: Opening socket on 0.0.0.0:60678

[9] 2010/05/12 21:18:04: UDP: Opening socket on 0.0.0.0:60679

[9] 2010/05/12 21:18:04: Resolve 1208: url sip:172.169.1.110

[9] 2010/05/12 21:18:04: Resolve 1208: udp 172.169.1.110 5060

[9] 2010/05/12 21:18:04: Message repetition, packet dropped

[8] 2010/05/12 21:18:04: Packet authenticated by transport layer

[7] 2010/05/12 21:18:05: Call 71579948@pbx#15169: Clear last INVITE

[7] 2010/05/12 21:18:05: Set packet length to 20

[8] 2010/05/12 21:18:05: Send codec=pcmu/8000 after answer

[6] 2010/05/12 21:18:05: Sending RTP for 71579948@pbx#15169 to 172.169.1.110:5004

[9] 2010/05/12 21:18:05: Resolve 1210: url sip:172.169.1.110:5060;transport=udp

[9] 2010/05/12 21:18:05: Resolve 1210: a udp 172.169.1.110 5060

[9] 2010/05/12 21:18:05: Resolve 1210: udp 172.169.1.110 5060

[7] 2010/05/12 21:18:05: Determine pass-through mode after receiving response

[8] 2010/05/12 21:18:05: Call state for call object 5: alerting

[8] 2010/05/12 21:18:05: Play audio_en/ringback.wav

[8] 2010/05/12 21:18:05: Call state for call object 5: connected

[9] 2010/05/12 21:18:05: Resolve 1211: aaaa udp 172.169.1.110 5070

[9] 2010/05/12 21:18:05: Resolve 1211: a udp 172.169.1.110 5070

[9] 2010/05/12 21:18:05: Resolve 1211: udp 172.169.1.110 5070

[7] 2010/05/12 21:18:05: 71579948@pbx#15169: RTP pass-through mode

[7] 2010/05/12 21:18:05: 15840b0650a56da395e5b7d6e7825c42@172.169.1.110#8664a79045: RTP pass-through mode

[8] 2010/05/12 21:18:06: Packet authenticated by transport layer

[8] 2010/05/12 21:18:15: Last message repeated 13 times

[9] 2010/05/12 21:18:15: Resolve 1225: aaaa udp 172.169.1.110 5070

[9] 2010/05/12 21:18:15: Resolve 1225: a udp 172.169.1.110 5070

[9] 2010/05/12 21:18:15: Resolve 1225: udp 172.169.1.110 5070

[7] 2010/05/12 21:18:15: 71579948@pbx#15169: Media-aware pass-through mode

[8] 2010/05/12 21:18:15: Hangup: Call 15840b0650a56da395e5b7d6e7825c42@172.169.1.110#8664a79045 not found

[9] 2010/05/12 21:18:15: Resolve 1226: url sip:172.169.1.110:5060;transport=udp

[9] 2010/05/12 21:18:15: Resolve 1226: a udp 172.169.1.110 5060

[9] 2010/05/12 21:18:15: Resolve 1226: udp 172.169.1.110 5060

[7] 2010/05/12 21:18:15: Call 71579948@pbx#15169: Clear last request

[5] 2010/05/12 21:18:15: BYE Response: Terminate 71579948@pbx

[8] 2010/05/12 21:18:18: Packet authenticated by transport layer

 

 

 

these 2 logs are 2 separate call attempts i made, and grabbed the logs off of them to see what they said.

 

 

if anyone can help me out on this, with, well, just a random little idea, that'd be great!

Link to comment
Share on other sites

I did not go though the complete log. What/where was the problem/solution?

 

 

one of my idiot users....

 

hit call forward on both reception phones, and didn't include a call forwarding destination..

 

so the calls were going to outer space

 

never would have thought to check that..

 

so i went in and changed that soft key......

Link to comment
Share on other sites

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.
Note: Your post will require moderator approval before it will be visible.

Guest
Reply to this topic...

×   Pasted as rich text.   Paste as plain text instead

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.

×
×
  • Create New...