Menu

g711->t.38 issues and NO CARRIER

Help
Alexey
2013-02-21
2016-10-19
  • Alexey

    Alexey - 2013-02-21

    Hi folks. I have t38modem 2.0, with hylafax.  I'm able to sip register, dial, but cannot complete sending  a fax. Can someone explain what the issue is here with switching from g711 to t.38 and why am I getting a no carrier?  Thank you very much!

    /bin/t38modem -tttt -o /var/log/t38modem.log --no-h323 -u ${USER} --ptty +/dev/ttyT38-1 --sip-proxy ${USER}@66.23.129.253 --sip-register ${USER}@66.23.129.253,${PASS},12038646060@66.23.129.253,nexvortex.com,${USER} --route modem:.*=sip:\<dn\>@66.23.129.253 --route sip:.*=modem:\<dn\> --ports rtp:10000-25000 
    T38Modem Version 2.0.0
     (OPAL-3.9.0/3.9beta0, PTLIB-2.9.0/2.9beta0 (svn:24165)) by Vyacheslav Frolov on Unix Linux (2.6.32-279.19.1.el6.centos.plus.x86_64-x86_64)
    Disabled H.323 protocol
    Waiting for incoming SIP calls from udp$*:5060,tcp$*:5060,tcps$*:5061
    Route table:
      modem:.*=sip:<dn>@66.23.129.253
      sip:.*=modem:<dn>
    Call[C049f6ca11] from modem:${USER} to 12037691544@+/dev/ttyT38-1, route to sip:12037691544@66.23.129.253
    Open OpalRTPMediaStream-Source-G.711-uLaw-64k for Call[C049f6ca11]
    Open AudioModemMediaStream-Sink-PCM-16 for Call[C049f6ca11]
    Open AudioModemMediaStream-Source-PCM-16 for Call[C049f6ca11]
    Open OpalRTPMediaStream-Sink-G.711-uLaw-64k for Call[C049f6ca11]
    Close OpalRTPMediaStream-Sink-G.711-uLaw-64k for Call[C049f6ca11]
    Close AudioModemMediaStream-Source-PCM-16 for Call[C049f6ca11]
    Close AudioModemMediaStream-Sink-PCM-16 for Call[C049f6ca11]
    Close OpalRTPMediaStream-Source-G.711-uLaw-64k for Call[C049f6ca11]
    Open OpalRTPMediaStream-Source-T.38 for Call[C049f6ca11]
    Open T38ModemMediaStream-Source-T.38 for Call[C049f6ca11]
    Open OpalRTPMediaStream-Sink-T.38 for Call[C049f6ca11]
    Open T38ModemMediaStream-Sink-T.38 for Call[C049f6ca11]
    Close T38ModemMediaStream-Sink-T.38 for Call[C049f6ca11]
    Close OpalRTPMediaStream-Source-T.38 for Call[C049f6ca11]
    Close OpalRTPMediaStream-Sink-T.38 for Call[C049f6ca11]
    Close T38ModemMediaStream-Source-T.38 for Call[C049f6ca11]
    Call[C049f6ca11] cleared (Remote party cleared call)
    

    /var/log/t38modem.log for this one call:

    2013/02/21 17:56:40.829                T38Modem SIP Start REGISTER
              aor=MYUSERNAME@66.23.129.253
           remote=
            local=
          contact=12038646060@66.23.129.253
           authID=MYUSERNAME
            realm=nexvortex.com
           expire=300
          restore=30
         minRetry=default
         maxRetry=default
    compatibility=FullyCompliant
    2013/02/21 17:56:40.829 Opal Liste...0xde64b700 TCPS    Waiting on socket accept on tcps$*:5061
    2013/02/21 17:56:40.829                T38Modem PWLib   File handle high water mark set: 36 PUDPSocket
    2013/02/21 17:56:40.829                T38Modem SIP Constructed handler for sip:MYUSERNAME@66.23.129.253
    2013/02/21 17:56:40.830                T38Modem SIP Executing state change to Subscribing for REGISTER handler, target=sip:MYUSERNAME@66.23.129.253, id=7adc9a9f-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    2013/02/21 17:56:40.830                T38Modem SIP Changing REGISTER handler from Unavailable to Subscribing, target=sip:MYUSERNAME@66.23.129.253, id=7adc9a9f-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    2013/02/21 17:56:40.830                T38Modem OpalUDP Binding to interface: 0.0.0.0:5060
    2013/02/21 17:56:40.830                T38Modem SIP Created transport udp$66.23.129.253:5060<if=udp$*:5060>
    2013/02/21 17:56:40.830                T38Modem OpalUDP Started connect to 66.23.129.253:5060
    2013/02/21 17:56:40.830                T38Modem OpalUDP Writing to interface 0 - "192.168.77.42%eth0"
    2013/02/21 17:56:40.830                T38Modem SIP Transaction created.
    2013/02/21 17:56:40.831                T38Modem SIP Transaction remote address is udp$66.23.129.253:5060
    2013/02/21 17:56:40.831                T38Modem SIP Sending PDU (566 bytes) to: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    REGISTER sip:66.23.129.253 SIP/2.0
    CSeq: 1 REGISTER
    Via: SIP/2.0/UDP 192.168.77.42:5060;branch=z9hG4bK9e219b9f-e77a-e211-8957-5254007747e9;rport
    User-Agent: T38Modem/2.0.0
    From: <sip:MYUSERNAME@66.23.129.253>;tag=2ce99a9f-e77a-e211-8957-5254007747e9
    Call-ID: 7adc9a9f-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    Organization: Vyacheslav Frolov
    To: <sip:MYUSERNAME@66.23.129.253>
    Contact: <sip:12038646060@66.23.129.253>
    Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING
    Expires: 300
    Content-Length: 0
    Max-Forwards: 70
    2013/02/21 17:56:40.832                T38Modem OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:56:40.832                T38Modem SIP Transaction timers set: retry=0.500, completion=16.000
    2013/02/21 17:56:40.832                T38Modem OpalMan Added route "modem:.*=sip:<dn>@66.23.129.253"
    2013/02/21 17:56:40.832                T38Modem OpalMan Added route "sip:.*=modem:<dn>"
    2013/02/21 17:56:40.832                T38Modem PTLib   Destroyed PXConfig 0x24eebe0
    2013/02/21 17:56:40.863 Opal Liste...0xde6cd700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:56:40.863 Opal Liste...0xde6cd700 SIP Waiting for PDU on udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:56:40.863 Opal Liste...0xde6cd700 SIP PDU received: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    SIP/2.0 401 Unauthorized
    CSeq: 1 REGISTER
    Via: SIP/2.0/UDP 192.168.77.42;branch=z9hG4bK9e219b9f-e77a-e211-8957-5254007747e9;rport=5060
    Server: nVSIP 12.01.02
    From: <sip:MYUSERNAME@66.23.129.253>;tag=2ce99a9f-e77a-e211-8957-5254007747e9
    Call-ID: 7adc9a9f-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:MYUSERNAME@66.23.129.253>;tag=b27e1a1d33761e85846fc98f5f3a7e58.4799
    Content-Length: 0
    WWW-Authenticate: Digest realm="nexvortex.com", nonce="5126a753ae3a3bd14837baeea109fcb448919f1d"
    2013/02/21 17:56:40.863 Opal Liste...0xde6cd700 SIP Queueing PDU "1 REGISTER <401>", transaction=z9hG4bK9e219b9f-e77a-e211-8957-5254007747e9, token=7adc9a9f-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    2013/02/21 17:56:40.863 Opal Liste...0xde6cd700 PWLib   File handle high water mark set: 37 Thread unblock pipe
    2013/02/21 17:56:40.863 Opal Liste...0xde6cd700 PTLib   Thread high water mark set: 13
    2013/02/21 17:56:40.863 Opal Liste...0xde6cd700 Opal    Transport clean up on termination
    2013/02/21 17:56:40.864 Opal Liste...0xde6cd700 Opal    Transport Close
    2013/02/21 17:56:40.864 Opal Liste...0xde6cd700 PWLib   File handle high water mark set: 38 PUDPSocket
    2013/02/21 17:56:40.864 Opal Liste...0xde6cd700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:56:40.864         Pool:0xde60a700 SIP Handling PDU "1 REGISTER <401>" for transaction=z9hG4bK9e219b9f-e77a-e211-8957-5254007747e9
    2013/02/21 17:56:40.864         Pool:0xde60a700 SIP REGISTER transaction id=z9hG4bK9e219b9f-e77a-e211-8957-5254007747e9 completed.
    2013/02/21 17:56:40.864         Pool:0xde60a700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:56:40.864         Pool:0xde60a700 SIP Received Authentication Required response
    2013/02/21 17:56:40.864         Pool:0xde60a700 SIP Updating authentication credentials.
    2013/02/21 17:56:40.864         Pool:0xde60a700 SIP Transaction created.
    2013/02/21 17:56:40.865         Pool:0xde60a700 HTTP    Adding authentication information
    2013/02/21 17:56:40.865         Pool:0xde60a700 SIP Transaction remote address is udp$66.23.129.253:5060
    2013/02/21 17:56:40.865         Pool:0xde60a700 SIP Sending PDU (769 bytes) to: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    REGISTER sip:66.23.129.253 SIP/2.0
    CSeq: 2 REGISTER
    Via: SIP/2.0/UDP 192.168.77.42:5060;branch=z9hG4bK424ba09f-e77a-e211-8957-5254007747e9;rport
    User-Agent: T38Modem/2.0.0
    Authorization: Digest username="MYUSERNAME", realm="nexvortex.com", nonce="5126a753ae3a3bd14837baeea109fcb448919f1d", uri="sip:66.23.129.253", algorithm=MD5, response="c03ad9c3d6c37b1d3b8a883a60ee002b"
    From: <sip:MYUSERNAME@66.23.129.253>;tag=2ce99a9f-e77a-e211-8957-5254007747e9
    Call-ID: 7adc9a9f-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    Organization: Vyacheslav Frolov
    To: <sip:MYUSERNAME@66.23.129.253>
    Contact: <sip:12038646060@66.23.129.253>
    Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING
    Expires: 300
    Content-Length: 0
    Max-Forwards: 70
    2013/02/21 17:56:40.865         Pool:0xde60a700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:56:40.866         Pool:0xde60a700 SIP Transaction timers set: retry=0.500, completion=16.000
    2013/02/21 17:56:40.866         Pool:0xde60a700 SIP Handled PDU "1 REGISTER <401>"
    2013/02/21 17:56:40.897 Opal Liste...0xde6cd700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:56:40.897 Opal Liste...0xde6cd700 SIP Waiting for PDU on udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:56:40.898 Opal Liste...0xde6cd700 SIP PDU received: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    SIP/2.0 200 OK
    CSeq: 2 REGISTER
    Via: SIP/2.0/UDP 192.168.77.42;branch=z9hG4bK424ba09f-e77a-e211-8957-5254007747e9;rport=5060
    Server: nVSIP 12.01.02
    From: <sip:MYUSERNAME@66.23.129.253>;tag=2ce99a9f-e77a-e211-8957-5254007747e9
    Call-ID: 7adc9a9f-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:MYUSERNAME@66.23.129.253>;tag=b27e1a1d33761e85846fc98f5f3a7e58.4799
    Contact: <sip:s@63.115.29.134:5060>;expires=141, <sip:12038646060@108.170.107.7>;expires=300
    Content-Length: 0
    2013/02/21 17:56:40.898 Opal Liste...0xde6cd700 SIP Queueing PDU "2 REGISTER <200>", transaction=z9hG4bK424ba09f-e77a-e211-8957-5254007747e9, token=7adc9a9f-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    2013/02/21 17:56:40.898 Opal Liste...0xde6cd700 Opal    Transport clean up on termination
    2013/02/21 17:56:40.898 Opal Liste...0xde6cd700 Opal    Transport Close
    2013/02/21 17:56:40.898 Opal Liste...0xde6cd700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:56:40.898         Pool:0xde60a700 SIP Handling PDU "2 REGISTER <200>" for transaction=z9hG4bK424ba09f-e77a-e211-8957-5254007747e9
    2013/02/21 17:56:40.898         Pool:0xde60a700 SIP REGISTER transaction id=z9hG4bK424ba09f-e77a-e211-8957-5254007747e9 completed.
    2013/02/21 17:56:40.898         Pool:0xde60a700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:56:40.898         Pool:0xde60a700 SIP Product Info: name="nVSIP", version="", vendor="", comments="12.01.02"
    2013/02/21 17:56:40.898         Pool:0xde60a700 SIP Changing REGISTER handler from Subscribing to Subscribed, target=sip:MYUSERNAME@66.23.129.253, id=7adc9a9f-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    2013/02/21 17:56:40.898         Pool:0xde60a700 SIP Product Info: name="nVSIP", version="", vendor="", comments="12.01.02"
    2013/02/21 17:56:40.898         Pool:0xde60a700 SIP Handled PDU "2 REGISTER <200>"
    2013/02/21 17:56:45.026 ttyT38-1(i...0xde74f700 --> read ERROR -1 Input/output error
    2013/02/21 17:56:45.026 ttyT38-1(i...0xde74f700 --> Stopped
    2013/02/21 17:56:45.026 ttyT38-1(i...0xde74f700 PTLib   Thread ended: name="ttyT38-1(i):3732207360:0xde74f700", real=4.206, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
    2013/02/21 17:56:45.026 ttyT38-1(o...0xde70e700 <-- Stopped
    2013/02/21 17:56:45.027 ttyT38-1(o...0xde70e700 PWLib   File handle low water mark set: 18 PTextFile
    2013/02/21 17:56:45.027 ttyT38-1(o...0xde70e700 PTLib   Thread ended: name="ttyT38-1(o):3731941120:0xde70e700", real=4.205, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
    2013/02/21 17:56:45.037 ttyT38-1(e...0xde7d1700 <-> Stopped
    2013/02/21 17:56:45.037 ttyT38-1(e...0xde7d1700 PTLib   Thread ended: name="ttyT38-1(e):3732739840:0xde7d1700", real=4.217, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
    2013/02/21 17:56:45.047 ttyT38-1(b...0xde853700 PseudoModemPty::OpenPty removed link /dev/ttyT38-1 -> /dev/pts/1
    2013/02/21 17:56:45.047 ttyT38-1(b...0xde853700 PseudoModemPty::OpenPty read ERROR -1 Input/output error
    2013/02/21 17:56:45.047 ttyT38-1(b...0xde853700 PseudoModemPty::OpenPty added link /dev/ttyT38-1 -> /dev/pts/1
    2013/02/21 17:56:45.047 ttyT38-1(o...0xde74f700 RenameCurrentThread old ThreadName=OutPty:0xde74f700
    2013/02/21 17:56:45.047 ttyT38-1(e...0xde7d1700 RenameCurrentThread old ThreadName=ModemEngine:0xde7d1700
    2013/02/21 17:56:45.048 ttyT38-1(e...0xde7d1700 <-> Started
    2013/02/21 17:56:45.048 ttyT38-1(o...0xde74f700 <-- Started
    2013/02/21 17:56:45.048 ttyT38-1(i...0xde70e700 RenameCurrentThread old ThreadName=InPty:0xde70e700
    2013/02/21 17:56:45.048 ttyT38-1(i...0xde70e700 --> Started
    2013/02/21 17:56:45.865  Housekeeper:0xde790700 SIP Set state Terminated_Success for REGISTER transaction id=z9hG4bK9e219b9f-e77a-e211-8957-5254007747e9
    2013/02/21 17:56:45.899  Housekeeper:0xde790700 SIP Set state Terminated_Success for REGISTER transaction id=z9hG4bK424ba09f-e77a-e211-8957-5254007747e9
    2013/02/21 17:56:46.819 Opal Garbage:0xde894700 SIP Transaction id=z9hG4bK9e219b9f-e77a-e211-8957-5254007747e9 destroyed.
    2013/02/21 17:56:46.819 Opal Garbage:0xde894700 SIP Transaction id=z9hG4bK424ba09f-e77a-e211-8957-5254007747e9 destroyed.
    2013/02/21 17:57:19.749 ttyT38-1(e...0xde7d1700 --> ATZ
    2013/02/21 17:57:19.749 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:22.854 ttyT38-1(e...0xde7d1700 --> AT#CID=10
    2013/02/21 17:57:22.854 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:22.956 ttyT38-1(e...0xde7d1700 --> ATS0=0
    2013/02/21 17:57:22.956 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:23.058 ttyT38-1(e...0xde7d1700 --> ATE0
    2013/02/21 17:57:23.058 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:23.160 ttyT38-1(e...0xde7d1700 --> ATV1
    2013/02/21 17:57:23.160 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:23.262 ttyT38-1(e...0xde7d1700 --> ATQ0
    2013/02/21 17:57:23.262 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:23.364 ttyT38-1(e...0xde7d1700 --> ATS8=2
    2013/02/21 17:57:23.364 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:23.466 ttyT38-1(e...0xde7d1700 --> ATS7=60
    2013/02/21 17:57:23.466 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:23.568 ttyT38-1(e...0xde7d1700 --> AT+FCLASS=?
    2013/02/21 17:57:23.568 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 31 2c 38 0d 0a 4f  4b 0d 0a                  ..1,8..OK.. }
    2013/02/21 17:57:23.670 ttyT38-1(e...0xde7d1700 --> AT+FCLASS=1
    2013/02/21 17:57:23.670 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:23.772 ttyT38-1(e...0xde7d1700 --> ATI3
    2013/02/21 17:57:23.772 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 56 79 61 63 68 65  73 6c 61 76 20 46 72 6f   ..Vyacheslav Fro
      6c 6f 76 0d 0a 4f 4b 0d  0a                        lov..OK.. }
    2013/02/21 17:57:23.874 ttyT38-1(e...0xde7d1700 --> ATI0
    2013/02/21 17:57:23.874 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 54 33 38 46 41 58  0d 0a 4f 4b 0d 0a         ..T38FAX..OK.. }
    2013/02/21 17:57:23.976 ttyT38-1(e...0xde7d1700 --> AT+FREV?
    2013/02/21 17:57:23.976 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 32 2e 30 2e 30 0d  0a 4f 4b 0d 0a            ..2.0.0..OK.. }
    2013/02/21 17:57:24.078 ttyT38-1(e...0xde7d1700 --> AT+FTM=?
    2013/02/21 17:57:24.078 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 32 34 2c 34 38 2c  37 32 2c 37 33 2c 37 34   ..24,48,72,73,74
      2c 39 36 2c 39 37 2c 39  38 2c 31 32 31 2c 31 32   ,96,97,98,121,12
      32 2c 31 34 35 2c 31 34  36 0d 0a 4f 4b 0d 0a      2,145,146..OK.. }
    2013/02/21 17:57:24.180 ttyT38-1(e...0xde7d1700 --> AT+FRM=?
    2013/02/21 17:57:24.180 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 32 34 2c 34 38 2c  37 32 2c 37 33 2c 37 34   ..24,48,72,73,74
      2c 39 36 2c 39 37 2c 39  38 2c 31 32 31 2c 31 32   ,96,97,98,121,12
      32 2c 31 34 35 2c 31 34  36 0d 0a 4f 4b 0d 0a      2,145,146..OK.. }
    2013/02/21 17:57:24.282 ttyT38-1(e...0xde7d1700 --> ATL0M1
    2013/02/21 17:57:24.282 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:24.384 ttyT38-1(i...0xde70e700 --> read ERROR -1 Input/output error
    2013/02/21 17:57:24.385 ttyT38-1(i...0xde70e700 --> Stopped
    2013/02/21 17:57:24.385 ttyT38-1(i...0xde70e700 PTLib   Thread ended: name="ttyT38-1(i):3731941120:0xde70e700", real=39.337, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
    2013/02/21 17:57:24.385 ttyT38-1(o...0xde74f700 <-- Stopped
    2013/02/21 17:57:24.385 ttyT38-1(o...0xde74f700 PTLib   Thread ended: name="ttyT38-1(o):3732207360:0xde74f700", real=39.338, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
    2013/02/21 17:57:24.395 ttyT38-1(e...0xde7d1700 <-> Stopped
    2013/02/21 17:57:24.396 ttyT38-1(e...0xde7d1700 PTLib   Thread ended: name="ttyT38-1(e):3732739840:0xde7d1700", real=39.348, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
    2013/02/21 17:57:24.405 ttyT38-1(b...0xde853700 PseudoModemPty::OpenPty removed link /dev/ttyT38-1 -> /dev/pts/1
    2013/02/21 17:57:24.406 ttyT38-1(b...0xde853700 PseudoModemPty::OpenPty read ERROR -1 Input/output error
    2013/02/21 17:57:24.406 ttyT38-1(b...0xde853700 PseudoModemPty::OpenPty added link /dev/ttyT38-1 -> /dev/pts/1
    2013/02/21 17:57:24.406 ttyT38-1(o...0xde70e700 RenameCurrentThread old ThreadName=OutPty:0xde70e700
    2013/02/21 17:57:24.406 ttyT38-1(o...0xde70e700 <-- Started
    2013/02/21 17:57:24.406 ttyT38-1(i...0xde74f700 RenameCurrentThread old ThreadName=InPty:0xde74f700
    2013/02/21 17:57:24.406 ttyT38-1(i...0xde74f700 --> Started
    2013/02/21 17:57:24.406 ttyT38-1(e...0xde7d1700 RenameCurrentThread old ThreadName=ModemEngine:0xde7d1700
    2013/02/21 17:57:24.406 ttyT38-1(e...0xde7d1700 <-> Started
    2013/02/21 17:57:29.355 ttyT38-1(e...0xde7d1700 --> ATZ
    2013/02/21 17:57:29.355 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:32.460 ttyT38-1(e...0xde7d1700 --> AT#CID=10
    2013/02/21 17:57:32.460 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:32.562 ttyT38-1(e...0xde7d1700 --> ATS0=0
    2013/02/21 17:57:32.562 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:32.664 ttyT38-1(e...0xde7d1700 --> ATE0
    2013/02/21 17:57:32.664 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:32.766 ttyT38-1(e...0xde7d1700 --> ATV1
    2013/02/21 17:57:32.766 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:32.868 ttyT38-1(e...0xde7d1700 --> ATQ0
    2013/02/21 17:57:32.868 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:32.970 ttyT38-1(e...0xde7d1700 --> ATS8=2
    2013/02/21 17:57:32.970 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:33.072 ttyT38-1(e...0xde7d1700 --> ATS7=60
    2013/02/21 17:57:33.072 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:33.174 ttyT38-1(e...0xde7d1700 --> AT+FCLASS=?
    2013/02/21 17:57:33.174 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 31 2c 38 0d 0a 4f  4b 0d 0a                  ..1,8..OK.. }
    2013/02/21 17:57:33.276 ttyT38-1(e...0xde7d1700 --> AT+FCLASS=1
    2013/02/21 17:57:33.276 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:33.378 ttyT38-1(e...0xde7d1700 --> ATI3
    2013/02/21 17:57:33.378 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 56 79 61 63 68 65  73 6c 61 76 20 46 72 6f   ..Vyacheslav Fro
      6c 6f 76 0d 0a 4f 4b 0d  0a                        lov..OK.. }
    2013/02/21 17:57:33.480 ttyT38-1(e...0xde7d1700 --> ATI0
    2013/02/21 17:57:33.480 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 54 33 38 46 41 58  0d 0a 4f 4b 0d 0a         ..T38FAX..OK.. }
    2013/02/21 17:57:33.582 ttyT38-1(e...0xde7d1700 --> AT+FREV?
    2013/02/21 17:57:33.582 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 32 2e 30 2e 30 0d  0a 4f 4b 0d 0a            ..2.0.0..OK.. }
    2013/02/21 17:57:33.684 ttyT38-1(e...0xde7d1700 --> AT+FTM=?
    2013/02/21 17:57:33.684 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 32 34 2c 34 38 2c  37 32 2c 37 33 2c 37 34   ..24,48,72,73,74
      2c 39 36 2c 39 37 2c 39  38 2c 31 32 31 2c 31 32   ,96,97,98,121,12
      32 2c 31 34 35 2c 31 34  36 0d 0a 4f 4b 0d 0a      2,145,146..OK.. }
    2013/02/21 17:57:33.786 ttyT38-1(e...0xde7d1700 --> AT+FRM=?
    2013/02/21 17:57:33.786 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 32 34 2c 34 38 2c  37 32 2c 37 33 2c 37 34   ..24,48,72,73,74
      2c 39 36 2c 39 37 2c 39  38 2c 31 32 31 2c 31 32   ,96,97,98,121,12
      32 2c 31 34 35 2c 31 34  36 0d 0a 4f 4b 0d 0a      2,145,146..OK.. }
    2013/02/21 17:57:33.888 ttyT38-1(e...0xde7d1700 --> ATL0M1
    2013/02/21 17:57:33.888 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:33.991 ttyT38-1(e...0xde7d1700 --> AT+FCLASS=1
    2013/02/21 17:57:33.991 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:57:33.993 ttyT38-1(e...0xde7d1700 --> ATDF12037691544
    2013/02/21 17:57:33.993 ttyT38-1(e...0xde7d1700 ModemEngineBody::OffHook: off-hook cstCleared stCommand
    2013/02/21 17:57:33.993 ttyT38-1(e...0xde7d1700 Dial string: 12037691544@LF - OK
    2013/02/21 17:57:33.993 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetState: off-hook cstCleared stDial
    2013/02/21 17:57:33.994 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetCallState: off-hook cstDialing stDial
    2013/02/21 17:57:33.994 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetState: off-hook cstDialing stConnectWait
    2013/02/21 17:57:33.994 ttyT38-1(e...0xde7d1700 ModemEndPoint::OnMyCallback command=dial extra=5
    2013/02/21 17:57:33.994 ttyT38-1(e...0xde7d1700 PseudoModemQ::Dequeue ttyT38-1
    2013/02/21 17:57:33.994 ttyT38-1(e...0xde7d1700 MyManager::OnMyCallback SetUpCall(modem:, 12037691544@+/dev/ttyT38-1)
    2013/02/21 17:57:33.994 ttyT38-1(e...0xde7d1700 OpalMan Set up call from modem: to 12037691544@+/dev/ttyT38-1
    2013/02/21 17:57:33.994 ttyT38-1(e...0xde7d1700 Call    Created Call[C049f6ca11]
    2013/02/21 17:57:33.994 ttyT38-1(e...0xde7d1700 OpalMan Set up connection to "modem:"
    2013/02/21 17:57:33.995 ttyT38-1(e...0xde7d1700 ModemEndPoint::MakeConnection modem:
    2013/02/21 17:57:33.995 ttyT38-1(e...0xde7d1700 OpalCon Created connection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:33.995 ttyT38-1(e...0xde7d1700 ModemConnection::ModemConnection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:33.995 ttyT38-1(e...0xde7d1700 ModemConnection::SetUpConnection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:33.995 ttyT38-1(e...0xde7d1700 OpalCon SetPhase from UninitialisedPhase to SetUpPhase for Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:33.995 ttyT38-1(e...0xde7d1700 OpalMan OnIncoming connection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:33.996 ttyT38-1(e...0xde7d1700 OpalCon Applying string options:
    2013/02/21 17:57:33.996 ttyT38-1(e...0xde7d1700 Call    GetOtherPartyConnection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:33.996 ttyT38-1(e...0xde7d1700 OpalMan Searching for route "modem:MYUSERNAME   12037691544@+/dev/ttyT38-1"
    2013/02/21 17:57:33.996 ttyT38-1(e...0xde7d1700 OpalMan Matched regex "modem:.*"
    2013/02/21 17:57:33.996 ttyT38-1(e...0xde7d1700 OpalMan Set up connection to "sip:12037691544@66.23.129.253"
    2013/02/21 17:57:33.996 ttyT38-1(e...0xde7d1700 MySIPEndPoint::CreateConnection for Call[C049f6ca11]
    2013/02/21 17:57:33.997 ttyT38-1(e...0xde7d1700 OpalCon Created connection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:33.997 ttyT38-1(e...0xde7d1700 RFC2833 Handler created
    2013/02/21 17:57:33.997 ttyT38-1(e...0xde7d1700 RFC2833 Rx capability set to "0-16,32,36"
    2013/02/21 17:57:33.997 ttyT38-1(e...0xde7d1700 RFC2833 Handler created
    2013/02/21 17:57:33.997 ttyT38-1(e...0xde7d1700 RFC2833 Rx capability set to "192,193"
    2013/02/21 17:57:33.998 ttyT38-1(e...0xde7d1700 SIP Created connection.
    2013/02/21 17:57:33.998 ttyT38-1(e...0xde7d1700 Call[C049f6ca11] from modem:MYUSERNAME to 12037691544@+/dev/ttyT38-1, route to sip:12037691544@66.23.129.253
    2013/02/21 17:57:33.998 ttyT38-1(e...0xde7d1700 Outgoing call routed to sip:12037691544@66.23.129.253 for Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:33.998 ttyT38-1(e...0xde7d1700 Call    OnSetUp Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:33.998 ttyT38-1(e...0xde7d1700 MySIPConnection::SetUpConnection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] name=MYUSERNAME
    2013/02/21 17:57:33.998 ttyT38-1(e...0xde7d1700 SIP SetUpConnection: sip:12037691544@66.23.129.253
    2013/02/21 17:57:33.999 ttyT38-1(e...0xde7d1700 OpalCon SetPhase from UninitialisedPhase to SetUpPhase for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:33.999 ttyT38-1(e...0xde7d1700 OpalCon Applying string options:
    T38-UDPTL-Redundancy-Interval=50
    T38-UDPTL-Optimise-On-Retransmit=true
    T38-UDPTL-Redundancy=
    T38-UDPTL-Keep-Alive-Interval=0
    2013/02/21 17:57:33.999 ttyT38-1(e...0xde7d1700 MySIPConnection::OnApplyStringOptions Enabled formats (in preference order):
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:33.999 ttyT38-1(e...0xde7d1700 SIP Connecting to sip:12037691544@66.23.129.253 via sip:12037691544@66.23.129.253
    2013/02/21 17:57:33.999 ttyT38-1(e...0xde7d1700 SIP Found registrar on domain 66.23.129.253, using interface 192.168.77.42%eth0
    2013/02/21 17:57:34.000 ttyT38-1(e...0xde7d1700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:57:34.000 ttyT38-1(e...0xde7d1700 SIP Created transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:34.000 ttyT38-1(e...0xde7d1700 OpalUDP Started connect to 66.23.129.253:5060
    2013/02/21 17:57:34.000 ttyT38-1(e...0xde7d1700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:34.000 ttyT38-1(e...0xde7d1700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:34.003 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    G.711-ALaw-64k
    G.711-uLaw-64k
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    GSM-06.10
    GSM-AMR
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC
    iLBC-13k3
    iLBC-15k2
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:34.003 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:34.003 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.003 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.004 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:34.004 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.004 ttyT38-1(e...0xde7d1700 Call    GetMediaFormats for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.004 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.004 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove GSM-AMR
    2013/02/21 17:57:34.004 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove iLBC
    2013/02/21 17:57:34.004 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove GSM-06.10
    2013/02/21 17:57:34.004 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-16k
    2013/02/21 17:57:34.005 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-24k
    2013/02/21 17:57:34.005 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-32k
    2013/02/21 17:57:34.005 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-40k
    2013/02/21 17:57:34.005 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove LPC-10
    2013/02/21 17:57:34.005 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove MS-GSM
    2013/02/21 17:57:34.005 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove MS-IMA-ADPCM
    2013/02/21 17:57:34.005 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-11k
    2013/02/21 17:57:34.005 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-15k
    2013/02/21 17:57:34.005 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-18.2k
    2013/02/21 17:57:34.005 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-24.6k
    2013/02/21 17:57:34.006 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-5.95k
    2013/02/21 17:57:34.006 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-8k
    2013/02/21 17:57:34.006 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexNB
    2013/02/21 17:57:34.006 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexWNarrow-8k
    2013/02/21 17:57:34.006 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove iLBC-13k3
    2013/02/21 17:57:34.006 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove iLBC-15k2
    2013/02/21 17:57:34.006 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:34.006 ttyT38-1(e...0xde7d1700 SIP Remote media formats set to G.711-uLaw-64k,G.711-ALaw-64k,T.38,UserInput/RFC2833
    2013/02/21 17:57:34.006 ttyT38-1(e...0xde7d1700 SIP Updating dialog tag from "" to "7c8c4bbf-e77a-e211-8957-5254007747e9"
    2013/02/21 17:57:34.009 ttyT38-1(e...0xde7d1700 SIP INVITE transaction id=z9hG4bK7c494dbf-e77a-e211-8957-5254007747e9 created.
    2013/02/21 17:57:34.009 ttyT38-1(e...0xde7d1700 SIP Creating INVITE request
    2013/02/21 17:57:34.009 ttyT38-1(e...0xde7d1700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:34.009 ttyT38-1(e...0xde7d1700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:34.011 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    G.711-ALaw-64k
    G.711-uLaw-64k
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    GSM-06.10
    GSM-AMR
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC
    iLBC-13k3
    iLBC-15k2
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:34.012 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:34.012 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.012 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.013 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:34.013 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.013 ttyT38-1(e...0xde7d1700 Call    GetMediaFormats for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.013 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.013 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove GSM-AMR
    2013/02/21 17:57:34.013 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove iLBC
    2013/02/21 17:57:34.013 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove GSM-06.10
    2013/02/21 17:57:34.013 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-16k
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-24k
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-32k
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-40k
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove LPC-10
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove MS-GSM
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove MS-IMA-ADPCM
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-11k
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-15k
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-18.2k
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-24.6k
    2013/02/21 17:57:34.014 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-5.95k
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-8k
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexNB
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexWNarrow-8k
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove iLBC-13k3
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove iLBC-15k2
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 SIP Offering media type audio in SDP with formats
    G.711-uLaw-64k,G.711-ALaw-64k,T.38,UserInput/RFC2833
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 Call    IsMediaBypassPossible Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] session 1
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 OpalMan IsMediaBypassPossible: session 1
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 OpalCon IsMediaBypassPossible: default returns false
    2013/02/21 17:57:34.015 ttyT38-1(e...0xde7d1700 RTP Cannot find media session 1
    2013/02/21 17:57:34.016 ttyT38-1(e...0xde7d1700 RTP Cannot find RTP session 1
    2013/02/21 17:57:34.016 ttyT38-1(e...0xde7d1700 RTP_UDP Session 1, created with NAT flag set to 0
    2013/02/21 17:57:34.016 ttyT38-1(e...0xde7d1700 PWLib   File handle high water mark set: 39 PUDPSocket
    2013/02/21 17:57:34.016 ttyT38-1(e...0xde7d1700 RTP_UDP Session 1 created: 192.168.77.42:10000-10001 ssrc=3239158679
    2013/02/21 17:57:34.017 ttyT38-1(e...0xde7d1700 PWLib   File handle high water mark set: 40 PUDPSocket
    2013/02/21 17:57:34.017 ttyT38-1(e...0xde7d1700 RTP Creating new session RTP_UDP
    2013/02/21 17:57:34.017 ttyT38-1(e...0xde7d1700 RTP Found existing media session 1
    2013/02/21 17:57:34.018 ttyT38-1(e...0xde7d1700 RFC2833 Tx capability merged with "0-16,32,36"
    2013/02/21 17:57:34.018 ttyT38-1(e...0xde7d1700 SIP Using default RTP payload [pt=101] for UserInput/RFC2833
    2013/02/21 17:57:34.018 ttyT38-1(e...0xde7d1700 RFC2833 Tx capability set to "-"
    2013/02/21 17:57:34.018 ttyT38-1(e...0xde7d1700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:34.018 ttyT38-1(e...0xde7d1700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:34.020 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    G.711-ALaw-64k
    G.711-uLaw-64k
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    GSM-06.10
    GSM-AMR
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC
    iLBC-13k3
    iLBC-15k2
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:34.021 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:34.021 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.021 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.021 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:34.022 ttyT38-1(e...0xde7d1700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.022 ttyT38-1(e...0xde7d1700 Call    GetMediaFormats for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.022 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.022 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove GSM-AMR
    2013/02/21 17:57:34.022 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove iLBC
    2013/02/21 17:57:34.022 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove GSM-06.10
    2013/02/21 17:57:34.022 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-16k
    2013/02/21 17:57:34.022 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-24k
    2013/02/21 17:57:34.022 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-32k
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove G.726-40k
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove LPC-10
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove MS-GSM
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove MS-IMA-ADPCM
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-11k
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-15k
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-18.2k
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-24.6k
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-5.95k
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-8k
    2013/02/21 17:57:34.023 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexNB
    2013/02/21 17:57:34.024 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove SpeexWNarrow-8k
    2013/02/21 17:57:34.024 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove iLBC-13k3
    2013/02/21 17:57:34.024 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats Remove iLBC-15k2
    2013/02/21 17:57:34.024 ttyT38-1(e...0xde7d1700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:34.024 ttyT38-1(e...0xde7d1700 SIP No media formats of type video, not adding SDP
    2013/02/21 17:57:34.024 ttyT38-1(e...0xde7d1700 SIP Transaction remote address is udp$66.23.129.253:5060
    2013/02/21 17:57:34.025 ttyT38-1(e...0xde7d1700 SIP Sending PDU (858 bytes) to: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    INVITE sip:12037691544@66.23.129.253 SIP/2.0
    CSeq: 1 INVITE
    Via: SIP/2.0/UDP 192.168.77.42:5060;branch=z9hG4bK7c494dbf-e77a-e211-8957-5254007747e9;rport
    User-Agent: T38Modem/2.0.0
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    Organization: Vyacheslav Frolov
    To: <sip:12037691544@66.23.129.253>
    Contact: <sip:MYUSERNAME@192.168.77.42>
    Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING
    Content-Type: application/sdp
    Content-Length: 258
    Max-Forwards: 70
    v=0
    o=- 1361487453 1 IN IP4 192.168.77.42
    s=T38Modem/2.0.0
    c=IN IP4 192.168.77.42
    t=0 0
    m=audio 10000 RTP/AVP 0 8 101
    a=sendrecv
    a=rtpmap:0 PCMU/8000/1
    a=rtpmap:8 PCMA/8000/1
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16,32,36
    a=maxptime:240
    2013/02/21 17:57:34.026 ttyT38-1(e...0xde7d1700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:57:34.026 ttyT38-1(e...0xde7d1700 SIP Transaction timers set: retry=0.500, completion=32.000
    2013/02/21 17:57:34.026 ttyT38-1(e...0xde7d1700 OpalCon OnSetUpConnectionCall[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:34.027 ttyT38-1(e...0xde7d1700 OpalEP  OnSetUpConnection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:34.027 ttyT38-1(e...0xde7d1700 OpalMan SetUpCall succeeded, call=Call[C049f6ca11]
    2013/02/21 17:57:34.027 ttyT38-1(e...0xde7d1700 ModemEndPoint::OnMyCallback request={
    calltoken=modem:/C049f6ca11/0
    localpartyname=
    command=dial
    response=confirm
    number=12037691544
    modemtoken=ttyT38-1
    }
    2013/02/21 17:57:34.047 Opal Liste...0xde6cd700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:57:34.047 Opal Liste...0xde6cd700 SIP Waiting for PDU on udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:34.047 Opal Liste...0xde6cd700 SIP PDU received: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    SIP/2.0 407 Proxy Authentication Required
    CSeq: 1 INVITE
    Via: SIP/2.0/UDP 192.168.77.42;branch=z9hG4bK7c494dbf-e77a-e211-8957-5254007747e9;rport=5060
    Server: nVSIP 12.02.01
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:12037691544@66.23.129.253>;tag=9c6a9fdfd4d16ebaa52f34c4c528cbe5.03bd
    Proxy-Authenticate: Digest realm="nexvortex.com", nonce="5126a78949c9bc7af127ddd04d070a682539462f"
    Content-Length: 0
    2013/02/21 17:57:34.048 Opal Liste...0xde6cd700 SIP Queueing PDU "1 INVITE <407>", transaction=z9hG4bK7c494dbf-e77a-e211-8957-5254007747e9, token=7c8c4bbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:34.048 Opal Liste...0xde6cd700 PWLib   File handle high water mark set: 41 Thread unblock pipe
    2013/02/21 17:57:34.048 Opal Liste...0xde6cd700 PTLib   Thread high water mark set: 14
    2013/02/21 17:57:34.048 Opal Liste...0xde6cd700 Opal    Transport clean up on termination
    2013/02/21 17:57:34.048 Opal Liste...0xde6cd700 Opal    Transport Close
    2013/02/21 17:57:34.048 Opal Liste...0xde6cd700 PWLib   File handle high water mark set: 42 PUDPSocket
    2013/02/21 17:57:34.048 Opal Liste...0xde6cd700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:34.049         Pool:0xde5c9700 SIP Handling PDU "1 INVITE <407>" for transaction=z9hG4bK7c494dbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:34.050         Pool:0xde5c9700 SIP Sending PDU (422 bytes) to: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    ACK sip:12037691544@66.23.129.253 SIP/2.0
    CSeq: 1 ACK
    Via: SIP/2.0/UDP 192.168.77.42:5060;branch=z9hG4bK7c494dbf-e77a-e211-8957-5254007747e9;rport
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:12037691544@66.23.129.253>;tag=9c6a9fdfd4d16ebaa52f34c4c528cbe5.03bd
    Content-Length: 0
    Max-Forwards: 70
    2013/02/21 17:57:34.050         Pool:0xde5c9700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:57:34.051         Pool:0xde5c9700 SIP INVITE transaction id=z9hG4bK7c494dbf-e77a-e211-8957-5254007747e9 completed.
    2013/02/21 17:57:34.051         Pool:0xde5c9700 SIP Received Proxy Authentication Required response for 1 INVITE sip:12037691544@66.23.129.253
    2013/02/21 17:57:34.051         Pool:0xde5c9700 SIP Located existing credentials for ID "MYUSERNAME" at realm "nexvortex.com"
    2013/02/21 17:57:34.051         Pool:0xde5c9700 SIP Found auth info for realm "nexvortex.com", user "MYUSERNAME"
    2013/02/21 17:57:34.051         Pool:0xde5c9700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:57:34.053         Pool:0xde5c9700 SIP INVITE transaction id=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9 created.
    2013/02/21 17:57:34.053         Pool:0xde5c9700 SIP Creating INVITE request
    2013/02/21 17:57:34.053         Pool:0xde5c9700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:34.053         Pool:0xde5c9700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:34.055         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    G.711-ALaw-64k
    G.711-uLaw-64k
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    GSM-06.10
    GSM-AMR
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC
    iLBC-13k3
    iLBC-15k2
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:34.055         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:34.055         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.055         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.056         Pool:0xde5c9700 Call    GetMediaFormats for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove GSM-AMR
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove GSM-06.10
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-16k
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-24k
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-32k
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-40k
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove LPC-10
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove MS-GSM
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove MS-IMA-ADPCM
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-11k
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-15k
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-18.2k
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-24.6k
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-5.95k
    2013/02/21 17:57:34.056         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-8k
    2013/02/21 17:57:34.057         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexNB
    2013/02/21 17:57:34.057         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexWNarrow-8k
    2013/02/21 17:57:34.057         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC-13k3
    2013/02/21 17:57:34.057         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC-15k2
    2013/02/21 17:57:34.057         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:34.057         Pool:0xde5c9700 SIP Offering media type audio in SDP with formats
    G.711-uLaw-64k,G.711-ALaw-64k,T.38,UserInput/RFC2833
    2013/02/21 17:57:34.057         Pool:0xde5c9700 Call    IsMediaBypassPossible Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] session 1
    2013/02/21 17:57:34.057         Pool:0xde5c9700 OpalMan IsMediaBypassPossible: session 1
    2013/02/21 17:57:34.057         Pool:0xde5c9700 OpalCon IsMediaBypassPossible: default returns false
    2013/02/21 17:57:34.057         Pool:0xde5c9700 RTP Found existing media session 1
    2013/02/21 17:57:34.057         Pool:0xde5c9700 RTP Found existing RTP session 1
    2013/02/21 17:57:34.057         Pool:0xde5c9700 RFC2833 Tx capability merged with "0-16,32,36"
    2013/02/21 17:57:34.058         Pool:0xde5c9700 SIP Using default RTP payload [pt=101] for UserInput/RFC2833
    2013/02/21 17:57:34.058         Pool:0xde5c9700 RFC2833 Tx capability set to "-"
    2013/02/21 17:57:34.058         Pool:0xde5c9700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:34.058         Pool:0xde5c9700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:34.059         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    G.711-ALaw-64k
    G.711-uLaw-64k
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    GSM-06.10
    GSM-AMR
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC
    iLBC-13k3
    iLBC-15k2
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:34.060         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:34.060         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.060         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.060         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:34.060         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.060         Pool:0xde5c9700 Call    GetMediaFormats for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.060         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:34.060         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove GSM-AMR
    2013/02/21 17:57:34.060         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove GSM-06.10
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-16k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-24k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-32k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-40k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove LPC-10
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove MS-GSM
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove MS-IMA-ADPCM
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-11k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-15k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-18.2k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-24.6k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-5.95k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-8k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexNB
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexWNarrow-8k
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC-13k3
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC-15k2
    2013/02/21 17:57:34.061         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:34.061         Pool:0xde5c9700 SIP No media formats of type video, not adding SDP
    2013/02/21 17:57:34.061         Pool:0xde5c9700 HTTP    Adding authentication information
    2013/02/21 17:57:34.061         Pool:0xde5c9700 SIP Transaction remote address is udp$66.23.129.253:5060
    2013/02/21 17:57:34.062         Pool:0xde5c9700 SIP Sending PDU (1079 bytes) to: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    INVITE sip:12037691544@66.23.129.253 SIP/2.0
    CSeq: 2 INVITE
    Via: SIP/2.0/UDP 192.168.77.42:5060;branch=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9;rport
    User-Agent: T38Modem/2.0.0
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    Organization: Vyacheslav Frolov
    To: <sip:12037691544@66.23.129.253>
    Contact: <sip:MYUSERNAME@192.168.77.42>
    Proxy-Authorization: Digest username="MYUSERNAME", realm="nexvortex.com", nonce="5126a78949c9bc7af127ddd04d070a682539462f", uri="sip:12037691544@66.23.129.253", algorithm=MD5, response="f57cecf9af1b6479b452c97633f713a2"
    Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING
    Content-Type: application/sdp
    Content-Length: 258
    Max-Forwards: 70
    v=0
    o=- 1361487453 1 IN IP4 192.168.77.42
    s=T38Modem/2.0.0
    c=IN IP4 192.168.77.42
    t=0 0
    m=audio 10000 RTP/AVP 0 8 101
    a=sendrecv
    a=rtpmap:0 PCMU/8000/1
    a=rtpmap:8 PCMA/8000/1
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16,32,36
    a=maxptime:240
    2013/02/21 17:57:34.062         Pool:0xde5c9700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:57:34.063         Pool:0xde5c9700 SIP Transaction timers set: retry=0.500, completion=32.000
    2013/02/21 17:57:34.063         Pool:0xde5c9700 SIP Handled PDU "1 INVITE <407>"
    2013/02/21 17:57:34.128 Opal Liste...0xde6cd700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:57:34.128 Opal Liste...0xde6cd700 SIP Waiting for PDU on udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:34.128 Opal Liste...0xde6cd700 SIP PDU received: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    SIP/2.0 100 trying -- your call is important to us
    CSeq: 2 INVITE
    Via: SIP/2.0/UDP 192.168.77.42;branch=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9;rport=5060
    Server: nVSIP 12.02.01
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:12037691544@66.23.129.253>
    Content-Length: 0
    2013/02/21 17:57:34.129 Opal Liste...0xde6cd700 SIP Queueing PDU "2 INVITE <100>", transaction=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9, token=7c8c4bbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:34.129 Opal Liste...0xde6cd700 Opal    Transport clean up on termination
    2013/02/21 17:57:34.129 Opal Liste...0xde6cd700 Opal    Transport Close
    2013/02/21 17:57:34.129 Opal Liste...0xde6cd700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:34.129         Pool:0xde5c9700 SIP Handling PDU "2 INVITE <100>" for transaction=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:34.129         Pool:0xde5c9700 SIP Product Info: name="nVSIP", version="", vendor="", comments="12.02.01"
    2013/02/21 17:57:34.130         Pool:0xde5c9700 SIP INVITE transaction id=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9 proceeding.
    2013/02/21 17:57:34.130         Pool:0xde5c9700 SIP Received Trying response
    2013/02/21 17:57:34.130         Pool:0xde5c9700 OpalCon SetPhase from SetUpPhase to ProceedingPhase for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:34.130         Pool:0xde5c9700 OpalMan OnProceeding Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:34.130         Pool:0xde5c9700 Call    OnProceeding Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:34.130         Pool:0xde5c9700 SIP Handled PDU "2 INVITE <100>"
    2013/02/21 17:57:36.999 Opal Liste...0xde6cd700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:57:36.999 Opal Liste...0xde6cd700 SIP Waiting for PDU on udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:37.000 Opal Liste...0xde6cd700 SIP PDU received: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    SIP/2.0 183 Session Progress
    CSeq: 2 INVITE
    Via: SIP/2.0/UDP 192.168.77.42;branch=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9;rport=5060
    Server: DC-SIP/2.0
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    Organization: Metaswitch Networks
    To: <sip:12037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Contact: <sip:2037691544@69.54.92.148:5060;transport=udp>
    Allow: INVITE, ACK, CANCEL, BYE, REGISTER, OPTIONS, PRACK, UPDATE, SUBSCRIBE, NOTIFY, REFER, INFO, PUBLISH
    Content-Length: 186
    Content-Type: application/sdp
    Record-Route: <sip:12037691544@66.23.129.253:5060;nat=yes;ftag=7c8c4bbf-e77a-e211-8957-5254007747e9;lr=on>
    v=0
    o=- 1628064046 4277788597 IN IP4 69.54.92.148
    s=-
    c=IN IP4 69.54.92.148
    t=0 0
    m=audio 61596 RTP/AVP 0 101
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16,32,36
    a=ptime:20
    2013/02/21 17:57:37.000 Opal Liste...0xde6cd700 SIP Queueing PDU "2 INVITE <183>", transaction=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9, token=7c8c4bbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:37.000 Opal Liste...0xde6cd700 Opal    Transport clean up on termination
    2013/02/21 17:57:37.000 Opal Liste...0xde6cd700 Opal    Transport Close
    2013/02/21 17:57:37.000 Opal Liste...0xde6cd700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:37.000         Pool:0xde5c9700 SIP Handling PDU "2 INVITE <183>" for transaction=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:37.001         Pool:0xde5c9700 SIP Updating dialog tag from "" to "metaswitch+1+fb972e+979e608a"
    2013/02/21 17:57:37.001         Pool:0xde5c9700 SDP Parsed connection address udp$69.54.92.148
    2013/02/21 17:57:37.001         Pool:0xde5c9700 SDP Parsed connection address udp$69.54.92.148
    2013/02/21 17:57:37.001         Pool:0xde5c9700 SDP Media session port=61596
    2013/02/21 17:57:37.001         Pool:0xde5c9700 SIP RTP payload type telephone-event matched to codec UserInput/RFC2833
    2013/02/21 17:57:37.001         Pool:0xde5c9700 SDP Parsed media session with 2 'audio' formats
    2013/02/21 17:57:37.001         Pool:0xde5c9700 SIP RTP payload type  matched to codec G.711-uLaw-64k
    2013/02/21 17:57:37.002         Pool:0xde5c9700 SIP Product Info: name="DC-SIP", version="2.0", vendor="Metaswitch Networks", comments=""
    2013/02/21 17:57:37.002         Pool:0xde5c9700 SIP INVITE transaction id=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9 proceeding.
    2013/02/21 17:57:37.002         Pool:0xde5c9700 SIP Received Session Progress response
    2013/02/21 17:57:37.002         Pool:0xde5c9700 SIP Processing received SDP media description for audio
    2013/02/21 17:57:37.002         Pool:0xde5c9700 Call    IsMediaBypassPossible Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] session 1
    2013/02/21 17:57:37.002         Pool:0xde5c9700 OpalMan IsMediaBypassPossible: session 1
    2013/02/21 17:57:37.002         Pool:0xde5c9700 OpalCon IsMediaBypassPossible: default returns false
    2013/02/21 17:57:37.002         Pool:0xde5c9700 RTP Found existing RTP session 1
    2013/02/21 17:57:37.003         Pool:0xde5c9700 RTP_UDP Session 1, SetRemoteSocketInfo: data channel, new=69.54.92.148:61596, local=192.168.77.42:10000-10001, remote=0.0.0.0:0-0
    2013/02/21 17:57:37.003         Pool:0xde5c9700 RTP Found existing media session 1
    2013/02/21 17:57:37.003         Pool:0xde5c9700 Call    OpenSourceMediaStreams open for audio session 1 on Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:37.003         Pool:0xde5c9700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:37.003         Pool:0xde5c9700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:37.003         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:37.003         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:37.003         Pool:0xde5c9700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    UserInput/RFC2833
    T.38
    2013/02/21 17:57:37.003         Pool:0xde5c9700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    UserInput/RFC2833
    T.38
    2013/02/21 17:57:37.003         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    UserInput/RFC2833
    T.38
    2013/02/21 17:57:37.003         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    UserInput/RFC2833
    T.38
    2013/02/21 17:57:37.003         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    UserInput/RFC2833
    PCM-16
    G.711-uLaw-64k
    G.711-ALaw-64k
    YUV420P
    RFC4175_YCbCr-4:2:0
    RGB24
    RFC4175_RGB
    PCM-16-16kHz
    PCM-16-32kHz
    PCM-16-48kHz
    GSM-AMR
    G.726-40k
    G.726-32k
    G.726-24k
    G.726-16k
    GSM-06.10
    MS-GSM
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFWide-20.6k
    SpeexWNarrow-8k
    SpeexWide-20.6k
    SpeexNB
    SpeexWB
    MS-IMA-ADPCM
    iLBC
    iLBC-13k3
    iLBC-15k2
    LPC-10
    G.722-64k
    H.261-CIF
    H.261-QCIF
    H.261
    NamedSignalEvent
    T.140
    T.38
    2013/02/21 17:57:37.004         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:37.004         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    H.261
    RFC4175_YCbCr-4:2:0
    RFC4175_RGB
    G.726-40k
    G.726-32k
    G.726-24k
    G.726-16k
    MS-GSM
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFWide-20.6k
    SpeexWNarrow-8k
    SpeexWide-20.6k
    SpeexNB
    SpeexWB
    MS-IMA-ADPCM
    iLBC-13k3
    iLBC-15k2
    LPC-10
    G.722-64k
    H.261-CIF
    H.261-QCIF
    NamedSignalEvent
    T.140
    2013/02/21 17:57:37.004         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into G.711-uLaw-64k
    2013/02/21 17:57:37.004         Pool:0xde5c9700 MediaFormat Merging PCM-16 into G.711-uLaw-64k
    2013/02/21 17:57:37.004         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into PCM-16
    2013/02/21 17:57:37.004         Pool:0xde5c9700 MediaFormat Changed media option "Max Bit Rate" from 128000 to 64000
    2013/02/21 17:57:37.004         Pool:0xde5c9700 Call    Selected media formats G.711-uLaw-64k -> PCM-16
    2013/02/21 17:57:37.004         Pool:0xde5c9700 Call    IsMediaBypassPossible Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] session 1
    2013/02/21 17:57:37.004         Pool:0xde5c9700 OpalMan IsMediaBypassPossible: session 1
    2013/02/21 17:57:37.004         Pool:0xde5c9700 OpalCon IsMediaBypassPossible: default returns false
    2013/02/21 17:57:37.005         Pool:0xde5c9700 RTP Found existing RTP session 1
    2013/02/21 17:57:37.005         Pool:0xde5c9700 RTP Found existing media session 1
    2013/02/21 17:57:37.005         Pool:0xde5c9700 RTP_UDP Session 1 reopened for reading
    2013/02/21 17:57:37.005         Pool:0xde5c9700 MySIPConnection::OnOpenMediaStream: OpalRTPMediaStream-Source-G.711-uLaw-64k
    2013/02/21 17:57:37.005         Pool:0xde5c9700 RTP Found existing RTP session 1
    2013/02/21 17:57:37.005         Pool:0xde5c9700 OpalMan OnOpenMediaStream Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9],OpalRTPMediaStream-Source-G.711-uLaw-64k
    2013/02/21 17:57:37.005         Pool:0xde5c9700 OpalCon Opened source stream C049f6ca11_1 with format G.711-uLaw-64k
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ModemConnection::CreateMediaStream Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] mediaFormat=PCM-16 sessionID=1 isSource=0
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ttyT38-1 AudioEngine AudioEngine
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ttyT38-1 AudioEngine Attach
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ttyT38-1 AudioEngine OnAttach Attached
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ttyT38-1 AudioEngine OnResetModemState
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ttyT38-1 AudioEngine ChangeModemClass to mcFax
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ttyT38-1 AudioEngine OnChangeModemClass to mcFax
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ttyT38-1 AudioEngine SendOnIdle dtNone
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ModemEngineBody::_AttachEngine Attached mceAudio
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ModemEngineBody::NewPtrEngine created pointer for engine mceAudio
    2013/02/21 17:57:37.005         Pool:0xde5c9700 AudioModemMediaStream::AudioModemMediaStream AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:37.005         Pool:0xde5c9700 AudioModemMediaStream::Open AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ttyT38-1 AudioEngine OpenIn: open 0x7fd0a400c980
    2013/02/21 17:57:37.005         Pool:0xde5c9700 ModemEngineBody::OnEngineCallback AudioEngine cbpUpdateState (0, stConnectWait)
    2013/02/21 17:57:37.005         Pool:0xde5c9700 OpalMan OnOpenMediaStream Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0],AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:37.005         Pool:0xde5c9700 OpalCon Opened sink stream C049f6ca11_1 with format PCM-16
    2013/02/21 17:57:37.005         Pool:0xde5c9700 RTP_UDP Session 1, Shutting down read.
    2013/02/21 17:57:37.005         Pool:0xde5c9700 Adding patch Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k on stream OpalRTPMediaStream-Source-G.711-uLaw-64k
    2013/02/21 17:57:37.005         Pool:0xde5c9700 RTP_UDP Session 1 reopened for reading
    2013/02/21 17:57:37.006         Pool:0xde5c9700 Adding patch Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k on stream AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:37.006         Pool:0xde5c9700 Patch   Created Sink: format=PCM-16
    2013/02/21 17:57:37.006         Pool:0xde5c9700 Codec   G711-uLaw-64k decoder created
    2013/02/21 17:57:37.006         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into G.711-uLaw-64k
    2013/02/21 17:57:37.006         Pool:0xde5c9700 MediaFormat Merging PCM-16 into PCM-16
    2013/02/21 17:57:37.006         Pool:0xde5c9700 Patch   Created primary codec G.711-uLaw-64k->PCM-16 with ID C049f6ca11_1
    2013/02/21 17:57:37.006         Pool:0xde5c9700 Media   Set data size from 16 to 3840
    2013/02/21 17:57:37.006         Pool:0xde5c9700 Patch   Added media stream sink AudioModemMediaStream-Sink-PCM-16 using transcoder G.711-uLaw-64k->PCM-16, data size=3840
    2013/02/21 17:57:37.006         Pool:0xde5c9700 Media   RTP data size cannot be changed to 8, fixed at 2048
    2013/02/21 17:57:37.006         Pool:0xde5c9700 OpalCon Adding audio filters to patch Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:37.006         Pool:0xde5c9700 OpalCon Added send DTMF filter on connection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0], patch Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:37.006         Pool:0xde5c9700 OpalCon Sink stream of connection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] uses patch Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:37.006         Pool:0xde5c9700 OpalCon Adding audio filters to patch Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:37.006         Pool:0xde5c9700 OpalCon Source stream of connection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] uses patch Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:37.006         Pool:0xde5c9700 RTPCon  Adding RFC2833 receive handler
    2013/02/21 17:57:37.006         Pool:0xde5c9700 RTPCon  Adding Cisco NSE receive handler
    2013/02/21 17:57:37.006         Pool:0xde5c9700 Call    GetOtherPartyConnection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:37.006         Pool:0xde5c9700 Call    OpenSourceMediaStreams open for audio session 1 on Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:37.006         Pool:0xde5c9700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    UserInput/RFC2833
    T.38
    2013/02/21 17:57:37.006         Pool:0xde5c9700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    UserInput/RFC2833
    T.38
    2013/02/21 17:57:37.006         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    UserInput/RFC2833
    T.38
    2013/02/21 17:57:37.006         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    UserInput/RFC2833
    T.38
    2013/02/21 17:57:37.006         Pool:0xde5c9700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:37.006         Pool:0xde5c9700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:37.007         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:37.007         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:37.007         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    UserInput/RFC2833
    PCM-16
    G.711-uLaw-64k
    G.711-ALaw-64k
    YUV420P
    RFC4175_YCbCr-4:2:0
    RGB24
    RFC4175_RGB
    PCM-16-16kHz
    PCM-16-32kHz
    PCM-16-48kHz
    GSM-AMR
    G.726-40k
    G.726-32k
    G.726-24k
    G.726-16k
    GSM-06.10
    MS-GSM
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFWide-20.6k
    SpeexWNarrow-8k
    SpeexWide-20.6k
    SpeexNB
    SpeexWB
    MS-IMA-ADPCM
    iLBC
    iLBC-13k3
    iLBC-15k2
    LPC-10
    G.722-64k
    H.261-CIF
    H.261-QCIF
    H.261
    NamedSignalEvent
    T.140
    T.38
    2013/02/21 17:57:37.007         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:37.008         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    H.261
    PCM-16
    YUV420P
    RFC4175_YCbCr-4:2:0
    RGB24
    RFC4175_RGB
    PCM-16-16kHz
    PCM-16-32kHz
    PCM-16-48kHz
    G.726-40k
    G.726-32k
    G.726-24k
    G.726-16k
    MS-GSM
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFWide-20.6k
    SpeexWNarrow-8k
    SpeexWide-20.6k
    SpeexNB
    SpeexWB
    MS-IMA-ADPCM
    iLBC-13k3
    iLBC-15k2
    LPC-10
    G.722-64k
    H.261-CIF
    H.261-QCIF
    NamedSignalEvent
    T.140
    2013/02/21 17:57:37.008         Pool:0xde5c9700 MediaFormat Merging PCM-16 into PCM-16
    2013/02/21 17:57:37.008         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into G.711-uLaw-64k
    2013/02/21 17:57:37.008         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into PCM-16
    2013/02/21 17:57:37.008         Pool:0xde5c9700 MediaFormat Changed media option "Max Bit Rate" from 128000 to 64000
    2013/02/21 17:57:37.008         Pool:0xde5c9700 MediaFormat Merging PCM-16 into G.711-uLaw-64k
    2013/02/21 17:57:37.008         Pool:0xde5c9700 Call    Selected media formats PCM-16 -> G.711-uLaw-64k
    2013/02/21 17:57:37.008         Pool:0xde5c9700 ModemConnection::CreateMediaStream Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] mediaFormat=PCM-16 sessionID=1 isSource=1
    2013/02/21 17:57:37.008         Pool:0xde5c9700 ttyT38-1 AudioEngine SendOnIdle dtNone
    2013/02/21 17:57:37.008         Pool:0xde5c9700 ModemEngineBody::_AttachEngine Attached mceAudio
    2013/02/21 17:57:37.008         Pool:0xde5c9700 ModemEngineBody::NewPtrEngine created pointer for engine mceAudio
    2013/02/21 17:57:37.008         Pool:0xde5c9700 AudioModemMediaStream::AudioModemMediaStream AudioModemMediaStream-Source-PCM-16
    2013/02/21 17:57:37.008         Pool:0xde5c9700 AudioModemMediaStream::Open AudioModemMediaStream-Source-PCM-16
    2013/02/21 17:57:37.008         Pool:0xde5c9700 ttyT38-1 AudioEngine OpenOut: open 0x7fd0a4010010
    2013/02/21 17:57:37.008         Pool:0xde5c9700 ModemEngineBody::OnEngineCallback AudioEngine cbpUpdateState (0, stConnectWait)
    2013/02/21 17:57:37.008         Pool:0xde5c9700 OpalMan OnOpenMediaStream Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0],AudioModemMediaStream-Source-PCM-16
    2013/02/21 17:57:37.008         Pool:0xde5c9700 OpalCon Opened source stream C049f6ca11_1 with format PCM-16
    2013/02/21 17:57:37.008         Pool:0xde5c9700 Call    IsMediaBypassPossible Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] session 1
    2013/02/21 17:57:37.008         Pool:0xde5c9700 OpalMan IsMediaBypassPossible: session 1
    2013/02/21 17:57:37.008         Pool:0xde5c9700 OpalCon IsMediaBypassPossible: default returns false
    2013/02/21 17:57:37.008         Pool:0xde5c9700 RTP Found existing RTP session 1
    2013/02/21 17:57:37.008         Pool:0xde5c9700 RTP Found existing media session 1
    2013/02/21 17:57:37.009         Pool:0xde5c9700 RTP_UDP Session 1 reopened for writing
    2013/02/21 17:57:37.009         Pool:0xde5c9700 MySIPConnection::OnOpenMediaStream: OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 RTP Found existing RTP session 1
    2013/02/21 17:57:37.009         Pool:0xde5c9700 OpalMan OnOpenMediaStream Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9],OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 OpalCon Opened sink stream C049f6ca11_1 with format G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 Adding patch Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 on stream AudioModemMediaStream-Source-PCM-16
    2013/02/21 17:57:37.009         Pool:0xde5c9700 Adding patch Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 on stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 Patch   Created Sink: format=G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 Codec   G711-uLaw-64k encoder created
    2013/02/21 17:57:37.009         Pool:0xde5c9700 MediaFormat Merging PCM-16 into PCM-16
    2013/02/21 17:57:37.009         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 Patch   Created primary codec PCM-16->G.711-uLaw-64k with ID C049f6ca11_1
    2013/02/21 17:57:37.009         Pool:0xde5c9700 Media   RTP data size cannot be changed to 1920, fixed at 528
    2013/02/21 17:57:37.009         Pool:0xde5c9700 Patch   Added media stream sink OpalRTPMediaStream-Sink-G.711-uLaw-64k using transcoder PCM-16->G.711-uLaw-64k, data size=528
    2013/02/21 17:57:37.009         Pool:0xde5c9700 Media   Set data size from 16 to 320
    2013/02/21 17:57:37.009         Pool:0xde5c9700 OpalCon Adding audio filters to patch Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 OpalCon Source stream of connection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] uses patch Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 OpalCon Adding audio filters to patch Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 OpalCon Added send DTMF filter on connection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9], patch Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 OpalCon Sink stream of connection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] uses patch Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:37.009         Pool:0xde5c9700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:37.009         Pool:0xde5c9700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:37.011         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    G.711-ALaw-64k
    G.711-uLaw-64k
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    GSM-06.10
    GSM-AMR
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC
    iLBC-13k3
    iLBC-15k2
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:37.012         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:37.012         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:37.012         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:37.012         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:37.012         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:37.012         Pool:0xde5c9700 Call    GetMediaFormats for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:37.012         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:37.012         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove GSM-AMR
    2013/02/21 17:57:37.012         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC
    2013/02/21 17:57:37.012         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove GSM-06.10
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-16k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-24k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-32k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-40k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove LPC-10
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove MS-GSM
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove MS-IMA-ADPCM
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-11k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-15k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-18.2k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-24.6k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-5.95k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-8k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexNB
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexWNarrow-8k
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC-13k3
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC-15k2
    2013/02/21 17:57:37.013         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:37.013         Pool:0xde5c9700 RFC2833 Tx capability merged with "0-16,32,36"
    2013/02/21 17:57:37.013         Pool:0xde5c9700 SIP Using default RTP payload [pt=101] for UserInput/RFC2833
    2013/02/21 17:57:37.013         Pool:0xde5c9700 RFC2833 Tx capability set to "-"
    2013/02/21 17:57:37.013         Pool:0xde5c9700 OpalCon SetPhase from ProceedingPhase to AlertingPhase for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:37.013         Pool:0xde5c9700 OpalMan OnAlerting Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:37.013         Pool:0xde5c9700 Call    OnAlerting Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:37.013         Pool:0xde5c9700 ModemConnection::SetAlerting Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] 12037691544@66.23.129.253 1
    2013/02/21 17:57:37.013         Pool:0xde5c9700 OpalCon SetPhase from SetUpPhase to AlertingPhase for Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:37.014         Pool:0xde5c9700 ModemEngineBody::Request: stConnectWait request={
    calltoken=modem:/C049f6ca11/0
    command=alerting
    }
    2013/02/21 17:57:37.014         Pool:0xde5c9700 ModemEngineBody::SetCallState: off-hook cstAlerted stConnectWait
    2013/02/21 17:57:37.014         Pool:0xde5c9700 SIP Starting receive media to annunciate remote progress tones
    2013/02/21 17:57:37.014         Pool:0xde5c9700 PWLib   File handle high water mark set: 43 Thread unblock pipe
    2013/02/21 17:57:37.014         Pool:0xde5c9700 PTLib   Thread high water mark set: 15
    2013/02/21 17:57:37.014  Media Patch:0xde588700 Patch   Thread started for Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:37.014         Pool:0xde5c9700 Media   Starting thread Media Patch:0xde588700
    2013/02/21 17:57:37.014  Media Patch:0xde588700 RTP_UDP Session 1, flushed 1 RTP data packets on startup
    2013/02/21 17:57:37.015         Pool:0xde5c9700 PWLib   File handle high water mark set: 45 Thread unblock pipe
    2013/02/21 17:57:37.015  Media Patch:0xde588700 RTP_UDP Session 1, Received control packet too small: 1 bytes
    2013/02/21 17:57:37.015         Pool:0xde5c9700 PTLib   Thread high water mark set: 16
    2013/02/21 17:57:37.015  Media Patch:0xde547700 Patch   Thread started for Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:37.015         Pool:0xde5c9700 Media   Starting thread Media Patch:0xde547700
    2013/02/21 17:57:37.015         Pool:0xde5c9700 OpalCon Media stream threads started.
    2013/02/21 17:57:37.015         Pool:0xde5c9700 SIP Handled PDU "2 INVITE <183>"
    2013/02/21 17:57:37.015  Media Patch:0xde547700 ModemEngineBody::OnEngineCallback AudioEngine cbpUpdateState (0, stConnectWait)
    2013/02/21 17:57:37.016  Media Patch:0xde547700 RTP Session 1, first sent data: ver=2 pt=PCMU psz=160 m=1 x=0 seq=16927 ts=0 src=c111a397 ccnt=0
    2013/02/21 17:57:37.022  Media Patch:0xde588700 RTP Session 1, first receive data: ver=2 pt=PCMU psz=160 m=0 x=0 seq=26566 ts=2400 src=103fb58b ccnt=0
    2013/02/21 17:57:37.022  Media Patch:0xde588700 ModemEngineBody::OnEngineCallback AudioEngine cbpUpdateState (0, stConnectWait)
    2013/02/21 17:57:39.016  Media Patch:0xde547700 RTP Session 1, transmit statistics:  packets=101 octets=16160 avgTime=20 maxTime=21 minTime=19
    2013/02/21 17:57:39.022  Media Patch:0xde588700 RTP Session 1, receive statistics: packets=101 octets=16160 lost=0 tooLate=0 order=0 avgTime=20 maxTime=24 minTime=16 jitter=1028487 maxJitter=33554431
    2013/02/21 17:57:39.063  Housekeeper:0xde790700 SIP Set state Terminated_Success for INVITE transaction id=z9hG4bK7c494dbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:40.830 Network In...0xde812700 PWLib   File handle high water mark set: 46 PUDPSocket
    2013/02/21 17:57:41.015  Media Patch:0xde547700 RTP Session 1, transmit statistics:  packets=201 octets=32160 avgTime=20 maxTime=21 minTime=19
    2013/02/21 17:57:41.022  Media Patch:0xde588700 RTP Session 1, receive statistics: packets=201 octets=32160 lost=0 tooLate=0 order=0 avgTime=19 maxTime=24 minTime=15 jitter=1619 maxJitter=33554431
    2013/02/21 17:57:41.924  Media Patch:0xde588700 RTP Session 1, OnRxSenderReport: ssrc=272610699 ntp=2013/2/21-17:55:21.371661 rtp=41440 psent=250 osent=40000
      RR: ssrc=3239158679 fraction=0 lost=0 last_seq=17161 jitter=8 lsr=0.000 dlsr=50653:36:59.863
    2013/02/21 17:57:41.924  Media Patch:0xde588700 RTP Session 1, SourceDescription item 0x7fd0980058c4, current size = 2
    2013/02/21 17:57:41.924  Media Patch:0xde588700 RTP Session 1, OnSourceDescription: 1 entries
      ssrc=272610699
      item[0]: type=CNAME data=""
    2013/02/21 17:57:43.015  Media Patch:0xde547700 RTP Session 1, transmit statistics:  packets=301 octets=48160 avgTime=20 maxTime=21 minTime=19
    2013/02/21 17:57:43.027  Media Patch:0xde588700 RTP Session 1, receive statistics: packets=301 octets=48160 lost=0 tooLate=0 order=0 avgTime=20 maxTime=25 minTime=15 jitter=2 maxJitter=33554431
    2013/02/21 17:57:45.015  Media Patch:0xde547700 RTP Session 1, transmit statistics:  packets=401 octets=64160 avgTime=20 maxTime=21 minTime=19
    2013/02/21 17:57:45.022  Media Patch:0xde588700 RTP Session 1, receive statistics: packets=401 octets=64160 lost=0 tooLate=0 order=0 avgTime=19 maxTime=24 minTime=15 jitter=1514855 maxJitter=33554431
    2013/02/21 17:57:45.464  Media Patch:0xde588700 RTP Session 1, SSRC changed from bf22807a to 103fb58b
    2013/02/21 17:57:45.464  Media Patch:0xde588700 RTP Session 1, adjusting sequence numbers to expect 33356 ssrc=3206709370
    2013/02/21 17:57:45.532 Opal Liste...0xde6cd700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:57:45.532 Opal Liste...0xde6cd700 SIP Waiting for PDU on udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:45.533 Opal Liste...0xde6cd700 SIP PDU received: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    SIP/2.0 200 OK
    CSeq: 2 INVITE
    Via: SIP/2.0/UDP 192.168.77.42;branch=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9;rport=5060
    Server: DC-SIP/2.0
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    Supported: resource-priority, 100rel
    Organization: Metaswitch Networks
    To: <sip:12037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Accept: application/sdp, application/simple-message-summary, message/sipfrag, application/isup, application/x-simple-call-service-info, multipart/mixed, application/broadsoft, application/vq-rtcpxr, application/media_control+xml, application/dtmf-relay, text/plain, application/x-as-feature-event+xml
    Contact: <sip:2037691544@69.54.92.148:5060;transport=udp>
    Allow: INVITE, ACK, CANCEL, BYE, REGISTER, OPTIONS, PRACK, UPDATE, SUBSCRIBE, NOTIFY, REFER, INFO, PUBLISH
    Allow-Events: message-summary, refer, dialog, line-seize, presence, call-info, as-feature-event
    Content-Length: 186
    Content-Type: application/sdp
    Accept-Encoding: identity
    Record-Route: <sip:12037691544@66.23.129.253:5060;nat=yes;ftag=7c8c4bbf-e77a-e211-8957-5254007747e9;lr=on>
    v=0
    o=- 1628064046 4277788597 IN IP4 69.54.92.148
    s=-
    c=IN IP4 69.54.92.148
    t=0 0
    m=audio 61596 RTP/AVP 0 101
    a=rtpmap:101 telephone-event/8000
    a=fmtp:101 0-16,32,36
    a=ptime:20
    2013/02/21 17:57:45.534 Opal Liste...0xde6cd700 SIP Queueing PDU "2 INVITE <200>", transaction=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9, token=7c8c4bbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:45.534 Opal Liste...0xde6cd700 Opal    Transport clean up on termination
    2013/02/21 17:57:45.534 Opal Liste...0xde6cd700 Opal    Transport Close
    2013/02/21 17:57:45.534 Opal Liste...0xde6cd700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:45.534         Pool:0xde5c9700 SIP Handling PDU "2 INVITE <200>" for transaction=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:45.535         Pool:0xde5c9700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:57:45.535         Pool:0xde5c9700 SDP Parsed connection address udp$69.54.92.148
    2013/02/21 17:57:45.535         Pool:0xde5c9700 SDP Parsed connection address udp$69.54.92.148
    2013/02/21 17:57:45.535         Pool:0xde5c9700 SDP Media session port=61596
    2013/02/21 17:57:45.535         Pool:0xde5c9700 SIP RTP payload type telephone-event matched to codec UserInput/RFC2833
    2013/02/21 17:57:45.535         Pool:0xde5c9700 SDP Parsed media session with 2 'audio' formats
    2013/02/21 17:57:45.536         Pool:0xde5c9700 SIP RTP payload type  matched to codec G.711-uLaw-64k
    2013/02/21 17:57:45.536         Pool:0xde5c9700 SIP Product Info: name="DC-SIP", version="2.0", vendor="Metaswitch Networks", comments=""
    2013/02/21 17:57:45.536         Pool:0xde5c9700 SIP No SRV lookup as has explicit port number.
    2013/02/21 17:57:45.536         Pool:0xde5c9700 SIP Transaction remote address changed to udp$66.23.129.253:5060
    2013/02/21 17:57:45.538         Pool:0xde5c9700 HTTP    Adding authentication information
    2013/02/21 17:57:45.538         Pool:0xde5c9700 SIP Sending PDU (776 bytes) to: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    ACK sip:12037691544@66.23.129.253 SIP/2.0
    Route: <sip:12037691544@66.23.129.253:5060;nat=yes;ftag=7c8c4bbf-e77a-e211-8957-5254007747e9;lr=on>
    CSeq: 2 ACK
    Via: SIP/2.0/UDP 192.168.77.42:5060;branch=z9hG4bK7a792cc6-e77a-e211-8957-5254007747e9;rport
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:12037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Contact: <sip:MYUSERNAME@192.168.77.42>
    Proxy-Authorization: Digest username="MYUSERNAME", realm="nexvortex.com", nonce="5126a78949c9bc7af127ddd04d070a682539462f", uri="sip:12037691544@66.23.129.253", algorithm=MD5, response="feafc7b14454766a65e8960ce2d0896b"
    Content-Length: 0
    Max-Forwards: 70
    2013/02/21 17:57:45.539         Pool:0xde5c9700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:57:45.539         Pool:0xde5c9700 SIP INVITE transaction id=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9 completed.
    2013/02/21 17:57:45.539         Pool:0xde5c9700 SIP Handling 200 OK response for INVITE
    2013/02/21 17:57:45.539         Pool:0xde5c9700 SIP Received INVITE OK response
    2013/02/21 17:57:45.539         Pool:0xde5c9700 SIP Processing received SDP media description for audio
    2013/02/21 17:57:45.539         Pool:0xde5c9700 Call    IsMediaBypassPossible Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] session 1
    2013/02/21 17:57:45.539         Pool:0xde5c9700 OpalMan IsMediaBypassPossible: session 1
    2013/02/21 17:57:45.539         Pool:0xde5c9700 OpalCon IsMediaBypassPossible: default returns false
    2013/02/21 17:57:45.539         Pool:0xde5c9700 RTP Found existing RTP session 1
    2013/02/21 17:57:45.540         Pool:0xde5c9700 RTP Found existing media session 1
    2013/02/21 17:57:45.540         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into G.711-uLaw-64k
    2013/02/21 17:57:45.541         Pool:0xde5c9700 Media   Media format updated on OpalRTPMediaStream-Source-G.711-uLaw-64k
    2013/02/21 17:57:45.541         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into G.711-uLaw-64k
    2013/02/21 17:57:45.541         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into PCM-16
    2013/02/21 17:57:45.541         Pool:0xde5c9700 MediaFormat Changed media option "Max Bit Rate" from 128000 to 64000
    2013/02/21 17:57:45.541         Pool:0xde5c9700 Media   Media format updated on AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:45.541         Pool:0xde5c9700 Patch   Updated Sink: format=G.711-uLaw-64k ok=1
    2013/02/21 17:57:45.541         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into PCM-16
    2013/02/21 17:57:45.541         Pool:0xde5c9700 MediaFormat Changed media option "Max Bit Rate" from 128000 to 64000
    2013/02/21 17:57:45.541         Pool:0xde5c9700 Media   Media format updated on AudioModemMediaStream-Source-PCM-16
    2013/02/21 17:57:45.541         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into G.711-uLaw-64k
    2013/02/21 17:57:45.542         Pool:0xde5c9700 MediaFormat Merging G.711-uLaw-64k into G.711-uLaw-64k
    2013/02/21 17:57:45.542         Pool:0xde5c9700 Media   Media format updated on OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:45.542         Pool:0xde5c9700 Patch   Updated Sink: format=G.711-uLaw-64k ok=1
    2013/02/21 17:57:45.542         Pool:0xde5c9700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:45.542         Pool:0xde5c9700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:45.545         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    PCM-16
    G.711-ALaw-64k
    G.711-uLaw-64k
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    GSM-06.10
    GSM-AMR
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC
    iLBC-13k3
    iLBC-15k2
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:45.546         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:45.546         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:45.546         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    PCM-16
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:45.547         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:45.547         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:45.547         Pool:0xde5c9700 Call    GetMediaFormats for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:45.547         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    G.726-16k
    G.726-24k
    G.726-32k
    G.726-40k
    LPC-10
    MS-GSM
    MS-IMA-ADPCM
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexNB
    SpeexWNarrow-8k
    iLBC-13k3
    iLBC-15k2
    2013/02/21 17:57:45.547         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove GSM-AMR
    2013/02/21 17:57:45.547         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC
    2013/02/21 17:57:45.547         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove GSM-06.10
    2013/02/21 17:57:45.547         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-16k
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-24k
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-32k
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove G.726-40k
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove LPC-10
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove MS-GSM
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove MS-IMA-ADPCM
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-11k
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-15k
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-18.2k
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-24.6k
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-5.95k
    2013/02/21 17:57:45.548         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-8k
    2013/02/21 17:57:45.549         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexNB
    2013/02/21 17:57:45.549         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove SpeexWNarrow-8k
    2013/02/21 17:57:45.549         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC-13k3
    2013/02/21 17:57:45.549         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats Remove iLBC-15k2
    2013/02/21 17:57:45.549         Pool:0xde5c9700 MySIPConnection::GetLocalMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:45.549         Pool:0xde5c9700 RFC2833 Tx capability merged with "0-16,32,36"
    2013/02/21 17:57:45.549         Pool:0xde5c9700 SIP Using default RTP payload [pt=101] for UserInput/RFC2833
    2013/02/21 17:57:45.549         Pool:0xde5c9700 RFC2833 Tx capability set to "-"
    2013/02/21 17:57:45.549         Pool:0xde5c9700 OpalCon SetPhase from AlertingPhase to ConnectedPhase for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:45.549         Pool:0xde5c9700 OpalCon OnConnected for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:45.549         Pool:0xde5c9700 OpalMan OnConnected Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:45.549         Pool:0xde5c9700 Call    OnConnected Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:45.549         Pool:0xde5c9700 ModemConnection::SetConnected Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalCon SetConnected for Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalCon SetPhase from AlertingPhase to ConnectedPhase for Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalCon SetPhase from ConnectedPhase to EstablishedPhase for Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 ModemConnection::OnEstablished Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 ModemEngineBody::Request: stConnectWait request={
    calltoken=modem:/C049f6ca11/0
    command=established
    }
    2013/02/21 17:57:45.550         Pool:0xde5c9700 ttyT38-1 AudioEngine RecvOnIdle dtNone
    2013/02/21 17:57:45.550         Pool:0xde5c9700 ModemEngineBody::SetCallState: off-hook cstEstablished stConnectWait
    2013/02/21 17:57:45.550         Pool:0xde5c9700 ModemEngineBody::SetState: off-hook cstEstablished stConnectHandle.chConnected
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalCon OnEstablished Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalCon Media stream threads started.
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalMan OnEstablished Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 Call    OnEstablished Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalCon Media stream threads started.
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalCon SetPhase from ConnectedPhase to EstablishedPhase for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalCon OnEstablished Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalCon Media stream threads started.
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalMan OnEstablished Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 Call    OnEstablished Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:45.550         Pool:0xde5c9700 OpalCon Media stream threads started.
    2013/02/21 17:57:45.550         Pool:0xde5c9700 SIP Handled PDU "2 INVITE <200>"
    2013/02/21 17:57:45.550 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetSubState: off-hook cstEstablished stConnectHandle.chAudioEngineAttached
    2013/02/21 17:57:45.550 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetSubState: off-hook cstEstablished stConnectHandle.chTonePlayed
    2013/02/21 17:57:45.550 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetSubState: off-hook cstEstablished stConnectHandle.chConnectionEstablishDelay
    2013/02/21 17:57:46.016  Media Patch:0xde588700 RTP Session 1, SentSenderReport: ssrc=3239158679 ntp=3570476266.70421600 rtp=0 psent=451 osent=72160
    2013/02/21 17:57:46.016  Media Patch:0xde588700 RTP Session 1, SentReceiverReport: ssrc=3206709370 fraction=0 lost=0 last_seq=0 jitter=547119 lsr=0 dlsr=0
    2013/02/21 17:57:46.016  Media Patch:0xde588700 RTP Session 1, sending SDES: root@fax1.dev.mycompany.com
    2013/02/21 17:57:46.551  Housekeeper:0xde790700 ModemEngineBody::OnTimerCallback stConnectHandle Timeout 0
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetSubState: off-hook cstEstablished stConnectHandle.chConnectionEstablished
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 ModemEngineBody::SendOnIdle dtCng
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 ttyT38-1 AudioEngine SendOnIdle dtCng
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetState: off-hook cstEstablished stReqModeAckWait
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 ModemEndPoint::OnMyCallback command=requestmode extra=4
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 ModemConnection::RequestMode: Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] fax
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 ModemConnection::RequestMode: options: 
    T38-UDPTL-Redundancy-Interval=50
    T38-UDPTL-Optimise-On-Retransmit=true
    T38-UDPTL-Redundancy=
    T38-UDPTL-Keep-Alive-Interval=0
    Try-Next-Count=1
    Original-Party-B=12037691544@+/dev/ttyT38-1
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 ModemConnection::RequestMode: force fax mode for other connection
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 PWLib   File handle high water mark set: 47 Thread unblock pipe
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 PTLib   Thread high water mark set: 17
    2013/02/21 17:57:46.551 ttyT38-1(e...0xde7d1700 ModemEndPoint::OnMyCallback request={
    calltoken=modem:/C049f6ca11/0
    mode=fax
    command=requestmode
    response=confirm
    modemtoken=ttyT38-1
    }
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 Call    GetOtherPartyConnection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 ModemConnection::RequestMode: other connection formats: 
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::SwitchFaxMediaStreams: fax
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 MySIPConnection::SwitchFaxMediaStreams:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.552 PSimpleThr...0xde506700 OpalCon SwitchFaxMediaStreams to fax on Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 Call    OpenSourceMediaStreams replace for fax session 1 (T.38) on Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 ModemConnection::GetMediaFormats Remove PCM-16
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 ModemConnection::GetMediaFormats Remove UserInput/RFC2833
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    T.38
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    T.38
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.553 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.554 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    UserInput/RFC2833
    PCM-16
    G.711-uLaw-64k
    G.711-ALaw-64k
    YUV420P
    RFC4175_YCbCr-4:2:0
    RGB24
    RFC4175_RGB
    PCM-16-16kHz
    PCM-16-32kHz
    PCM-16-48kHz
    GSM-AMR
    G.726-40k
    G.726-32k
    G.726-24k
    G.726-16k
    GSM-06.10
    MS-GSM
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFWide-20.6k
    SpeexWNarrow-8k
    SpeexWide-20.6k
    SpeexNB
    SpeexWB
    MS-IMA-ADPCM
    iLBC
    iLBC-13k3
    iLBC-15k2
    LPC-10
    G.722-64k
    H.261-CIF
    H.261-QCIF
    H.261
    NamedSignalEvent
    T.140
    T.38
    2013/02/21 17:57:46.555 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:46.555 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    H.261
    RFC4175_YCbCr-4:2:0
    RFC4175_RGB
    G.726-40k
    G.726-32k
    G.726-24k
    G.726-16k
    MS-GSM
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFWide-20.6k
    SpeexWNarrow-8k
    SpeexWide-20.6k
    SpeexNB
    SpeexWB
    MS-IMA-ADPCM
    iLBC-13k3
    iLBC-15k2
    LPC-10
    G.722-64k
    H.261-CIF
    H.261-QCIF
    NamedSignalEvent
    T.140
    2013/02/21 17:57:46.555 PSimpleThr...0xde506700 MediaFormat Merging T.38 into T.38
    2013/02/21 17:57:46.555 PSimpleThr...0xde506700 MediaFormat Merging T.38 into T.38
    2013/02/21 17:57:46.555 PSimpleThr...0xde506700 MediaFormat Merging T.38 into T.38
    2013/02/21 17:57:46.555 PSimpleThr...0xde506700 MediaFormat Merging T.38 into T.38
    2013/02/21 17:57:46.555 PSimpleThr...0xde506700 Call    Selected media formats T.38 -> T.38
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 AudioModemMediaStream::Close AudioModemMediaStream-Source-PCM-16
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 ttyT38-1 AudioEngine CloseOut: close 0x7fd0a4010010
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 ModemEngineBody::OnEngineCallback AudioEngine cbpUpdateState (0, stReqModeAckWait)
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 Media   Closing stream AudioModemMediaStream-Source-PCM-16
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 Media   Disconnecting AudioModemMediaStream-Source-PCM-16 from patch thread Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 Patch   Closing media patch Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 Patch   Setting media patch bypass to 0 on Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 Media   Closing RTP for OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 RTP_UDP Session 1, shutting down write.
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 Media   Closing stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 Media   Disconnecting OpalRTPMediaStream-Sink-G.711-uLaw-64k from patch thread Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:46.556 PSimpleThr...0xde506700 Patch   Removing media stream sink OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:46.557 PSimpleThr...0xde506700 OpalCon Removed media stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
    2013/02/21 17:57:46.557 PSimpleThr...0xde506700 Patch   Waiting for media patch thread to stop Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16
    2013/02/21 17:57:46.575  Media Patch:0xde547700 Patch   Thread ended because source read failed
    2013/02/21 17:57:46.575  Media Patch:0xde547700 Patch   Thread ended for Patch[0x7fd0a4010700] AudioModemMediaStream-Source-PCM-16
    2013/02/21 17:57:46.575  Media Patch:0xde547700 PWLib   File handle high water mark set: 48 PTextFile
    2013/02/21 17:57:46.575  Media Patch:0xde547700 PTLib   Thread ended: name="Media Patch:0xde547700", real=9.559, kernel=0.030 (0.3%), user=0.050 (0.5%), both=0.080 (0.8%)
    2013/02/21 17:57:46.577 PSimpleThr...0xde506700 OpalCon Removed media stream AudioModemMediaStream-Source-PCM-16
    2013/02/21 17:57:46.577 PSimpleThr...0xde506700 Media   Closing RTP for OpalRTPMediaStream-Source-G.711-uLaw-64k
    2013/02/21 17:57:46.578 PSimpleThr...0xde506700 RTP_UDP Session 1, Shutting down read.
    2013/02/21 17:57:46.578  Media Patch:0xde588700 RTP_UDP Session 1, Read shutdown.
    2013/02/21 17:57:46.578  Media Patch:0xde588700 Patch   Thread ended because source read failed
    2013/02/21 17:57:46.578  Media Patch:0xde588700 Patch   Thread ended for Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:46.578  Media Patch:0xde588700 PWLib   File handle low water mark set: 44 PTextFile
    2013/02/21 17:57:46.578  Media Patch:0xde588700 PTLib   Thread ended: name="Media Patch:0xde588700", real=9.563, kernel=0.020 (0.2%), user=0.070 (0.7%), both=0.090 (0.9%)
    2013/02/21 17:57:46.578 PSimpleThr...0xde506700 Media   Closing stream OpalRTPMediaStream-Source-G.711-uLaw-64k
    2013/02/21 17:57:46.578 PSimpleThr...0xde506700 Media   Disconnecting OpalRTPMediaStream-Source-G.711-uLaw-64k from patch thread Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:46.578 PSimpleThr...0xde506700 Patch   Closing media patch Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:46.579 PSimpleThr...0xde506700 Patch   Setting media patch bypass to 0 on Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:46.579 PSimpleThr...0xde506700 AudioModemMediaStream::Close AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:46.579 PSimpleThr...0xde506700 ttyT38-1 AudioEngine CloseIn: close 0x7fd0a400c980
    2013/02/21 17:57:46.579 PSimpleThr...0xde506700 ModemEngineBody::OnEngineCallback AudioEngine cbpUpdateState (0, stReqModeAckWait)
    2013/02/21 17:57:46.579 PSimpleThr...0xde506700 Media   Closing stream AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:46.579 PSimpleThr...0xde506700 Media   Disconnecting AudioModemMediaStream-Sink-PCM-16 from patch thread Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:46.579 PSimpleThr...0xde506700 Patch   Removing media stream sink AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:46.579 PSimpleThr...0xde506700 OpalCon Removed media stream AudioModemMediaStream-Sink-PCM-16
    2013/02/21 17:57:46.580 PSimpleThr...0xde506700 Patch   Waiting for media patch thread to stop Patch[0x7fd0a400ccf0] OpalRTPMediaStream-Source-G.711-uLaw-64k
    2013/02/21 17:57:46.580 PSimpleThr...0xde506700 OpalCon Removed media stream OpalRTPMediaStream-Source-G.711-uLaw-64k
    2013/02/21 17:57:46.580 PSimpleThr...0xde506700 Call    IsMediaBypassPossible Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] session 1
    2013/02/21 17:57:46.580 PSimpleThr...0xde506700 OpalMan IsMediaBypassPossible: session 1
    2013/02/21 17:57:46.580 PSimpleThr...0xde506700 OpalCon IsMediaBypassPossible: default returns false
    2013/02/21 17:57:46.580 PSimpleThr...0xde506700 RTP Found existing RTP session 1
    2013/02/21 17:57:46.580 PSimpleThr...0xde506700 RTP Found existing media session 1
    2013/02/21 17:57:46.581 PSimpleThr...0xde506700 T38_UDPTL   Use redundancy "32767:1"
    2013/02/21 17:57:46.581 PSimpleThr...0xde506700 T38_UDPTL   Use redundancy interval 0.000
    2013/02/21 17:57:46.581 PSimpleThr...0xde506700 T38_UDPTL   Use keep-alive interval 0.000
    2013/02/21 17:57:46.581 PSimpleThr...0xde506700 T38_UDPTL   Use optimise on retransmit - false
    2013/02/21 17:57:46.581 PSimpleThr...0xde506700 RTP Changed RTP session format from 'rtp/avp' to 'udptl'
    2013/02/21 17:57:46.581 PSimpleThr...0xde506700 RTP_UDP Session 1 reopened for reading
    2013/02/21 17:57:46.581 PSimpleThr...0xde506700 MySIPConnection::OnOpenMediaStream: OpalRTPMediaStream-Source-T.38
    2013/02/21 17:57:46.581 PSimpleThr...0xde506700 RTP Found existing RTP session 1
    2013/02/21 17:57:46.582 PSimpleThr...0xde506700 T38_UDPTL   Use redundancy interval 0.050
    2013/02/21 17:57:46.582 PSimpleThr...0xde506700 T38_UDPTL   Use optimise on retransmit - true
    2013/02/21 17:57:46.582 PSimpleThr...0xde506700 T38_UDPTL   Use redundancy ""
    2013/02/21 17:57:46.582 PSimpleThr...0xde506700 T38_UDPTL   Use keep-alive interval 0.000
    2013/02/21 17:57:46.582 PSimpleThr...0xde506700 T38_UDPTL   Ignored option Try-Next-Count = "1"
    2013/02/21 17:57:46.582 PSimpleThr...0xde506700 T38_UDPTL   Ignored option Original-Party-B = "12037691544@+/dev/ttyT38-1"
    2013/02/21 17:57:46.582 PSimpleThr...0xde506700 OpalMan OnOpenMediaStream Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9],OpalRTPMediaStream-Source-T.38
    2013/02/21 17:57:46.582 PSimpleThr...0xde506700 OpalCon Opened source stream C049f6ca11_1 with format T.38
    2013/02/21 17:57:46.582 PSimpleThr...0xde506700 Call    GetOtherPartyConnection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 Call    OpenSourceMediaStreams open for fax session 1 (T.38) on Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 ModemConnection::GetMediaFormats Remove PCM-16
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 ModemConnection::GetMediaFormats Remove UserInput/RFC2833
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    T.38
    2013/02/21 17:57:46.583 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    T.38
    2013/02/21 17:57:46.584 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    UserInput/RFC2833
    PCM-16
    G.711-uLaw-64k
    G.711-ALaw-64k
    YUV420P
    RFC4175_YCbCr-4:2:0
    RGB24
    RFC4175_RGB
    PCM-16-16kHz
    PCM-16-32kHz
    PCM-16-48kHz
    GSM-AMR
    G.726-40k
    G.726-32k
    G.726-24k
    G.726-16k
    GSM-06.10
    MS-GSM
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFWide-20.6k
    SpeexWNarrow-8k
    SpeexWide-20.6k
    SpeexNB
    SpeexWB
    MS-IMA-ADPCM
    iLBC
    iLBC-13k3
    iLBC-15k2
    LPC-10
    G.722-64k
    H.261-CIF
    H.261-QCIF
    H.261
    NamedSignalEvent
    T.140
    T.38
    2013/02/21 17:57:46.585 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:46.585 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    H.261
    PCM-16
    YUV420P
    RFC4175_YCbCr-4:2:0
    RGB24
    RFC4175_RGB
    PCM-16-16kHz
    PCM-16-32kHz
    PCM-16-48kHz
    G.726-40k
    G.726-32k
    G.726-24k
    G.726-16k
    MS-GSM
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFWide-20.6k
    SpeexWNarrow-8k
    SpeexWide-20.6k
    SpeexNB
    SpeexWB
    MS-IMA-ADPCM
    iLBC-13k3
    iLBC-15k2
    LPC-10
    G.722-64k
    H.261-CIF
    H.261-QCIF
    NamedSignalEvent
    T.140
    2013/02/21 17:57:46.586 PSimpleThr...0xde506700 MediaFormat Merging T.38 into T.38
    2013/02/21 17:57:46.586 PSimpleThr...0xde506700 MediaFormat Merging T.38 into T.38
    2013/02/21 17:57:46.586 PSimpleThr...0xde506700 MediaFormat Merging T.38 into T.38
    2013/02/21 17:57:46.586 PSimpleThr...0xde506700 MediaFormat Merging T.38 into T.38
    2013/02/21 17:57:46.586 PSimpleThr...0xde506700 Call    Selected media formats T.38 -> T.38
    2013/02/21 17:57:46.586 PSimpleThr...0xde506700 ModemConnection::CreateMediaStream Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] mediaFormat=T.38 sessionID=1 isSource=1
    2013/02/21 17:57:46.586 PSimpleThr...0xde506700 ttyT38-1 T38Engine T38Engine
    2013/02/21 17:57:46.586 PSimpleThr...0xde506700 ttyT38-1 T38Engine Attach
    2013/02/21 17:57:46.586 PSimpleThr...0xde506700 ttyT38-1 T38Engine OnAttach Attached
    2013/02/21 17:57:46.586 PSimpleThr...0xde506700 ttyT38-1 T38Engine OnResetModemState
    2013/02/21 17:57:46.587 PSimpleThr...0xde506700 ttyT38-1 T38Engine ChangeModemClass to mcFax
    2013/02/21 17:57:46.587 PSimpleThr...0xde506700 ttyT38-1 T38Engine OnChangeModemClass to mcFax
    2013/02/21 17:57:46.587 PSimpleThr...0xde506700 ttyT38-1 T38Engine SendOnIdle dtCng
    2013/02/21 17:57:46.587 PSimpleThr...0xde506700 ModemEngineBody::SetState: off-hook cstEstablished stReqModeAckHandle
    2013/02/21 17:57:46.587 PSimpleThr...0xde506700 ModemEngineBody::_AttachEngine Attached mceT38
    2013/02/21 17:57:46.587 PSimpleThr...0xde506700 ModemEngineBody::NewPtrEngine created pointer for engine mceT38
    2013/02/21 17:57:46.587 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetState: off-hook cstEstablished stRecvBegWait
    2013/02/21 17:57:46.588 PSimpleThr...0xde506700 T38ModemMediaStream::T38ModemMediaStream T38ModemMediaStream-Source-T.38
    2013/02/21 17:57:46.588 PSimpleThr...0xde506700 T38ModemMediaStream::T38ModemMediaStream DataSize=512
    2013/02/21 17:57:46.588 PSimpleThr...0xde506700 T38ModemMediaStream::Open T38ModemMediaStream-Source-T.38
    2013/02/21 17:57:46.588 PSimpleThr...0xde506700 ttyT38-1 T38Engine OpenOut: open 0x264c2b0
    2013/02/21 17:57:46.588 PSimpleThr...0xde506700 ModemEngineBody::OnEngineCallback T38Engine cbpUpdateState (1, stRecvBegWait)
    2013/02/21 17:57:46.588 PSimpleThr...0xde506700 OpalMan OnOpenMediaStream Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0],T38ModemMediaStream-Source-T.38
    2013/02/21 17:57:46.588 PSimpleThr...0xde506700 OpalCon Opened source stream C049f6ca11_1 with format T.38
    2013/02/21 17:57:46.588 PSimpleThr...0xde506700 Call    IsMediaBypassPossible Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] session 1
    2013/02/21 17:57:46.588 PSimpleThr...0xde506700 OpalMan IsMediaBypassPossible: session 1
    2013/02/21 17:57:46.588 PSimpleThr...0xde506700 OpalCon IsMediaBypassPossible: default returns false
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 RTP Found existing RTP session 1
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 RTP Found existing media session 1
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 RTP_UDP Session 1 reopened for writing
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 MySIPConnection::OnOpenMediaStream: OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 RTP Found existing RTP session 1
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 T38_UDPTL   Use redundancy interval 0.050
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 T38_UDPTL   Use optimise on retransmit - true
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 T38_UDPTL   Use redundancy ""
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 T38_UDPTL   Use keep-alive interval 0.000
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 T38_UDPTL   Ignored option Try-Next-Count = "1"
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 T38_UDPTL   Ignored option Original-Party-B = "12037691544@+/dev/ttyT38-1"
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 OpalMan OnOpenMediaStream Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9],OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:57:46.589 PSimpleThr...0xde506700 OpalCon Opened sink stream C049f6ca11_1 with format T.38
    2013/02/21 17:57:46.590 PSimpleThr...0xde506700 Adding patch Patch[0x2655ad0] T38ModemMediaStream-Source-T.38 on stream T38ModemMediaStream-Source-T.38
    2013/02/21 17:57:46.590 PSimpleThr...0xde506700 Adding patch Patch[0x2655ad0] T38ModemMediaStream-Source-T.38 on stream OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:57:46.590 PSimpleThr...0xde506700 Patch   Created Sink: format=T.38
    2013/02/21 17:57:46.590 PSimpleThr...0xde506700 Media   RTP data size cannot be changed to 512, fixed at 528
    2013/02/21 17:57:46.590 PSimpleThr...0xde506700 Patch   Added direct media stream sink OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:57:46.590 PSimpleThr...0xde506700 OpalCon Source stream of connection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] uses patch Patch[0x2655ad0] T38ModemMediaStream-Source-T.38 -> OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:57:46.590 PSimpleThr...0xde506700 OpalCon Sink stream of connection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] uses patch Patch[0x2655ad0] T38ModemMediaStream-Source-T.38 -> OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:57:46.590 PSimpleThr...0xde506700 SIP Starting re-INVITE to open channel
    2013/02/21 17:57:46.591 PSimpleThr...0xde506700 PWLib   File handle low water mark set: 42 PUDPSocket
    2013/02/21 17:57:46.593 PSimpleThr...0xde506700 SIP INVITE transaction id=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9 created.
    2013/02/21 17:57:46.593 PSimpleThr...0xde506700 SIP Creating INVITE request
    2013/02/21 17:57:46.593 PSimpleThr...0xde506700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:46.593 PSimpleThr...0xde506700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:46.593 PSimpleThr...0xde506700 ModemConnection::GetMediaFormats Remove PCM-16
    2013/02/21 17:57:46.593 PSimpleThr...0xde506700 ModemConnection::GetMediaFormats Remove UserInput/RFC2833
    2013/02/21 17:57:46.594 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    T.38
    2013/02/21 17:57:46.594 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:46.594 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    T.38
    2013/02/21 17:57:46.594 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    T.38
    2013/02/21 17:57:46.594 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:46.594 PSimpleThr...0xde506700 MySIPConnection::AdjustMediaFormats:
    T.38
    2013/02/21 17:57:46.594 PSimpleThr...0xde506700 Call    GetMediaFormats for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    T.38
    2013/02/21 17:57:46.594 PSimpleThr...0xde506700 MySIPConnection::GetLocalMediaFormats:
    T.38
    2013/02/21 17:57:46.594 PSimpleThr...0xde506700 MySIPConnection::GetLocalMediaFormats:
    T.38
    2013/02/21 17:57:46.595 PSimpleThr...0xde506700 SIP Offering media type fax in SDP with formats
    T.38
    2013/02/21 17:57:46.595 PSimpleThr...0xde506700 Call    IsMediaBypassPossible Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] session 1
    2013/02/21 17:57:46.595 PSimpleThr...0xde506700 OpalMan IsMediaBypassPossible: session 1
    2013/02/21 17:57:46.595 PSimpleThr...0xde506700 OpalCon IsMediaBypassPossible: default returns false
    2013/02/21 17:57:46.595 PSimpleThr...0xde506700 RTP Found existing media session 1
    2013/02/21 17:57:46.595 PSimpleThr...0xde506700 RTP Found existing RTP session 1
    2013/02/21 17:57:46.596 PSimpleThr...0xde506700 HTTP    Adding authentication information
    2013/02/21 17:57:46.596 PSimpleThr...0xde506700 SIP Transaction remote address is udp$66.23.129.253:5060
    2013/02/21 17:57:46.596 PSimpleThr...0xde506700 SIP Sending PDU (1143 bytes) to: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    INVITE sip:12037691544@66.23.129.253 SIP/2.0
    Route: <sip:12037691544@66.23.129.253:5060;nat=yes;ftag=7c8c4bbf-e77a-e211-8957-5254007747e9;lr=on>
    CSeq: 3 INVITE
    Via: SIP/2.0/UDP 192.168.77.42:5060;branch=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9;rport
    User-Agent: T38Modem/2.0.0
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    Organization: Vyacheslav Frolov
    To: <sip:12037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Contact: <sip:MYUSERNAME@192.168.77.42>
    Proxy-Authorization: Digest username="MYUSERNAME", realm="nexvortex.com", nonce="5126a78949c9bc7af127ddd04d070a682539462f", uri="sip:12037691544@66.23.129.253", algorithm=MD5, response="f57cecf9af1b6479b452c97633f713a2"
    Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING
    Content-Type: application/sdp
    Content-Length: 188
    Max-Forwards: 70
    v=0
    o=- 1361487453 2 IN IP4 192.168.77.42
    s=T38Modem/2.0.0
    c=IN IP4 192.168.77.42
    t=0 0
    m=image 10000 udptl t38
    a=sendrecv
    a=T38FaxVersion:0
    a=T38FaxRateManagement:transferredTCF
    2013/02/21 17:57:46.597 PSimpleThr...0xde506700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:57:46.597 PSimpleThr...0xde506700 SIP Transaction timers set: retry=0.499, completion=32.000
    2013/02/21 17:57:46.597 PSimpleThr...0xde506700 ModemConnection::CreateMediaStream Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] mediaFormat=T.38 sessionID=1 isSource=0
    2013/02/21 17:57:46.597 PSimpleThr...0xde506700 ttyT38-1 T38Engine SendOnIdle dtCng
    2013/02/21 17:57:46.597 PSimpleThr...0xde506700 ModemEngineBody::_AttachEngine Attached mceT38
    2013/02/21 17:57:46.598 PSimpleThr...0xde506700 ModemEngineBody::NewPtrEngine created pointer for engine mceT38
    2013/02/21 17:57:46.598 PSimpleThr...0xde506700 T38ModemMediaStream::T38ModemMediaStream T38ModemMediaStream-Sink-T.38
    2013/02/21 17:57:46.598 PSimpleThr...0xde506700 T38ModemMediaStream::T38ModemMediaStream DataSize=512
    2013/02/21 17:57:46.598 PSimpleThr...0xde506700 T38ModemMediaStream::Open T38ModemMediaStream-Sink-T.38
    2013/02/21 17:57:46.598 PSimpleThr...0xde506700 ttyT38-1 T38Engine OpenIn: open 0x2657cb0
    2013/02/21 17:57:46.598 PSimpleThr...0xde506700 ModemEngineBody::OnEngineCallback T38Engine cbpUpdateState (1, stRecvBegWait)
    2013/02/21 17:57:46.598 PSimpleThr...0xde506700 OpalMan OnOpenMediaStream Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0],T38ModemMediaStream-Sink-T.38
    2013/02/21 17:57:46.598 PSimpleThr...0xde506700 OpalCon Opened sink stream C049f6ca11_1 with format T.38
    2013/02/21 17:57:46.599 PSimpleThr...0xde506700 RTP_UDP Session 1, Shutting down read.
    2013/02/21 17:57:46.599 PSimpleThr...0xde506700 Adding patch Patch[0x2658030] OpalRTPMediaStream-Source-T.38 on stream OpalRTPMediaStream-Source-T.38
    2013/02/21 17:57:46.599 PSimpleThr...0xde506700 RTP_UDP Session 1 reopened for reading
    2013/02/21 17:57:46.599 PSimpleThr...0xde506700 Adding patch Patch[0x2658030] OpalRTPMediaStream-Source-T.38 on stream T38ModemMediaStream-Sink-T.38
    2013/02/21 17:57:46.599 PSimpleThr...0xde506700 Patch   Created Sink: format=T.38
    2013/02/21 17:57:46.599 PSimpleThr...0xde506700 Media   RTP data size cannot be changed to 512, fixed at 2048
    2013/02/21 17:57:46.599 PSimpleThr...0xde506700 Patch   Added direct media stream sink T38ModemMediaStream-Sink-T.38
    2013/02/21 17:57:46.599 PSimpleThr...0xde506700 OpalCon Sink stream of connection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] uses patch Patch[0x2658030] OpalRTPMediaStream-Source-T.38 -> T38ModemMediaStream-Sink-T.38
    2013/02/21 17:57:46.599 PSimpleThr...0xde506700 OpalCon Source stream of connection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] uses patch Patch[0x2658030] OpalRTPMediaStream-Source-T.38 -> T38ModemMediaStream-Sink-T.38
    2013/02/21 17:57:46.599 PSimpleThr...0xde506700 MySIPConnection::SwitchFaxMediaStreams: OK
    2013/02/21 17:57:46.600 PSimpleThr...0xde506700 PTLib   Thread ended: name="PSimpleThread:0xde506700", real=0.048, kernel=0.000 (0%), user=0.010 (20.8%), both=0.010 (20.8%)
    2013/02/21 17:57:46.635 Opal Liste...0xde6cd700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:57:46.635 Opal Liste...0xde6cd700 SIP Waiting for PDU on udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:46.635 Opal Liste...0xde6cd700 SIP PDU received: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    SIP/2.0 100 trying -- your call is important to us
    CSeq: 3 INVITE
    Via: SIP/2.0/UDP 192.168.77.42;branch=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9;rport=5060
    Server: nVSIP 12.02.01
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:12037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Content-Length: 0
    2013/02/21 17:57:46.636 Opal Liste...0xde6cd700 SIP Queueing PDU "3 INVITE <100>", transaction=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9, token=7c8c4bbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:46.636 Opal Liste...0xde6cd700 Opal    Transport clean up on termination
    2013/02/21 17:57:46.636 Opal Liste...0xde6cd700 Opal    Transport Close
    2013/02/21 17:57:46.636 Opal Liste...0xde6cd700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:46.636         Pool:0xde5c9700 SIP Handling PDU "3 INVITE <100>" for transaction=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:46.636         Pool:0xde5c9700 SIP INVITE transaction id=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9 proceeding.
    2013/02/21 17:57:46.636         Pool:0xde5c9700 SIP Received Trying response
    2013/02/21 17:57:46.637         Pool:0xde5c9700 SIP Handled PDU "3 INVITE <100>"
    2013/02/21 17:57:46.796 Opal Liste...0xde6cd700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:57:46.796 Opal Liste...0xde6cd700 SIP Waiting for PDU on udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:46.797 Opal Liste...0xde6cd700 SIP PDU received: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    SIP/2.0 486 Busy Here
    CSeq: 3 INVITE
    Via: SIP/2.0/UDP 192.168.77.42;branch=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9;rport=5060
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:12037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Content-Length: 0
    2013/02/21 17:57:46.798 Opal Liste...0xde6cd700 SIP Queueing PDU "3 INVITE <486>", transaction=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9, token=7c8c4bbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:46.798 Opal Liste...0xde6cd700 Opal    Transport clean up on termination
    2013/02/21 17:57:46.798 Opal Liste...0xde6cd700 Opal    Transport Close
    2013/02/21 17:57:46.798 Opal Liste...0xde6cd700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:46.798         Pool:0xde5c9700 SIP Handling PDU "3 INVITE <486>" for transaction=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:46.800         Pool:0xde5c9700 HTTP    Adding authentication information
    2013/02/21 17:57:46.800         Pool:0xde5c9700 SIP Sending PDU (735 bytes) to: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    ACK sip:12037691544@66.23.129.253 SIP/2.0
    Route: <sip:12037691544@66.23.129.253:5060;nat=yes;ftag=7c8c4bbf-e77a-e211-8957-5254007747e9;lr=on>
    CSeq: 3 ACK
    Via: SIP/2.0/UDP 192.168.77.42:5060;branch=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9;rport
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:12037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Proxy-Authorization: Digest username="MYUSERNAME", realm="nexvortex.com", nonce="5126a78949c9bc7af127ddd04d070a682539462f", uri="sip:12037691544@66.23.129.253", algorithm=MD5, response="feafc7b14454766a65e8960ce2d0896b"
    Content-Length: 0
    Max-Forwards: 70
    2013/02/21 17:57:46.801         Pool:0xde5c9700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:57:46.801         Pool:0xde5c9700 SIP INVITE transaction id=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9 completed.
    2013/02/21 17:57:46.801         Pool:0xde5c9700 MySIPConnection::OnSwitchedFaxMediaStreams: NOT switched to fax
    2013/02/21 17:57:46.801         Pool:0xde5c9700 OpalCon Switch of media streams to fax failed on Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:46.801         Pool:0xde5c9700 Call    GetOtherPartyConnection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:46.801         Pool:0xde5c9700 MySIPConnection::OnSwitchedFaxMediaStreams: fallback to audio
    2013/02/21 17:57:46.801         Pool:0xde5c9700 MySIPConnection::SwitchFaxMediaStreams: audio
    2013/02/21 17:57:46.801         Pool:0xde5c9700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.801         Pool:0xde5c9700 MySIPConnection::GetMediaFormats Remove T.38
    2013/02/21 17:57:46.802         Pool:0xde5c9700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    UserInput/RFC2833
    2013/02/21 17:57:46.802         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    UserInput/RFC2833
    2013/02/21 17:57:46.802         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:46.802         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    UserInput/RFC2833
    2013/02/21 17:57:46.802         Pool:0xde5c9700 MySIPConnection::SwitchFaxMediaStreams:
    G.711-uLaw-64k
    G.711-ALaw-64k
    UserInput/RFC2833
    2013/02/21 17:57:46.802         Pool:0xde5c9700 OpalCon SwitchFaxMediaStreams to audio on Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:46.802         Pool:0xde5c9700 Call    OpenSourceMediaStreams replace for audio session 1 (G.711-uLaw-64k) on Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:57:46.802         Pool:0xde5c9700 ModemConnection::GetMediaFormats Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:57:46.803         Pool:0xde5c9700 ModemEndPoint::GetMediaFormats
    2013/02/21 17:57:46.803         Pool:0xde5c9700 ModemConnection::GetMediaFormats Remove PCM-16
    2013/02/21 17:57:46.803         Pool:0xde5c9700 ModemConnection::GetMediaFormats Remove UserInput/RFC2833
    2013/02/21 17:57:46.803         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    T.38
    2013/02/21 17:57:46.803         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    T.38
    2013/02/21 17:57:46.803         Pool:0xde5c9700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    T.38
    UserInput/RFC2833
    2013/02/21 17:57:46.803         Pool:0xde5c9700 MySIPConnection::GetMediaFormats Remove T.38
    2013/02/21 17:57:46.803         Pool:0xde5c9700 MySIPConnection::GetMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    UserInput/RFC2833
    2013/02/21 17:57:46.803         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    UserInput/RFC2833
    2013/02/21 17:57:46.803         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    UserInput/RFC2833
    2013/02/21 17:57:46.804         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    UserInput/RFC2833
    PCM-16
    G.711-uLaw-64k
    G.711-ALaw-64k
    YUV420P
    RFC4175_YCbCr-4:2:0
    RGB24
    RFC4175_RGB
    PCM-16-16kHz
    PCM-16-32kHz
    PCM-16-48kHz
    GSM-AMR
    G.726-40k
    G.726-32k
    G.726-24k
    G.726-16k
    GSM-06.10
    MS-GSM
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFWide-20.6k
    SpeexWNarrow-8k
    SpeexWide-20.6k
    SpeexNB
    SpeexWB
    MS-IMA-ADPCM
    iLBC
    iLBC-13k3
    iLBC-15k2
    LPC-10
    G.722-64k
    H.261-CIF
    H.261-QCIF
    H.261
    NamedSignalEvent
    T.140
    T.38
    2013/02/21 17:57:46.804         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats: reordered
    2013/02/21 17:57:46.804         Pool:0xde5c9700 MySIPConnection::AdjustMediaFormats:
    G.711-uLaw-64k
    G.711-ALaw-64k
    UserInput/RFC2833
    GSM-AMR
    iLBC
    GSM-06.10
    H.261
    RFC4175_YCbCr-4:2:0
    RFC4175_RGB
    G.726-40k
    G.726-32k
    G.726-24k
    G.726-16k
    MS-GSM
    SpeexIETFNarrow-5.95k
    SpeexIETFNarrow-8k
    SpeexIETFNarrow-11k
    SpeexIETFNarrow-15k
    SpeexIETFNarrow-18.2k
    SpeexIETFNarrow-24.6k
    SpeexIETFWide-20.6k
    SpeexWNarrow-8k
    SpeexWide-20.6k
    SpeexNB
    SpeexWB
    MS-IMA-ADPCM
    iLBC-13k3
    iLBC-15k2
    LPC-10
    G.722-64k
    H.261-CIF
    H.261-QCIF
    NamedSignalEvent
    T.140
    T.38
    2013/02/21 17:57:46.805         Pool:0xde5c9700 Call    SelectMediaFormats could not find compatible audio format:
      source formats=G.711-uLaw-64k
       sink  formats=T.38
    2013/02/21 17:57:46.805         Pool:0xde5c9700 MySIPConnection::SwitchFaxMediaStreams: FAIL
    2013/02/21 17:57:46.805         Pool:0xde5c9700 SIP Handled PDU "3 INVITE <486>"
    2013/02/21 17:57:46.825 Opal Liste...0xde6cd700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:57:46.825 Opal Liste...0xde6cd700 SIP Waiting for PDU on udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:46.826 Opal Liste...0xde6cd700 SIP PDU received: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    SIP/2.0 486 Busy Here
    CSeq: 3 INVITE
    Via: SIP/2.0/UDP 192.168.77.42;branch=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9;rport=5060
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:12037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Content-Length: 0
    2013/02/21 17:57:46.827 Opal Liste...0xde6cd700 SIP Queueing PDU "3 INVITE <486>", transaction=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9, token=7c8c4bbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:46.827 Opal Liste...0xde6cd700 Opal    Transport clean up on termination
    2013/02/21 17:57:46.827 Opal Liste...0xde6cd700 Opal    Transport Close
    2013/02/21 17:57:46.827 Opal Liste...0xde6cd700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:57:46.827         Pool:0xde5c9700 SIP Handling PDU "3 INVITE <486>" for transaction=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:46.828         Pool:0xde5c9700 HTTP    Adding authentication information
    2013/02/21 17:57:46.829         Pool:0xde5c9700 SIP Sending PDU (735 bytes) to: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    ACK sip:12037691544@66.23.129.253 SIP/2.0
    Route: <sip:12037691544@66.23.129.253:5060;nat=yes;ftag=7c8c4bbf-e77a-e211-8957-5254007747e9;lr=on>
    CSeq: 3 ACK
    Via: SIP/2.0/UDP 192.168.77.42:5060;branch=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9;rport
    From: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: <sip:12037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Proxy-Authorization: Digest username="MYUSERNAME", realm="nexvortex.com", nonce="5126a78949c9bc7af127ddd04d070a682539462f", uri="sip:12037691544@66.23.129.253", algorithm=MD5, response="feafc7b14454766a65e8960ce2d0896b"
    Content-Length: 0
    Max-Forwards: 70
    2013/02/21 17:57:46.829         Pool:0xde5c9700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:57:46.829         Pool:0xde5c9700 SIP Ignoring duplicate response to INVITE transaction id=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:46.829         Pool:0xde5c9700 SIP Handled PDU "3 INVITE <486>"
    2013/02/21 17:57:50.551  Housekeeper:0xde790700 SIP Set state Terminated_Success for INVITE transaction id=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:51.830  Housekeeper:0xde790700 SIP Set state Terminated_Success for INVITE transaction id=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9
    2013/02/21 17:57:51.833 Opal Garbage:0xde894700 SIP Transaction id=z9hG4bKd46ecdc6-e77a-e211-8957-5254007747e9 destroyed.
    2013/02/21 17:58:46.080 Opal Liste...0xde6cd700 OpalUDP Binding to interface: 192.168.77.42:5060
    2013/02/21 17:58:46.081 Opal Liste...0xde6cd700 SIP Waiting for PDU on udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:58:46.081 Opal Liste...0xde6cd700 SIP PDU received: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    BYE sip:MYUSERNAME@192.168.77.42 SIP/2.0
    CSeq: 790782954 BYE
    Via: SIP/2.0/UDP 66.23.129.253:5060;branch=z9hG4bK505f.c9387241.0
    Via: SIP/2.0/UDP 69.54.92.148:5060;branch=z9hG4bK70km07203oqhe25157j1.1
    From: <sip:2037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    Supported: resource-priority, 100rel
    Organization: Metaswitch Networks
    To: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Allow-Events: message-summary, refer, dialog, line-seize, presence, call-info, as-feature-event
    Content-Length: 0
    Max-Forwards: 16
    Record-Route: <sip:MYUSERNAME@66.23.129.253:5060;nat=yes;ftag=metaswitch+1+fb972e+979e608a;lr=on>
    2013/02/21 17:58:46.082 Opal Liste...0xde6cd700 SIP Queueing PDU "790782954 BYE sip:MYUSERNAME@192.168.77.42", transaction=z9hG4bK505f.c9387241.0, token=7c8c4bbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:58:46.082 Opal Liste...0xde6cd700 Opal    Transport clean up on termination
    2013/02/21 17:58:46.082 Opal Liste...0xde6cd700 Opal    Transport Close
    2013/02/21 17:58:46.082 Opal Liste...0xde6cd700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:58:46.082         Pool:0xde5c9700 SIP Handling PDU "790782954 BYE sip:MYUSERNAME@192.168.77.42" for token=7c8c4bbf-e77a-e211-8957-5254007747e9
    2013/02/21 17:58:46.082         Pool:0xde5c9700 SIP BYE received for call a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    2013/02/21 17:58:46.083         Pool:0xde5c9700 SIP Sending PDU (520 bytes) to: rem=udp$66.23.129.253:5060,local=udp$192.168.77.42:5060,if=192.168.77.42%eth0
    SIP/2.0 200 OK
    CSeq: 790782954 BYE
    Via: SIP/2.0/UDP 66.23.129.253:5060;branch=z9hG4bK505f.c9387241.0
    Via: SIP/2.0/UDP 69.54.92.148:5060;branch=z9hG4bK70km07203oqhe25157j1.1
    From: <sip:2037691544@66.23.129.253>;tag=metaswitch+1+fb972e+979e608a
    Call-ID: a6ad4bbf-e77a-e211-8957-5254007747e9@fax1.dev.mycompany.com
    To: "root" <sip:MYUSERNAME@66.23.129.253>;tag=7c8c4bbf-e77a-e211-8957-5254007747e9
    Content-Length: 0
    Record-Route: <sip:MYUSERNAME@66.23.129.253:5060;nat=yes;ftag=metaswitch+1+fb972e+979e608a;lr=on>
    2013/02/21 17:58:46.083         Pool:0xde5c9700 OpalUDP Setting interface to 192.168.77.42%eth0
    2013/02/21 17:58:46.084         Pool:0xde5c9700 SIP No User-Agent or Server fields, Product Info unknown.
    2013/02/21 17:58:46.084         Pool:0xde5c9700 OpalCon SetPhase from EstablishedPhase to ReleasingPhase for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:58:46.084         Pool:0xde5c9700 OpalCon Releasing Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:58:46.084         Pool:0xde5c9700 OpalCon Call end reason for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] set to EndedByRemoteUser
    2013/02/21 17:58:46.084         Pool:0xde5c9700 SIP Handled PDU "790782954 BYE sip:MYUSERNAME@192.168.77.42"
    2013/02/21 17:58:46.084    OnRelease:0xde506700 SIP OnReleased: Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9], phase = ReleasingPhase
    2013/02/21 17:58:46.084    OnRelease:0xde506700 OpalCon SetPhase from ReleasingPhase to ReleasingPhase for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:58:46.084    OnRelease:0xde506700 Media   Closing RTP for OpalRTPMediaStream-Source-T.38
    2013/02/21 17:58:46.084    OnRelease:0xde506700 RTP_UDP Session 1, Shutting down read.
    2013/02/21 17:58:46.084    OnRelease:0xde506700 Media   Closing stream OpalRTPMediaStream-Source-T.38
    2013/02/21 17:58:46.084    OnRelease:0xde506700 Media   Disconnecting OpalRTPMediaStream-Source-T.38 from patch thread Patch[0x2658030] OpalRTPMediaStream-Source-T.38 -> T38ModemMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Patch   Closing media patch Patch[0x2658030] OpalRTPMediaStream-Source-T.38 -> T38ModemMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Patch   Setting media patch bypass to 0 on Patch[0x2658030] OpalRTPMediaStream-Source-T.38 -> T38ModemMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 T38ModemMediaStream::Close T38ModemMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 T38ModemMediaStream::Close Send statistics: sequence=0 lost=0
    2013/02/21 17:58:46.085    OnRelease:0xde506700 ttyT38-1 T38Engine CloseIn: close 0x2657cb0
    2013/02/21 17:58:46.085    OnRelease:0xde506700 ModemEngineBody::OnEngineCallback T38Engine cbpUpdateState (1, stRecvBegWait)
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Media   Closing stream T38ModemMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Media   Disconnecting T38ModemMediaStream-Sink-T.38 from patch thread Patch[0x2658030] OpalRTPMediaStream-Source-T.38 -> T38ModemMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Patch   Removing media stream sink T38ModemMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 OpalCon Removed media stream T38ModemMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Patch   Waiting for media patch thread to stop Patch[0x2658030] OpalRTPMediaStream-Source-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 OpalCon Removed media stream OpalRTPMediaStream-Source-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Media   Closing RTP for OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 RTP_UDP Session 1, shutting down write.
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Media   Closing stream OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Media   Disconnecting OpalRTPMediaStream-Sink-T.38 from patch thread Patch[0x2655ad0] T38ModemMediaStream-Source-T.38 -> OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Patch   Removing media stream sink OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 OpalCon Removed media stream OpalRTPMediaStream-Sink-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Call    GetOtherPartyConnection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:58:46.085    OnRelease:0xde506700 T38ModemMediaStream::Close T38ModemMediaStream-Source-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 T38ModemMediaStream::Close Receive statistics: sequence=0
    2013/02/21 17:58:46.085    OnRelease:0xde506700 ttyT38-1 T38Engine CloseOut: close 0x264c2b0
    2013/02/21 17:58:46.085    OnRelease:0xde506700 ModemEngineBody::OnEngineCallback T38Engine cbpUpdateState (1, stRecvBegWait)
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Media   Closing stream T38ModemMediaStream-Source-T.38
    2013/02/21 17:58:46.085    OnRelease:0xde506700 Media   Disconnecting T38ModemMediaStream-Source-T.38 from patch thread Patch[0x2655ad0] T38ModemMediaStream-Source-T.38
    2013/02/21 17:58:46.086    OnRelease:0xde506700 Patch   Closing media patch Patch[0x2655ad0] T38ModemMediaStream-Source-T.38
    2013/02/21 17:58:46.086    OnRelease:0xde506700 Patch   Setting media patch bypass to 0 on Patch[0x2655ad0] T38ModemMediaStream-Source-T.38
    2013/02/21 17:58:46.086    OnRelease:0xde506700 Patch   Waiting for media patch thread to stop Patch[0x2655ad0] T38ModemMediaStream-Source-T.38
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalCon Removed media stream T38ModemMediaStream-Source-T.38
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalCon Media streams closed.
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalCon SetPhase from ReleasingPhase to ReleasedPhase for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalCon OnReleased Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalEP  OnReleased Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalMan OnReleased Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 Call    OnReleased Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalCon SetPhase from EstablishedPhase to ReleasingPhase for Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalCon Releasing Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalCon Call end reason for Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] set to EndedByRemoteUser
    2013/02/21 17:58:46.086    OnRelease:0xde506700 ModemConnection::OnReleased Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalCon OnReleased Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalEP  OnReleased Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalMan OnReleased Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 Call    OnReleased Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0]
    2013/02/21 17:58:46.086    OnRelease:0xde506700 Call[C049f6ca11] cleared (EndedByRemoteUser)
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalMan OnClearedCall Call[C049f6ca11] from "modem:" to "sip:12037691544@66.23.129.253"
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalCon Media streams closed.
    2013/02/21 17:58:46.086    OnRelease:0xde506700 OpalCon Media streams closed.
    2013/02/21 17:58:46.086    OnRelease:0xde506700 Opal    Transport clean up on termination
    2013/02/21 17:58:46.086    OnRelease:0xde506700 Opal    Transport Close
    2013/02/21 17:58:46.086    OnRelease:0xde506700 Opal    Transport clean up on termination
    2013/02/21 17:58:46.086    OnRelease:0xde506700 Opal    Transport Close
    2013/02/21 17:58:46.087    OnRelease:0xde506700 Opal    Deleted transport udp$66.23.129.253:5060<if=udp$192.168.77.42:5060>
    2013/02/21 17:58:46.087    OnRelease:0xde506700 OpalCon OnRelease thread completed for Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9]
    2013/02/21 17:58:46.087    OnRelease:0xde506700 PTLib   Thread ended: name="OnRelease:0xde506700", real=0.003, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
    2013/02/21 17:58:46.587  Housekeeper:0xde790700 ModemEngineBody::OnTimerCallback stRecvBegWait Timeout 0
    2013/02/21 17:58:46.588 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetState: off-hook cstEstablished stCommand
    2013/02/21 17:58:46.588 ttyT38-1(e...0xde7d1700 ttyT38-1 T38Engine OnResetModemState
    2013/02/21 17:58:46.588 ttyT38-1(e...0xde7d1700 ttyT38-1 T38Engine T38Engine::OnResetModemState stateModem(4) != stmIdle, reset
    2013/02/21 17:58:46.588 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4e 4f 20 43 41 52  52 49 45 52 0d 0a         ..NO CARRIER.. }
    2013/02/21 17:58:46.588 ttyT38-1(e...0xde7d1700 ModemEngineBody::SendOnIdle dtNone
    2013/02/21 17:58:46.588 ttyT38-1(e...0xde7d1700 ttyT38-1 AudioEngine SendOnIdle dtNone
    2013/02/21 17:58:46.588 ttyT38-1(e...0xde7d1700 ttyT38-1 T38Engine SendOnIdle dtNone
    2013/02/21 17:58:46.848 Opal Garbage:0xde894700 ModemConnection::~ModemConnection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] EndedByRemoteUser
    2013/02/21 17:58:46.848 Opal Garbage:0xde894700 PseudoModemQ::Enqueue ttyT38-1
    2013/02/21 17:58:46.848 Opal Garbage:0xde894700 ModemEngineBody::Request: stCommand request={
    calltoken=modem:/C049f6ca11/0
    command=clearcall
    }
    2013/02/21 17:58:46.848 Opal Garbage:0xde894700 ModemEngineBody::SetCallState: off-hook cstReleasing.0 stCommand
    2013/02/21 17:58:46.848 Opal Garbage:0xde894700 ModemEngineBody::OnTimerCallback stCommand Timeout 1
    2013/02/21 17:58:46.848 Opal Garbage:0xde894700 ttyT38-1 AudioEngine RecvOnIdle dtBusy
    2013/02/21 17:58:46.848 Opal Garbage:0xde894700 OpalCon Connection Call[C049f6ca11]-EP<modem>[modem:/C049f6ca11/0] destroyed.
    2013/02/21 17:58:46.848 Opal Garbage:0xde894700 SIP Transaction id=z9hG4bK7c494dbf-e77a-e211-8957-5254007747e9 destroyed.
    2013/02/21 17:58:46.848 Opal Garbage:0xde894700 SIP Transaction id=z9hG4bK7afe53bf-e77a-e211-8957-5254007747e9 destroyed.
    2013/02/21 17:58:46.849 Opal Garbage:0xde894700 SIP Deleted connection.
    2013/02/21 17:58:46.849 Opal Garbage:0xde894700 RTP Closing session 1
    2013/02/21 17:58:46.849 Opal Garbage:0xde894700 RTP Deleting session 1
    2013/02/21 17:58:46.849 Opal Garbage:0xde894700 RTP_UDP Session 1, read already shut down .
    2013/02/21 17:58:46.849 Opal Garbage:0xde894700 RTP_UDP Session 1, read already shut down .
    2013/02/21 17:58:46.849 Opal Garbage:0xde894700 RTP_UDP Session 1, write already shut down .
    2013/02/21 17:58:46.849 Opal Garbage:0xde894700 OpalCon Connection Call[C049f6ca11]-EP<sip>[7c8c4bbf-e77a-e211-8957-5254007747e9] destroyed.
    2013/02/21 17:58:46.849 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetCallSubState: off-hook cstReleasing.1 stCommand
    2013/02/21 17:58:47.589 ttyT38-1(e...0xde7d1700 --> ATH0
    2013/02/21 17:58:47.589 ttyT38-1(e...0xde7d1700 ttyT38-1 T38Engine Detach
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ttyT38-1 T38Engine OnChangeModemClass to mcUndefined
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ttyT38-1 T38Engine OnDetach Detached
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ttyT38-1 T38Engine OnResetModemState
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ttyT38-1 T38Engine ~T38Engine
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ModemEngineBody::_DetachEngine Detached mceT38
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ttyT38-1 AudioEngine Detach
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ttyT38-1 AudioEngine OnChangeModemClass to mcUndefined
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ttyT38-1 AudioEngine OnDetach Detached
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ttyT38-1 AudioEngine OnResetModemState
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ttyT38-1 AudioEngine ~AudioEngine
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ModemEngineBody::_DetachEngine Detached mceAudio
    2013/02/21 17:58:47.590 ttyT38-1(e...0xde7d1700 ModemEngineBody::OnHook: on-hook cstReleasing.1 stCommand
    2013/02/21 17:58:47.591 ttyT38-1(e...0xde7d1700 ModemEngineBody::SetCallState: on-hook cstCleared stCommand
    2013/02/21 17:58:47.591 ttyT38-1(e...0xde7d1700 <--  {
      0d 0a 4f 4b 0d 0a                                  ..OK.. }
    2013/02/21 17:58:47.592 ttyT38-1(i...0xde74f700 --> read ERROR -1 Input/output error
    2013/02/21 17:58:47.592 ttyT38-1(i...0xde74f700 --> Stopped
    2013/02/21 17:58:47.592 ttyT38-1(i...0xde74f700 PWLib   File handle low water mark set: 38 PTextFile
    2013/02/21 17:58:47.593 ttyT38-1(i...0xde74f700 PTLib   Thread ended: name="ttyT38-1(i):3732207360:0xde74f700", real=83.186, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
    2013/02/21 17:58:47.593 ttyT38-1(o...0xde70e700 <-- Stopped
    2013/02/21 17:58:47.593 ttyT38-1(o...0xde70e700 PWLib   File handle low water mark set: 18 PTextFile
    2013/02/21 17:58:47.593 ttyT38-1(o...0xde70e700 PTLib   Thread ended: name="ttyT38-1(o):3731941120:0xde70e700", real=83.186, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
    2013/02/21 17:58:47.603 ttyT38-1(e...0xde7d1700 <-> Stopped
    2013/02/21 17:58:47.603 ttyT38-1(e...0xde7d1700 PTLib   Thread ended: name="ttyT38-1(e):3732739840:0xde7d1700", real=83.197, kernel=0.000 (0%), user=0.020 (0%), both=0.020 (0%)
    2013/02/21 17:58:47.613 ttyT38-1(b...0xde853700 PseudoModemPty::OpenPty removed link /dev/ttyT38-1 -> /dev/pts/1
    2013/02/21 17:58:47.613 ttyT38-1(b...0xde853700 PseudoModemPty::OpenPty read ERROR -1 Input/output error
    2013/02/21 17:58:47.614 ttyT38-1(b...0xde853700 PseudoModemPty::OpenPty added link /dev/ttyT38-1 -> /dev/pts/1
    2013/02/21 17:58:47.614 ttyT38-1(o...0xde74f700 RenameCurrentThread old ThreadName=OutPty:0xde74f700
    2013/02/21 17:58:47.614 ttyT38-1(o...0xde74f700 <-- Started
    2013/02/21 17:58:47.614 ttyT38-1(i...0xde70e700 RenameCurrentThread old ThreadName=InPty:0xde70e700
    2013/02/21 17:58:47.615 ttyT38-1(i...0xde70e700 --> Started
    2013/02/21 17:58:47.615 ttyT38-1(e...0xde7d1700 RenameCurrentThread old ThreadName=ModemEngine:0xde7d1700
    2013/02/21 17:58:47.615 ttyT38-1(e...0xde7d1700 <-> Started
    2013/02/21 17:58:47.850 Opal Garbage:0xde894700 Call    Call[C049f6ca11] destroyed.
    

    my /etc/hylafax/etc/config.ttyT38-1:

    #
    # HylaFAX configuration for a T38FAX Pseudo Modem
    #
    SessionTracing:         0x2FFF
    RingsBeforeAnswer:      1
    ModemType:              Class1          # use class 1 interface
    ModemFlowControl:       rtscts          # default
    ModemRevQueryCmd:       AT+FREV?
    #
    # AT#CID=10 enables ANI/DNIS reporting between the 
    # first and second RINGs in the form:
    #
    #   RING
    #   NMBR = <calling number>
    #   NDID = <called number>
    #   RING
    #
    ModemResetCmds: "AT#CID=10"     # enable ANI/DNIS reporting
    RingsBeforeAnswer:      0               # collect info between two RINGs
    #QualifyCID:            etc/cid         # CID access control list file
    CIDNumber:              "NMBR = "       # pattern string for calling number
    CIDName:                "NDID = "       # pattern string for called number
    #
    # T.38 dial modifiers
    #
    # F - enable T.38 mode request after dialing
    # V - disable T.38 mode request after dialing (remote host should do it)
    #
    # calling/called number dial modifiers
    #
    # L - reset and begin of calling number
    # D - continue of called number
    #
    ModemDialCmd:           ATDF%s          # user can override F by dial V
    #ModemDialCmd:          ATDV%s          # user can override V by dial F
    #ModemDialCmd:          ATD%sF          # user can't override F
    #ModemDialCmd:          ATD%sV          # user can't override V
    #ModemDialCmd:          ATD%sVL         # user can't override V or calling number
    

    Someone please help I'm going nuts trying to figure this out!!!

     
  • Anonymous

    Anonymous - 2013-04-09

    Hi,

    Did you try forcing T.38 mode like this:

    -route modem:.*=sip:<dn>@${ASTERISK_IP};OPAL-Force-Fax-Mode=true

    Cheers

    Alex

     
  • Ana

    Ana - 2016-10-19

    Hello Alexey,

    This is an old topic, i know, but I am suffering from the exact same problem and I just wonder if you ever got it resolved? Please any help would be apreciated, really.

    Thank you and kind regards,

     

Log in to post a comment.