Bug#706883: t38modem: segfault at 558 ip 00007fcd6f3a5604 sp 00007fcd55ec6cd0 error 4 in libopal.so.3.10.4

Sebastian Niehaus niehaus at web.de
Sun May 5 19:42:28 UTC 2013


Package: t38modem
Version: 2.0.0-3
Severity: important

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Dear Maintainer,


t38modem segfaults here. Syslog says: 
May  5 21:09:33 ceramic kernel: [ 7830.372934] t38modem[21847]: segfault at 558 ip 00007fcd6f3a5604 sp 00007fcd55ec6cd0 error 4 in libopal.so.3.10.4[7fcd6e811000+ec0000]


I try to use t38modem as SIP-Modem for hylafax. Setup worked on Squeeze somehow
but not very reliable. 

I registered t38modem on my ATA which "speaks" T.38 (Fritz.Box 7390 by AVM). The FritzBox
registers at my SIP provider. 


t38modem is started by an init script. 


the command is

/usr/bin/t38modem -tttt -o /var/log/t38modem.log  --no-h323  --sip-listen 192.168.0.21 --sip-register sipusername at 192.168.0.222,topsecret --sip-old-asn --ptty +/dev/ttyT38-1 --route modem:.*=sip:<dn>@${192.168.0.222} --route sip:.*=modem:<dn>"

192.168.0.21 is the IP address of the maschine running t38modem
192.168.0.222 is the IP address of the ATA ("Fritz Box").

The ATA shows a phone call of one second duration, so at least something works correctly. 

I attached the t38modem logfile which may help to debug.


Thank you very much!


Sebastian





- -- System Information:
Debian Release: 7.0
  APT prefers stable
  APT policy: (500, 'stable')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 3.2.0-4-amd64 (SMP w/3 CPU cores)
Locale: LANG=de_DE.UTF-8, LC_CTYPE=de_DE.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages t38modem depends on:
ii  libc6          2.13-38
ii  libgcc1        1:4.7.2-5
ii  libopal3.10.4  3.10.4~dfsg-3
ii  libpt2.10.4    2.10.4~dfsg-1
ii  libspeexdsp1   1.2~rc1-7
ii  libstdc++6     4.7.2-5

t38modem recommends no packages.

Versions of packages t38modem suggests:
ii  hylafax-server  3:6.0.6-5

- -- debconf-show failed

