Trying to get T.38 passthrough working to send faxes using HT-502 <- Internet -> Asterisk 1.4.31 <- Internet -> Gafachi
The HT-502 has a public IP and is set to T.38 Auto and Detection to Caller and Callee (There appears to be no T.38 negotiation if I just set this to callee)
In Asterisk I have tried every combination of reinvite for both the HT-502 and Gafachi with no luck. I currently have reinvite set to no for Gafachi and yes for the HT-502. I’m using the default udptl.conf and t38pt_udptl=yes in sip_general_custom.
Exerts from the debug info are below.
Asterisk Debug
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing session-level SDP v=0… UNSUPPORTED.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing session-level SDP o=5202 8000 8001 IN IP4 24.148.91.7… UNSUPPORTED.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing session-level SDP s=SIP Call… UNSUPPORTED.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing session-level SDP c=IN IP4 24.148.91.7… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing session-level SDP t=0 0… UNSUPPORTED.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: T38 state changed to 3 on channel SIP/5202-0000000d
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: FaxVersion: 0
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38FaxVersion:0… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: T38MaxBitRate: 9600
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38MaxBitRate:9600… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: RateManagement: transferredTCF
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38FaxRateManagement:transferredTCF… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: MaxBufferSize:400
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38FaxMaxBuffer:400… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: FaxMaxDatagram: 280
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38FaxMaxDatagram:280… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: UDP EC: t38UDPRedundancy
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38FaxUdpEC:t38UDPRedundancy… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Have T.38 but no audio codecs, accepting offer anyway
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: We’re settling with these formats: 0x0 (nothing)
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: We have an owner, now see if we need to change this call
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: SIP/5202-0000000d: This call is UP…
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Sending reinvite on SIP ‘[email protected]’ - It’s UDPTL soon redirected to us (IP 74.119.216.170)
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: T38MaxBitRate 9600 found
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Done building SDP. Settling with this capability: 0x0 (nothing)
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Initializing already initialized SIP dialog [email protected] (presumably reinvite)
[2010-05-16 10:04:50] DEBUG[3909] rtp.c: Setting the marker bit due to a source update
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Acked pending invite 104
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 104: Match Found
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: SIP response 200 to RE-invite on outgoing call [email protected]
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing session-level SDP v=0… UNSUPPORTED.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing session-level SDP o=root 553669791 553669793 IN IP4 67.216.37.20… UNSUPPORTED.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing session-level SDP s=session… UNSUPPORTED.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing session-level SDP c=IN IP4 67.216.37.20… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing session-level SDP t=0 0… UNSUPPORTED.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: T38 state changed to 3 on channel SIP/gafachi1a-0000000e
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: FaxVersion: 0
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38FaxVersion:0… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: RateManagement: transferredTCFlocalTCF
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38FaxRateManagement:transferredTCFlocalTCF… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: UDP EC: t38UDPFEC
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38FaxUdpEC:t38UDPFEC… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38FaxMaxBufferSize:2000… UNSUPPORTED.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: FaxMaxDatagram: 512
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38MaxDatagram:512… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: T38MaxBitRate: 14400
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Processing media-level (image) SDP a=T38FaxMaxRate:14400… OK.
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Have T.38 but no audio codecs, accepting offer anyway
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: We’re settling with these formats: 0x0 (nothing)
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: We have an owner, now see if we need to change this call
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Updating call counter for outgoing call
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Responding 200 OK on SIP ‘[email protected]’ - It’s UDPTL soon redirected to us (IP 74.119.216.170)
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: T38 changed state to 4 on channel SIP/gafachi1a-0000000e
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: T38 changed state to 4 on channel SIP/5202-0000000d
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: T38MaxBitRate 9600 found
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: Done building SDP. Settling with this capability: 0x0 (nothing)
[2010-05-16 10:04:50] DEBUG[5613] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
HT-502 Log
2010-05-16 10:04:44 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Dialing 832918884732963
2010-05-16 10:04:44 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] ATACtrl::call on port 0:0, status = 2(CALL_DIALED)
2010-05-16 10:04:44 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Bound to RTP port 5004, socket 20
2010-05-16 10:04:44 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] SigCtrl::call on port 0:0, status = 2(CALL_DIALED)
2010-05-16 10:04:44 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Received 407 response for transaction 94(INVITE)
2010-05-16 10:04:44 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Request (94) got status code 407 refKnt 2, retryAfter 0
2010-05-16 10:04:44 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Received 100 response for transaction 95(INVITE)
2010-05-16 10:04:45 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Received 180 response for transaction 95(INVITE)
2010-05-16 10:04:45 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:04:45 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Dispatching event: 26 (SIG_REMOTE_RING) on port 0:0
2010-05-16 10:04:45 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] ATACtrl::processSigRemoteRing on port 0:0, status = CALL_DIALED/CALL_IDLE
2010-05-16 10:04:45 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic::stopTone, Stop tone on port 0, direction 0
2010-05-16 10:04:45 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic::playTone, Play tone 38 on port 0, direction 1
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Received 200 response for transaction 95(INVITE)
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] SIPDialog, set SDP media to remote 74.119.216.170:13780, state=2 sdp=0
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Kill ICT transaction 95
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Request (95) got status code 200 refKnt 2, retryAfter 0
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Peer has no RFC2833 in SDP, hasINFO= 1, port 0, ch 0
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] DTMF method negotiated: SIP_INFO
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] RTP::setSDP, current sdp: (nil), new sdp: 0x1001b7d0
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] ::processMedia, Call started on port 0:0:5004, disable2833=1 use:SIP_INFO
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Polarity reversal on port 0
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic22::disableLEC, LEC is disabled on port 0:0
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic22::startRTP, RTP encoder type is 8@20, port 0:0, dev 0:0 dtmf:0-1-102
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic22::enableLEC, WLEC is enabled on port 0:0
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] VAD is disabled on port 0:0
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] RTP start on port 0, remote target 74.119.216.170:13780, local rtp port:5004
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] RTP start on port 0, SRTP status NO_SRTP
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Dispatching event: 11 (CALL_STARTED) on port 0:0
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] ATACtrl::processCallStarted on port 0:0, status = CALL_RINGING/CALL_IDLE, isCaller 1
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic::stopTone, Stop tone on port 0, direction 0
2010-05-16 10:04:51 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] CALL_STARTED, port 0:0, evtPort 0:0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] CNG TX signal detected on port 0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Dispatching event: 8 (PHONE_FAX_TX_DETECTED) on port 0:0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Fax/Modem signal detected on port 0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic22::disableLEC, LEC is disabled on port 0:0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] VAD is disabled on port 0:0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Received 100 response for transaction 96(INVITE)
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Received 200 response for transaction 96(INVITE)
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] SIPDialog, set SDP media to remote 74.119.216.170:4629, state=2 sdp=1
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] SIPStack, ReinviteSDP SRTP status = 0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Kill ICT transaction 96
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Dispatching event: 32 (SIG_MEDIA_CHANGE) on port 0:0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] SIG_MEDIA_CHANGE, port 0:0, evtPort 0:0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] RTPStat on port 0/0: sent 44, loss 1, jitter 8
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic22::disableLEC, LEC is disabled on port 0:0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Call::processMedia, changeSDP, start rtp on port 0:0:5004, t38=0, t38dir=0, SRTP=0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] RTP stop on port 0 local rtp port:5004 sdp:0x1001b7d0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] T38 sent CM msg: port:0 ch:0
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] T38 session started at port:0 ch:0, max rate:9600
2010-05-16 10:04:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] T38 received msg: 6 for port:0 ch:0 st:0 cxn:1
2010-05-16 10:04:59 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Mark server 74.119.216.170 available
2010-05-16 10:04:59 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Received SIP request OPTIONS (0)
2010-05-16 10:04:59 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:04:59 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Mark server 74.119.216.170 available
2010-05-16 10:04:59 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Received SIP request OPTIONS (1)
2010-05-16 10:05:14 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:05:16 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Kill ICT transaction 94
2010-05-16 10:05:16 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:05:31 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Kill NIST transaction 97
2010-05-16 10:05:31 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:05:31 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Kill NIST transaction 98
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Received SIP request BYE (0)
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Active call dialogs (0): 1
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Dispatching event: 30 (SIG_REMOTE_DISCONNECT) on port 0:0
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] ATACtrl::processSigRemoteDisconnect on port 0:0, status = CALL_COMMUNICATION/CALL_IDLE
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic::stopTone, Stop tone on port 0, direction 0
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic::playTone, Play tone 40 on port 0, direction 1
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Dispatching event: 19 (CALL_COMPLETED) on port 0:0
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] SipSigControl::processCallCompleted on port 0:0, status = CALL_ENDING/CALL_IDLE
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] ATACtrl::processCallCompleted on port 0:0, status = CALL_IDLE/CALL_IDLE
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic22::disableLEC, LEC is disabled on port 0:0
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] T38 session stopped at port:0 ch:0 st:1 cxn:1
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] T38 received msg: 8 for port:0 ch:0 st:1 cxn:1
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Call::processMedia, Call stopped on port 0:0
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Polarity reversal on port 0
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Deleting Call object 6 port 0:0
2010-05-16 10:05:36 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Unregister event listener Call
2010-05-16 10:05:41 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Dispatching event: 2 (PHONE_ON_HOOK) on port 0:0
2010-05-16 10:05:41 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] ATACtrl::processPhoneOnHook on port 0:0, status = CALL_IDLE/CALL_IDLE
2010-05-16 10:05:41 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Vinetic::stopTone, Stop tone on port 0, direction 0
2010-05-16 10:05:41 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Phone at port 0 is on-hook
2010-05-16 10:05:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Deleting call dialog (0:6)
2010-05-16 10:05:52 Local7.Debug 192.168.2.1 HT502: [00:0B:82:24:77:74][1.0.1.57] Deleting SDP in the dialog