[2009-11-05 05:22:33.8739] DEBUG[23918] pbx.c: Launching 'ReceiveFAX' [2009-11-05 05:22:33.8739] VERBOSE[23918] pbx.c:-- Executing [21906@fax_receive:11] ReceiveFAX("SIP/provider-c823f4b0", "/var/spool/hylafax/recvq/fax_in_1257427353.566.tiff") in new stack [2009-11-05 05:22:33.8741] DEBUG[23918] chan_sip.c: Strict routing enforced for session 980236120c013a8 [2009-11-05 05:22:33.8742] VERBOSE[23918] chan_sip.c: set_destination: Parsing for address/port to send to [2009-11-05 05:22:33.8742] VERBOSE[23918] chan_sip.c: set_destination: set destination to 192.168.200.152, port 5060 [2009-11-05 05:22:33.8743] DEBUG[23918] chan_sip.c: T.38 UDPTL is at 192.168.135.103 port 4297 [2009-11-05 05:22:33.8744] DEBUG[23918] chan_sip.c: Initializing already initialized SIP dialog 980236120c013a8 (presumably reinvite) [2009-11-05 05:22:33.8745] VERBOSE[23918] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.200.152:5060: INVITE sip:192.168.200.152:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.135.103:5060;branch=z9hG4bK3f45760a;rport Max-Forwards: 70 From: ;tag=as18a7c1b9 To: ;tag=20c013a8+1+11cc055f+c58c3971 Contact: Call-ID: 980236120c013a8 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.1.6 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 337 v=0 o=root 125566217 125566218 IN IP4 192.168.135.103 s=Asterisk PBX 1.6.1.6 c=IN IP4 192.168.135.103 t=0 0 m=image 4297 udptl t38 a=T38Faxversion:0 a=T38MaxBitRate:9600 a=T38FaxFillBitRemoval a=T38FaxTranscodingMMR a=T38FaxTranscodingJBIG a=T38FaxRateManagement:transferredTCF a=T38FaxMaxDatagram:1400 a=T38FaxUdpEC:t38UDPFEC --- [2009-11-05 05:22:33.8746] DEBUG[23918] chan_sip.c: Trying to put 'INVITE sip' onto UDP socket destined for 192.168.200.152:5060 [2009-11-05 05:22:33.8747] DEBUG[23918] app_fax.c: Negotiating T.38 for receive on SIP/provider-c823f4b0 [2009-11-05 05:22:33.8993] VERBOSE[30804] chan_sip.c: <--- SIP read from UDP://192.168.200.152:5060 ---> SIP/2.0 415 Unsupported Media Type Via: SIP/2.0/UDP 192.168.135.103:5060;branch=z9hG4bK3f45760a;rport=5060 From: ;tag=as18a7c1b9 To: ;tag=20c013a8+1+11cc055f+c58c3971 Call-ID: 980236120c013a8 CSeq: 102 INVITE Server: DC-SIP/2.0 Content-Length: 0 <-------------> [2009-11-05 05:22:33.8994] VERBOSE[30804] chan_sip.c: --- (8 headers 0 lines) --- [2009-11-05 05:22:33.8995] DEBUG[30804] chan_sip.c: Acked pending invite 102 [2009-11-05 05:22:33.8995] DEBUG[30804] chan_sip.c: Stopping retransmission on '980236120c013a8' of Request 102: Match Found [2009-11-05 05:22:33.8996] DEBUG[30804] chan_sip.c: Strict routing enforced for session 980236120c013a8 [2009-11-05 05:22:33.8997] VERBOSE[30804] chan_sip.c: set_destination: Parsing for address/port to send to [2009-11-05 05:22:33.8998] VERBOSE[30804] chan_sip.c: set_destination: set destination to 192.168.200.152, port 5060 [2009-11-05 05:22:33.8998] VERBOSE[30804] chan_sip.c: Transmitting (no NAT) to 192.168.200.152:5060: ACK sip:192.168.200.152:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.135.103:5060;branch=z9hG4bK3f45760a;rport Max-Forwards: 70 From: ;tag=as18a7c1b9 To: ;tag=20c013a8+1+11cc055f+c58c3971 Contact: Call-ID: 980236120c013a8 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.1.6 Content-Length: 0 --- [2009-11-05 05:22:33.8999] DEBUG[30804] chan_sip.c: Trying to put 'ACK sip:20' onto UDP socket destined for 192.168.200.152:5060 [2009-11-05 05:22:33.9000] DEBUG[30804] chan_sip.c: Strict routing enforced for session 980236120c013a8 [2009-11-05 05:22:33.9001] VERBOSE[30804] chan_sip.c: set_destination: Parsing for address/port to send to [2009-11-05 05:22:33.9002] VERBOSE[30804] chan_sip.c: set_destination: set destination to 192.168.200.152, port 5060 [2009-11-05 05:22:33.9003] DEBUG[30804] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [2009-11-05 05:22:33.9003] DEBUG[30804] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [2009-11-05 05:22:33.9004] VERBOSE[30804] chan_sip.c: Audio is at 192.168.135.103 port 44568 [2009-11-05 05:22:33.9004] VERBOSE[30804] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [2009-11-05 05:22:33.9005] VERBOSE[30804] chan_sip.c: Adding codec 0x8 (alaw) to SDP [2009-11-05 05:22:33.9006] DEBUG[30804] chan_sip.c: Initializing already initialized SIP dialog 980236120c013a8 (presumably reinvite) [2009-11-05 05:22:33.9007] VERBOSE[30804] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.200.152:5060: INVITE sip:192.168.200.152:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.135.103:5060;branch=z9hG4bK226adb9c;rport Max-Forwards: 70 From: ;tag=as18a7c1b9 To: ;tag=20c013a8+1+11cc055f+c58c3971 Contact: -- t=0 0 m=audio 44568 RTP/AVP 0 8 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [2009-11-05 05:22:33.9008] DEBUG[30804] chan_sip.c: Trying to put 'INVITE sip' onto UDP socket destined for 192.168.200.152:5060 [2009-11-05 05:22:33.9012] WARNING[23918] app_fax.c: channel 'SIP/provider-c823f4b0' refused to negotiate T.38 [2009-11-05 05:22:33.9013] DEBUG[23918] channel.c: Set channel SIP/provider-c823f4b0 to read format slin [2009-11-05 05:22:33.9014] DEBUG[23918] channel.c: Set channel SIP/provider-c823f4b0 to write format slin [2009-11-05 05:22:33.9016] DEBUG[23918] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [2009-11-05 05:22:33.9125] DEBUG[23918] channel.c: Generator got voice, switching to phase locked mode [2009-11-05 05:22:33.9126] DEBUG[23918] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2009-11-05 05:22:33.9127] DEBUG[23918] rtp.c: Ooh, format changed from unknown to ulaw [2009-11-05 05:22:33.9127] DEBUG[23918] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [2009-11-05 05:22:34.1834] VERBOSE[30804] chan_sip.c: <--- SIP read from UDP://192.168.200.152:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.135.103:5060;branch=z9hG4bK226adb9c;rport=5060 From: ;tag=as18a7c1b9 To: ;tag=20c013a8+1+11cc055f+c58c3971 Call-ID: 980236120c013a8 CSeq: 103 INVITE Server: DC-SIP/2.0 Allow: INVITE, BYE, REGISTER, ACK, OPTIONS, CANCEL, SUBSCRIBE, NOTIFY, PRACK, INFO, REFER, UPDATE Contact: Content-Type: application/sdp Content-Length: 386 v=0 o=PVG 1257426459040 1257426459040 IN IP4 192.168.200.152 s=- p=+1 6135555555 c=IN IP4 192.168.200.152 t=0 0 a=sqn: 0 a=cdsc: 1 audio RTP/AVP 0 8 108 18 13 120 a=cpar: a=rtpmap:108 AAL2-G726-32/8000 a=cpar: a=rtpmap:120 telephone-event/8000 a=cpar: a=fmtp:120 0-15 a=cpar: a=ptime:10 a=cpar: a=ptime:20 a=cpar: a=fmtp:18 annexb=yes m=audio 10614 RTP/AVP 0 8 a=ptime:20 <-------------> [2009-11-05 05:22:34.1835] VERBOSE[30804] chan_sip.c: --- (11 headers 16 lines) --- [2009-11-05 05:22:34.1837] DEBUG[30804] chan_sip.c: Acked pending invite 103 [2009-11-05 05:22:34.1838] DEBUG[30804] chan_sip.c: Stopping retransmission on '980236120c013a8' of Request 103: Match Found [2009-11-05 05:22:34.1839] VERBOSE[30804] chan_sip.c: Found RTP audio format 0 [2009-11-05 05:22:34.1840] VERBOSE[30804] chan_sip.c: Found RTP audio format 8 [2009-11-05 05:22:34.1841] DEBUG[30804] chan_sip.c: Peer doesn't provide T.38 UDPTL [2009-11-05 05:22:34.1841] VERBOSE[30804] chan_sip.c: Peer audio RTP is at port 192.168.200.152:10614 [2009-11-05 05:22:34.1842] VERBOSE[30804] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [2009-11-05 05:22:34.1843] VERBOSE[30804] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [2009-11-05 05:22:34.1843] VERBOSE[30804] chan_sip.c: Peer audio RTP is at port 192.168.200.152:10614 [2009-11-05 05:22:34.1844] DEBUG[30804] chan_sip.c: Strict routing enforced for session 980236120c013a8 [2009-11-05 05:23:17.0924] DEBUG[23918] app_fax.c: Fax phase E handler. result=0 [2009-11-05 05:23:17.0925] DEBUG[23918] app_fax.c: Fax transmitted successfully. [2009-11-05 05:23:17.0926] DEBUG[23918] app_fax.c:Remote station ID: FAXBACK [2009-11-05 05:23:17.0926] DEBUG[23918] app_fax.c:Pages transferred: 1 [2009-11-05 05:23:17.0927] DEBUG[23918] app_fax.c:Image resolution:8031 x 7700 [2009-11-05 05:23:17.0927] DEBUG[23918] app_fax.c:Transfer Rate:9600 [2009-11-05 05:23:17.0928] DEBUG[23918] app_fax.c: Loop finished, res=0