*** /tmp/t38modem.log
2013/05/05 21:07:58.756	               T38Modem		Version 2.0.0 by Vyacheslav Frolov on Unix Linux (3.2.0-4-amd64-x86_64) with PTLib (v2.10.4 (svn:26606)) at 2013/5/5 21:07:58.756
2013/05/05 21:07:58.756	               T38Modem	T38Modem Version 2.0.0 (OPAL-3.10.4/3.10.4 (svn:26616), PTLIB-2.10.4/2.10.4 (svn:26606)) on Unix Linux (3.2.0-4-amd64-x86_64)
2013/05/05 21:07:58.756	               T38Modem	Options: -tttt -o /var/log/t38modem.log --no-h323 --sip-listen 192.168.0.21 --sip-register sipusername at 192.168.0.222,topsecret --sip-old-asn --ptty +/dev/ttyT38-0 --route modem:.*=sip:<dn>@192.168.0.222 --route sip:.*=modem:<dn>
2013/05/05 21:07:58.756	               T38Modem	Detecting V4L2 devices
2013/05/05 21:07:58.756	               T38Modem	Unable to detect v4l2 directory
2013/05/05 21:07:58.761	               T38Modem	PWLib	File handle high water mark set: 10 Thread unblock pipe
2013/05/05 21:07:58.761	               T38Modem	PTLib	Thread high water mark set: 3
2013/05/05 21:07:58.761	               T38Modem	OpalMan	Created manager.
2013/05/05 21:07:58.762	               T38Modem	OpalMan	Attached endpoint with prefix modem
2013/05/05 21:07:58.762	               T38Modem	OpalEP	Created endpoint: modem
2013/05/05 21:07:58.762	               T38Modem	ModemEndPoint::ModemEndPoint
2013/05/05 21:07:58.762	               T38Modem	PWLib	File handle high water mark set: 14 Thread unblock pipe
2013/05/05 21:07:58.762	               T38Modem	PseudoModemList::Append ttyT38-0 (0) OK
2013/05/05 21:07:58.762	               T38Modem	PTLib	Thread high water mark set: 4
2013/05/05 21:07:58.762	               T38Modem	OpalMan	Attached endpoint with prefix sip
2013/05/05 21:07:58.762	               T38Modem	OpalEP	Created endpoint: sip
2013/05/05 21:07:58.762	ttyT38-0(b...0x6fa12700	RenameCurrentThread old ThreadName=PseudoModemPty:0x6fa12700
2013/05/05 21:07:58.762	               T38Modem	PWLib	File handle high water mark set: 15 PUDPSocket
2013/05/05 21:07:58.762	ttyT38-0(b...0x6fa12700	Started for /dev/ttyT38-0 (accepts all)
2013/05/05 21:07:58.762	ttyT38-0(b...0x6fa12700	ModemEndPoint::OnMyCallback command=addmodem extra=10
2013/05/05 21:07:58.762	               T38Modem	IfaceMon	Initial interface list:
127.0.0.1 <00-00-00-00-00-00> (lo)
192.168.0.21 <6C-62-6D-B6-9C-09> (eth0)
10.8.0.1 <00-00-00-00-00-00> (tun0)
fe80::ffff:ffff:ffff <00-00-00-00-00-00> (teredo)
2001:0:53aa:64c:cde:673e:adac:d617 <00-00-00-00-00-00> (teredo)
fe80::6e62:6dff:feb6:9c09 <6C-62-6D-B6-9C-09> (eth0)
::1 <00-00-00-00-00-00> (lo)

2013/05/05 21:07:58.762	ttyT38-0(b...0x6fa12700	PseudoModemQ::Enqueue ttyT38-0
2013/05/05 21:07:58.762	               T38Modem	PTLIB	Opened NetLink socket
2013/05/05 21:07:58.762	               T38Modem	PWLib	File handle high water mark set: 19 Thread unblock pipe
2013/05/05 21:07:58.763	               T38Modem	PTLib	Thread high water mark set: 5
2013/05/05 21:07:58.763	ttyT38-0(b...0x6fa12700	ModemEndPoint::OnMyCallback request={
command=addmodem
response=confirm
modemtoken=ttyT38-0
}
2013/05/05 21:07:58.763	               T38Modem	PWLib	File handle high water mark set: 21 Thread unblock pipe
2013/05/05 21:07:58.763	               T38Modem	PTLib	Thread high water mark set: 6
2013/05/05 21:07:58.763	ttyT38-0(b...0x6fa12700	PseudoModemPty::OpenPty removed link /dev/ttyT38-0 -> /dev/pts/9
2013/05/05 21:07:58.763	ttyT38-0(b...0x6fa12700	PseudoModemPty::OpenPty added link /dev/ttyT38-0 -> /dev/pts/9
2013/05/05 21:07:58.763	               T38Modem	OpalMan	Attached endpoint with prefix sips
2013/05/05 21:07:58.763	               T38Modem	SIP	Created endpoint.
2013/05/05 21:07:58.763	ttyT38-0(b...0x6fa12700	PWLib	File handle high water mark set: 24 Thread unblock pipe
2013/05/05 21:07:58.763	ttyT38-0(b...0x6fa12700	PWLib	File handle high water mark set: 26 Thread unblock pipe
2013/05/05 21:07:58.763	ttyT38-0(b...0x6fa12700	PWLib	File handle high water mark set: 28 Thread unblock pipe
2013/05/05 21:07:58.763	               T38Modem	PWLib	File handle high water mark set: 29 PUDPSocket
2013/05/05 21:07:58.763	               T38Modem	MonSock	Created monitored socket for interfaces 192.168.0.21
2013/05/05 21:07:58.763	Network In...0x60189700	IfaceMon	Started interface monitor thread.
2013/05/05 21:07:58.764	               T38Modem	PWLib	File handle high water mark set: 30 PUDPSocket
2013/05/05 21:07:58.764	ttyT38-0(b...0x6fa12700	PTLib	Thread high water mark set: 7
2013/05/05 21:07:58.764	               T38Modem	MonSock	Created bundled UDP socket 192.168.0.21:5060
2013/05/05 21:07:58.764	               T38Modem	PWLib	File handle high water mark set: 32 Thread unblock pipe
2013/05/05 21:07:58.764	ttyT38-0(b...0x6fa12700	PTLib	Thread high water mark set: 8
2013/05/05 21:07:58.764	               T38Modem	PTLib	Thread high water mark set: 9
2013/05/05 21:07:58.764	ttyT38-0(e...0x60107700	RenameCurrentThread old ThreadName=ModemEngine:0x60107700
2013/05/05 21:07:58.764	ttyT38-0(e...0x60107700	<-> Started
2013/05/05 21:07:58.764	ttyT38-0(b...0x6fa12700	PTLib	Thread high water mark set: 10
2013/05/05 21:07:58.764	               T38Modem	PWLib	File handle high water mark set: 33 PTCPSocket
2013/05/05 21:07:58.764	Opal Liste...0x60085700	Listen	Started listening thread on udp$192.168.0.21:5060
2013/05/05 21:07:58.764	               T38Modem	PWLib	File handle high water mark set: 35 Thread unblock pipe
2013/05/05 21:07:58.765	               T38Modem	PTLib	Thread high water mark set: 11
2013/05/05 21:07:58.765	               T38Modem	OpalEP	Could not create listener: tcps$:5061192.168.0.21
2013/05/05 21:07:58.765	ttyT38-0(o...0x60044700	RenameCurrentThread old ThreadName=OutPty:0x60044700
2013/05/05 21:07:58.765	Opal Liste...0x55f4a700	Listen	Started listening thread on tcp$192.168.0.21:5060
2013/05/05 21:07:58.765	               T38Modem	SIP	Start REGISTER
          aor=620 at 192.168.0.222
       remote=
        local=
      contact=
       authID=
        realm=
       expire=300
      restore=30
     minRetry=default
     maxRetry=default
compatibility=FullyCompliant
2013/05/05 21:07:58.765	ttyT38-0(i...0x600c6700	RenameCurrentThread old ThreadName=InPty:0x600c6700
2013/05/05 21:07:58.765	ttyT38-0(o...0x60044700	<-- Started
2013/05/05 21:07:58.765	ttyT38-0(i...0x600c6700	--> Started
2013/05/05 21:07:58.765	Opal Liste...0x55f4a700	Listen	Waiting on socket accept on tcp$192.168.0.21:5060
2013/05/05 21:07:58.766	               T38Modem	PWLib	File handle high water mark set: 36 PUDPSocket
2013/05/05 21:07:58.766	               T38Modem	SIP	Constructed REGISTER handler for sip:620 at 192.168.0.222
2013/05/05 21:07:58.767	               T38Modem	SIP	Executing state change to Subscribing for REGISTER handler, target=sip:620 at 192.168.0.222, id=72e6c5c4-24b4-e211-9edb-6c626db69c09 at ceramic
2013/05/05 21:07:58.767	               T38Modem	SIP	Changing REGISTER handler from Unavailable to Subscribing, target=sip:620 at 192.168.0.222, id=72e6c5c4-24b4-e211-9edb-6c626db69c09 at ceramic
2013/05/05 21:07:58.768	               T38Modem	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:07:58.768	               T38Modem	SIP	Created transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:07:58.768	               T38Modem	OpalUDP	Started connect to 192.168.0.222:5060
2013/05/05 21:07:58.768	               T38Modem	OpalUDP	Writing to interface 0 - "192.168.0.21%eth0"
2013/05/05 21:07:58.770	               T38Modem	OpalMan	Listener interfaces: associated transport=udp$192.168.0.21:5060
    udp$192.168.0.21:5060,tcp$192.168.0.21:5060
2013/05/05 21:07:58.771	               T38Modem	SIP	Transaction created.
2013/05/05 21:07:58.774	               T38Modem	SIP	Transaction remote address is udp$192.168.0.222:5060
2013/05/05 21:07:58.774	               T38Modem	SIP	Sending PDU (595 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
REGISTER sip:192.168.0.222 SIP/2.0
CSeq: 1 REGISTER
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bKb4e4c6c4-24b4-e211-9edb-6c626db69c09;rport
User-Agent: T38Modem/2.0.0
From: <sip:620 at 192.168.0.222>;tag=f20bc6c4-24b4-e211-9edb-6c626db69c09
Call-ID: 72e6c5c4-24b4-e211-9edb-6c626db69c09 at ceramic
Organization: Vyacheslav Frolov
To: <sip:620 at 192.168.0.222>
Contact: <sip:620 at 192.168.0.21:5060>;q=1, <sip:620 at 192.168.0.21:5060;transport=tcp>;q=0.500
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING,PRACK
Expires: 300
Content-Length: 0
Max-Forwards: 70


2013/05/05 21:07:58.775	               T38Modem	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:07:58.775	               T38Modem	SIP	Transaction timers set: retry=0.500, completion=16.000
2013/05/05 21:07:58.775	               T38Modem	OpalMan	Added route "modem:.*=sip:<dn>@192.168.0.222"
2013/05/05 21:07:58.775	               T38Modem	OpalMan	Added route "sip:.*=modem:<dn>"
2013/05/05 21:07:58.775	               T38Modem	PTLib	Destroyed PXConfig 0xffabf0
2013/05/05 21:07:58.778	Opal Liste...0x60085700	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:07:58.779	Opal Liste...0x60085700	SIP	Waiting for PDU on udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:07:58.779	Opal Liste...0x60085700	SIP	PDU received: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
SIP/2.0 401 Unauthorized
CSeq: 1 REGISTER
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bKb4e4c6c4-24b4-e211-9edb-6c626db69c09;rport=5060
User-Agent: AVM FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)
From: <sip:620 at 192.168.0.222>;tag=f20bc6c4-24b4-e211-9edb-6c626db69c09
Call-ID: 72e6c5c4-24b4-e211-9edb-6c626db69c09 at ceramic
To: <sip:620 at 192.168.0.222>;tag=0092F42E6D62559B
Content-Length: 0
WWW-Authenticate: Digest realm="fritz.box", nonce="91F5F34845F27E77"


2013/05/05 21:07:58.780	Opal Liste...0x60085700	SIP	Queueing PDU "1 REGISTER <401>", transaction=z9hG4bKb4e4c6c4-24b4-e211-9edb-6c626db69c09, token=72e6c5c4-24b4-e211-9edb-6c626db69c09 at ceramic
2013/05/05 21:07:58.780	Opal Liste...0x60085700	PWLib	File handle high water mark set: 37 Thread unblock pipe
2013/05/05 21:07:58.780	Opal Liste...0x60085700	PTLib	Thread high water mark set: 12
2013/05/05 21:07:58.780	Opal Liste...0x60085700	Opal	Transport clean up on termination
2013/05/05 21:07:58.780	Opal Liste...0x60085700	Opal	Transport Close
2013/05/05 21:07:58.780	Opal Liste...0x60085700	Opal	Deleted transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:07:58.781	        Pool:0x55f09700	SIP	Handling PDU "1 REGISTER <401>" for transaction=z9hG4bKb4e4c6c4-24b4-e211-9edb-6c626db69c09
2013/05/05 21:07:58.781	        Pool:0x55f09700	SIP	REGISTER transaction id=z9hG4bKb4e4c6c4-24b4-e211-9edb-6c626db69c09 completing.
2013/05/05 21:07:58.781	        Pool:0x55f09700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:07:58.781	        Pool:0x55f09700	SIP	Received Authentication Required response
2013/05/05 21:07:58.781	        Pool:0x55f09700	SIP	Updating authentication credentials.
2013/05/05 21:07:58.781	        Pool:0x55f09700	SIP	Auth realm set to fritz.box
2013/05/05 21:07:58.783	        Pool:0x55f09700	OpalMan	Listener interfaces: associated transport=udp$192.168.0.21:5060
    udp$192.168.0.21:5060,tcp$192.168.0.21:5060
2013/05/05 21:07:58.785	        Pool:0x55f09700	SIP	Transaction created.
2013/05/05 21:07:58.786	        Pool:0x55f09700	HTTP	Adding authentication information
2013/05/05 21:07:58.787	        Pool:0x55f09700	SIP	Transaction remote address is udp$192.168.0.222:5060
2013/05/05 21:07:58.787	        Pool:0x55f09700	SIP	Sending PDU (763 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
REGISTER sip:192.168.0.222 SIP/2.0
CSeq: 2 REGISTER
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK32ecc8c4-24b4-e211-9edb-6c626db69c09;rport
User-Agent: T38Modem/2.0.0
Authorization: Digest username="620", realm="fritz.box", nonce="91F5F34845F27E77", uri="sip:192.168.0.222", algorithm=MD5, response="ae404500825431e8f5d0d5e6a1439a59"
From: <sip:620 at 192.168.0.222>;tag=f20bc6c4-24b4-e211-9edb-6c626db69c09
Call-ID: 72e6c5c4-24b4-e211-9edb-6c626db69c09 at ceramic
Organization: Vyacheslav Frolov
To: <sip:620 at 192.168.0.222>
Contact: <sip:620 at 192.168.0.21:5060>;q=1, <sip:620 at 192.168.0.21:5060;transport=tcp>;q=0.500
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING,PRACK
Expires: 300
Content-Length: 0
Max-Forwards: 70


2013/05/05 21:07:58.788	        Pool:0x55f09700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:07:58.788	        Pool:0x55f09700	SIP	Transaction timers set: retry=0.500, completion=16.000
2013/05/05 21:07:58.788	        Pool:0x55f09700	SIP	REGISTER transaction id=z9hG4bKb4e4c6c4-24b4-e211-9edb-6c626db69c09 completed.
2013/05/05 21:07:58.788	        Pool:0x55f09700	SIP	Handled PDU "1 REGISTER <401>"
2013/05/05 21:07:58.794	Opal Liste...0x60085700	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:07:58.794	Opal Liste...0x60085700	SIP	Waiting for PDU on udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:07:58.795	Opal Liste...0x60085700	SIP	PDU received: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
SIP/2.0 200 OK
CSeq: 2 REGISTER
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK32ecc8c4-24b4-e211-9edb-6c626db69c09;rport=5060
User-Agent: AVM FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)
From: <sip:620 at 192.168.0.222>;tag=f20bc6c4-24b4-e211-9edb-6c626db69c09
Call-ID: 72e6c5c4-24b4-e211-9edb-6c626db69c09 at ceramic
Supported: 100rel,replaces,timer
To: <sip:620 at 192.168.0.222>;tag=7888ACD42C67A55E
Contact: <sip:620 at 192.168.0.21:5060>;q=1;expires=300
Contact: <sip:620 at 10.8.0.1:5060>;q=0.934;expires=261
Contact: <sip:620@[fe80::ffff:ffff:ffff]:5060>;q=0.868;expires=261
Contact: <sip:620@[2001:0:53aa:64c:cde:673e:adac:d617]:5060>;q=0.802;expires=261
Contact: <sip:620@[fe80::6e62:6dff:feb6:9c09]:5060>;q=0.736;expires=261
Accept: application/sdp, multipart/mixed
Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE,PUBLISH
Allow-Events: telephone-event,refer,reg
Content-Length: 0
Accept-Encoding: identity


2013/05/05 21:07:58.795	Opal Liste...0x60085700	SIP	Queueing PDU "2 REGISTER <200>", transaction=z9hG4bK32ecc8c4-24b4-e211-9edb-6c626db69c09, token=72e6c5c4-24b4-e211-9edb-6c626db69c09 at ceramic
2013/05/05 21:07:58.795	Opal Liste...0x60085700	Opal	Transport clean up on termination
2013/05/05 21:07:58.795	Opal Liste...0x60085700	Opal	Transport Close
2013/05/05 21:07:58.795	Opal Liste...0x60085700	Opal	Deleted transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:07:58.796	        Pool:0x55f09700	SIP	Handling PDU "2 REGISTER <200>" for transaction=z9hG4bK32ecc8c4-24b4-e211-9edb-6c626db69c09
2013/05/05 21:07:58.796	        Pool:0x55f09700	SIP	REGISTER transaction id=z9hG4bK32ecc8c4-24b4-e211-9edb-6c626db69c09 completing.
2013/05/05 21:07:58.796	        Pool:0x55f09700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:07:58.796	        Pool:0x55f09700	SIP	Product Info: name="AVM", version="", vendor="", comments="FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)"
2013/05/05 21:07:58.798	        Pool:0x55f09700	SIP	Expiry time for REGISTER set to 300 seconds.
2013/05/05 21:07:58.798	        Pool:0x55f09700	SIP	Changing REGISTER handler from Subscribing to Subscribed, target=sip:620 at 192.168.0.222, id=72e6c5c4-24b4-e211-9edb-6c626db69c09 at ceramic
2013/05/05 21:07:58.798	        Pool:0x55f09700	SIP	REGISTER transaction id=z9hG4bK32ecc8c4-24b4-e211-9edb-6c626db69c09 completed.
2013/05/05 21:07:58.798	        Pool:0x55f09700	SIP	Handled PDU "2 REGISTER <200>"
2013/05/05 21:08:03.789	 Housekeeper:0x60148700	SIP	Set state Terminated_Success for REGISTER transaction id=z9hG4bKb4e4c6c4-24b4-e211-9edb-6c626db69c09
2013/05/05 21:08:03.789	 Housekeeper:0x60148700	SIP	Completed state for transaction id=z9hG4bKb4e4c6c4-24b4-e211-9edb-6c626db69c09
2013/05/05 21:08:03.814	 Housekeeper:0x60148700	SIP	Set state Terminated_Success for REGISTER transaction id=z9hG4bK32ecc8c4-24b4-e211-9edb-6c626db69c09
2013/05/05 21:08:03.814	 Housekeeper:0x60148700	SIP	Completed state for transaction id=z9hG4bK32ecc8c4-24b4-e211-9edb-6c626db69c09
2013/05/05 21:08:04.763	Opal Garbage:0x6fa53700	SIP	Transaction id=z9hG4bK32ecc8c4-24b4-e211-9edb-6c626db69c09 destroyed.
2013/05/05 21:08:04.763	Opal Garbage:0x6fa53700	SIP	Transaction id=z9hG4bKb4e4c6c4-24b4-e211-9edb-6c626db69c09 destroyed.
2013/05/05 21:08:58.815	Network In...0x60189700	PWLib	File handle high water mark set: 38 PUDPSocket
2013/05/05 21:09:11.208	ttyT38-0(e...0x60107700	--> ATZ
2013/05/05 21:09:11.208	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:14.305	ttyT38-0(e...0x60107700	--> ATS0=0
2013/05/05 21:09:14.306	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:14.405	ttyT38-0(e...0x60107700	--> ATE0
2013/05/05 21:09:14.405	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:14.505	ttyT38-0(e...0x60107700	--> ATV1
2013/05/05 21:09:14.505	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:14.605	ttyT38-0(e...0x60107700	--> ATQ0
2013/05/05 21:09:14.605	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:14.705	ttyT38-0(e...0x60107700	--> ATS8=2
2013/05/05 21:09:14.705	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:14.805	ttyT38-0(e...0x60107700	--> ATS7=60
2013/05/05 21:09:14.805	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:14.905	ttyT38-0(e...0x60107700	--> AT+FCLASS=?
2013/05/05 21:09:14.905	ttyT38-0(e...0x60107700	<--  {
  0d 0a 31 2c 38 0d 0a 4f  4b 0d 0a                  ..1,8..OK.. }
2013/05/05 21:09:15.005	ttyT38-0(e...0x60107700	--> AT+FCLASS=1
2013/05/05 21:09:15.005	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:15.105	ttyT38-0(e...0x60107700	--> ATI3
2013/05/05 21:09:15.105	ttyT38-0(e...0x60107700	<--  {
  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/05/05 21:09:15.205	ttyT38-0(e...0x60107700	--> ATI0
2013/05/05 21:09:15.205	ttyT38-0(e...0x60107700	<--  {
  0d 0a 54 33 38 46 41 58  0d 0a 4f 4b 0d 0a         ..T38FAX..OK.. }
2013/05/05 21:09:15.305	ttyT38-0(e...0x60107700	--> AT+FREV?
2013/05/05 21:09:15.305	ttyT38-0(e...0x60107700	<--  {
  0d 0a 32 2e 30 2e 30 0d  0a 4f 4b 0d 0a            ..2.0.0..OK.. }
2013/05/05 21:09:15.405	ttyT38-0(e...0x60107700	--> AT+FTM=?
2013/05/05 21:09:15.405	ttyT38-0(e...0x60107700	<--  {
  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/05/05 21:09:15.505	ttyT38-0(e...0x60107700	--> AT+FRM=?
2013/05/05 21:09:15.505	ttyT38-0(e...0x60107700	<--  {
  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/05/05 21:09:15.605	ttyT38-0(e...0x60107700	--> ATM0
2013/05/05 21:09:15.605	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:15.706	ttyT38-0(i...0x600c6700	--> read ERROR -1 Input/output error
2013/05/05 21:09:15.706	ttyT38-0(i...0x600c6700	--> Stopped
2013/05/05 21:09:15.706	ttyT38-0(i...0x600c6700	PTLib	Thread ended: name="ttyT38-0(i):1611425536:0x600c6700", real=76.942, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
2013/05/05 21:09:15.716	ttyT38-0(o...0x60044700	<-- Stopped
2013/05/05 21:09:15.717	ttyT38-0(o...0x60044700	PWLib	File handle low water mark set: 23 PTextFile
2013/05/05 21:09:15.717	ttyT38-0(o...0x60044700	PTLib	Thread ended: name="ttyT38-0(o):1610893056:0x60044700", real=76.952, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
2013/05/05 21:09:15.727	ttyT38-0(e...0x60107700	<-> Stopped
2013/05/05 21:09:15.727	ttyT38-0(e...0x60107700	PTLib	Thread ended: name="ttyT38-0(e):1611691776:0x60107700", real=76.963, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
2013/05/05 21:09:15.737	ttyT38-0(o...0x600c6700	RenameCurrentThread old ThreadName=OutPty:0x600c6700
2013/05/05 21:09:15.737	ttyT38-0(o...0x600c6700	<-- Started
2013/05/05 21:09:15.737	ttyT38-0(e...0x60107700	RenameCurrentThread old ThreadName=ModemEngine:0x60107700
2013/05/05 21:09:15.738	ttyT38-0(e...0x60107700	<-> Started
2013/05/05 21:09:15.737	ttyT38-0(i...0x60044700	RenameCurrentThread old ThreadName=InPty:0x60044700
2013/05/05 21:09:15.738	ttyT38-0(i...0x60044700	--> Started
2013/05/05 21:09:19.393	ttyT38-0(i...0x60044700	--> read ERROR -1 Input/output error
2013/05/05 21:09:19.393	ttyT38-0(i...0x60044700	--> Stopped
2013/05/05 21:09:19.394	ttyT38-0(i...0x60044700	PTLib	Thread ended: name="ttyT38-0(i):1610893056:0x60044700", real=3.656, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
2013/05/05 21:09:19.404	ttyT38-0(o...0x600c6700	<-- Stopped
2013/05/05 21:09:19.404	ttyT38-0(o...0x600c6700	PTLib	Thread ended: name="ttyT38-0(o):1611425536:0x600c6700", real=3.666, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
2013/05/05 21:09:19.414	ttyT38-0(e...0x60107700	<-> Stopped
2013/05/05 21:09:19.414	ttyT38-0(e...0x60107700	PTLib	Thread ended: name="ttyT38-0(e):1611691776:0x60107700", real=3.677, kernel=0.000 (0%), user=0.000 (0%), both=0.000 (0%)
2013/05/05 21:09:19.424	ttyT38-0(o...0x60044700	RenameCurrentThread old ThreadName=OutPty:0x60044700
2013/05/05 21:09:19.425	ttyT38-0(o...0x60044700	<-- Started
2013/05/05 21:09:19.424	ttyT38-0(e...0x60107700	RenameCurrentThread old ThreadName=ModemEngine:0x60107700
2013/05/05 21:09:19.425	ttyT38-0(e...0x60107700	<-> Started
2013/05/05 21:09:19.425	ttyT38-0(i...0x600c6700	RenameCurrentThread old ThreadName=InPty:0x600c6700
2013/05/05 21:09:19.425	ttyT38-0(i...0x600c6700	--> Started
2013/05/05 21:09:20.404	ttyT38-0(e...0x60107700	--> ATZ
2013/05/05 21:09:20.404	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:23.502	ttyT38-0(e...0x60107700	--> ATS0=0
2013/05/05 21:09:23.502	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:23.601	ttyT38-0(e...0x60107700	--> ATE0
2013/05/05 21:09:23.601	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:23.701	ttyT38-0(e...0x60107700	--> ATV1
2013/05/05 21:09:23.701	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:23.801	ttyT38-0(e...0x60107700	--> ATQ0
2013/05/05 21:09:23.801	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:23.901	ttyT38-0(e...0x60107700	--> ATS8=2
2013/05/05 21:09:23.901	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:24.001	ttyT38-0(e...0x60107700	--> ATS7=60
2013/05/05 21:09:24.001	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:24.101	ttyT38-0(e...0x60107700	--> AT+FCLASS=?
2013/05/05 21:09:24.101	ttyT38-0(e...0x60107700	<--  {
  0d 0a 31 2c 38 0d 0a 4f  4b 0d 0a                  ..1,8..OK.. }
2013/05/05 21:09:24.201	ttyT38-0(e...0x60107700	--> AT+FCLASS=1
2013/05/05 21:09:24.201	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:24.301	ttyT38-0(e...0x60107700	--> ATI3
2013/05/05 21:09:24.301	ttyT38-0(e...0x60107700	<--  {
  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/05/05 21:09:24.405	ttyT38-0(e...0x60107700	--> ATI0
2013/05/05 21:09:24.405	ttyT38-0(e...0x60107700	<--  {
  0d 0a 54 33 38 46 41 58  0d 0a 4f 4b 0d 0a         ..T38FAX..OK.. }
2013/05/05 21:09:24.513	ttyT38-0(e...0x60107700	--> AT+FREV?
2013/05/05 21:09:24.513	ttyT38-0(e...0x60107700	<--  {
  0d 0a 32 2e 30 2e 30 0d  0a 4f 4b 0d 0a            ..2.0.0..OK.. }
2013/05/05 21:09:24.613	ttyT38-0(e...0x60107700	--> AT+FTM=?
2013/05/05 21:09:24.613	ttyT38-0(e...0x60107700	<--  {
  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/05/05 21:09:24.713	ttyT38-0(e...0x60107700	--> AT+FRM=?
2013/05/05 21:09:24.713	ttyT38-0(e...0x60107700	<--  {
  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/05/05 21:09:24.813	ttyT38-0(e...0x60107700	--> ATM0
2013/05/05 21:09:24.813	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:24.914	ttyT38-0(e...0x60107700	--> AT+FCLASS=1
2013/05/05 21:09:24.915	ttyT38-0(e...0x60107700	<--  {
  0d 0a 4f 4b 0d 0a                                  ..OK.. }
2013/05/05 21:09:24.915	ttyT38-0(e...0x60107700	--> ATDT189659
2013/05/05 21:09:24.915	ttyT38-0(e...0x60107700	ModemEngineBody::OffHook: off-hook cstCleared stCommand
2013/05/05 21:09:24.915	ttyT38-0(e...0x60107700	Dial string: 189659 at LV - OK
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	ModemEngineBody::SetState: off-hook cstCleared stDial
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	ModemEngineBody::SetCallState: off-hook cstDialing stDial
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	ModemEngineBody::SetState: off-hook cstDialing stConnectWait
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	ModemEndPoint::OnMyCallback command=dial extra=5
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	PseudoModemQ::Dequeue ttyT38-0
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	MyManager::OnMyCallback SetUpCall(modem:, 189659 at +/dev/ttyT38-0)
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	OpalMan	Set up call from modem: to 189659 at +/dev/ttyT38-0
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	Call	Created Call[C3ff77e3a1]
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	OpalMan	Set up connection to "modem:"
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	ModemEndPoint::MakeConnection modem:
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	OpalCon	Created connection Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:24.916	ttyT38-0(e...0x60107700	ModemConnection::ModemConnection Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:24.917	ttyT38-0(e...0x60107700	ModemConnection::SetUpConnection Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:24.917	ttyT38-0(e...0x60107700	OpalCon	SetPhase from UninitialisedPhase to SetUpPhase for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:24.917	ttyT38-0(e...0x60107700	OpalMan	OnIncoming connection Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:24.917	ttyT38-0(e...0x60107700	Call	GetOtherPartyConnection Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:24.917	ttyT38-0(e...0x60107700	OpalMan	Searching for route "modem:T38Modem%20v2.0.0	189659 at +/dev/ttyT38-0"
2013/05/05 21:09:24.917	ttyT38-0(e...0x60107700	OpalMan	Matched regex "^modem:.*	.*$" ("modem:.*")
2013/05/05 21:09:24.917	ttyT38-0(e...0x60107700	OpalMan	Set up connection to "sip:189659 at 192.168.0.222"
2013/05/05 21:09:24.918	ttyT38-0(e...0x60107700	MySIPEndPoint::CreateConnection for Call[C3ff77e3a1]
2013/05/05 21:09:24.918	ttyT38-0(e...0x60107700	OpalCon	Created connection Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:24.918	ttyT38-0(e...0x60107700	RFC2833	Handler created
2013/05/05 21:09:24.918	ttyT38-0(e...0x60107700	RFC2833	Handler created
2013/05/05 21:09:24.919	ttyT38-0(e...0x60107700	SIP	Created connection.
2013/05/05 21:09:24.919	ttyT38-0(e...0x60107700	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/05/05 21:09:24.920	ttyT38-0(e...0x60107700	MySIPConnection::OnApplyStringOptions Enabled formats (in preference order):
G.711-uLaw-64k
G.711-ALaw-64k
T.38
UserInput/RFC2833

2013/05/05 21:09:24.920	ttyT38-0(e...0x60107700	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/05/05 21:09:24.920	ttyT38-0(e...0x60107700	MySIPConnection::OnApplyStringOptions Enabled formats (in preference order):
G.711-uLaw-64k
G.711-ALaw-64k
T.38
UserInput/RFC2833

2013/05/05 21:09:24.920	ttyT38-0(e...0x60107700	Call[C3ff77e3a1] from modem:T38Modem%20v2.0.0 to 189659 at +/dev/ttyT38-0, route to sip:189659 at 192.168.0.222
2013/05/05 21:09:24.921	ttyT38-0(e...0x60107700	Outgoing call routed to sip:189659 at 192.168.0.222 for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:24.921	ttyT38-0(e...0x60107700	Call	OnSetUp Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:24.921	ttyT38-0(e...0x60107700	MySIPConnection::SetUpConnection Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] name=T38Modem v2.0.0
2013/05/05 21:09:24.921	ttyT38-0(e...0x60107700	SIP	SetUpConnection: sip:189659 at 192.168.0.222
2013/05/05 21:09:24.921	ttyT38-0(e...0x60107700	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/05/05 21:09:24.921	ttyT38-0(e...0x60107700	MySIPConnection::OnApplyStringOptions Enabled formats (in preference order):
G.711-uLaw-64k
G.711-ALaw-64k
T.38
UserInput/RFC2833

2013/05/05 21:09:24.921	ttyT38-0(e...0x60107700	SIP	Connecting to sip:189659 at 192.168.0.222 via sip:189659 at 192.168.0.222
2013/05/05 21:09:24.921	ttyT38-0(e...0x60107700	SIP	Setting new transport for destination "sip:189659 at 192.168.0.222"
2013/05/05 21:09:24.921	ttyT38-0(e...0x60107700	SIP	Found registrar on domain 192.168.0.222, using interface 192.168.0.21%eth0
2013/05/05 21:09:24.922	ttyT38-0(e...0x60107700	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:09:24.922	ttyT38-0(e...0x60107700	SIP	Created transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:24.922	ttyT38-0(e...0x60107700	OpalUDP	Started connect to 192.168.0.222:5060
2013/05/05 21:09:24.922	ttyT38-0(e...0x60107700	ModemConnection::GetMediaFormats Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:24.922	ttyT38-0(e...0x60107700	ModemEndPoint::GetMediaFormats
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	Call	GetMediaFormats for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
    GSM-AMR,GSM-06.10,G.726-40k,G.726-32k,G.726-24k,G.726-16k,G.711-uLaw-64k,G.711-ALaw-64k,LPC-10,MS-GSM,MS-IMA-ADPCM,SILK-8,SpeexIETFNarrow-11k,SpeexIETFNarrow-15k,SpeexIETFNarrow-18.2k,SpeexIETFNarrow-24.6k,SpeexIETFNarrow-5.95k,SpeexIETFNarrow-8k,SpeexNB,SpeexWNarrow-8k,T.38,UserInput/RFC2833
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	SIP	Local media formats set:
    GSM-AMR,GSM-06.10,G.726-40k,G.726-32k,G.726-24k,G.726-16k,G.711-uLaw-64k,G.711-ALaw-64k,LPC-10,MS-GSM,MS-IMA-ADPCM,SILK-8,SpeexIETFNarrow-11k,SpeexIETFNarrow-15k,SpeexIETFNarrow-18.2k,SpeexIETFNarrow-24.6k,SpeexIETFNarrow-5.95k,SpeexIETFNarrow-8k,SpeexNB,SpeexWNarrow-8k,T.38,UserInput/RFC2833
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats:
GSM-AMR
GSM-06.10
G.726-40k
G.726-32k
G.726-24k
G.726-16k
G.711-uLaw-64k
G.711-ALaw-64k
LPC-10
MS-GSM
MS-IMA-ADPCM
SILK-8
SpeexIETFNarrow-11k
SpeexIETFNarrow-15k
SpeexIETFNarrow-18.2k
SpeexIETFNarrow-24.6k
SpeexIETFNarrow-5.95k
SpeexIETFNarrow-8k
SpeexNB
SpeexWNarrow-8k
T.38
UserInput/RFC2833

2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove GSM-AMR
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove GSM-06.10
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove G.726-40k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove G.726-32k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove G.726-24k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove G.726-16k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove LPC-10
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove MS-GSM
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove MS-IMA-ADPCM
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove SILK-8
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-11k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-15k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-18.2k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-24.6k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-5.95k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove SpeexIETFNarrow-8k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove SpeexNB
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats Remove SpeexWNarrow-8k
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	MySIPConnection::GetLocalMediaFormats:
G.711-uLaw-64k
G.711-ALaw-64k
T.38
UserInput/RFC2833

2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	SIP	Remote media formats set:
    G.711-uLaw-64k,G.711-ALaw-64k,T.38,UserInput/RFC2833
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	SIP	Getting local URI from registeration: sip:620 at 192.168.0.222
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	SIP	Updating dialog tag from "" to "7aa61ff8-24b4-e211-9edb-6c626db69c09"
2013/05/05 21:09:24.935	ttyT38-0(e...0x60107700	SIP	Remote dialog address from target: sip:189659 at 192.168.0.222
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	SIP	INVITE transaction id=z9hG4bK946122f8-24b4-e211-9edb-6c626db69c09 created.
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	SIP	Creating INVITE request
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	SIP	Offering all configured media:
    GSM-AMR,GSM-06.10,G.726-40k,G.726-32k,G.726-24k,G.726-16k,G.711-uLaw-64k,G.711-ALaw-64k,LPC-10,MS-GSM,MS-IMA-ADPCM,SILK-8,SpeexIETFNarrow-11k,SpeexIETFNarrow-15k,SpeexIETFNarrow-18.2k,SpeexIETFNarrow-24.6k,SpeexIETFNarrow-5.95k,SpeexIETFNarrow-8k,SpeexNB,SpeexWNarrow-8k,T.38,UserInput/RFC2833
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	SIP	Offering media type audio in SDP
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	RTP	Cannot find media session 1
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	RTP	Cannot find RTP session 1
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	PTLib	Created PXConfig 0x7fcd50018ad0
2013/05/05 21:09:24.936	ttyT38-0(e...0x60107700	VoIP Metrics	RTCP_XR_Metrics created.
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	RTP_UDP	Session 1, created with NAT flag set to 0
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	PWLib	File handle high water mark set: 39 PUDPSocket
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	PWLib	File handle low water mark set: 38 PUDPSocket
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	RTP_UDP	Session 1 created: 192.168.0.21:5000-5001 ssrc=453989732
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	RTP	Creating new session RTP_UDP
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	RTPEp	Session 1, remembering local RTP port 5000 on connection Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	RTP	Found existing media session 1
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	SDP	SDP not including MS-GSM as it is not a SIP transportable format
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	SDP	SDP not including MS-IMA-ADPCM as it is not a SIP transportable format
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	SDP	SDP not including SpeexIETFNarrow-11k as it is not a SIP transportable format
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	SDP	SDP not including SpeexIETFNarrow-15k as it is not a SIP transportable format
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	SDP	SDP not including SpeexIETFNarrow-18.2k as it is not a SIP transportable format
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	SDP	SDP not including SpeexIETFNarrow-24.6k as it is not a SIP transportable format
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	SDP	SDP not including SpeexIETFNarrow-5.95k as it is not a SIP transportable format
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	SDP	SDP not including SpeexIETFNarrow-8k as it is not a SIP transportable format
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	SDP	SDP not including SpeexWNarrow-8k as it is not a SIP transportable format
2013/05/05 21:09:24.937	ttyT38-0(e...0x60107700	MediaFormat	Merging UserInput/RFC2833 into UserInput/RFC2833
2013/05/05 21:09:24.938	ttyT38-0(e...0x60107700	RFC2833	Set tx pt=[pt=101], events="0-16,32,36" for UserInput/RFC2833
2013/05/05 21:09:24.938	ttyT38-0(e...0x60107700	RFC2833	Set rx pt=[pt=101], events="0-16,32,36" for UserInput/RFC2833
2013/05/05 21:09:24.938	ttyT38-0(e...0x60107700	RFC2833	Set tx pt=[pt=128], events="" for NamedSignalEvent
2013/05/05 21:09:24.938	ttyT38-0(e...0x60107700	SIP	No media formats of type video, not adding SDP
2013/05/05 21:09:24.938	ttyT38-0(e...0x60107700	SIP	Transaction remote address is udp$192.168.0.222:5060
2013/05/05 21:09:24.938	ttyT38-0(e...0x60107700	OpalPlugin	to_customised_options: SILK-8
2013/05/05 21:09:24.939	ttyT38-0(e...0x60107700	SIP	Sending PDU (1139 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
INVITE sip:189659 at 192.168.0.222 SIP/2.0
CSeq: 1 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK946122f8-24b4-e211-9edb-6c626db69c09;rport
User-Agent: T38Modem/2.0.0
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
Supported: 100rel,replaces
Organization: Vyacheslav Frolov
To: <sip:189659 at 192.168.0.222>
Contact: "root" <sip:620 at 192.168.0.21:5060>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING,PRACK
Content-Length: 532
Content-Type: application/sdp
Max-Forwards: 70

v=0
o=- 1367780964 1 IN IP4 192.168.0.21
s=T38Modem/2.0.0
c=IN IP4 192.168.0.21
t=0 0
m=audio 5000 RTP/AVP 120 3 102 103 104 105 0 8 126 121 118 101
a=sendrecv
a=rtpmap:120 AMR/8000/1
a=rtpmap:3 gsm/8000/1
a=rtpmap:102 G726-40/8000/1
a=rtpmap:103 G726-32/8000/1
a=rtpmap:104 G726-24/8000/1
a=rtpmap:105 G726-16/8000/1
a=rtpmap:0 PCMU/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:126 lpc10/8000/1
a=rtpmap:121 SILK/8000/1
a=rtpmap:118 Speex/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,32,36
a=maxptime:22

2013/05/05 21:09:24.939	ttyT38-0(e...0x60107700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:24.939	ttyT38-0(e...0x60107700	SIP	Transaction timers set: retry=0.500, completion=32.000
2013/05/05 21:09:24.939	ttyT38-0(e...0x60107700	OpalCon	SetPhase from UninitialisedPhase to SetUpPhase for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:24.939	ttyT38-0(e...0x60107700	OpalCon	OnSetUpConnectionCall[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:24.939	ttyT38-0(e...0x60107700	OpalEP	OnSetUpConnection Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:24.939	ttyT38-0(e...0x60107700	OpalMan	SetUpCall succeeded, call=Call[C3ff77e3a1]
2013/05/05 21:09:24.939	ttyT38-0(e...0x60107700	OpalCon	Applying string options:
Try-Next-Count=1
Original-Party-B=189659 at +/dev/ttyT38-0

2013/05/05 21:09:24.939	ttyT38-0(e...0x60107700	ModemEndPoint::OnMyCallback request={
calltoken=modem:/C3ff77e3a1/0
localpartyname=
command=dial
response=confirm
number=189659
modemtoken=ttyT38-0
}
2013/05/05 21:09:24.943	Opal Liste...0x60085700	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:09:24.944	Opal Liste...0x60085700	SIP	Waiting for PDU on udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:24.944	Opal Liste...0x60085700	SIP	PDU received: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
SIP/2.0 401 Unauthorized
CSeq: 1 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK946122f8-24b4-e211-9edb-6c626db69c09;rport=5060
User-Agent: AVM FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
To: <sip:189659 at 192.168.0.222>;tag=81DB78A3B1AE49EE
Content-Length: 0
WWW-Authenticate: Digest realm="fritz.box", nonce="66B56F740C61018A"


2013/05/05 21:09:24.945	Opal Liste...0x60085700	SIP	Queueing PDU "1 INVITE <401>", transaction=z9hG4bK946122f8-24b4-e211-9edb-6c626db69c09, token=7aa61ff8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:24.945	Opal Liste...0x60085700	PWLib	File handle high water mark set: 41 Thread unblock pipe
2013/05/05 21:09:24.945	Opal Liste...0x60085700	PTLib	Thread high water mark set: 13
2013/05/05 21:09:24.945	Opal Liste...0x60085700	Opal	Transport clean up on termination
2013/05/05 21:09:24.945	Opal Liste...0x60085700	Opal	Transport Close
2013/05/05 21:09:24.945	Opal Liste...0x60085700	Opal	Deleted transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:24.945	        Pool:0x55ec8700	SIP	Handling PDU "1 INVITE <401>" for transaction=z9hG4bK946122f8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:24.948	        Pool:0x55ec8700	SIP	Sending PDU (370 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
ACK sip:189659 at 192.168.0.222 SIP/2.0
CSeq: 1 ACK
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK946122f8-24b4-e211-9edb-6c626db69c09;rport
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
To: <sip:189659 at 192.168.0.222>;tag=81DB78A3B1AE49EE
Content-Length: 0
Max-Forwards: 70


2013/05/05 21:09:24.948	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:24.948	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK946122f8-24b4-e211-9edb-6c626db69c09 completing.
2013/05/05 21:09:24.948	        Pool:0x55ec8700	SIP	Received Authentication Required response for 1 INVITE sip:189659 at 192.168.0.222
2013/05/05 21:09:24.949	        Pool:0x55ec8700	SIP	Located existing credentials for ID "620" at realm "fritz.box"
2013/05/05 21:09:24.949	        Pool:0x55ec8700	SIP	Found auth info for realm "fritz.box", user "620"
2013/05/05 21:09:24.949	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:24.949	        Pool:0x55ec8700	SIP	Remote dialog address from target: sip:189659 at 192.168.0.222
2013/05/05 21:09:24.951	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09 created.
2013/05/05 21:09:24.951	        Pool:0x55ec8700	SIP	Creating INVITE request
2013/05/05 21:09:24.951	        Pool:0x55ec8700	SIP	Offering all configured media:
    GSM-AMR,GSM-06.10,G.726-40k,G.726-32k,G.726-24k,G.726-16k,G.711-uLaw-64k,G.711-ALaw-64k,LPC-10,MS-GSM,MS-IMA-ADPCM,SILK-8,SpeexIETFNarrow-11k,SpeexIETFNarrow-15k,SpeexIETFNarrow-18.2k,SpeexIETFNarrow-24.6k,SpeexIETFNarrow-5.95k,SpeexIETFNarrow-8k,SpeexNB,SpeexWNarrow-8k,T.38,UserInput/RFC2833
2013/05/05 21:09:24.952	        Pool:0x55ec8700	SIP	Offering media type audio in SDP
2013/05/05 21:09:24.952	        Pool:0x55ec8700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:24.952	        Pool:0x55ec8700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:24.952	        Pool:0x55ec8700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:24.952	        Pool:0x55ec8700	RTP	Found existing media session 1
2013/05/05 21:09:24.952	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:24.953	        Pool:0x55ec8700	SDP	SDP not including MS-GSM as it is not a SIP transportable format
2013/05/05 21:09:24.953	        Pool:0x55ec8700	SDP	SDP not including MS-IMA-ADPCM as it is not a SIP transportable format
2013/05/05 21:09:24.953	        Pool:0x55ec8700	SDP	SDP not including SpeexIETFNarrow-11k as it is not a SIP transportable format
2013/05/05 21:09:24.953	        Pool:0x55ec8700	SDP	SDP not including SpeexIETFNarrow-15k as it is not a SIP transportable format
2013/05/05 21:09:24.953	        Pool:0x55ec8700	SDP	SDP not including SpeexIETFNarrow-18.2k as it is not a SIP transportable format
2013/05/05 21:09:24.953	        Pool:0x55ec8700	SDP	SDP not including SpeexIETFNarrow-24.6k as it is not a SIP transportable format
2013/05/05 21:09:24.953	        Pool:0x55ec8700	SDP	SDP not including SpeexIETFNarrow-5.95k as it is not a SIP transportable format
2013/05/05 21:09:24.953	        Pool:0x55ec8700	SDP	SDP not including SpeexIETFNarrow-8k as it is not a SIP transportable format
2013/05/05 21:09:24.953	        Pool:0x55ec8700	SDP	SDP not including SpeexWNarrow-8k as it is not a SIP transportable format
2013/05/05 21:09:24.953	        Pool:0x55ec8700	MediaFormat	Merging UserInput/RFC2833 into UserInput/RFC2833
2013/05/05 21:09:24.954	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=101], events="0-16,32,36" for UserInput/RFC2833
2013/05/05 21:09:24.954	        Pool:0x55ec8700	RFC2833	Set rx pt=[pt=101], events="0-16,32,36" for UserInput/RFC2833
2013/05/05 21:09:24.954	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=128], events="" for NamedSignalEvent
2013/05/05 21:09:24.954	        Pool:0x55ec8700	SIP	No media formats of type video, not adding SDP
2013/05/05 21:09:24.954	        Pool:0x55ec8700	HTTP	Adding authentication information
2013/05/05 21:09:24.954	        Pool:0x55ec8700	SIP	Transaction remote address is udp$192.168.0.222:5060
2013/05/05 21:09:24.955	        Pool:0x55ec8700	OpalPlugin	to_customised_options: SILK-8
2013/05/05 21:09:24.958	        Pool:0x55ec8700	SIP	PDU is too large (1314 bytes) trying compact form.
2013/05/05 21:09:24.958	        Pool:0x55ec8700	SIP	Sending PDU (1264 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
INVITE sip:189659 at 192.168.0.222 SIP/2.0
CSeq: 2 INVITE
v: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09;rport
User-Agent: T38Modem/2.0.0
Authorization: Digest username="620", realm="fritz.box", nonce="66B56F740C61018A", uri="sip:189659 at 192.168.0.222", algorithm=MD5, response="c9be58d0c8de5a66ccf28b5457b12835"
f: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
i: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
k: 100rel,replaces
Organization: Vyacheslav Frolov
t: <sip:189659 at 192.168.0.222>
m: "root" <sip:620 at 192.168.0.21:5060>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING,PRACK
l: 532
c: application/sdp
Max-Forwards: 70

v=0
o=- 1367780964 1 IN IP4 192.168.0.21
s=T38Modem/2.0.0
c=IN IP4 192.168.0.21
t=0 0
m=audio 5000 RTP/AVP 120 3 102 103 104 105 0 8 126 121 118 101
a=sendrecv
a=rtpmap:120 AMR/8000/1
a=rtpmap:3 gsm/8000/1
a=rtpmap:102 G726-40/8000/1
a=rtpmap:103 G726-32/8000/1
a=rtpmap:104 G726-24/8000/1
a=rtpmap:105 G726-16/8000/1
a=rtpmap:0 PCMU/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:126 lpc10/8000/1
a=rtpmap:121 SILK/8000/1
a=rtpmap:118 Speex/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,32,36
a=maxptime:22

2013/05/05 21:09:24.959	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:24.959	        Pool:0x55ec8700	SIP	Transaction timers set: retry=0.500, completion=32.000
2013/05/05 21:09:24.959	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK946122f8-24b4-e211-9edb-6c626db69c09 completed.
2013/05/05 21:09:24.959	        Pool:0x55ec8700	SIP	Handled PDU "1 INVITE <401>"
2013/05/05 21:09:24.976	Opal Liste...0x60085700	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:09:24.976	Opal Liste...0x60085700	SIP	Waiting for PDU on udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:24.977	Opal Liste...0x60085700	SIP	PDU received: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
SIP/2.0 100 Trying
CSeq: 2 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09;rport=5060
User-Agent: AVM FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
To: <sip:189659 at 192.168.0.222>
Content-Length: 0


2013/05/05 21:09:24.977	Opal Liste...0x60085700	SIP	Queueing PDU "2 INVITE <100>", transaction=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09, token=7aa61ff8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:24.977	Opal Liste...0x60085700	Opal	Transport clean up on termination
2013/05/05 21:09:24.977	Opal Liste...0x60085700	Opal	Transport Close
2013/05/05 21:09:24.977	Opal Liste...0x60085700	Opal	Deleted transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:24.978	        Pool:0x55ec8700	SIP	Handling PDU "2 INVITE <100>" for transaction=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:24.978	        Pool:0x55ec8700	SIP	Route set is 
2013/05/05 21:09:24.979	        Pool:0x55ec8700	SIP	Product Info: name="AVM", version="", vendor="", comments="FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)"
2013/05/05 21:09:24.979	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09 proceeding.
2013/05/05 21:09:24.979	        Pool:0x55ec8700	SIP	Received Trying response
2013/05/05 21:09:24.979	        Pool:0x55ec8700	OpalCon	SetPhase from SetUpPhase to ProceedingPhase for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:24.979	        Pool:0x55ec8700	OpalMan	OnProceeding Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:24.979	        Pool:0x55ec8700	Call	OnProceeding Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:24.979	        Pool:0x55ec8700	SIP	Handled PDU "2 INVITE <100>"
2013/05/05 21:09:24.993	Opal Liste...0x60085700	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:09:24.993	Opal Liste...0x60085700	SIP	Waiting for PDU on udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:24.993	Opal Liste...0x60085700	SIP	PDU received: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
SIP/2.0 183 Session Progress
CSeq: 2 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09;rport=5060
User-Agent: AVM FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Contact: <sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222>
Content-Type: application/sdp
Content-Length: 353

v=0
o=user 4295806 4295806 IN IP4 192.168.0.222
s=T38Modem/2.0.0
c=IN IP4 192.168.0.222
t=0 0
m=audio 7078 RTP/AVP 102 103 104 0 8 101
a=rtpmap:102 G726-40/8000/1
a=rtpmap:103 G726-32/8000/1
a=rtpmap:104 G726-24/8000/1
a=rtpmap:0 PCMU/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=rtcp:7079

2013/05/05 21:09:24.994	Opal Liste...0x60085700	SIP	Queueing PDU "2 INVITE <183>", transaction=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09, token=7aa61ff8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:24.994	Opal Liste...0x60085700	Opal	Transport clean up on termination
2013/05/05 21:09:24.994	Opal Liste...0x60085700	Opal	Transport Close
2013/05/05 21:09:24.994	Opal Liste...0x60085700	Opal	Deleted transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:24.994	        Pool:0x55ec8700	SIP	Handling PDU "2 INVITE <183>" for transaction=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:24.994	        Pool:0x55ec8700	SIP	Route set is 
2013/05/05 21:09:24.995	        Pool:0x55ec8700	SIP	Updating dialog tag from "" to "4E5A5E865B23136B"
2013/05/05 21:09:24.995	        Pool:0x55ec8700	SIP	Product Info: name="AVM", version="", vendor="", comments="FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)"
2013/05/05 21:09:24.996	        Pool:0x55ec8700	SDP	Parsed connection address udp$192.168.0.222
2013/05/05 21:09:24.996	        Pool:0x55ec8700	SDP	Parsed connection address udp$192.168.0.222
2013/05/05 21:09:24.996	        Pool:0x55ec8700	SDP	Media session port=7078
2013/05/05 21:09:24.996	        Pool:0x55ec8700	SDP	Unknown media attribute rtcp
2013/05/05 21:09:24.997	        Pool:0x55ec8700	SDP	Parsed final media session with 6 'audio' formats
2013/05/05 21:09:24.997	        Pool:0x55ec8700	SIP	RTP payload type G726-40 matched to codec G.726-40k
2013/05/05 21:09:24.997	        Pool:0x55ec8700	SIP	RTP payload type G726-32 matched to codec G.726-32k
2013/05/05 21:09:24.998	        Pool:0x55ec8700	SIP	RTP payload type G726-24 matched to codec G.726-24k
2013/05/05 21:09:24.998	        Pool:0x55ec8700	SIP	RTP payload type PCMU matched to codec G.711-uLaw-64k
2013/05/05 21:09:24.998	        Pool:0x55ec8700	SIP	RTP payload type PCMA matched to codec G.711-ALaw-64k
2013/05/05 21:09:24.999	        Pool:0x55ec8700	SIP	RTP payload type telephone-event matched to codec UserInput/RFC2833
2013/05/05 21:09:24.999	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09 proceeding.
2013/05/05 21:09:24.999	        Pool:0x55ec8700	SIP	Received Session Progress response
2013/05/05 21:09:24.999	        Pool:0x55ec8700	SIP	Processing received SDP media description for audio
2013/05/05 21:09:24.999	        Pool:0x55ec8700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:24.999	        Pool:0x55ec8700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:25.000	        Pool:0x55ec8700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:25.000	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:25.000	        Pool:0x55ec8700	RTP_UDP	Session 1, SetRemoteSocketInfo: data channel, new=192.168.0.222:7078, local=192.168.0.21:5000-5001, remote=0.0.0.0:0-0
2013/05/05 21:09:25.000	        Pool:0x55ec8700	RTP	Found existing media session 1
2013/05/05 21:09:25.000	        Pool:0x55ec8700	Call	OpenSourceMediaStreams open for audio session 1 on Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:25.000	        Pool:0x55ec8700	ModemConnection::GetMediaFormats Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:25.000	        Pool:0x55ec8700	ModemEndPoint::GetMediaFormats
2013/05/05 21:09:25.001	        Pool:0x55ec8700	SIP	Using offered media format list
2013/05/05 21:09:25.001	        Pool:0x55ec8700	MySIPConnection::GetMediaFormats:
G.726-40k
G.726-32k
G.726-24k
G.711-uLaw-64k
G.711-ALaw-64k
UserInput/RFC2833
T.38

2013/05/05 21:09:25.001	        Pool:0x55ec8700	MySIPConnection::GetMediaFormats Remove G.726-40k
2013/05/05 21:09:25.001	        Pool:0x55ec8700	MySIPConnection::GetMediaFormats Remove G.726-32k
2013/05/05 21:09:25.001	        Pool:0x55ec8700	MySIPConnection::GetMediaFormats Remove G.726-24k
2013/05/05 21:09:25.001	        Pool:0x55ec8700	MySIPConnection::GetMediaFormats:
G.711-uLaw-64k
G.711-ALaw-64k
UserInput/RFC2833
T.38

2013/05/05 21:09:25.003	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:25.004	        Pool:0x55ec8700	MediaFormat	Merging PCM-16 into PCM-16
2013/05/05 21:09:25.004	        Pool:0x55ec8700	MediaFormat	Merging PCM-16 into G.711-uLaw-64k
2013/05/05 21:09:25.004	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into PCM-16
2013/05/05 21:09:25.004	        Pool:0x55ec8700	MediaFormat	Changed media option "Max Bit Rate" from "128000" to "64000"
2013/05/05 21:09:25.004	        Pool:0x55ec8700	Call	Selected media formats G.711-uLaw-64k -> PCM-16
2013/05/05 21:09:25.004	        Pool:0x55ec8700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:25.004	        Pool:0x55ec8700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:25.004	        Pool:0x55ec8700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:25.005	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:25.005	        Pool:0x55ec8700	RTP	Found existing media session 1
2013/05/05 21:09:25.005	        Pool:0x55ec8700	RTP_UDP	Session 1 reopened for reading
2013/05/05 21:09:25.005	        Pool:0x55ec8700	MySIPConnection::OnOpenMediaStream: OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:25.005	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:25.005	        Pool:0x55ec8700	OpalMan	OnOpenMediaStream Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09],OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:25.005	        Pool:0x55ec8700	OpalCon	Opened source stream C3ff77e3a1_1 with format G.711-uLaw-64k
2013/05/05 21:09:25.005	        Pool:0x55ec8700	ModemConnection::CreateMediaStream Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0] mediaFormat=PCM-16 sessionID=1 isSource=0
2013/05/05 21:09:25.005	        Pool:0x55ec8700	ttyT38-0 AudioEngine AudioEngine
2013/05/05 21:09:25.005	        Pool:0x55ec8700	ttyT38-0 AudioEngine Attach
2013/05/05 21:09:25.005	        Pool:0x55ec8700	ttyT38-0 AudioEngine OnAttach Attached
2013/05/05 21:09:25.005	        Pool:0x55ec8700	ttyT38-0 AudioEngine OnResetModemState
2013/05/05 21:09:25.005	        Pool:0x55ec8700	ttyT38-0 AudioEngine ChangeModemClass to mcFax
2013/05/05 21:09:25.005	        Pool:0x55ec8700	ttyT38-0 AudioEngine OnChangeModemClass to mcFax
2013/05/05 21:09:25.006	        Pool:0x55ec8700	ttyT38-0 AudioEngine SendOnIdle dtNone
2013/05/05 21:09:25.006	        Pool:0x55ec8700	ModemEngineBody::_AttachEngine Attached mceAudio
2013/05/05 21:09:25.006	        Pool:0x55ec8700	ModemEngineBody::NewPtrEngine created pointer for engine mceAudio
2013/05/05 21:09:25.006	        Pool:0x55ec8700	AudioModemMediaStream::AudioModemMediaStream AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:25.006	        Pool:0x55ec8700	AudioModemMediaStream::Open AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:25.006	        Pool:0x55ec8700	ttyT38-0 AudioEngine OpenIn: open 0x103a2a0
2013/05/05 21:09:25.006	        Pool:0x55ec8700	ModemEngineBody::OnEngineCallback AudioEngine cbpUpdateState (0, stConnectWait)
2013/05/05 21:09:25.006	        Pool:0x55ec8700	OpalMan	OnOpenMediaStream Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0],AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:25.006	        Pool:0x55ec8700	OpalCon	Opened sink stream C3ff77e3a1_1 with format PCM-16
2013/05/05 21:09:25.007	        Pool:0x55ec8700	PWLib	File handle high water mark set: 42 PUDPSocket
2013/05/05 21:09:25.007	        Pool:0x55ec8700	Adding patch Patch[0x103a610] OpalRTPMediaStream-Source-G.711-uLaw-64k on stream OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:25.007	        Pool:0x55ec8700	Adding patch Patch[0x103a610] OpalRTPMediaStream-Source-G.711-uLaw-64k on stream AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:25.007	        Pool:0x55ec8700	Patch	Created Sink: format=PCM-16
2013/05/05 21:09:25.007	        Pool:0x55ec8700	Codec	G711-uLaw-64k decoder created
2013/05/05 21:09:25.007	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:25.008	        Pool:0x55ec8700	MediaFormat	Merging PCM-16 into PCM-16
2013/05/05 21:09:25.008	        Pool:0x55ec8700	Patch	Created primary codec G.711-uLaw-64k->PCM-16 with ID C3ff77e3a1_1
2013/05/05 21:09:25.008	        Pool:0x55ec8700	Media	Set data size from 16 to 3840
2013/05/05 21:09:25.008	        Pool:0x55ec8700	Patch	Added media stream sink AudioModemMediaStream-Sink-PCM-16 using transcoder G.711-uLaw-64k->PCM-16, data size=3840
2013/05/05 21:09:25.008	        Pool:0x55ec8700	Media	RTP data size cannot be changed to 160, fixed at 2048
2013/05/05 21:09:25.008	        Pool:0x55ec8700	OpalCon	Added send DTMF filter on connection Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0], patch Patch[0x103a610] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:25.008	        Pool:0x55ec8700	OpalCon	Sink stream of connection Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0] uses patch Patch[0x103a610] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:25.008	        Pool:0x55ec8700	OpalCon	Source stream of connection Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] uses patch Patch[0x103a610] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:25.009	        Pool:0x55ec8700	RTPCon	Adding RFC2833 receive handler
2013/05/05 21:09:25.009	        Pool:0x55ec8700	RTPCon	Adding Cisco NSE receive handler
2013/05/05 21:09:25.009	        Pool:0x55ec8700	PWLib	File handle high water mark set: 43 Thread unblock pipe
2013/05/05 21:09:25.009	        Pool:0x55ec8700	PTLib	Thread high water mark set: 14
2013/05/05 21:09:25.009	 Media Patch:0x55e87700	Patch	Thread started for Patch[0x103a610] OpalRTPMediaStream-Source-G.711-uLaw-64k -> AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:25.009	 Media Patch:0x55e87700	RTP_UDP	Session 1, flushed 1 RTP data packets on startup
2013/05/05 21:09:25.009	        Pool:0x55ec8700	Media	Starting thread Media Patch:0x55e87700
2013/05/05 21:09:25.009	        Pool:0x55ec8700	Call	GetOtherPartyConnection Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:25.010	        Pool:0x55ec8700	Call	OpenSourceMediaStreams open for audio session 1 on Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:25.010	        Pool:0x55ec8700	SIP	Using offered media format list
2013/05/05 21:09:25.010	        Pool:0x55ec8700	MySIPConnection::GetMediaFormats:
G.726-40k
G.726-32k
G.726-24k
G.711-uLaw-64k
G.711-ALaw-64k
UserInput/RFC2833
T.38

2013/05/05 21:09:25.010	        Pool:0x55ec8700	MySIPConnection::GetMediaFormats Remove G.726-40k
2013/05/05 21:09:25.010	        Pool:0x55ec8700	MySIPConnection::GetMediaFormats Remove G.726-32k
2013/05/05 21:09:25.010	        Pool:0x55ec8700	MySIPConnection::GetMediaFormats Remove G.726-24k
2013/05/05 21:09:25.010	        Pool:0x55ec8700	MySIPConnection::GetMediaFormats:
G.711-uLaw-64k
G.711-ALaw-64k
UserInput/RFC2833
T.38

2013/05/05 21:09:25.010	        Pool:0x55ec8700	ModemConnection::GetMediaFormats Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:25.010	        Pool:0x55ec8700	ModemEndPoint::GetMediaFormats
2013/05/05 21:09:25.013	        Pool:0x55ec8700	MediaFormat	Merging PCM-16 into PCM-16
2013/05/05 21:09:25.013	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:25.013	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into PCM-16
2013/05/05 21:09:25.013	        Pool:0x55ec8700	MediaFormat	Changed media option "Max Bit Rate" from "128000" to "64000"
2013/05/05 21:09:25.013	        Pool:0x55ec8700	MediaFormat	Merging PCM-16 into G.711-uLaw-64k
2013/05/05 21:09:25.013	        Pool:0x55ec8700	Call	Selected media formats PCM-16 -> G.711-uLaw-64k
2013/05/05 21:09:25.013	        Pool:0x55ec8700	ModemConnection::CreateMediaStream Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0] mediaFormat=PCM-16 sessionID=1 isSource=1
2013/05/05 21:09:25.014	        Pool:0x55ec8700	ttyT38-0 AudioEngine SendOnIdle dtNone
2013/05/05 21:09:25.014	        Pool:0x55ec8700	ModemEngineBody::_AttachEngine Attached mceAudio
2013/05/05 21:09:25.014	        Pool:0x55ec8700	ModemEngineBody::NewPtrEngine created pointer for engine mceAudio
2013/05/05 21:09:25.014	        Pool:0x55ec8700	AudioModemMediaStream::AudioModemMediaStream AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:25.014	        Pool:0x55ec8700	AudioModemMediaStream::Open AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:25.014	        Pool:0x55ec8700	ttyT38-0 AudioEngine OpenOut: open 0x1042150
2013/05/05 21:09:25.014	        Pool:0x55ec8700	ModemEngineBody::OnEngineCallback AudioEngine cbpUpdateState (0, stConnectWait)
2013/05/05 21:09:25.014	        Pool:0x55ec8700	OpalMan	OnOpenMediaStream Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0],AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:25.014	        Pool:0x55ec8700	OpalCon	Opened source stream C3ff77e3a1_1 with format PCM-16
2013/05/05 21:09:25.014	        Pool:0x55ec8700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:25.014	        Pool:0x55ec8700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:25.014	        Pool:0x55ec8700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:25.014	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:25.014	        Pool:0x55ec8700	RTP	Found existing media session 1
2013/05/05 21:09:25.014	        Pool:0x55ec8700	RTP_UDP	Session 1 reopened for writing
2013/05/05 21:09:25.015	        Pool:0x55ec8700	MySIPConnection::OnOpenMediaStream: OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:25.015	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:25.015	        Pool:0x55ec8700	OpalMan	OnOpenMediaStream Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09],OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:25.015	        Pool:0x55ec8700	OpalCon	Opened sink stream C3ff77e3a1_1 with format G.711-uLaw-64k
2013/05/05 21:09:25.015	        Pool:0x55ec8700	PWLib	File handle high water mark set: 44 PUDPSocket
2013/05/05 21:09:25.015	        Pool:0x55ec8700	Adding patch Patch[0x1042840] AudioModemMediaStream-Source-PCM-16 on stream AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:25.016	        Pool:0x55ec8700	Adding patch Patch[0x1042840] AudioModemMediaStream-Source-PCM-16 on stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:25.016	        Pool:0x55ec8700	Patch	Created Sink: format=G.711-uLaw-64k
2013/05/05 21:09:25.016	        Pool:0x55ec8700	Codec	G711-uLaw-64k encoder created
2013/05/05 21:09:25.016	        Pool:0x55ec8700	MediaFormat	Merging PCM-16 into PCM-16
2013/05/05 21:09:25.016	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:25.016	        Pool:0x55ec8700	Patch	Created primary codec PCM-16->G.711-uLaw-64k with ID C3ff77e3a1_1
2013/05/05 21:09:25.016	        Pool:0x55ec8700	Media	RTP data size cannot be changed to 1920, fixed at 528
2013/05/05 21:09:25.016	        Pool:0x55ec8700	Patch	Added media stream sink OpalRTPMediaStream-Sink-G.711-uLaw-64k using transcoder PCM-16->G.711-uLaw-64k, data size=528
2013/05/05 21:09:25.016	        Pool:0x55ec8700	Media	Set data size from 16 to 320
2013/05/05 21:09:25.017	        Pool:0x55ec8700	OpalCon	Source stream of connection Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0] uses patch Patch[0x1042840] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:25.017	        Pool:0x55ec8700	OpalCon	Added send DTMF filter on connection Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09], patch Patch[0x1042840] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:25.017	        Pool:0x55ec8700	OpalCon	Sink stream of connection Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] uses patch Patch[0x1042840] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:25.017	        Pool:0x55ec8700	PWLib	File handle high water mark set: 45 Thread unblock pipe
2013/05/05 21:09:25.017	        Pool:0x55ec8700	PTLib	Thread high water mark set: 15
2013/05/05 21:09:25.017	 Media Patch:0x55e46700	Patch	Thread started for Patch[0x1042840] AudioModemMediaStream-Source-PCM-16 -> OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:25.017	 Media Patch:0x55e46700	ModemEngineBody::OnEngineCallback AudioEngine cbpUpdateState (0, stConnectWait)
2013/05/05 21:09:25.018	 Media Patch:0x55e46700	RTP	Session 1, first sent data: ver=2 pt=PCMU psz=160 m=1 x=0 seq=51164 ts=0 src=1b0f5564 ccnt=0
2013/05/05 21:09:25.018	 Media Patch:0x55e46700	PWLib	File handle high water mark set: 46 PTextFile
2013/05/05 21:09:25.018	        Pool:0x55ec8700	Media	Starting thread Media Patch:0x55e46700
2013/05/05 21:09:25.018	        Pool:0x55ec8700	MediaFormat	Merging UserInput/RFC2833 into UserInput/RFC2833
2013/05/05 21:09:25.019	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=101], events="0-15" for UserInput/RFC2833
2013/05/05 21:09:25.019	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=128], events="" for NamedSignalEvent
2013/05/05 21:09:25.019	        Pool:0x55ec8700	SIP	Starting re-INVITE to resolve multiple codecs in answer
2013/05/05 21:09:25.019	        Pool:0x55ec8700	SIP	Remote dialog address from target: sip:189659 at 192.168.0.222
2013/05/05 21:09:25.021	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK68442ff8-24b4-e211-9edb-6c626db69c09 created.
2013/05/05 21:09:25.022	        Pool:0x55ec8700	SIP	Creating INVITE request
2013/05/05 21:09:25.022	        Pool:0x55ec8700	SIP	Offering only current media streams in Re-INVITE
2013/05/05 21:09:25.022	        Pool:0x55ec8700	SIP	Offering media type audio in SDP
2013/05/05 21:09:25.022	        Pool:0x55ec8700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:25.022	        Pool:0x55ec8700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:25.022	        Pool:0x55ec8700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:25.022	        Pool:0x55ec8700	RTP	Found existing media session 1
2013/05/05 21:09:25.022	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:25.023	        Pool:0x55ec8700	MediaFormat	Merging UserInput/RFC2833 into UserInput/RFC2833
2013/05/05 21:09:25.023	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=101], events="0-16,32,36" for UserInput/RFC2833
2013/05/05 21:09:25.023	        Pool:0x55ec8700	RFC2833	Set rx pt=[pt=101], events="0-16,32,36" for UserInput/RFC2833
2013/05/05 21:09:25.023	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=128], events="" for NamedSignalEvent
2013/05/05 21:09:25.023	        Pool:0x55ec8700	HTTP	Adding authentication information
2013/05/05 21:09:25.023	        Pool:0x55ec8700	SIP	Transaction remote address is udp$192.168.0.222:5060
2013/05/05 21:09:25.025	        Pool:0x55ec8700	SIP	Sending PDU (1032 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
INVITE sip:189659 at 192.168.0.222 SIP/2.0
CSeq: 3 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK68442ff8-24b4-e211-9edb-6c626db69c09;rport
User-Agent: T38Modem/2.0.0
Authorization: Digest username="620", realm="fritz.box", nonce="66B56F740C61018A", uri="sip:189659 at 192.168.0.222", algorithm=MD5, response="c9be58d0c8de5a66ccf28b5457b12835"
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
Supported: 100rel,replaces
Organization: Vyacheslav Frolov
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Contact: "root" <sip:620 at 192.168.0.21:5060>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING,PRACK
Content-Length: 229
Content-Type: application/sdp
Max-Forwards: 70

v=0
o=- 1367780964 2 IN IP4 192.168.0.21
s=T38Modem/2.0.0
c=IN IP4 192.168.0.21
t=0 0
m=audio 5000 RTP/AVP 0 101
a=sendrecv
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,32,36
a=maxptime:240

2013/05/05 21:09:25.025	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:25.025	        Pool:0x55ec8700	SIP	Transaction timers set: retry=0.500, completion=32.000
2013/05/05 21:09:25.026	        Pool:0x55ec8700	OpalCon	SetPhase from ProceedingPhase to AlertingPhase for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:25.026	        Pool:0x55ec8700	OpalMan	OnAlerting Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:25.026	        Pool:0x55ec8700	Call	OnAlerting Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:25.026	        Pool:0x55ec8700	ModemConnection::SetAlerting Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0] sip:189659 at 192.168.0.222 1
2013/05/05 21:09:25.026	        Pool:0x55ec8700	OpalCon	SetPhase from SetUpPhase to AlertingPhase for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:25.026	        Pool:0x55ec8700	ModemEngineBody::Request: stConnectWait request={
calltoken=modem:/C3ff77e3a1/0
command=alerting
}
2013/05/05 21:09:25.026	        Pool:0x55ec8700	ModemEngineBody::SetCallState: off-hook cstAlerted stConnectWait
2013/05/05 21:09:25.026	        Pool:0x55ec8700	SIP	Starting receive media to annunciate remote progress tones
2013/05/05 21:09:25.026	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:25.027	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:25.027	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:25.027	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:25.027	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:25.027	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:25.027	        Pool:0x55ec8700	SIP	Handled PDU "2 INVITE <183>"
2013/05/05 21:09:25.027	 Media Patch:0x55e87700	RTP	Session 1, first receive data: ver=2 pt=[pt=102] psz=100 m=0 x=0 seq=2 ts=320 src=4d1a32b3 ccnt=0
2013/05/05 21:09:25.027	 Media Patch:0x55e87700	VoIP Metrics	No Ie and Bpl data for payload type [pt=102], unable to calculate R Factor and MOS score.
2013/05/05 21:09:25.027	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.027	 Media Patch:0x55e87700	ModemEngineBody::OnEngineCallback AudioEngine cbpUpdateState (0, stConnectWait)
2013/05/05 21:09:25.030	Opal Liste...0x60085700	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:09:25.030	Opal Liste...0x60085700	SIP	Waiting for PDU on udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:25.031	Opal Liste...0x60085700	SIP	PDU received: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
SIP/2.0 491 Request Pending
CSeq: 3 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK68442ff8-24b4-e211-9edb-6c626db69c09;rport=5060
User-Agent: AVM FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Content-Length: 0


2013/05/05 21:09:25.031	Opal Liste...0x60085700	SIP	Queueing PDU "3 INVITE <491>", transaction=z9hG4bK68442ff8-24b4-e211-9edb-6c626db69c09, token=7aa61ff8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:25.031	Opal Liste...0x60085700	Opal	Transport clean up on termination
2013/05/05 21:09:25.031	Opal Liste...0x60085700	Opal	Transport Close
2013/05/05 21:09:25.031	Opal Liste...0x60085700	Opal	Deleted transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:25.032	        Pool:0x55ec8700	SIP	Handling PDU "3 INVITE <491>" for transaction=z9hG4bK68442ff8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:25.034	        Pool:0x55ec8700	HTTP	Adding authentication information
2013/05/05 21:09:25.034	        Pool:0x55ec8700	SIP	Sending PDU (545 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
ACK sip:189659 at 192.168.0.222 SIP/2.0
CSeq: 3 ACK
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK68442ff8-24b4-e211-9edb-6c626db69c09;rport
Authorization: Digest username="620", realm="fritz.box", nonce="66B56F740C61018A", uri="sip:189659 at 192.168.0.222", algorithm=MD5, response="5478b106b8487ed189d44aab9d4968a9"
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Content-Length: 0
Max-Forwards: 70


2013/05/05 21:09:25.034	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:25.035	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK68442ff8-24b4-e211-9edb-6c626db69c09 completing.
2013/05/05 21:09:25.035	        Pool:0x55ec8700	SIP	Queueing re-INVITE to retry after getting 491 Request Pending
2013/05/05 21:09:25.035	        Pool:0x55ec8700	SIP	Remote dialog address from target: sip:189659 at 192.168.0.222
2013/05/05 21:09:25.037	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK74ae31f8-24b4-e211-9edb-6c626db69c09 created.
2013/05/05 21:09:25.037	        Pool:0x55ec8700	SIP	Creating INVITE request
2013/05/05 21:09:25.037	        Pool:0x55ec8700	SIP	Offering only current media streams in Re-INVITE
2013/05/05 21:09:25.038	        Pool:0x55ec8700	SIP	Offering media type audio in SDP
2013/05/05 21:09:25.038	        Pool:0x55ec8700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:25.038	        Pool:0x55ec8700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:25.038	        Pool:0x55ec8700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:25.038	        Pool:0x55ec8700	RTP	Found existing media session 1
2013/05/05 21:09:25.038	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:25.038	        Pool:0x55ec8700	MediaFormat	Merging UserInput/RFC2833 into UserInput/RFC2833
2013/05/05 21:09:25.039	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=101], events="0-16,32,36" for UserInput/RFC2833
2013/05/05 21:09:25.039	        Pool:0x55ec8700	RFC2833	Set rx pt=[pt=101], events="0-16,32,36" for UserInput/RFC2833
2013/05/05 21:09:25.039	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=128], events="" for NamedSignalEvent
2013/05/05 21:09:25.039	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK68442ff8-24b4-e211-9edb-6c626db69c09 completed.
2013/05/05 21:09:25.039	        Pool:0x55ec8700	SIP	Handled PDU "3 INVITE <491>"
2013/05/05 21:09:25.046	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.066	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.109	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.110	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.126	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.146	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.166	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.186	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.207	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.229	 Media Patch:0x55e87700	Patch	Removing frame with mismatched payload type [pt=102] - should be PCMU
2013/05/05 21:09:25.247	 Media Patch:0x55e87700	Patch	Consecutive mismatched payload type, was expecting PCMU, now using [pt=102]
2013/05/05 21:09:25.247	 Media Patch:0x55e87700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:25.247	 Media Patch:0x55e87700	MediaFormat	Changing payload type from PCMU to [pt=102] in G.711-uLaw-64k
2013/05/05 21:09:27.017	 Media Patch:0x55e46700	RTP	Session 1, transmit statistics:  packets=101 octets=16160 avgTime=19 maxTime=22 minTime=18
2013/05/05 21:09:27.026	 Media Patch:0x55e87700	RTP	Session 1, receive statistics: packets=101 octets=10100 lost=0 tooLate=0 order=0 avgTime=19 maxTime=43 minTime=1 jitter=68389 maxJitter=33554431
2013/05/05 21:09:27.479	 Media Patch:0x55e87700	RTP	Session 1, OnRxSenderReport: ssrc=1293562547 ntp=2013/5/5-21:9:27.477047 rtp=19840 psent=124 osent=12400
  RR: ssrc=453989732 fraction=0 lost=0 last_seq=51286 jitter=21 lsr=0.000 dlsr=0.000

2013/05/05 21:09:27.479	 Media Patch:0x55e87700	RTP	Session 1, OnExtendedReport: ssrc=1293562547

2013/05/05 21:09:27.479	 Media Patch:0x55e87700	RTP	Session 1, SourceDescription item 0x1049c80, current size = 22
2013/05/05 21:09:27.479	 Media Patch:0x55e87700	RTP	Session 1, OnSourceDescription: 1 entries
  ssrc=1293562547
  item[0]: type=CNAME data="192.168.0.222%5:5060"
2013/05/05 21:09:29.017	 Media Patch:0x55e46700	RTP	Session 1, transmit statistics:  packets=201 octets=32160 avgTime=20 maxTime=21 minTime=19
2013/05/05 21:09:29.026	 Media Patch:0x55e87700	RTP	Session 1, receive statistics: packets=201 octets=20100 lost=0 tooLate=0 order=0 avgTime=20 maxTime=22 minTime=18 jitter=107 maxJitter=33554431
2013/05/05 21:09:29.960	 Housekeeper:0x60148700	SIP	Set state Terminated_Success for INVITE transaction id=z9hG4bK946122f8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:29.960	 Housekeeper:0x60148700	SIP	Completed state for transaction id=z9hG4bK946122f8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:30.040	 Housekeeper:0x60148700	SIP	Set state Terminated_Success for INVITE transaction id=z9hG4bK68442ff8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:30.040	 Housekeeper:0x60148700	SIP	Completed state for transaction id=z9hG4bK68442ff8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:31.017	 Media Patch:0x55e46700	RTP	Session 1, transmit statistics:  packets=301 octets=48160 avgTime=20 maxTime=21 minTime=19
2013/05/05 21:09:31.026	 Media Patch:0x55e87700	RTP	Session 1, receive statistics: packets=301 octets=30100 lost=0 tooLate=0 order=0 avgTime=20 maxTime=22 minTime=18 jitter=0 maxJitter=33554431
2013/05/05 21:09:31.054	 Media Patch:0x55e87700	RTP	Session 1, OnRxSenderReport: ssrc=1293562547 ntp=2013/5/5-21:9:31.052682 rtp=48480 psent=303 osent=30300
  RR: ssrc=453989732 fraction=0 lost=0 last_seq=51465 jitter=21 lsr=0.000 dlsr=0.000

2013/05/05 21:09:31.055	 Media Patch:0x55e87700	RTP	Session 1, OnExtendedReport: ssrc=1293562547

2013/05/05 21:09:31.055	 Media Patch:0x55e87700	RTP	Session 1, SourceDescription item 0x1049c80, current size = 22
2013/05/05 21:09:31.055	 Media Patch:0x55e87700	RTP	Session 1, OnSourceDescription: 1 entries
  ssrc=1293562547
  item[0]: type=CNAME data="192.168.0.222%5:5060"
2013/05/05 21:09:32.946	Opal Liste...0x60085700	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:09:32.946	Opal Liste...0x60085700	SIP	Waiting for PDU on udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:32.947	Opal Liste...0x60085700	SIP	PDU received: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
SIP/2.0 200 OK
CSeq: 2 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09;rport=5060
User-Agent: AVM FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
Supported: 100rel,replaces,timer
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Contact: <sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222>
Accept: application/sdp, multipart/mixed
Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE,PUBLISH
Allow-Events: telephone-event,refer
Content-Type: application/sdp
Content-Length: 353
Accept-Encoding: identity

v=0
o=user 4295806 4295806 IN IP4 192.168.0.222
s=T38Modem/2.0.0
c=IN IP4 192.168.0.222
t=0 0
m=audio 7078 RTP/AVP 102 103 104 0 8 101
a=rtpmap:102 G726-40/8000/1
a=rtpmap:103 G726-32/8000/1
a=rtpmap:104 G726-24/8000/1
a=rtpmap:0 PCMU/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=rtcp:7079

2013/05/05 21:09:32.948	Opal Liste...0x60085700	SIP	Queueing PDU "2 INVITE <200>", transaction=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09, token=7aa61ff8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:32.948	Opal Liste...0x60085700	Opal	Transport clean up on termination
2013/05/05 21:09:32.948	Opal Liste...0x60085700	Opal	Transport Close
2013/05/05 21:09:32.948	Opal Liste...0x60085700	Opal	Deleted transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:32.948	        Pool:0x55ec8700	SIP	Handling PDU "2 INVITE <200>" for transaction=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:32.948	        Pool:0x55ec8700	SIP	Route set is 
2013/05/05 21:09:32.949	        Pool:0x55ec8700	SIP	Set Request URI to sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222
2013/05/05 21:09:32.949	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:32.950	        Pool:0x55ec8700	SIP	Product Info: name="AVM", version="", vendor="", comments="FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)"
2013/05/05 21:09:32.950	        Pool:0x55ec8700	SDP	Parsed connection address udp$192.168.0.222
2013/05/05 21:09:32.950	        Pool:0x55ec8700	SDP	Parsed connection address udp$192.168.0.222
2013/05/05 21:09:32.950	        Pool:0x55ec8700	SDP	Media session port=7078
2013/05/05 21:09:32.951	        Pool:0x55ec8700	SDP	Unknown media attribute rtcp
2013/05/05 21:09:32.951	        Pool:0x55ec8700	SDP	Parsed final media session with 6 'audio' formats
2013/05/05 21:09:32.951	        Pool:0x55ec8700	SIP	RTP payload type G726-40 matched to codec G.726-40k
2013/05/05 21:09:32.952	        Pool:0x55ec8700	SIP	RTP payload type G726-32 matched to codec G.726-32k
2013/05/05 21:09:32.952	        Pool:0x55ec8700	SIP	RTP payload type G726-24 matched to codec G.726-24k
2013/05/05 21:09:32.952	        Pool:0x55ec8700	SIP	RTP payload type PCMU matched to codec G.711-uLaw-64k
2013/05/05 21:09:32.953	        Pool:0x55ec8700	SIP	RTP payload type PCMA matched to codec G.711-ALaw-64k
2013/05/05 21:09:32.953	        Pool:0x55ec8700	SIP	RTP payload type telephone-event matched to codec UserInput/RFC2833
2013/05/05 21:09:32.953	        Pool:0x55ec8700	SIP	Remote dialog address from target: sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222
2013/05/05 21:09:32.953	        Pool:0x55ec8700	SIP	Transaction remote address changed to udp$192.168.0.222:5060
2013/05/05 21:09:32.956	        Pool:0x55ec8700	HTTP	Adding authentication information
2013/05/05 21:09:32.956	        Pool:0x55ec8700	SIP	Sending PDU (636 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
ACK sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222 SIP/2.0
CSeq: 2 ACK
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK6af6e9fc-24b4-e211-9edb-6c626db69c09;rport
Authorization: Digest username="620", realm="fritz.box", nonce="66B56F740C61018A", uri="sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222", algorithm=MD5, response="c2853a0560184fc257d6175093bfef35"
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Contact: "root" <sip:620 at 192.168.0.21:5060>
Content-Length: 0
Max-Forwards: 70


2013/05/05 21:09:32.957	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:32.957	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09 completing.
2013/05/05 21:09:32.957	        Pool:0x55ec8700	SIP	Received INVITE OK response for INVITE
2013/05/05 21:09:32.958	        Pool:0x55ec8700	SIP	Processing received SDP media description for audio
2013/05/05 21:09:32.958	        Pool:0x55ec8700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:32.958	        Pool:0x55ec8700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:32.958	        Pool:0x55ec8700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:32.958	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:32.959	        Pool:0x55ec8700	RTP	Found existing media session 1
2013/05/05 21:09:32.959	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into PCM-16
2013/05/05 21:09:32.959	        Pool:0x55ec8700	MediaFormat	Changed media option "Max Bit Rate" from "128000" to "64000"
2013/05/05 21:09:32.959	        Pool:0x55ec8700	Media	Media format updated on AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:32.959	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:32.959	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:32.960	        Pool:0x55ec8700	Media	Media format updated on OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:32.960	        Pool:0x55ec8700	Patch	Updated Sink: format=G.711-uLaw-64k ok=1
2013/05/05 21:09:32.960	        Pool:0x55ec8700	SIP	INVITE change needs to resume stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:32.960	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:32.960	        Pool:0x55ec8700	Media	Media format updated on OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:32.960	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:32.960	        Pool:0x55ec8700	MediaFormat	Changing payload type from [pt=102] to PCMU in G.711-uLaw-64k
2013/05/05 21:09:32.960	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into PCM-16
2013/05/05 21:09:32.961	        Pool:0x55ec8700	MediaFormat	Changed media option "Max Bit Rate" from "128000" to "64000"
2013/05/05 21:09:32.961	        Pool:0x55ec8700	Media	Media format updated on AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:32.961	        Pool:0x55ec8700	Patch	Updated Sink: format=G.711-uLaw-64k ok=1
2013/05/05 21:09:32.961	        Pool:0x55ec8700	SIP	INVITE change needs to resume stream OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:32.961	        Pool:0x55ec8700	MediaFormat	Merging UserInput/RFC2833 into UserInput/RFC2833
2013/05/05 21:09:32.961	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=101], events="0-15" for UserInput/RFC2833
2013/05/05 21:09:32.961	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=128], events="" for NamedSignalEvent
2013/05/05 21:09:32.961	        Pool:0x55ec8700	SIP	Queueing re-INVITE to resolve multiple codecs in answer
2013/05/05 21:09:32.962	        Pool:0x55ec8700	SIP	Remote dialog address from target: sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222
2013/05/05 21:09:32.964	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK6635ebfc-24b4-e211-9edb-6c626db69c09 created.
2013/05/05 21:09:32.964	        Pool:0x55ec8700	SIP	Creating INVITE request
2013/05/05 21:09:32.964	        Pool:0x55ec8700	SIP	Offering only current media streams in Re-INVITE
2013/05/05 21:09:32.964	        Pool:0x55ec8700	SIP	Offering media type audio in SDP
2013/05/05 21:09:32.964	        Pool:0x55ec8700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:32.964	        Pool:0x55ec8700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:32.964	        Pool:0x55ec8700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:32.964	        Pool:0x55ec8700	RTP	Found existing media session 1
2013/05/05 21:09:32.965	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:32.965	        Pool:0x55ec8700	MediaFormat	Merging UserInput/RFC2833 into UserInput/RFC2833
2013/05/05 21:09:32.965	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=101], events="0-16,32,36" for UserInput/RFC2833
2013/05/05 21:09:32.966	        Pool:0x55ec8700	RFC2833	Set rx pt=[pt=101], events="0-16,32,36" for UserInput/RFC2833
2013/05/05 21:09:32.966	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=128], events="" for NamedSignalEvent
2013/05/05 21:09:32.966	        Pool:0x55ec8700	OpalCon	SetPhase from AlertingPhase to ConnectedPhase for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.966	        Pool:0x55ec8700	OpalCon	OnConnected for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.966	        Pool:0x55ec8700	OpalMan	OnConnected Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.966	        Pool:0x55ec8700	Call	OnConnected Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.966	        Pool:0x55ec8700	ModemConnection::SetConnected Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.966	        Pool:0x55ec8700	OpalCon	SetConnected for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.966	        Pool:0x55ec8700	OpalCon	SetPhase from AlertingPhase to ConnectedPhase for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.966	        Pool:0x55ec8700	OpalCon	SetPhase from ConnectedPhase to EstablishedPhase for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.966	        Pool:0x55ec8700	ModemConnection::OnEstablished Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.966	        Pool:0x55ec8700	ModemEngineBody::Request: stConnectWait request={
calltoken=modem:/C3ff77e3a1/0
command=established
}
2013/05/05 21:09:32.966	        Pool:0x55ec8700	ttyT38-0 AudioEngine RecvOnIdle dtNone
2013/05/05 21:09:32.966	        Pool:0x55ec8700	ModemEngineBody::SetCallState: off-hook cstEstablished stConnectWait
2013/05/05 21:09:32.966	        Pool:0x55ec8700	ModemEngineBody::SetState: off-hook cstEstablished stConnectHandle.chConnected
2013/05/05 21:09:32.967	        Pool:0x55ec8700	OpalCon	OnEstablished Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.967	ttyT38-0(e...0x60107700	ModemEngineBody::SetSubState: off-hook cstEstablished stConnectHandle.chAudioEngineAttached
2013/05/05 21:09:32.967	ttyT38-0(e...0x60107700	ModemEngineBody::SetSubState: off-hook cstEstablished stConnectHandle.chTonePlayed
2013/05/05 21:09:32.967	ttyT38-0(e...0x60107700	ModemEngineBody::SetSubState: off-hook cstEstablished stConnectHandle.chConnectionEstablishDelay
2013/05/05 21:09:32.967	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:32.967	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:32.967	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.967	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:32.967	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:32.967	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.967	        Pool:0x55ec8700	OpalMan	OnEstablished Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.967	        Pool:0x55ec8700	Call	OnEstablished Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.967	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:32.967	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:32.967	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.967	        Pool:0x55ec8700	OpalCon	SetPhase from ConnectedPhase to EstablishedPhase for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.968	        Pool:0x55ec8700	OpalCon	OnEstablished Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.968	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:32.968	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:32.968	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:32.968	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:32.968	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:32.968	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.968	        Pool:0x55ec8700	OpalMan	OnEstablished Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.968	        Pool:0x55ec8700	Call	OnEstablished Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.968	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:32.968	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:32.968	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:32.968	        Pool:0x55ec8700	Call	Established Call[C3ff77e3a1]
2013/05/05 21:09:32.968	        Pool:0x55ec8700	HTTP	Adding authentication information
2013/05/05 21:09:32.968	        Pool:0x55ec8700	SIP	Transaction remote address is udp$192.168.0.222:5060
2013/05/05 21:09:32.970	        Pool:0x55ec8700	SIP	Sending PDU (1032 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
INVITE sip:189659 at 192.168.0.222 SIP/2.0
CSeq: 4 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK74ae31f8-24b4-e211-9edb-6c626db69c09;rport
User-Agent: T38Modem/2.0.0
Authorization: Digest username="620", realm="fritz.box", nonce="66B56F740C61018A", uri="sip:189659 at 192.168.0.222", algorithm=MD5, response="c9be58d0c8de5a66ccf28b5457b12835"
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
Supported: 100rel,replaces
Organization: Vyacheslav Frolov
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Contact: "root" <sip:620 at 192.168.0.21:5060>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING,PRACK
Content-Length: 229
Content-Type: application/sdp
Max-Forwards: 70

v=0
o=- 1367780964 3 IN IP4 192.168.0.21
s=T38Modem/2.0.0
c=IN IP4 192.168.0.21
t=0 0
m=audio 5000 RTP/AVP 0 101
a=sendrecv
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,32,36
a=maxptime:240

2013/05/05 21:09:32.970	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:32.970	        Pool:0x55ec8700	SIP	Transaction timers set: retry=0.500, completion=32.000
2013/05/05 21:09:32.971	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK729024f8-24b4-e211-9edb-6c626db69c09 completed.
2013/05/05 21:09:32.971	        Pool:0x55ec8700	SIP	Handled PDU "2 INVITE <200>"
2013/05/05 21:09:32.971	 Media Patch:0x55e87700	Patch	Consecutive mismatched payload type, was expecting PCMU, now using [pt=102]
2013/05/05 21:09:32.971	 Media Patch:0x55e87700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:32.971	 Media Patch:0x55e87700	MediaFormat	Changing payload type from PCMU to [pt=102] in G.711-uLaw-64k
2013/05/05 21:09:32.991	Opal Liste...0x60085700	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:09:32.991	Opal Liste...0x60085700	SIP	Waiting for PDU on udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:32.991	Opal Liste...0x60085700	SIP	PDU received: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
SIP/2.0 200 OK
CSeq: 4 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK74ae31f8-24b4-e211-9edb-6c626db69c09;rport=5060
User-Agent: AVM FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
Supported: 100rel,replaces,timer
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Contact: <sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222>
Accept: application/sdp, multipart/mixed
Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE,PUBLISH
Allow-Events: telephone-event,refer
Content-Type: application/sdp
Content-Length: 228
Accept-Encoding: identity

v=0
o=user 4295806 4295807 IN IP4 192.168.0.222
s=T38Modem/2.0.0
c=IN IP4 192.168.0.222
t=0 0
m=audio 7078 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=rtcp:7079

2013/05/05 21:09:32.992	Opal Liste...0x60085700	SIP	Queueing PDU "4 INVITE <200>", transaction=z9hG4bK74ae31f8-24b4-e211-9edb-6c626db69c09, token=7aa61ff8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:32.992	Opal Liste...0x60085700	Opal	Transport clean up on termination
2013/05/05 21:09:32.992	Opal Liste...0x60085700	Opal	Transport Close
2013/05/05 21:09:32.992	Opal Liste...0x60085700	Opal	Deleted transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:32.993	        Pool:0x55ec8700	SIP	Handling PDU "4 INVITE <200>" for transaction=z9hG4bK74ae31f8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:32.993	        Pool:0x55ec8700	SIP	Route set is 
2013/05/05 21:09:32.993	        Pool:0x55ec8700	SIP	Set Request URI to sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222
2013/05/05 21:09:32.994	        Pool:0x55ec8700	SIP	Remote dialog address from target: sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222
2013/05/05 21:09:32.994	        Pool:0x55ec8700	SIP	Transaction remote address changed to udp$192.168.0.222:5060
2013/05/05 21:09:32.996	        Pool:0x55ec8700	HTTP	Adding authentication information
2013/05/05 21:09:32.997	        Pool:0x55ec8700	SIP	Sending PDU (636 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
ACK sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222 SIP/2.0
CSeq: 4 ACK
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bKa22bf0fc-24b4-e211-9edb-6c626db69c09;rport
Authorization: Digest username="620", realm="fritz.box", nonce="66B56F740C61018A", uri="sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222", algorithm=MD5, response="c2853a0560184fc257d6175093bfef35"
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Contact: "root" <sip:620 at 192.168.0.21:5060>
Content-Length: 0
Max-Forwards: 70


2013/05/05 21:09:32.997	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:32.998	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK74ae31f8-24b4-e211-9edb-6c626db69c09 completing.
2013/05/05 21:09:32.998	        Pool:0x55ec8700	SIP	Received INVITE OK response for INVITE
2013/05/05 21:09:32.999	        Pool:0x55ec8700	SDP	Parsed connection address udp$192.168.0.222
2013/05/05 21:09:32.999	        Pool:0x55ec8700	SDP	Parsed connection address udp$192.168.0.222
2013/05/05 21:09:32.999	        Pool:0x55ec8700	SDP	Media session port=7078
2013/05/05 21:09:32.999	        Pool:0x55ec8700	SDP	Unknown media attribute rtcp
2013/05/05 21:09:32.999	        Pool:0x55ec8700	SDP	Parsed final media session with 2 'audio' formats
2013/05/05 21:09:33.000	        Pool:0x55ec8700	SIP	RTP payload type PCMU matched to codec G.711-uLaw-64k
2013/05/05 21:09:33.000	        Pool:0x55ec8700	SIP	RTP payload type telephone-event matched to codec UserInput/RFC2833
2013/05/05 21:09:33.000	        Pool:0x55ec8700	SIP	Processing received SDP media description for audio
2013/05/05 21:09:33.000	        Pool:0x55ec8700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:33.000	        Pool:0x55ec8700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:33.000	        Pool:0x55ec8700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:33.000	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:33.001	        Pool:0x55ec8700	RTP	Found existing media session 1
2013/05/05 21:09:33.001	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into PCM-16
2013/05/05 21:09:33.001	        Pool:0x55ec8700	Media	Media format updated on AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:33.001	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:33.002	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:33.002	        Pool:0x55ec8700	Media	Media format updated on OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:33.002	        Pool:0x55ec8700	Patch	Updated Sink: format=G.711-uLaw-64k ok=1
2013/05/05 21:09:33.002	        Pool:0x55ec8700	SIP	INVITE change needs to resume stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:33.002	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:33.002	        Pool:0x55ec8700	Media	Media format updated on OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:33.002	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:33.002	        Pool:0x55ec8700	MediaFormat	Changing payload type from [pt=102] to PCMU in G.711-uLaw-64k
2013/05/05 21:09:33.003	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into PCM-16
2013/05/05 21:09:33.003	        Pool:0x55ec8700	Media	Media format updated on AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:33.003	        Pool:0x55ec8700	Patch	Updated Sink: format=G.711-uLaw-64k ok=1
2013/05/05 21:09:33.003	        Pool:0x55ec8700	SIP	INVITE change needs to resume stream OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:33.003	        Pool:0x55ec8700	MediaFormat	Merging UserInput/RFC2833 into UserInput/RFC2833
2013/05/05 21:09:33.003	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=101], events="0-15" for UserInput/RFC2833
2013/05/05 21:09:33.003	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=128], events="" for NamedSignalEvent
2013/05/05 21:09:33.003	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:33.004	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:33.004	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:33.004	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:33.004	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:33.004	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:33.004	        Pool:0x55ec8700	HTTP	Adding authentication information
2013/05/05 21:09:33.004	        Pool:0x55ec8700	SIP	Transaction remote address is udp$192.168.0.222:5060
2013/05/05 21:09:33.005	        Pool:0x55ec8700	SIP	Sending PDU (1078 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
INVITE sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222 SIP/2.0
CSeq: 5 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK6635ebfc-24b4-e211-9edb-6c626db69c09;rport
User-Agent: T38Modem/2.0.0
Authorization: Digest username="620", realm="fritz.box", nonce="66B56F740C61018A", uri="sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222", algorithm=MD5, response="d5f21e243d42cd10181601ee557ee8fc"
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
Supported: 100rel,replaces
Organization: Vyacheslav Frolov
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Contact: "root" <sip:620 at 192.168.0.21:5060>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING,PRACK
Content-Length: 229
Content-Type: application/sdp
Max-Forwards: 70

v=0
o=- 1367780964 4 IN IP4 192.168.0.21
s=T38Modem/2.0.0
c=IN IP4 192.168.0.21
t=0 0
m=audio 5000 RTP/AVP 0 101
a=sendrecv
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16,32,36
a=maxptime:240

2013/05/05 21:09:33.006	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:33.006	        Pool:0x55ec8700	SIP	Transaction timers set: retry=0.500, completion=32.000
2013/05/05 21:09:33.006	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK74ae31f8-24b4-e211-9edb-6c626db69c09 completed.
2013/05/05 21:09:33.006	        Pool:0x55ec8700	SIP	Handled PDU "4 INVITE <200>"
2013/05/05 21:09:33.017	 Media Patch:0x55e46700	RTP	Session 1, transmit statistics:  packets=401 octets=64160 avgTime=20 maxTime=30 minTime=11
2013/05/05 21:09:33.025	Opal Liste...0x60085700	OpalUDP	Binding to interface: 192.168.0.21:5060
2013/05/05 21:09:33.025	Opal Liste...0x60085700	SIP	Waiting for PDU on udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:33.026	Opal Liste...0x60085700	SIP	PDU received: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
SIP/2.0 200 OK
CSeq: 5 INVITE
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bK6635ebfc-24b4-e211-9edb-6c626db69c09;rport=5060
User-Agent: AVM FRITZ!Box Fon WLAN 7390 (UI) 84.05.50 (Dec 11 2012)
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
Supported: 100rel,replaces,timer
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Contact: <sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222>
Accept: application/sdp, multipart/mixed
Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE,PUBLISH
Allow-Events: telephone-event,refer
Content-Type: application/sdp
Content-Length: 228
Accept-Encoding: identity

v=0
o=user 4295806 4295807 IN IP4 192.168.0.222
s=T38Modem/2.0.0
c=IN IP4 192.168.0.222
t=0 0
m=audio 7078 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=rtcp:7079

2013/05/05 21:09:33.026	Opal Liste...0x60085700	SIP	Queueing PDU "5 INVITE <200>", transaction=z9hG4bK6635ebfc-24b4-e211-9edb-6c626db69c09, token=7aa61ff8-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:33.026	Opal Liste...0x60085700	Opal	Transport clean up on termination
2013/05/05 21:09:33.026	Opal Liste...0x60085700	Opal	Transport Close
2013/05/05 21:09:33.027	Opal Liste...0x60085700	Opal	Deleted transport udp$192.168.0.222:5060<if=udp$192.168.0.21:5060>
2013/05/05 21:09:33.027	        Pool:0x55ec8700	SIP	Handling PDU "5 INVITE <200>" for transaction=z9hG4bK6635ebfc-24b4-e211-9edb-6c626db69c09
2013/05/05 21:09:33.027	        Pool:0x55ec8700	SIP	Route set is 
2013/05/05 21:09:33.027	        Pool:0x55ec8700	SIP	Set Request URI to sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222
2013/05/05 21:09:33.028	        Pool:0x55ec8700	SIP	Remote dialog address from target: sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222
2013/05/05 21:09:33.028	        Pool:0x55ec8700	SIP	Transaction remote address changed to udp$192.168.0.222:5060
2013/05/05 21:09:33.031	        Pool:0x55ec8700	HTTP	Adding authentication information
2013/05/05 21:09:33.031	        Pool:0x55ec8700	SIP	Sending PDU (636 bytes) to: rem=udp$192.168.0.222:5060,local=udp$192.168.0.21:5060,if=192.168.0.21%eth0
ACK sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222 SIP/2.0
CSeq: 5 ACK
Via: SIP/2.0/UDP 192.168.0.21:5060;branch=z9hG4bKdc64f5fc-24b4-e211-9edb-6c626db69c09;rport
Authorization: Digest username="620", realm="fritz.box", nonce="66B56F740C61018A", uri="sip:770B0FD401C302B2E03DDC78D1910 at 192.168.0.222", algorithm=MD5, response="c2853a0560184fc257d6175093bfef35"
From: "root" <sip:620 at 192.168.0.222>;tag=7aa61ff8-24b4-e211-9edb-6c626db69c09
Call-ID: dab91ff8-24b4-e211-9edb-6c626db69c09 at ceramic
To: <sip:189659 at 192.168.0.222>;tag=4E5A5E865B23136B
Contact: "root" <sip:620 at 192.168.0.21:5060>
Content-Length: 0
Max-Forwards: 70


2013/05/05 21:09:33.032	        Pool:0x55ec8700	OpalUDP	Setting interface to 192.168.0.21%eth0
2013/05/05 21:09:33.032	        Pool:0x55ec8700	SIP	INVITE transaction id=z9hG4bK6635ebfc-24b4-e211-9edb-6c626db69c09 completing.
2013/05/05 21:09:33.032	        Pool:0x55ec8700	SIP	Received INVITE OK response for INVITE
2013/05/05 21:09:33.033	        Pool:0x55ec8700	SDP	Parsed connection address udp$192.168.0.222
2013/05/05 21:09:33.033	        Pool:0x55ec8700	SDP	Parsed connection address udp$192.168.0.222
2013/05/05 21:09:33.033	        Pool:0x55ec8700	SDP	Media session port=7078
2013/05/05 21:09:33.033	        Pool:0x55ec8700	SDP	Unknown media attribute rtcp
2013/05/05 21:09:33.033	        Pool:0x55ec8700	SDP	Parsed final media session with 2 'audio' formats
2013/05/05 21:09:33.034	        Pool:0x55ec8700	SIP	RTP payload type PCMU matched to codec G.711-uLaw-64k
2013/05/05 21:09:33.034	        Pool:0x55ec8700	SIP	RTP payload type telephone-event matched to codec UserInput/RFC2833
2013/05/05 21:09:33.034	        Pool:0x55ec8700	SIP	Processing received SDP media description for audio
2013/05/05 21:09:33.034	        Pool:0x55ec8700	Call	IsMediaBypassPossible Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09] session 1
2013/05/05 21:09:33.034	        Pool:0x55ec8700	OpalMan	IsMediaBypassPossible: session 1
2013/05/05 21:09:33.034	        Pool:0x55ec8700	OpalCon	IsMediaBypassPossible: default returns false
2013/05/05 21:09:33.034	        Pool:0x55ec8700	RTP	Found existing RTP session 1
2013/05/05 21:09:33.035	        Pool:0x55ec8700	RTP	Found existing media session 1
2013/05/05 21:09:33.035	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into PCM-16
2013/05/05 21:09:33.035	        Pool:0x55ec8700	Media	Media format updated on AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:33.035	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:33.035	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:33.036	        Pool:0x55ec8700	Media	Media format updated on OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:33.036	        Pool:0x55ec8700	Patch	Updated Sink: format=G.711-uLaw-64k ok=1
2013/05/05 21:09:33.036	        Pool:0x55ec8700	SIP	INVITE change needs to resume stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:33.036	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:33.036	        Pool:0x55ec8700	Media	Media format updated on OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:33.036	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into G.711-uLaw-64k
2013/05/05 21:09:33.036	        Pool:0x55ec8700	MediaFormat	Merging G.711-uLaw-64k into PCM-16
2013/05/05 21:09:33.037	        Pool:0x55ec8700	Media	Media format updated on AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:33.037	        Pool:0x55ec8700	Patch	Updated Sink: format=G.711-uLaw-64k ok=1
2013/05/05 21:09:33.037	        Pool:0x55ec8700	SIP	INVITE change needs to resume stream OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:33.037	        Pool:0x55ec8700	MediaFormat	Merging UserInput/RFC2833 into UserInput/RFC2833
2013/05/05 21:09:33.037	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=101], events="0-15" for UserInput/RFC2833
2013/05/05 21:09:33.037	        Pool:0x55ec8700	RFC2833	Set tx pt=[pt=128], events="" for NamedSignalEvent
2013/05/05 21:09:33.037	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Sink-PCM-16
2013/05/05 21:09:33.037	        Pool:0x55ec8700	Media	Starting stream AudioModemMediaStream-Source-PCM-16
2013/05/05 21:09:33.037	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<modem>[modem:/C3ff77e3a1/0]
2013/05/05 21:09:33.038	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Source-G.711-uLaw-64k
2013/05/05 21:09:33.038	        Pool:0x55ec8700	Media	Starting stream OpalRTPMediaStream-Sink-G.711-uLaw-64k
2013/05/05 21:09:33.038	        Pool:0x55ec8700	OpalCon	Media stream threads started for Call[C3ff77e3a1]-EP<sip>[7aa61ff8-24b4-e211-9edb-6c626db69c09]
2013/05/05 21:09:33.038	        Pool:0x55ec8700	PWLib	Assertion fail: Null pointer reference, file /usr/include/ptlib/safecoll.h, line 851, Error=107

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.12 (GNU/Linux)

iEYEARECAAYFAlGGtiAACgkQqVj5VlP9Od1XtwCgpvGKu+dDX0Y6fysf5mq/3xBB
zLEAn1LI1G8XMjhvliNVGTNHLGaI7k2x
=3/EA
-----END PGP SIGNATURE-----




More information about the Pkg-voip-maintainers mailing list