rendered paste bodyApr 25 16:56:09 NOTICE[3080128176] cdr.c: CDR simple logging enabled.
Apr 25 16:56:09 WARNING[3080128176] res_musiconhold.c: No music on hold classes configured, disabling music on hold.
Apr 25 16:56:09 VERBOSE[3080128176] logger.c: CHAN FAX: Starting Fax Modem SLOT 0
Apr 25 16:56:09 VERBOSE[3080128176] logger.c: CHAN FAX: Starting Fax Modem SLOT 1
Apr 25 16:56:09 NOTICE[2988989344] faxmodem.c: Opened pty, slave device: /dev/pts/0
Apr 25 16:56:09 ERROR[2988989344] faxmodem.c: Fatal error: failed to create /dev/fax/0 symbolic link
Apr 25 16:56:09 VERBOSE[2988989344] logger.c: CHAN FAX: Thread ended for /dev/fax/0
Apr 25 16:56:09 NOTICE[2988723104] faxmodem.c: Opened pty, slave device: /dev/pts/0
Apr 25 16:56:09 ERROR[2988723104] faxmodem.c: Fatal error: failed to create /dev/fax/1 symbolic link
Apr 25 16:56:09 VERBOSE[2988723104] logger.c: CHAN FAX: Thread ended for /dev/fax/1
Apr 25 16:56:09 NOTICE[3080128176] app_nconference.c: Loading NConference module
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 0: OPTIONS sip:400@10.10.7.37 SIP/2.0 (34)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK5f5180c9 (57)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 2: From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as39f10b81 (63)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:400@10.10.7.37> (24)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 4: Contact: <sip:callweaver@10.10.250.62> (38)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 5: Call-ID: 53919d702b3abb0d435168587bf8ce08@10.10.250.62 (54)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 7: User-Agent: CallWeaver (22)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 8: Max-Forwards: 70 (16)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 9: Date: Wed, 25 Apr 2007 20:57:09 GMT (35)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 11: Content-Length: 0 (17)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 12: (0)
Apr 25 16:57:09 VERBOSE[2988723104] logger.c: 12 headers, 0 lines
Apr 25 16:57:09 VERBOSE[2988723104] logger.c: Reliably Transmitting (NAT) to 10.10.7.37:5060:
OPTIONS sip:400@10.10.7.37 SIP/2.0
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK5f5180c9
From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as39f10b81
To: <sip:400@10.10.7.37>
Contact: <sip:callweaver@10.10.250.62>
Call-ID: 53919d702b3abb0d435168587bf8ce08@10.10.250.62
CSeq: 102 OPTIONS
User-Agent: CallWeaver
Max-Forwards: 70
Date: Wed, 25 Apr 2007 20:57:09 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0
---
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #6
Apr 25 16:57:09 VERBOSE[2988723104] logger.c:
<-- SIP read from 10.10.7.37:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK5f5180c9
From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as39f10b81
To: <sip:400@10.10.7.37>;tag=87d6e961af9c79c2
Call-ID: 53919d702b3abb0d435168587bf8ce08@10.10.250.62
CSeq: 102 OPTIONS
User-Agent: Grandstream HT386 1.0.3.64 FXS1
Contact: <sip:400@10.10.7.37>
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Supported: replaces
Content-Length: 0
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 0: SIP/2.0 200 OK (14)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK5f5180c9 (57)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 2: From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as39f10b81 (63)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:400@10.10.7.37>;tag=87d6e961af9c79c2 (45)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 4: Call-ID: 53919d702b3abb0d435168587bf8ce08@10.10.250.62 (54)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 6: User-Agent: Grandstream HT386 1.0.3.64 FXS1 (43)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 7: Contact: <sip:400@10.10.7.37> (29)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 9: Supported: replaces (19)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 10: Content-Length: 0 (17)
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Header 11: (0)
Apr 25 16:57:09 VERBOSE[2988723104] logger.c: --- (11 headers 0 lines) ---
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: = Found Their Call ID: 53919d702b3abb0d435168587bf8ce08@10.10.250.62 Their Tag Our tag: as39f10b81
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #6
Apr 25 16:57:09 DEBUG[2988723104] chan_sip.c: Stopping retransmission on '53919d702b3abb0d435168587bf8ce08@10.10.250.62' of Request 102: Match Found
Apr 25 16:57:09 VERBOSE[2988723104] logger.c: Destroying call '53919d702b3abb0d435168587bf8ce08@10.10.250.62'
Apr 25 16:57:25 VERBOSE[2988723104] logger.c:
<-- SIP read from 10.10.7.37:5060:
INVITE sip:666@10.10.250.62 SIP/2.0
Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK493fec461f25c67b
From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
To: <sip:666@10.10.250.62>
Contact: <sip:400@10.10.7.37>
Supported: replaces
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 5257 INVITE
User-Agent: Grandstream HT386 1.0.3.64 FXS1
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Content-Type: application/sdp
Content-Length: 328
v=0
o=400 8000 8000 IN IP4 10.10.7.37
s=SIP Call
c=IN IP4 10.10.7.37
t=0 0
m=audio 5008 RTP/AVP 0 18 4 2 97 101
a=sendrecv
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=rtpmap:4 G723/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=20
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 0: INVITE sip:666@10.10.250.62 SIP/2.0 (35)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK493fec461f25c67b (58)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 2: From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f (49)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:666@10.10.250.62> (26)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 4: Contact: <sip:400@10.10.7.37> (29)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 5: Supported: replaces (19)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 6: Call-ID: f66398437721a5ce@10.10.7.37 (36)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 7: CSeq: 5257 INVITE (17)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 8: User-Agent: Grandstream HT386 1.0.3.64 FXS1 (43)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 9: Max-Forwards: 70 (16)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 10: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 11: Content-Type: application/sdp (29)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 12: Content-Length: 328 (19)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 13: (0)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: v=0 (3)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: o=400 8000 8000 IN IP4 10.10.7.37 (33)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: s=SIP Call (10)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: c=IN IP4 10.10.7.37 (19)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: t=0 0 (5)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: m=audio 5008 RTP/AVP 0 18 4 2 97 101 (36)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=sendrecv (10)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:97 iLBC/8000 (21)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=fmtp:97 mode=20 (17)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=ptime:20 (10)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=fmtp:101 0-11 (15)
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: --- (13 headers 16 lines) ---
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Allocating new SIP dialog for f66398437721a5ce@10.10.7.37 - INVITE (With RTP)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Begin: parsing SIP "Supported: replaces"
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Found SIP option: -replaces-
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Matched SIP option: replaces
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: * SIP extension value: 1 for call f66398437721a5ce@10.10.7.37
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Using INVITE request as basis request - f66398437721a5ce@10.10.7.37
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Sending to 10.10.7.37 : 5060 (NAT)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: *** Setting NAT on RTP to 1
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Setting NAT on UDPTL to 1
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Reliably Transmitting (NAT) to 10.10.7.37:5060:
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK493fec461f25c67b;received=10.10.7.37
From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
To: <sip:666@10.10.250.62>;tag=as1cd8a96e
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 5257 INVITE
User-Agent: CallWeaver
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Max-Forwards: 70
WWW-Authenticate: Digest algorithm=MD5, realm="callweaver.org", nonce="3814410f"
Content-Length: 0
---
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #9
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Scheduling destruction of call 'f66398437721a5ce@10.10.7.37' in 15000 ms
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found user '400'
Apr 25 16:57:25 VERBOSE[2988723104] logger.c:
<-- SIP read from 10.10.7.37:5060:
ACK sip:666@10.10.250.62 SIP/2.0
Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK493fec461f25c67b
From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
To: <sip:666@10.10.250.62>;tag=as1cd8a96e
Contact: <sip:400@10.10.7.37>
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 5257 ACK
User-Agent: Grandstream HT386 1.0.3.64 FXS1
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Content-Length: 0
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 0: ACK sip:666@10.10.250.62 SIP/2.0 (32)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK493fec461f25c67b (58)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 2: From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f (49)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:666@10.10.250.62>;tag=as1cd8a96e (41)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 4: Contact: <sip:400@10.10.7.37> (29)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 5: Call-ID: f66398437721a5ce@10.10.7.37 (36)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 6: CSeq: 5257 ACK (14)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 7: User-Agent: Grandstream HT386 1.0.3.64 FXS1 (43)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 8: Max-Forwards: 70 (16)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 9: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 10: Content-Length: 0 (17)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 11: (0)
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: --- (11 headers 0 lines) ---
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: = Found Their Call ID: f66398437721a5ce@10.10.7.37 Their Tag 40e2b4adca7ff28f Our tag: as1cd8a96e
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #9
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Stopping retransmission on 'f66398437721a5ce@10.10.7.37' of Response 5257: Match Found
Apr 25 16:57:25 VERBOSE[2988723104] logger.c:
<-- SIP read from 10.10.7.37:5060:
INVITE sip:666@10.10.250.62 SIP/2.0
Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK5ad6166f33a595a5
From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
To: <sip:666@10.10.250.62>
Contact: <sip:400@10.10.7.37>
Supported: replaces
Authorization: Digest username="400", realm="callweaver.org", algorithm=MD5, uri="sip:666@10.10.250.62", nonce="3814410f", response="a80d5c9686cf6a4ff9463c5f644a8cd9"
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 5258 INVITE
User-Agent: Grandstream HT386 1.0.3.64 FXS1
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Content-Type: application/sdp
Content-Length: 328
v=0
o=400 8000 8001 IN IP4 10.10.7.37
s=SIP Call
c=IN IP4 10.10.7.37
t=0 0
m=audio 5008 RTP/AVP 0 18 4 2 97 101
a=sendrecv
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=rtpmap:4 G723/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=20
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 0: INVITE sip:666@10.10.250.62 SIP/2.0 (35)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK5ad6166f33a595a5 (58)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 2: From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f (49)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:666@10.10.250.62> (26)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 4: Contact: <sip:400@10.10.7.37> (29)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 5: Supported: replaces (19)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 6: Authorization: Digest username="400", realm="callweaver.org", algorithm=MD5, uri="sip:666@10.10.250.62", nonce="3814410f", response="a80d5c9686cf6a4ff9463c5f644a8cd9" (166)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 7: Call-ID: f66398437721a5ce@10.10.7.37 (36)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 8: CSeq: 5258 INVITE (17)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 9: User-Agent: Grandstream HT386 1.0.3.64 FXS1 (43)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 10: Max-Forwards: 70 (16)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 11: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 12: Content-Type: application/sdp (29)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 13: Content-Length: 328 (19)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 14: (0)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: v=0 (3)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: o=400 8000 8001 IN IP4 10.10.7.37 (33)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: s=SIP Call (10)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: c=IN IP4 10.10.7.37 (19)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: t=0 0 (5)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: m=audio 5008 RTP/AVP 0 18 4 2 97 101 (36)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=sendrecv (10)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:2 G726-32/8000 (23)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:97 iLBC/8000 (21)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=fmtp:97 mode=20 (17)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=ptime:20 (10)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Line: a=fmtp:101 0-11 (15)
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: --- (14 headers 16 lines) ---
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: = Found Their Call ID: f66398437721a5ce@10.10.7.37 Their Tag 40e2b4adca7ff28f Our tag: as1cd8a96e
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Using INVITE request as basis request - f66398437721a5ce@10.10.7.37
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Sending to 10.10.7.37 : 5060 (NAT)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: *** Setting NAT on RTP to 1
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Setting NAT on UDPTL to 1
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found user '400'
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found RTP audio format 0
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found RTP audio format 18
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found RTP audio format 4
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found RTP audio format 2
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found RTP audio format 97
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found RTP audio format 101
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Activating RTP on response f66398437721a5ce@10.10.7.37 (1)
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Peer audio RTP is at port 10.10.7.37:5008
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Peer audio RTP is at port 10.10.7.37:5008
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found description format PCMU
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found description format G729
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found description format G723
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found description format G726-32
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found description format iLBC
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Found description format telephone-event
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: T38 state changed to 0 on channel <none>
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x515 (g723|ulaw|g726|g729|ilbc)/video=0x0 (nothing), combined - 0x4 (ulaw)
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Checking SIP call limits for device 400
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Updating call counter for incoming call
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Looking for 666 in inbound (domain 10.10.250.62)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: build_route: Contact hop: <sip:400@10.10.7.37>
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: list_route: hop: <sip:400@10.10.7.37>
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: Transmitting (NAT) to 10.10.7.37:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK5ad6166f33a595a5;received=10.10.7.37
From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
To: <sip:666@10.10.250.62>
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 5258 INVITE
User-Agent: CallWeaver
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Max-Forwards: 70
Contact: <sip:666@10.10.250.62>
Content-Length: 0
---
Apr 25 16:57:25 DEBUG[3079719840] chan_sip.c: Checking device state for peer 400
Apr 25 16:57:25 DEBUG[3079719840] devicestate.c: Changing state for SIP/400 - state 2 (In use)
Apr 25 16:57:25 DEBUG[2983607200] pbx.c: Launching 'Goto'
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: -- Executing Goto("SIP/400-66a0", "sipfax|s|1") in new stack
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: -- Goto (sipfax,s,1)
Apr 25 16:57:25 DEBUG[2983607200] pbx.c: Launching 'Set'
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: -- Executing Set("SIP/400-66a0", "LOCALSTATIONID=Navynet.it FAX") in new stack
Apr 25 16:57:25 DEBUG[2983607200] pbx.c: Launching 'Set'
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: -- Executing Set("SIP/400-66a0", "LOCALHEADERINFO=Navynet SRL is a solution provider for business") in new stack
Apr 25 16:57:25 DEBUG[2983607200] pbx.c: Launching 'Set'
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: -- Executing Set("SIP/400-66a0", "FAXFILE=/opt/tmp/fax.tif") in new stack
Apr 25 16:57:25 DEBUG[2983607200] pbx.c: Launching 'Set'
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: -- Executing Set("SIP/400-66a0", "FAXFILENOEXT=/opt/tmp/fax") in new stack
Apr 25 16:57:25 DEBUG[2983607200] pbx.c: Launching 'FaxDetect'
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: -- Executing FaxDetect("SIP/400-66a0", "4000") in new stack
Apr 25 16:57:25 DEBUG[2983607200] app_faxdetect.c: Preparing detect of fax (waitdur=4000ms, sildur=1000ms, mindur=100ms, maxdur=-1ms)
Apr 25 16:57:25 DEBUG[3079719840] chan_sip.c: Checking device state for peer 400
Apr 25 16:57:25 DEBUG[3079719840] channel.c: Avoiding initial deadlock for 'SIP/400-66a0'
Apr 25 16:57:25 DEBUG[2983607200] chan_sip.c: sip_answer(SIP/400-66a0)
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: We're at 10.10.250.62 port 11564
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: Adding codec 0x4 (ulaw) to SDP
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: Adding codec 0x2 (gsm) to SDP
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: Adding codec 0x8 (alaw) to SDP
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
Apr 25 16:57:25 VERBOSE[2983607200] logger.c: Reliably Transmitting (NAT) to 10.10.7.37:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK5ad6166f33a595a5;received=10.10.7.37
From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
To: <sip:666@10.10.250.62>;tag=as73a4778b
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 5258 INVITE
User-Agent: CallWeaver
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Max-Forwards: 70
Contact: <sip:666@10.10.250.62>
Content-Type: application/sdp
Content-Length: 263
v=0
o=root 23771 23771 IN IP4 10.10.250.62
s=session
c=IN IP4 10.10.250.62
t=0 0
m=audio 11564 RTP/AVP 0 3 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
---
Apr 25 16:57:25 DEBUG[2983607200] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #11
Apr 25 16:57:25 DEBUG[2983607200] channel.c: Set channel SIP/400-66a0 to read format slin
Apr 25 16:57:25 DEBUG[2983607200] channel.c: Set channel SIP/400-66a0 to write format slin
Apr 25 16:57:25 DEBUG[2983340960] app_queue.c: Device 'SIP/400' changed to state '2' (In use)
Apr 25 16:57:25 VERBOSE[2988723104] logger.c:
<-- SIP read from 10.10.7.37:5060:
ACK sip:666@10.10.250.62 SIP/2.0
Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK5286369c13a02805
From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
To: <sip:666@10.10.250.62>;tag=as73a4778b
Contact: <sip:400@10.10.7.37>
Authorization: Digest username="400", realm="callweaver.org", algorithm=MD5, uri="sip:666@10.10.250.62", nonce="3814410f", response="e0b77cddaa74266cbfc42425fe15768d"
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 5258 ACK
User-Agent: Grandstream HT386 1.0.3.64 FXS1
Max-Forwards: 70
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Content-Length: 0
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 0: ACK sip:666@10.10.250.62 SIP/2.0 (32)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.7.37;branch=z9hG4bK5286369c13a02805 (58)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 2: From: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f (49)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:666@10.10.250.62>;tag=as73a4778b (41)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 4: Contact: <sip:400@10.10.7.37> (29)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 5: Authorization: Digest username="400", realm="callweaver.org", algorithm=MD5, uri="sip:666@10.10.250.62", nonce="3814410f", response="e0b77cddaa74266cbfc42425fe15768d" (166)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 6: Call-ID: f66398437721a5ce@10.10.7.37 (36)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 7: CSeq: 5258 ACK (14)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 8: User-Agent: Grandstream HT386 1.0.3.64 FXS1 (43)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 9: Max-Forwards: 70 (16)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 10: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 11: Content-Length: 0 (17)
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Header 12: (0)
Apr 25 16:57:25 VERBOSE[2988723104] logger.c: --- (12 headers 0 lines) ---
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: = Found Their Call ID: f66398437721a5ce@10.10.7.37 Their Tag 40e2b4adca7ff28f Our tag: as73a4778b
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #11
Apr 25 16:57:25 DEBUG[2988723104] chan_sip.c: Stopping retransmission on 'f66398437721a5ce@10.10.7.37' of Response 5258: Match Found
Apr 25 16:57:25 DEBUG[3079719840] devicestate.c: Changing state for SIP/400 - state 2 (In use)
Apr 25 16:57:25 DEBUG[2983340960] app_queue.c: Device 'SIP/400' changed to state '2' (In use)
Apr 25 16:57:25 DEBUG[2983607200] rtp.c: Ooh, format changed from unknown to ulaw
Apr 25 16:57:25 DEBUG[2983607200] rtp.c: Had to change frame MS from 0 to 20
Apr 25 16:57:25 DEBUG[2983607200] rtp.c: Able to create smoother :) ms: 20 len 160
Apr 25 16:57:27 DEBUG[2983607200] app_faxdetect.c: Start of voice token
Apr 25 16:57:27 DEBUG[2983607200] app_faxdetect.c: Fax detected on SIP/400-66a0
Apr 25 16:57:27 NOTICE[2983607200] app_faxdetect.c: Redirecting SIP/400-66a0 to fax extension [DTMF]
Apr 25 16:57:27 DEBUG[2983607200] channel.c: Set channel SIP/400-66a0 to read format ulaw
Apr 25 16:57:27 DEBUG[2983607200] channel.c: Set channel SIP/400-66a0 to write format ulaw
Apr 25 16:57:27 DEBUG[2983607200] pbx.c: Launching 'SipT38SwitchOver'
Apr 25 16:57:27 VERBOSE[2983607200] logger.c: -- Executing SipT38SwitchOver("SIP/400-66a0", "") in new stack
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Forcing reinvite on SIP (SIP/400-66a0) for T.38 negotiation.
Apr 25 16:57:27 VERBOSE[2983607200] logger.c: set_destination: Parsing <sip:400@10.10.7.37> for address/port to send to
Apr 25 16:57:27 VERBOSE[2983607200] logger.c: set_destination: set destination to 10.10.7.37, port 5060
Apr 25 16:57:27 VERBOSE[2983607200] logger.c: T.38 UDPTL is at port 10.10.250.62:11564
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Our T38 capability (12048), peer T38 capability (0), joint capability (12048)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: T38MaxFaxRate 14400 found
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 0: INVITE sip:400@10.10.7.37 SIP/2.0 (33)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK3e672f4e (57)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 2: From: <sip:666@10.10.250.62>;tag=as73a4778b (43)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 3: To: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f (47)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 4: Contact: <sip:666@10.10.250.62> (31)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 5: Call-ID: f66398437721a5ce@10.10.7.37 (36)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 6: CSeq: 102 INVITE (16)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 7: User-Agent: CallWeaver (22)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 8: Max-Forwards: 70 (16)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 10: X-callweaver-info: SIP re-invite (T38 switchover) (49)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 11: Content-Type: application/sdp (29)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 12: Content-Length: 0 (17)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Header 13: (0)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: v=0 (3)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: o=root 23771 23772 IN IP4 10.10.250.62 (38)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: s=session (9)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: c=IN IP4 10.10.250.62 (21)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: t=0 0 (5)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: m=image 11564 udptl t38 (23)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: a=T38FaxVersion:0 (17)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: a=T38MaxBitRate:14400 (21)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: a=T38FaxFillBitRemoval:0 (24)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: a=T38FaxTranscodingMMR:0 (24)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: a=T38FaxTranscodingJBIG:0 (25)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: a=T38FaxRateManagement:transferredTCF (37)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: a=T38FaxMaxBuffer:400 (21)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: a=T38FaxMaxDatagram:400 (23)
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: Line: a=T38FaxUdpEC:t38UDPFEC (23)
Apr 25 16:57:27 VERBOSE[2983607200] logger.c: 13 headers, 15 lines
Apr 25 16:57:27 VERBOSE[2983607200] logger.c: Reliably Transmitting (NAT) to 10.10.7.37:5060:
INVITE sip:400@10.10.7.37 SIP/2.0
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK3e672f4e
From: <sip:666@10.10.250.62>;tag=as73a4778b
To: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
Contact: <sip:666@10.10.250.62>
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 102 INVITE
User-Agent: CallWeaver
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
X-callweaver-info: SIP re-invite (T38 switchover)
Content-Type: application/sdp
Content-Length: 344
v=0
o=root 23771 23772 IN IP4 10.10.250.62
s=session
c=IN IP4 10.10.250.62
t=0 0
m=image 11564 udptl t38
a=T38FaxVersion:0
a=T38MaxBitRate:14400
a=T38FaxFillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:400
a=T38FaxMaxDatagram:400
a=T38FaxUdpEC:t38UDPFEC
---
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #12
Apr 25 16:57:27 DEBUG[2983607200] chan_sip.c: T38 state changed to 2 on channel SIP/400-66a0
Apr 25 16:57:27 DEBUG[2983607200] pbx.c: Launching 'RxFAX'
Apr 25 16:57:27 VERBOSE[2983607200] logger.c: -- Executing RxFAX("SIP/400-66a0", "(/opt/tmp/fax.tif|debug|ecm") in new stack
Apr 25 16:57:27 DEBUG[2983607200] channel.c: Set channel SIP/400-66a0 to read format slin
Apr 25 16:57:27 DEBUG[2983607200] channel.c: Set channel SIP/400-66a0 to write format slin
Apr 25 16:57:28 DEBUG[2983607200] app_rxfax.c: Enabling ECM mode for app_rxfax
Apr 25 16:57:28 NOTICE[2983607200] channel.c: Dropping incompatible voice frame on SIP/400-66a0 of format slin since our native format has changed to ulaw
Apr 25 16:57:28 VERBOSE[2988723104] logger.c:
<-- SIP read from 10.10.7.37:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK3e672f4e
From: <sip:666@10.10.250.62>;tag=as73a4778b
To: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 102 INVITE
User-Agent: Grandstream HT386 1.0.3.64 FXS1
Contact: <sip:400@10.10.7.37>
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Content-Type: application/sdp
Supported: replaces
Content-Length: 336
v=0
o=400 8000 8002 IN IP4 10.10.7.37
s=SIP Call
c=IN IP4 10.10.7.37
t=0 0
m=image 5008 udptl t38
a=T38FaxVersion:0
a=T38MaxBitRate:9600
a=T38FaxFillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:400
a=T38FaxMaxDatagram:400
a=T38FaxUdpEC:t38UDPFEC
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 0: SIP/2.0 200 OK (14)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK3e672f4e (57)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 2: From: <sip:666@10.10.250.62>;tag=as73a4778b (43)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f (47)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 4: Call-ID: f66398437721a5ce@10.10.7.37 (36)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 5: CSeq: 102 INVITE (16)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 6: User-Agent: Grandstream HT386 1.0.3.64 FXS1 (43)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 7: Contact: <sip:400@10.10.7.37> (29)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 9: Content-Type: application/sdp (29)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 10: Supported: replaces (19)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 11: Content-Length: 336 (19)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Header 12: (0)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: v=0 (3)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: o=400 8000 8002 IN IP4 10.10.7.37 (33)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: s=SIP Call (10)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: c=IN IP4 10.10.7.37 (19)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: t=0 0 (5)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: m=image 5008 udptl t38 (22)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: a=T38FaxVersion:0 (17)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: a=T38MaxBitRate:9600 (20)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: a=T38FaxFillBitRemoval:0 (24)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: a=T38FaxTranscodingMMR:0 (24)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: a=T38FaxTranscodingJBIG:0 (25)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: a=T38FaxRateManagement:transferredTCF (37)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: a=T38FaxMaxBuffer:400 (21)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: a=T38FaxMaxDatagram:400 (23)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Line: a=T38FaxUdpEC:t38UDPFEC (23)
Apr 25 16:57:28 VERBOSE[2988723104] logger.c: --- (12 headers 15 lines) ---
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: = Found Their Call ID: f66398437721a5ce@10.10.7.37 Their Tag 40e2b4adca7ff28f Our tag: as73a4778b
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Acked pending invite 102
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #12
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Stopping retransmission on 'f66398437721a5ce@10.10.7.37' of Request 102: Match Found
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: SIP response 200 to RE-invite on outgoing call f66398437721a5ce@10.10.7.37
Apr 25 16:57:28 VERBOSE[2988723104] logger.c: Got T.38 offer in SDP
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Activating UDPTL on response f66398437721a5ce@10.10.7.37 (1)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: T38 state changed to 4 on channel SIP/400-66a0
Apr 25 16:57:28 VERBOSE[2988723104] logger.c: Peer T.38 UDPTL is at port 10.10.7.37:5008
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Peer T.38 UDPTL is at port 10.10.7.37:5008
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: FaxVersion: 0
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: T38MaxBitRate: 9600
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: FillBitRemoval: 0
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Transcoding MMR: 0
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Transcoding JBIG: 0
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: RateMangement: transferredTCF
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: MaxBufferSize:400
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: FaxMaxDatagram: 400
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: UDP EC: t38UDPFEC
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Our T38 capability = (12048), peer T38 capability (3856), joint T38 capability (3856)
Apr 25 16:57:28 VERBOSE[2988723104] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x515 (g723|ulaw|g726|g729|ilbc)/video=0x0 (nothing), combined - 0x4 (ulaw)
Apr 25 16:57:28 VERBOSE[2988723104] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: build_route: Contact hop: <sip:400@10.10.7.37>
Apr 25 16:57:28 VERBOSE[2988723104] logger.c: list_route: hop: <sip:400@10.10.7.37>
Apr 25 16:57:28 DEBUG[2988723104] chan_sip.c: Channel Bridge information is non-existant. T38 Termination requested.
Apr 25 16:57:28 VERBOSE[2988723104] logger.c: set_destination: Parsing <sip:400@10.10.7.37> for address/port to send to
Apr 25 16:57:28 VERBOSE[2988723104] logger.c: set_destination: set destination to 10.10.7.37, port 5060
Apr 25 16:57:28 VERBOSE[2988723104] logger.c: Transmitting (NAT) to 10.10.7.37:5060:
ACK sip:400@10.10.7.37 SIP/2.0
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK61e9625f
From: <sip:666@10.10.250.62>;tag=as73a4778b
To: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
Contact: <sip:666@10.10.250.62>
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 102 ACK
User-Agent: CallWeaver
Max-Forwards: 70
Content-Length: 0
---
Apr 25 16:57:28 DEBUG[2983607200] app_rxfax.c: Enabling ECM mode for app_rxfax
Apr 25 16:57:28 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 0: indicator no-signal
Apr 25 16:57:28 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 0, len 8)
Apr 25 16:57:28 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 10)
Apr 25 16:57:28 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 0: 00
Apr 25 16:57:28 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 0: indicator no-signal
Apr 25 16:57:28 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 10)
Apr 25 16:57:28 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 0: 00
Apr 25 16:57:28 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 0: Repeat packet number
Apr 25 16:57:28 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 10)
Apr 25 16:57:28 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 0: 00
Apr 25 16:57:28 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 0: Repeat packet number
Apr 25 16:57:28 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 1: indicator ced
Apr 25 16:57:28 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 1, len 8)
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Send complete in phase T30_PHASE_A_CED, state 1
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Starting answer mode
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from phase T30_PHASE_A_CED to T30_PHASE_B_TX
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set rx type 0
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set tx type 4
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 DIS:
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...1= Store and forward Internet fax (T.37): Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .1..= Real-time Internet fax (T.38): Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= 3G mobile network: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= V.8 capabilities: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Preferred octets: 256 octets
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Can receive fax: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= 2-D coding: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..10= Recording width: 215 mm +- 1-0x1.38f28b7e86f08p-226nd 255 mm +- 1 0x0.00005b7e0d57fp-1022nd 303 mm +- 1%
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 10..= Recording length: Unlimited
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .111 ....= Receiver's minimum scan line time: 0 ms at 3.85 l/mm: T7.7 = T3.85
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .1..= Error correction mode (ECM): ECM
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .1.. ....= T.6 coding: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= "Field not valid" supported: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Multiple selective polling: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Polled subaddress: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= T.43 coding: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...0 ....= Plane interleave: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...1= R8x15.4lines/mm: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4 mm: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 1...= Inch-based resolution preferred: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...0 ....= Metric-based resolution preferred: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Selective polling: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= Subaddressing: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Password: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= Character mode: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Digital network capability: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Duplex capability: Half only
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= JPEG coding: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...0 ....= Full colour mode: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= 12bits/pel component: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= No subsampling (1:1:1): Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Custom illuminant: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Custom gamut range: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 1...= North American Letter (215.9mm x 279.4mm): Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...1 ....= North American Legal (215.9mm x 355.6mm): Set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 0... ....= Extension indicator: Not set
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from state 1 to 15
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Sending ident 'Navynet.it FAX'
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Tx: CSI without final frame tag
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Tx: ff 03 40 58 41 46 20 74 69 2e 74 65 6e 79 76 61 4e 20 20 20 20 20 20
Apr 25 16:57:31 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 2: indicator v21-preamble
Apr 25 16:57:31 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 2, len 8)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 3: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 3: c0 01 80 00 00 ff
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 3, len 15)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 4: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 4: c0 01 80 00 00 c0
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 4, len 20)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 5: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 5: c0 01 80 00 00 02
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 5, len 20)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 6: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 6: c0 01 80 00 00 1a
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 6, len 27)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 7: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 7: c0 01 80 00 00 82
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 7, len 27)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 8: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 8: c0 01 80 00 00 62
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 8, len 27)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 9: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 9: c0 01 80 00 00 04
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 9, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 10: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 10: c0 01 80 00 00 2e
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 10, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 11: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 11: c0 01 80 00 00 96
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 11, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 12: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 12: c0 01 80 00 00 74
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 12, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 13: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 13: c0 01 80 00 00 2e
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 13, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 14: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 14: c0 01 80 00 00 a6
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 14, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 15: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 15: c0 01 80 00 00 76
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 15, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 16: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 16: c0 01 80 00 00 9e
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 16, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 17: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 17: c0 01 80 00 00 6e
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 17, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 18: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 18: c0 01 80 00 00 86
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 18, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 19: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 19: c0 01 80 00 00 72
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 19, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 20: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 20: c0 01 80 00 00 04
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 20, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 21: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 21: c0 01 80 00 00 04
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 21, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 22: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 22: c0 01 80 00 00 04
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 22, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 23: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 23: c0 01 80 00 00 04
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 23, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 24: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 24: c0 01 80 00 00 04
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 24, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 25: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 25: c0 01 80 00 00 04
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 25, len 34)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 15
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Tx: DIS with final frame tag
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Tx: ff 13 80 05 ee fa c4 80 8d 80 80 80 18
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 26: data v21/hdlc-fcs-OK + 0 byte(s)
Apr 25 16:57:32 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 26: c0 01 20
Apr 25 16:57:32 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 26, len 31)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 27: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 27: c0 01 80 00 00 ff
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 27, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 28: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 28: c0 01 80 00 00 c8
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 28, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 29: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 29: c0 01 80 00 00 01
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 29, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 30: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 30: c0 01 80 00 00 a0
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 30, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 31: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 31: c0 01 80 00 00 77
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 31, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 32: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 32: c0 01 80 00 00 5f
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 32, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 33: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 33: c0 01 80 00 00 23
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 33, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 34: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 34: c0 01 80 00 00 01
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 34, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 35: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 35: c0 01 80 00 00 b1
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 35, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 36: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 36: c0 01 80 00 00 01
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 36, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 37: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 37: c0 01 80 00 00 01
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 37, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 38: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 38: c0 01 80 00 00 01
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 38, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 39: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 39: c0 01 80 00 00 18
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 39, len 34)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 15
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 40: data v21/hdlc-fcs-OK-sig-end + 0 byte(s)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 40: c0 01 40
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 40, len 31)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 41: indicator no-signal
Apr 25 16:57:33 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 41, len 29)
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 15
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_B_RX
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set rx type 4
Apr 25 16:57:33 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set tx type 0
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 T4 timeout in phase T30_PHASE_B_RX, state 15
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_B_TX
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set rx type 0
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set tx type 4
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 DIS:
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...1= Store and forward Internet fax (T.37): Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .1..= Real-time Internet fax (T.38): Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= 3G mobile network: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= V.8 capabilities: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Preferred octets: 256 octets
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= Ready to transmit a fax document (polling): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..1.= Can receive fax: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= 2-D coding: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..10= Recording width: 215 mm +- 1-0x1.38ef8b7e86f08p-226nd 255 mm +- 1 0x0.00005b7e0d57fp-1022nd 303 mm +- 1%
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 10..= Recording length: Unlimited
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .111 ....= Receiver's minimum scan line time: 0 ms at 3.85 l/mm: T7.7 = T3.85
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .1..= Error correction mode (ECM): ECM
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .1.. ....= T.6 coding: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= "Field not valid" supported: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Multiple selective polling: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Polled subaddress: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= T.43 coding: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...0 ....= Plane interleave: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...1= R8x15.4lines/mm: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4 mm: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 1...= Inch-based resolution preferred: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...0 ....= Metric-based resolution preferred: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Selective polling: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= Subaddressing: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Password: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Ready to transmit a data file (polling): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...0 ....= Binary file transfer (BFT): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Document transfer mode (DTM): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Electronic data interchange (EDI): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= Basic transfer mode (BTM): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Ready to transfer a character or mixed mode document (polling): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= Character mode: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Mixed mode (Annex E/T.4): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= Processable mode 26 (Rec. T.505): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Digital network capability: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Duplex capability: Half only
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= JPEG coding: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...0 ....= Full colour mode: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= 12bits/pel component: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= No subsampling (1:1:1): Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Custom illuminant: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Custom gamut range: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 1...= North American Letter (215.9mm x 279.4mm): Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...1 ....= North American Legal (215.9mm x 355.6mm): Set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 0... ....= Extension indicator: Not set
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Sending ident 'Navynet.it FAX'
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Tx: CSI without final frame tag
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Tx: ff 03 40 58 41 46 20 74 69 2e 74 65 6e 79 76 61 4e 20 20 20 20 20 20
Apr 25 16:57:36 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 42: indicator v21-preamble
Apr 25 16:57:36 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 42, len 29)
Apr 25 16:57:37 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 43: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:37 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 43: c0 01 80 00 00 ff
Apr 25 16:57:37 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 43, len 34)
Apr 25 16:57:37 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 44: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:37 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 44: c0 01 80 00 00 c0
Apr 25 16:57:37 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 44, len 34)
Apr 25 16:57:37 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 45: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:37 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 45: c0 01 80 00 00 02
Apr 25 16:57:37 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 45, len 34)
Apr 25 16:57:37 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 46: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:37 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 46: c0 01 80 00 00 1a
Apr 25 16:57:37 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 46, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 47: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 47: c0 01 80 00 00 82
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 47, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 48: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 48: c0 01 80 00 00 62
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 48, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 49: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 49: c0 01 80 00 00 04
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 49, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 50: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 50: c0 01 80 00 00 2e
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 50, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 51: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 51: c0 01 80 00 00 96
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 51, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 52: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 52: c0 01 80 00 00 74
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 52, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 53: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 53: c0 01 80 00 00 2e
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 53, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 54: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 54: c0 01 80 00 00 a6
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 54, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 55: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 55: c0 01 80 00 00 76
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 55, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 56: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 56: c0 01 80 00 00 9e
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 56, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 57: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 57: c0 01 80 00 00 6e
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 57, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 58: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 58: c0 01 80 00 00 86
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 58, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 59: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 59: c0 01 80 00 00 72
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 59, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 60: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 60: c0 01 80 00 00 04
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 60, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 61: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 61: c0 01 80 00 00 04
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 61, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 62: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 62: c0 01 80 00 00 04
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 62, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 63: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 63: c0 01 80 00 00 04
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 63, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 64: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 64: c0 01 80 00 00 04
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 64, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 65: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 65: c0 01 80 00 00 04
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 65, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 15
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Tx: DIS with final frame tag
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Tx: ff 13 80 05 ee fa c4 80 8d 80 80 80 18
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 66: data v21/hdlc-fcs-OK + 0 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 66: c0 01 20
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 66, len 31)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 67: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 67: c0 01 80 00 00 ff
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 67, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 68: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 68: c0 01 80 00 00 c8
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 68, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 69: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 69: c0 01 80 00 00 01
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 69, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 70: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 70: c0 01 80 00 00 a0
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 70, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 71: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 71: c0 01 80 00 00 77
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 71, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 72: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 72: c0 01 80 00 00 5f
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 72, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 73: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 73: c0 01 80 00 00 23
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 73, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 74: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 74: c0 01 80 00 00 01
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 74, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 75: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 75: c0 01 80 00 00 b1
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 75, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 76: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 76: c0 01 80 00 00 01
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 76, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 77: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 77: c0 01 80 00 00 01
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 77, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 78: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 78: c0 01 80 00 00 01
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 78, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 79: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 79: c0 01 80 00 00 18
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 79, len 34)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 15
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 80: data v21/hdlc-fcs-OK-sig-end + 0 byte(s)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 80: c0 01 40
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 80, len 31)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 81: indicator no-signal
Apr 25 16:57:38 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 81, len 29)
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Send complete in phase T30_PHASE_B_TX, state 15
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from phase T30_PHASE_B_TX to T30_PHASE_B_RX
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set rx type 4
Apr 25 16:57:38 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set tx type 0
Apr 25 16:57:39 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 10)
Apr 25 16:57:39 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 1: 06
Apr 25 16:57:39 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 1: indicator v21-preamble
Apr 25 16:57:39 DEBUG[2983607200] app_rxfax.c: FLOW T.30 HDLC carrier up in state 15
Apr 25 16:57:39 DEBUG[2983607200] app_rxfax.c: FLOW T.30 HDLC framing OK in state 15
Apr 25 16:57:39 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 10)
Apr 25 16:57:39 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 1: 06
Apr 25 16:57:39 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 1: Repeat packet number
Apr 25 16:57:39 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 10)
Apr 25 16:57:39 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 1: 06
Apr 25 16:57:39 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 1: Repeat packet number
Apr 25 16:57:40 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 15)
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 65533: 00
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 65533: Late packet - expected 2
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 65534: 00
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 65534: Late packet - expected 2
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 65535: 00
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 65535: Late packet - expected 2
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 2: c0 01 80 00 00 ff
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 2: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:40 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 3: c0 01 80 00 00 c0
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 3: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:40 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 4: c0 01 80 00 00 c2
Apr 25 16:57:40 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 4: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 5: c0 01 80 00 00 ac
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 5: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 6: c0 01 80 00 00 4c
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 6: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 7: c0 01 80 00 00 4c
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 7: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 8: c0 01 80 00 00 6c
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 8: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 9: c0 01 80 00 00 1c
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 9: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 10: c0 01 80 00 00 6c
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 10: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 11: c0 01 80 00 00 6c
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 11: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 12: c0 01 80 00 00 6c
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 12: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 13: c0 01 80 00 00 6c
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 13: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 14: c0 01 80 00 00 1c
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 14: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 15: c0 01 80 00 00 8c
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 15: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 16: c0 01 80 00 00 04
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 16: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 17: c0 01 80 00 00 04
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 17: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 18: c0 01 80 00 00 04
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 18: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 19: c0 01 80 00 00 04
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 19: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 20: c0 01 80 00 00 04
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 20: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 21: c0 01 80 00 00 04
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 21: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 22: c0 01 80 00 00 04
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 22: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 23: c0 01 80 00 00 04
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 23: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 24: c0 01 80 00 00 04
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 24: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 17)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 25: c0 01 20
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 25: data v21/hdlc-fcs-OK + 0 byte(s)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Type TSI - CRC OK (clean)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Rx: TSI without final frame tag
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Rx: ff 03 43 35 32 32 36 38 36 36 36 36 38 31 20 20 20 20 20 20 20 20 20
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Remote fax gave TSI as: "18666686225"
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 26: c0 01 80 00 00 ff
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 26: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 27: c0 01 80 00 00 c8
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 27: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 28: c0 01 80 00 00 c1
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 28: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 29: c0 01 80 00 00 00
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 29: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 30: c0 01 80 00 00 60
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 30: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 31: c0 01 80 00 00 15
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 31: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 32: c0 01 80 00 00 01
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 32: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 33: c0 01 80 00 00 01
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 33: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 20)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 34: c0 01 80 00 00 00
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 34: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 17)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 35: c0 01 40
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 35: data v21/hdlc-fcs-OK-sig-end + 0 byte(s)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Type DCS - CRC OK, sig end (clean)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Rx: DCS with final frame tag
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Rx: ff 13 83 00 06 a8 80 80 00
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 In state 15
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 DCS:
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= Store and forward Internet fax (T.37): Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Real-time Internet fax (T.38): Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= 3G mobile network: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..1.= Can receive fax: Set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..00 01..= Selected data signalling rate: V.29, 9600bps
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 0... ....= 2-D coding: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..00= Recording width: 215 mm +- 1%
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 10..= Recording length: Unlimited
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .010 ....= Minimum scan line time: 10 ms
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= Compressed/uncompressed mode: Compressed
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= Error correction mode (ECM): Non-ECM
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= Frame size: 256 octets
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= T.6 coding: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= "Field not valid" supported: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= T.43 coding: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ...0 ....= Plane interleave: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .0.. ....= Reserved for the use of extended voice coding set: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 1... ....= Extension indicator: Set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ...0= R8x15.4lines/mm: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... ..0.= 300x300pels/25.4mm: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... .0..= R16x15.4lines/mm and/or 400x400pels/25.4 mm: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 .... 0...= Resolution type selection: Metric
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 0... ....= Extension indicator: Not set
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Selected compression 1
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Get document at 9600bps, modem 8
Apr 25 16:57:41 WARNING[2983607200] app_rxfax.c: WARNING T.30 Cannot open target TIFF file '(/opt/tmp/fax.tif'
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from state 15 to 3
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Tx: DCN with final frame tag
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Tx: ff 13 fa
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 HDLC carrier down in state 3
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_D_TX
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set rx type 0
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set tx type 4
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 82: indicator v21-preamble
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 82, len 29)
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 15)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 36: 00
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 36: indicator no-signal
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 15)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 36: 00
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 36: Repeat packet number
Apr 25 16:57:41 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 15)
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 36: 00
Apr 25 16:57:41 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 36: Repeat packet number
Apr 25 16:57:42 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 15)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 37: 0e
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 37: indicator v29-9600-training
Apr 25 16:57:42 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 15)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 37: 0e
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 37: Repeat packet number
Apr 25 16:57:42 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 15)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 37: 0e
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 37: Repeat packet number
Apr 25 16:57:42 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 64)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 38: c8 01 e0 00 2f 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 38: data v29-9600/t4-non-ecm-data + 48 byte(s)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Non-ECM carrier trained in state 3
Apr 25 16:57:42 VERBOSE[2983607200] logger.c: Got UDPTL packet from 10.10.7.37:5008 (len 114)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 39: c8 01 e0 00 2f 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Rx 39: data v29-9600/t4-non-ecm-data + 48 byte(s)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 83: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 83: c0 01 80 00 00 ff
Apr 25 16:57:42 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 83, len 34)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 84: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 84: c0 01 80 00 00 c8
Apr 25 16:57:42 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 84, len 34)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 85: data v21/hdlc-data + 1 byte(s)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 85: c0 01 80 00 00 5f
Apr 25 16:57:42 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 85, len 34)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 3
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 86: data v21/hdlc-fcs-OK-sig-end + 0 byte(s)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 86: c0 01 40
Apr 25 16:57:42 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 86, len 31)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38 Tx 87: indicator no-signal
Apr 25 16:57:42 VERBOSE[2983607200] logger.c: Sent UDPTL packet to 10.10.7.37:5008 (seq 87, len 29)
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 3
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Disconnecting
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from phase T30_PHASE_D_TX to T30_PHASE_E
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set rx type 0
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set tx type 1
Apr 25 16:57:42 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from state 3 to 2
Apr 25 16:57:44 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Send complete in phase T30_PHASE_E, state 2
Apr 25 16:57:44 DEBUG[2983607200] app_rxfax.c: ==============================================================================
Apr 25 16:57:44 DEBUG[2983607200] app_rxfax.c: Fax receive not successful - result (14) TIFF/F file cannot be opened.
Apr 25 16:57:44 DEBUG[2983607200] app_rxfax.c: ==============================================================================
Apr 25 16:57:44 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from state 2 to 30
Apr 25 16:57:44 DEBUG[2983607200] app_rxfax.c: FLOW T.30 Changing from phase T30_PHASE_E to T30_PHASE_CALL_FINISHED
Apr 25 16:57:44 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set rx type 13
Apr 25 16:57:44 DEBUG[2983607200] app_rxfax.c: FLOW T.38T Set tx type 13
Apr 25 16:57:44 DEBUG[2983607200] app_rxfax.c: FLOW T.38T FAX exchange complete
Apr 25 16:57:44 DEBUG[2983607200] channel.c: Set channel SIP/400-66a0 to read format ulaw
Apr 25 16:57:44 DEBUG[2983607200] channel.c: Set channel SIP/400-66a0 to write format ulaw
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Launching 'NoOp'
Apr 25 16:57:44 VERBOSE[2983607200] logger.c: -- Executing NoOp("SIP/400-66a0", "RX: REMOTESTATIONID is 18666686225") in new stack
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Launching 'NoOp'
Apr 25 16:57:44 VERBOSE[2983607200] logger.c: -- Executing NoOp("SIP/400-66a0", "RX: PHASEESTATUS is 14") in new stack
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Launching 'Hangup'
Apr 25 16:57:44 VERBOSE[2983607200] logger.c: -- Executing Hangup("SIP/400-66a0", "") in new stack
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Spawn extension (sipfax,fax,5) exited non-zero on 'SIP/400-66a0'
Apr 25 16:57:44 VERBOSE[2983607200] logger.c: == Spawn extension (sipfax, fax, 5) exited non-zero on 'SIP/400-66a0'
Apr 25 16:57:44 DEBUG[2983607200] cdr_sqlite3.c: CDR SQLITE3 SQL [INSERT INTO cdr (clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata, start,answer,end,duration,billsec,disposition,amaflags, accountcode) VALUES ('"ATA" <400>', '400', 'fax', 'sipfax', 'SIP/400-66a0', '', 'Hangup', '', '2007-04-25 16:57:25', '2007-04-25 16:57:25', '2007-04-25 16:57:44', 19, 19, 4, 3, '')]
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '"ATA" <400>'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '400'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is 'fax'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is 'sipfax'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is 'SIP/400-66a0'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '(null)'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is 'Hangup'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '(null)'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '2007-04-25 16:57:25'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '2007-04-25 16:57:25'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '2007-04-25 16:57:44'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '19'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '19'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is 'ANSWERED'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is 'DOCUMENTATION'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '(null)'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '1177534645.0'
Apr 25 16:57:44 DEBUG[2983607200] pbx.c: Function result is '(null)'
Apr 25 16:57:44 DEBUG[2983607200] channel.c: Hanging up channel 'SIP/400-66a0'
Apr 25 16:57:44 DEBUG[2983607200] chan_sip.c: Hangup call SIP/400-66a0, SIP callid f66398437721a5ce@10.10.7.37)
Apr 25 16:57:44 DEBUG[2983607200] chan_sip.c: update_call_counter(400) - decrement call limit counter
Apr 25 16:57:44 DEBUG[2983607200] chan_sip.c: Updating call counter for outgoing call
Apr 25 16:57:44 VERBOSE[2983607200] logger.c: Scheduling destruction of call 'f66398437721a5ce@10.10.7.37' in 32000 ms
Apr 25 16:57:44 VERBOSE[2983607200] logger.c: set_destination: Parsing <sip:400@10.10.7.37> for address/port to send to
Apr 25 16:57:44 VERBOSE[2983607200] logger.c: set_destination: set destination to 10.10.7.37, port 5060
Apr 25 16:57:44 VERBOSE[2983607200] logger.c: Reliably Transmitting (NAT) to 10.10.7.37:5060:
BYE sip:400@10.10.7.37 SIP/2.0
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK1eb89a48
From: <sip:666@10.10.250.62>;tag=as73a4778b
To: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
Contact: <sip:666@10.10.250.62>
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 103 BYE
User-Agent: CallWeaver
Max-Forwards: 70
Content-Length: 0
---
Apr 25 16:57:44 DEBUG[2983607200] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #14
Apr 25 16:57:44 DEBUG[2983607200] channel.c: Generator : deactivate after channel unlock (hangup function)
Apr 25 16:57:44 DEBUG[2983607200] generator.c: Trying to deactivate generator in SIP/400-66a0
Apr 25 16:57:44 VERBOSE[2988723104] logger.c:
<-- SIP read from 10.10.7.37:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK1eb89a48
From: <sip:666@10.10.250.62>;tag=as73a4778b
To: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f
Call-ID: f66398437721a5ce@10.10.7.37
CSeq: 103 BYE
User-Agent: Grandstream HT386 1.0.3.64 FXS1
Contact: <sip:400@10.10.7.37>
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Supported: replaces
Content-Length: 0
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 0: SIP/2.0 200 OK (14)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK1eb89a48 (57)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 2: From: <sip:666@10.10.250.62>;tag=as73a4778b (43)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:400@10.10.250.62>;tag=40e2b4adca7ff28f (47)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 4: Call-ID: f66398437721a5ce@10.10.7.37 (36)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 5: CSeq: 103 BYE (13)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 6: User-Agent: Grandstream HT386 1.0.3.64 FXS1 (43)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 7: Contact: <sip:400@10.10.7.37> (29)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 9: Supported: replaces (19)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 10: Content-Length: 0 (17)
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Header 11: (0)
Apr 25 16:57:44 VERBOSE[2988723104] logger.c: --- (11 headers 0 lines) ---
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: = Found Their Call ID: f66398437721a5ce@10.10.7.37 Their Tag 40e2b4adca7ff28f Our tag: as73a4778b
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #14
Apr 25 16:57:44 DEBUG[2988723104] chan_sip.c: Stopping retransmission on 'f66398437721a5ce@10.10.7.37' of Request 103: Match Found
Apr 25 16:57:44 VERBOSE[2988723104] logger.c: Destroying call 'f66398437721a5ce@10.10.7.37'
Apr 25 16:57:44 DEBUG[2983607200] generator.c: Generator on SIP/400-66a0 stopped after 0 iterations
Apr 25 16:57:44 DEBUG[3079719840] chan_sip.c: Checking device state for peer 400
Apr 25 16:57:44 DEBUG[3079719840] devicestate.c: Changing state for SIP/400 - state 1 (Not in use)
Apr 25 16:57:44 DEBUG[2983607200] app_queue.c: Device 'SIP/400' changed to state '1' (Not in use)
Apr 25 16:57:54 VERBOSE[2983873440] logger.c: -- Remote UNIX connection disconnected
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 0: OPTIONS sip:400@10.10.7.37 SIP/2.0 (34)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK3e2c8960 (57)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 2: From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as315d23c2 (63)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:400@10.10.7.37> (24)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 4: Contact: <sip:callweaver@10.10.250.62> (38)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 5: Call-ID: 478c715a657d126b40de5d21546ed0ae@10.10.250.62 (54)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 7: User-Agent: CallWeaver (22)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 8: Max-Forwards: 70 (16)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 9: Date: Wed, 25 Apr 2007 20:58:09 GMT (35)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 11: Content-Length: 0 (17)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 12: (0)
Apr 25 16:58:09 VERBOSE[2988723104] logger.c: 12 headers, 0 lines
Apr 25 16:58:09 VERBOSE[2988723104] logger.c: Reliably Transmitting (NAT) to 10.10.7.37:5060:
OPTIONS sip:400@10.10.7.37 SIP/2.0
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK3e2c8960
From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as315d23c2
To: <sip:400@10.10.7.37>
Contact: <sip:callweaver@10.10.250.62>
Call-ID: 478c715a657d126b40de5d21546ed0ae@10.10.250.62
CSeq: 102 OPTIONS
User-Agent: CallWeaver
Max-Forwards: 70
Date: Wed, 25 Apr 2007 20:58:09 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0
---
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #15
Apr 25 16:58:09 VERBOSE[2988723104] logger.c:
<-- SIP read from 10.10.7.37:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK3e2c8960
From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as315d23c2
To: <sip:400@10.10.7.37>;tag=2249234db585fb57
Call-ID: 478c715a657d126b40de5d21546ed0ae@10.10.250.62
CSeq: 102 OPTIONS
User-Agent: Grandstream HT386 1.0.3.64 FXS1
Contact: <sip:400@10.10.7.37>
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Supported: replaces
Content-Length: 0
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 0: SIP/2.0 200 OK (14)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK3e2c8960 (57)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 2: From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as315d23c2 (63)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:400@10.10.7.37>;tag=2249234db585fb57 (45)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 4: Call-ID: 478c715a657d126b40de5d21546ed0ae@10.10.250.62 (54)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 6: User-Agent: Grandstream HT386 1.0.3.64 FXS1 (43)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 7: Contact: <sip:400@10.10.7.37> (29)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 9: Supported: replaces (19)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 10: Content-Length: 0 (17)
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Header 11: (0)
Apr 25 16:58:09 VERBOSE[2988723104] logger.c: --- (11 headers 0 lines) ---
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: = Found Their Call ID: 478c715a657d126b40de5d21546ed0ae@10.10.250.62 Their Tag Our tag: as315d23c2
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #15
Apr 25 16:58:09 DEBUG[2988723104] chan_sip.c: Stopping retransmission on '478c715a657d126b40de5d21546ed0ae@10.10.250.62' of Request 102: Match Found
Apr 25 16:58:09 VERBOSE[2988723104] logger.c: Destroying call '478c715a657d126b40de5d21546ed0ae@10.10.250.62'
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 0: OPTIONS sip:400@10.10.7.37 SIP/2.0 (34)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK4f349c26 (57)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 2: From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as5ac7325e (63)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:400@10.10.7.37> (24)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 4: Contact: <sip:callweaver@10.10.250.62> (38)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 5: Call-ID: 5a0da3e651ff752e4c54e72f0d85b27d@10.10.250.62 (54)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 7: User-Agent: CallWeaver (22)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 8: Max-Forwards: 70 (16)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 9: Date: Wed, 25 Apr 2007 20:59:09 GMT (35)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 11: Content-Length: 0 (17)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 12: (0)
Apr 25 16:59:09 VERBOSE[2988723104] logger.c: 12 headers, 0 lines
Apr 25 16:59:09 VERBOSE[2988723104] logger.c: Reliably Transmitting (NAT) to 10.10.7.37:5060:
OPTIONS sip:400@10.10.7.37 SIP/2.0
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK4f349c26
From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as5ac7325e
To: <sip:400@10.10.7.37>
Contact: <sip:callweaver@10.10.250.62>
Call-ID: 5a0da3e651ff752e4c54e72f0d85b27d@10.10.250.62
CSeq: 102 OPTIONS
User-Agent: CallWeaver
Max-Forwards: 70
Date: Wed, 25 Apr 2007 20:59:09 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0
---
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #18
Apr 25 16:59:09 VERBOSE[2988723104] logger.c:
<-- SIP read from 10.10.7.37:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK4f349c26
From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as5ac7325e
To: <sip:400@10.10.7.37>;tag=336a6a73710cfe32
Call-ID: 5a0da3e651ff752e4c54e72f0d85b27d@10.10.250.62
CSeq: 102 OPTIONS
User-Agent: Grandstream HT386 1.0.3.64 FXS1
Contact: <sip:400@10.10.7.37>
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Supported: replaces
Content-Length: 0
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 0: SIP/2.0 200 OK (14)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK4f349c26 (57)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 2: From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as5ac7325e (63)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:400@10.10.7.37>;tag=336a6a73710cfe32 (45)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 4: Call-ID: 5a0da3e651ff752e4c54e72f0d85b27d@10.10.250.62 (54)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 6: User-Agent: Grandstream HT386 1.0.3.64 FXS1 (43)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 7: Contact: <sip:400@10.10.7.37> (29)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 9: Supported: replaces (19)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 10: Content-Length: 0 (17)
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Header 11: (0)
Apr 25 16:59:09 VERBOSE[2988723104] logger.c: --- (11 headers 0 lines) ---
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: = Found Their Call ID: 5a0da3e651ff752e4c54e72f0d85b27d@10.10.250.62 Their Tag Our tag: as5ac7325e
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18
Apr 25 16:59:09 DEBUG[2988723104] chan_sip.c: Stopping retransmission on '5a0da3e651ff752e4c54e72f0d85b27d@10.10.250.62' of Request 102: Match Found
Apr 25 16:59:09 VERBOSE[2988723104] logger.c: Destroying call '5a0da3e651ff752e4c54e72f0d85b27d@10.10.250.62'
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 0: OPTIONS sip:400@10.10.7.37 SIP/2.0 (34)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK43d99882 (57)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 2: From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as392cd96c (63)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:400@10.10.7.37> (24)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 4: Contact: <sip:callweaver@10.10.250.62> (38)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 5: Call-ID: 4f785bbb375a2e2016d0b326268ad1ec@10.10.250.62 (54)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 7: User-Agent: CallWeaver (22)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 8: Max-Forwards: 70 (16)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 9: Date: Wed, 25 Apr 2007 21:00:09 GMT (35)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 11: Content-Length: 0 (17)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 12: (0)
Apr 25 17:00:09 VERBOSE[2988723104] logger.c: 12 headers, 0 lines
Apr 25 17:00:09 VERBOSE[2988723104] logger.c: Reliably Transmitting (NAT) to 10.10.7.37:5060:
OPTIONS sip:400@10.10.7.37 SIP/2.0
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK43d99882
From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as392cd96c
To: <sip:400@10.10.7.37>
Contact: <sip:callweaver@10.10.250.62>
Call-ID: 4f785bbb375a2e2016d0b326268ad1ec@10.10.250.62
CSeq: 102 OPTIONS
User-Agent: CallWeaver
Max-Forwards: 70
Date: Wed, 25 Apr 2007 21:00:09 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0
---
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #21
Apr 25 17:00:09 VERBOSE[2988723104] logger.c:
<-- SIP read from 10.10.7.37:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK43d99882
From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as392cd96c
To: <sip:400@10.10.7.37>;tag=73ff2b668eb6ea61
Call-ID: 4f785bbb375a2e2016d0b326268ad1ec@10.10.250.62
CSeq: 102 OPTIONS
User-Agent: Grandstream HT386 1.0.3.64 FXS1
Contact: <sip:400@10.10.7.37>
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Supported: replaces
Content-Length: 0
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 0: SIP/2.0 200 OK (14)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.10.250.62:5060;branch=z9hG4bK43d99882 (57)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 2: From: "callweaver" <sip:callweaver@10.10.250.62>;tag=as392cd96c (63)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 3: To: <sip:400@10.10.7.37>;tag=73ff2b668eb6ea61 (45)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 4: Call-ID: 4f785bbb375a2e2016d0b326268ad1ec@10.10.250.62 (54)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 6: User-Agent: Grandstream HT386 1.0.3.64 FXS1 (43)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 7: Contact: <sip:400@10.10.7.37> (29)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 9: Supported: replaces (19)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 10: Content-Length: 0 (17)
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Header 11: (0)
Apr 25 17:00:09 VERBOSE[2988723104] logger.c: --- (11 headers 0 lines) ---
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: = Found Their Call ID: 4f785bbb375a2e2016d0b326268ad1ec@10.10.250.62 Their Tag Our tag: as392cd96c
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #21
Apr 25 17:00:09 DEBUG[2988723104] chan_sip.c: Stopping retransmission on '4f785bbb375a2e2016d0b326268ad1ec@10.10.250.62' of Request 102: Match Found
Apr 25 17:00:09 VERBOSE[2988723104] logger.c: Destroying call '4f785bbb375a2e2016d0b326268ad1ec@10.10.250.62'
Apr 25 17:00:32 VERBOSE[3080002464] logger.c: -- Remote UNIX connection
Apr 25 17:00:36 VERBOSE[2983873440] logger.c: Executing last minute cleanups
Apr 25 17:00:36 VERBOSE[2983873440] logger.c: CHAN FAX: Stopping Fax Modem SLOT 0
Apr 25 17:00:36 VERBOSE[2983873440] logger.c: CHAN FAX: Stopping Fax Modem SLOT 1
Apr 25 17:00:36 DEBUG[2983873440] channel.c: Unregistering channel type 'Fax'
Apr 25 17:00:36 VERBOSE[2983873440] logger.c: == Unregistered channel type 'Fax'
Apr 25 17:00:36 VERBOSE[2983873440] logger.c: == Destroying musiconhold processes
Apr 25 17:00:36 DEBUG[2983873440] callweaver.c: CallWeaver ending (0).