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!