[asterisk-users] SPA2100 sends an unexpected BYE message whentransmitting a FAX

Mike Aster aster.mike at gmail.com
Wed Dec 13 02:23:39 MST 2006


> Hi Mike,
>
> Do you have a full SIP trace?
>
> Cheers
> Dave

Dave,

here is the trace, the BYE message at the end:

<-- SIP read from 192.168.6.222:5060:
INVITE sip:902111111 at 192.168.6.220 SIP/2.0
Via: SIP/2.0/UDP 192.168.6.222:5060;branch=z9hG4bK-a993e341
From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
To: <sip:902111111 at 192.168.6.220>
Call-ID: e793a727-98582c99 at 192.168.6.222
CSeq: 101 INVITE
Max-Forwards: 70
Contact: 201 <sip:201 at 192.168.6.222:5060>
Expires: 240
User-Agent: Linksys/SPA2100-3.3.6
Content-Length: 255
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp

v=0
o=- 413461 413461 IN IP4 192.168.6.222
s=-
c=IN IP4 192.168.6.222
t=0 0
m=audio 16384 RTP/AVP 8 100 101
a=rtpmap:8 PCMA/8000
a=rtpmap:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv

chan_sip.c:3377 parse_request: Header 1: Via: SIP/2.0/UDP
192.168.6.222:5060;branch=z9hG4bK-a993e341 (59)
chan_sip.c:3377 parse_request: Header 2: From: 201
<sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0 (56)
chan_sip.c:3377 parse_request: Header 3: To: <sip:902111111 at 192.168.6.220> (33)
chan_sip.c:3377 parse_request: Header 4: Call-ID:
e793a727-98582c99 at 192.168.6.222 (40)
chan_sip.c:3377 parse_request: Header 5: CSeq: 101 INVITE (16)
chan_sip.c:3377 parse_request: Header 6: Max-Forwards: 70 (16)
chan_sip.c:3377 parse_request: Header 7: Contact: 201
<sip:201 at 192.168.6.222:5060> (41)
chan_sip.c:3377 parse_request: Header 8: Expires: 240 (12)
chan_sip.c:3377 parse_request: Header 9: User-Agent: Linksys/SPA2100-3.3.6 (33)
chan_sip.c:3377 parse_request: Header 10: Content-Length: 255 (19)
chan_sip.c:3377 parse_request: Header 11: Allow: ACK, BYE, CANCEL,
INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
chan_sip.c:3377 parse_request: Header 12: Supported: x-sipura (19)
chan_sip.c:3377 parse_request: Header 13: Content-Type: application/sdp (29)
chan_sip.c:3377 parse_request: Header 14:  (0)
chan_sip.c:3409 parse_request: Line: v=0 (3)
chan_sip.c:3409 parse_request: Line: o=- 413461 413461 IN IP4 192.168.6.222 (38)
chan_sip.c:3409 parse_request: Line: s=- (3)
chan_sip.c:3409 parse_request: Line: c=IN IP4 192.168.6.222 (22)
chan_sip.c:3409 parse_request: Line: t=0 0 (5)
chan_sip.c:3409 parse_request: Line: m=audio 16384 RTP/AVP 8 100 101 (31)
chan_sip.c:3409 parse_request: Line: a=rtpmap:8 PCMA/8000 (20)
chan_sip.c:3409 parse_request: Line: a=rtpmap:100 NSE/8000 (21)
chan_sip.c:3409 parse_request: Line: a=fmtp:100 192-193 (18)
chan_sip.c:3409 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33)
chan_sip.c:3409 parse_request: Line: a=fmtp:101 0-15 (15)
chan_sip.c:3409 parse_request: Line: a=ptime:30 (10)
chan_sip.c:3409 parse_request: Line: a=sendrecv (10)
--- (14 headers 13 lines)---
chan_sip.c:3147 sip_alloc: Allocating new SIP dialog for
e793a727-98582c99 at 192.168.6.222 - INVITE (With RTP)
chan_sip.c:11375 handle_request: **** Received INVITE (5) - Command in
SIP INVITE
chan_sip.c:1010 parse_sip_options: Begin: parsing SIP "Supported: x-sipura"
chan_sip.c:1022 parse_sip_options: Found SIP option: -x-sipura-
chan_sip.c:1033 parse_sip_options: Found no match for SIP option:
x-sipura (Please file bug report!)
chan_sip.c:1039 parse_sip_options: * SIP extension value: 0 for call
e793a727-98582c99 at 192.168.6.222
Using INVITE request as basis request - e793a727-98582c99 at 192.168.6.222
Sending to 192.168.6.222 : 5060 (non-NAT)
Dec 12 12:47:49 DEBUG[7416]: chan_sip.c:7258 check_user_full: Setting
NAT on RTP to 0
Reliably Transmitting (no NAT) to 192.168.6.222:5060:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP
192.168.6.222:5060;branch=z9hG4bK-a993e341;received=192.168.6.222
From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
To: <sip:902111111 at 192.168.6.220>;tag=as14e77426
Call-ID: e793a727-98582c99 at 192.168.6.222
CSeq: 101 INVITE
User-Agent: insido
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:902111111 at 192.168.6.220>
Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="36741c67"
Content-Length: 0


---
Dec 12 12:47:49 DEBUG[7416]: chan_sip.c:1299 __sip_reliable_xmit: ***
SIP TIMER: Initalizing retransmit timer on packet: Id  #256
Scheduling destruction of call 'e793a727-98582c99 at 192.168.6.222' in 15000 ms
Found user '201'
ipbx100*CLI>
<-- SIP read from 192.168.6.222:5060:
ACK sip:902111111 at 192.168.6.220 SIP/2.0
Via: SIP/2.0/UDP 192.168.6.222:5060;branch=z9hG4bK-a993e341
From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
To: <sip:902111111 at 192.168.6.220>;tag=as14e77426
Call-ID: e793a727-98582c99 at 192.168.6.222
CSeq: 101 ACK
Max-Forwards: 70
Contact: 201 <sip:201 at 192.168.6.222:5060>
User-Agent: Linksys/SPA2100-3.3.6
Content-Length: 0


chan_sip.c:3377 parse_request: Header 0: ACK
sip:902111111 at 192.168.6.220 SIP/2.0 (39)
Dchan_sip.c:3377 parse_request: Header 1: Via: SIP/2.0/UDP
192.168.6.222:5060;branch=z9hG4bK-a993e341 (59)
chan_sip.c:3377 parse_request: Header 2: From: 201
<sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0 (56)
chan_sip.c:3377 parse_request: Header 3: To:
<sip:902111111 at 192.168.6.220>;tag=as14e77426 (48)
chan_sip.c:3377 parse_request: Header 4: Call-ID:
e793a727-98582c99 at 192.168.6.222 (40)
chan_sip.c:3377 parse_request: Header 5: CSeq: 101 ACK (13)
chan_sip.c:3377 parse_request: Header 6: Max-Forwards: 70 (16)
chan_sip.c:3377 parse_request: Header 7: Contact: 201
<sip:201 at 192.168.6.222:5060> (41)
chan_sip.c:3377 parse_request: Header 8: User-Agent: Linksys/SPA2100-3.3.6 (33)
chan_sip.c:3377 parse_request: Header 9: Content-Length: 0 (17)
chan_sip.c:3377 parse_request: Header 10:  (0)
--- (10 headers 0 lines)---
chan_sip.c:3209 find_call: = Found Their Call ID:
e793a727-98582c99 at 192.168.6.222 Their Tag c6bf15cfef0f4e11o0 Our tag:
as14e77426
chan_sip.c:11375 handle_request: **** Received ACK (6) - Command in SIP ACK
chan_sip.c:1396 __sip_ack: ** SIP TIMER: Cancelling retransmit of
packet (reply received) Retransid #256
chan_sip.c:1407 __sip_ack: Stopping retransmission on
'e793a727-98582c99 at 192.168.6.222' of Response 101: Match Found

<-- SIP read from 192.168.6.222:5060:
INVITE sip:902111111 at 192.168.6.220 SIP/2.0
Via: SIP/2.0/UDP 192.168.6.222:5060;branch=z9hG4bK-536092e1
From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
To: <sip:902111111 at 192.168.6.220>
Call-ID: e793a727-98582c99 at 192.168.6.222
CSeq: 102 INVITE
Max-Forwards: 70
Proxy-Authorization: Digest
username="201",realm="asterisk",nonce="36741c67",uri="sip:902111111 at 192.168.6.220",algorithm=MD5,response="8a093792ff81050831d97df4c8f6f028"
Contact: 201 <sip:201 at 192.168.6.222:5060>
Expires: 240
User-Agent: Linksys/SPA2100-3.3.6
Content-Length: 255
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp

v=0
o=- 413461 413461 IN IP4 192.168.6.222
s=-
c=IN IP4 192.168.6.222
t=0 0
m=audio 16384 RTP/AVP 8 100 101
a=rtpmap:8 PCMA/8000
a=rtpmap:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv
chan_sip.c:3377 parse_request: Header 0: INVITE
sip:902111111 at 192.168.6.220 SIP/2.0 (42)
chan_sip.c:3377 parse_request: Header 1: Via: SIP/2.0/UDP
192.168.6.222:5060;branch=z9hG4bK-536092e1 (59)
chan_sip.c:3377 parse_request: Header 2: From: 201
<sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0 (56)
chan_sip.c:3377 parse_request: Header 3: To: <sip:902111111 at 192.168.6.220> (33)
chan_sip.c:3377 parse_request: Header 4: Call-ID:
e793a727-98582c99 at 192.168.6.222 (40)
chan_sip.c:3377 parse_request: Header 5: CSeq: 102 INVITE (16)
chan_sip.c:3377 parse_request: Header 6: Max-Forwards: 70 (16)
chan_sip.c:3377 parse_request: Header 7: Proxy-Authorization: Digest
username="201",realm="asterisk",nonce="36741c67",uri="sip:902111111 at 192.168.6.220",algorithm=MD5,response="8a093792ff81050831d97df4c8f6f028"
(168)
chan_sip.c:3377 parse_request: Header 8: Contact: 201
<sip:201 at 192.168.6.222:5060> (41)
chan_sip.c:3377 parse_request: Header 9: Expires: 240 (12)
chan_sip.c:3377 parse_request: Header 10: User-Agent: Linksys/SPA2100-3.3.6 (33)
chan_sip.c:3377 parse_request: Header 11: Content-Length: 255 (19)
chan_sip.c:3377 parse_request: Header 12: Allow: ACK, BYE, CANCEL,
INFO, INVITE, NOTIFY, OPTIONS, REFER (61)
chan_sip.c:3377 parse_request: Header 13: Supported: x-sipura (19)
chan_sip.c:3377 parse_request: Header 14: Content-Type: application/sdp (29)
chan_sip.c:3377 parse_request: Header 15:  (0)
chan_sip.c:3409 parse_request: Line: v=0 (3)
chan_sip.c:3409 parse_request: Line: o=- 413461 413461 IN IP4 192.168.6.222 (38)
chan_sip.c:3409 parse_request: Line: s=- (3)
chan_sip.c:3409 parse_request: Line: c=IN IP4 192.168.6.222 (22)
chan_sip.c:3409 parse_request: Line: t=0 0 (5)
chan_sip.c:3409 parse_request: Line: m=audio 16384 RTP/AVP 8 100 101 (31)
chan_sip.c:3409 parse_request: Line: a=rtpmap:8 PCMA/8000 (20)
chan_sip.c:3409 parse_request: Line: a=rtpmap:100 NSE/8000 (21)
chan_sip.c:3409 parse_request: Line: a=fmtp:100 192-193 (18)
chan_sip.c:3409 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33)
chan_sip.c:3409 parse_request: Line: a=fmtp:101 0-15 (15)
chan_sip.c:3409 parse_request: Line: a=ptime:30 (10)
chan_sip.c:3409 parse_request: Line: a=sendrecv (10)

chan_sip.c:3209 find_call: = Found Their Call ID:
e793a727-98582c99 at 192.168.6.222 Their Tag c6bf15cfef0f4e11o0 Our tag:
as14e77426
chan_sip.c:11375 handle_request: **** Received INVITE (5) - Command in
SIP INVITE
chan_sip.c:1010 parse_sip_options: Begin: parsing SIP "Supported: x-sipura"
chan_sip.c:1022 parse_sip_options: Found SIP option: -x-sipura-
chan_sip.c:1033 parse_sip_options: Found no match for SIP option:
x-sipura (Please file bug report!)
chan_sip.c:1039 parse_sip_options: * SIP extension value: 0 for call
e793a727-98582c99 at 192.168.6.222
Using INVITE request as basis request - e793a727-98582c99 at 192.168.6.222
Sending to 192.168.6.222 : 5060 (non-NAT)
Dec 12 12:47:49 DEBUG[7416]: chan_sip.c:7258 check_user_full: Setting
NAT on RTP to 0
Found user '201'
Found RTP audio format 8
Found RTP audio format 100
Found RTP audio format 101
Peer audio RTP is at port 192.168.6.222:16384
Dec 12 12:47:49 DEBUG[7416]: chan_sip.c:3618 process_sdp: Peer audio
RTP is at port 192.168.6.222:16384
Found description format PCMA
Found description format NSE
Found description format telephone-event
Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x8
(alaw)/video=0x0 (nothing), combined - 0x8 (alaw)
Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1
(telephone-event), combined - 0x1 (telephone-event)
Dec 12 12:47:49 DEBUG[7416]: chan_sip.c:10667 handle_request_invite:
Checking SIP call limits for device 201
Dec 12 12:47:49 DEBUG[7416]: chan_sip.c:2212 update_call_counter:
Updating call counter for incoming call
Looking for 902111111 in faxout (domain 192.168.6.220)
Dec 12 12:47:49 DEBUG[7416]: chan_sip.c:6169 build_route: build_route:
Contact hop: 201 <sip:201 at 192.168.6.222:5060>
list_route: hop: <sip:201 at 192.168.6.222:5060>
Transmitting (no NAT) to 192.168.6.222:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP
192.168.6.222:5060;branch=z9hG4bK-536092e1;received=192.168.6.222
From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
To: <sip:902111111 at 192.168.6.220>
Call-ID: e793a727-98582c99 at 192.168.6.222
CSeq: 102 INVITE
User-Agent: insido
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:902111111 at 192.168.6.220>
Content-Length: 0


---
chan_sip.c:11954 sip_devicestate: Checking device state for peer 201
devicestate.c:189 do_state_change: Changing state for SIP/201 - state 2 (In use)
pbx.c:1678 pbx_extension_helper: Launching 'Dial'
    -- Executing Dial("SIP/201-006ec610", "Zap/g2/902111111") in new stack
chan_zap.c:7967 zt_request: Using channel 1
dsp.c:1621 ast_dsp_set_busy_pattern: dsp busy pattern set to 0,0
devicestate.c:189 do_state_change: Changing state for Zap/1 - state 2 (In use)
channel.c:2911 ast_channel_inherit_variables: Not copying variable
STACK-faxout-902111111-1.
channel.c:2911 ast_channel_inherit_variables: Not copying variable SIPCALLID.
channel.c:2911 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT.
channel.c:2911 ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
channel.c:2911 ast_channel_inherit_variables: Not copying variable SIPURI.
chan_zap.c:2103 zt_call: Dialing '902111111'
chan_zap.c:2175 zt_call: Deferring dialing...
channel.c:797 channel_find_locked: Avoiding initial deadlock for 'Zap/1-1'
    -- Called g2/902111111
channel.c:2392 set_format: Set channel Zap/1-1 to read format slin
channel.c:2392 set_format: Set channel SIP/201-006ec610 to write format slin
channel.c:2392 set_format: Set channel SIP/201-006ec610 to read format slin
channel.c:2392 set_format: Set channel Zap/1-1 to write format slin
app_queue.c:490 changethread: Device 'SIP/201' changed to state '2'
(In use) but we don't care because they're not a member of any queue.
app_queue.c:490 changethread: Device 'Zap/1' changed to state '2' (In
use) but we don't care because they're not a member of any queue.
devicestate.c:189 do_state_change: Changing state for Zap/1 - state 2 (In use)
app_queue.c:490 changethread: Device 'Zap/1' changed to state '2' (In
use) but we don't care because they're not a member of any queue.
chan_zap.c:4654 __zt_exception: Exception on 13, channel 1
chan_zap.c:3842 zt_handle_event: Got event Hook Transition
Complete(12) on channel 1 (index 0)
chan_zap.c:4654 __zt_exception: Exception on 13, channel 1
chan_zap.c:3842 zt_handle_event: Got event Dial Complete(9) on channel
1 (index 0)
chan_zap.c:1587 zt_enable_ec: Enabled echo cancellation on channel 1
chan_zap.c:1603 zt_train_ec: Engaged echo training on channel 1
chan_zap.c:4654 __zt_exception: Exception on 13, channel 1
chan_zap.c:3842 zt_handle_event: Got event Dial Complete(9) on channel
1 (index 0)
chan_zap.c:1567 zt_enable_ec: Echo cancellation already on
We're at 192.168.6.220 port 16396
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Transmitting (no NAT) to 192.168.6.222:5060:
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP
192.168.6.222:5060;branch=z9hG4bK-536092e1;received=192.168.6.222
From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
To: <sip:902111111 at 192.168.6.220>;tag=as715a2601
Call-ID: e793a727-98582c99 at 192.168.6.222
CSeq: 102 INVITE
User-Agent: insido
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:902111111 at 192.168.6.220>
Content-Type: application/sdp
Content-Length: 216

v=0
o=root 7395 7395 IN IP4 192.168.6.220
s=session
c=IN IP4 192.168.6.220
t=0 0
m=audio 16396 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

---
Dec 12 12:47:53 DEBUG[10852]: rtp.c:1358 ast_rtp_write: Ooh, format
changed from unknown to alaw
Dec 12 12:48:00 DEBUG[10852]: chan_zap.c:4654 __zt_exception:
Exception on 13, channel 1
Dec 12 12:48:00 DEBUG[10852]: chan_zap.c:3842 zt_handle_event: Got
event Polarity Reversal(17) on channel 1 (index 0)
Dec 12 12:48:00 DEBUG[10852]: chan_zap.c:4523 zt_handle_event:
Answering on polarity switch!
    -- Zap/1-1 answered SIP/201-006ec610
Dec 12 12:48:00 DEBUG[10852]: channel.c:2392 set_format: Set channel
SIP/201-006ec610 to read format slin
Dec 12 12:48:00 DEBUG[10852]: channel.c:2392 set_format: Set channel
Zap/1-1 to write format slin
Dec 12 12:48:00 DEBUG[10852]: channel.c:2392 set_format: Set channel
Zap/1-1 to read format slin
Dec 12 12:48:00 DEBUG[10852]: channel.c:2392 set_format: Set channel
SIP/201-006ec610 to write format slin
Dec 12 12:48:00 DEBUG[10852]: chan_sip.c:2543 sip_answer:
sip_answer(SIP/201-006ec610)
We're at 192.168.6.220 port 16396
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 192.168.6.222:5060:
IP/2.0 200 OK
Via: SIP/2.0/UDP
192.168.6.222:5060;branch=z9hG4bK-536092e1;received=192.168.6.222
From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
To: <sip:902111111 at 192.168.6.220>;tag=as715a2601
Call-ID: e793a727-98582c99 at 192.168.6.222
CSeq: 102 INVITE
User-Agent: insido
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:902111111 at 192.168.6.220>
Content-Type: application/sdp
Content-Length: 216

v=0
o=root 7395 7396 IN IP4 192.168.6.220
s=session
c=IN IP4 192.168.6.220
t=0 0
m=audio 16396 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

---
Dec 12 12:48:00 DEBUG[10852]: chan_sip.c:1299 __sip_reliable_xmit: ***
SIP TIMER: Initalizing retransmit timer on packet: Id  #258
Dec 12 12:48:00 DEBUG[7398]: devicestate.c:189 do_state_change:
Changing state for Zap/1 - state 2 (In use)
Dec 12 12:48:00 DEBUG[7398]: chan_sip.c:11954 sip_devicestate:
Checking device state for peer 201
Dec 12 12:48:00 DEBUG[7398]: devicestate.c:189 do_state_change:
Changing state for SIP/201 - state 2 (In use)
Dec 12 12:48:00 DEBUG[10856]: app_queue.c:490 changethread: Device
'Zap/1' changed to state '2' (In use) but we don't care because
they're not a member of any queue.
Dec 12 12:48:00 DEBUG[10857]: app_queue.c:490 changethread: Device
'SIP/201' changed to state '2' (In use) but we don't care because
they're not a member of any queue.
ipbx100*CLI>
<-- SIP read from 192.168.6.222:5060:
ACK sip:902111111 at 192.168.6.220 SIP/2.0
Via: SIP/2.0/UDP 192.168.6.222:5060;branch=z9hG4bK-6e24a8ab
From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
To: <sip:902111111 at 192.168.6.220>;tag=as715a2601
Call-ID: e793a727-98582c99 at 192.168.6.222
CSeq: 102 ACK
Max-Forwards: 70
Proxy-Authorization: Digest
username="201",realm="asterisk",nonce="36741c67",uri="sip:902111111 at 192.168.6.220",algorithm=MD5,response="4f53099e9068867e7b6158fd58146f15"
Contact: 201 <sip:201 at 192.168.6.222:5060>
User-Agent: Linksys/SPA2100-3.3.6
Content-Length: 0


chan_sip.c:3377 parse_request: Header 0: ACK
sip:902111111 at 192.168.6.220 SIP/2.0 (39)
chan_sip.c:3377 parse_request: Header 1: Via: SIP/2.0/UDP
192.168.6.222:5060;branch=z9hG4bK-6e24a8ab (59)
chan_sip.c:3377 parse_request: Header 2: From: 201
<sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0 (56)
chan_sip.c:3377 parse_request: Header 3: To:
<sip:902111111 at 192.168.6.220>;tag=as715a2601 (48)
chan_sip.c:3377 parse_request: Header 4: Call-ID:
e793a727-98582c99 at 192.168.6.222 (40)
chan_sip.c:3377 parse_request: Header 5: CSeq: 102 ACK (13)
chan_sip.c:3377 parse_request: Header 6: Max-Forwards: 70 (16)
chan_sip.c:3377 parse_request: Header 7: Proxy-Authorization: Digest
username="201",realm="asterisk",nonce="36741c67",uri="sip:902111111 at 192.168.6.220",algorithm=MD5,response="4f53099e9068867e7b6158fd58146f15"
(168)
chan_sip.c:3377 parse_request: Header 8: Contact: 201
<sip:201 at 192.168.6.222:5060> (41)
chan_sip.c:3377 parse_request: Header 9: User-Agent: Linksys/SPA2100-3.3.6 (33)
chan_sip.c:3377 parse_request: Header 10: Content-Length: 0 (17)
chan_sip.c:3377 parse_request: Header 11:  (0)
chan_sip.c:3209 find_call: = Found Their Call ID:
e793a727-98582c99 at 192.168.6.222 Their Tag c6bf15cfef0f4e11o0 Our tag:
as715a2601
chan_sip.c:11375 handle_request: **** Received ACK (6) - Command in SIP ACK
chan_sip.c:1396 __sip_ack: ** SIP TIMER: Cancelling retransmit of
packet (reply received) Retransid #258
 chan_sip.c:1407 __sip_ack: Stopping retransmission on
'e793a727-98582c99 at 192.168.6.222' of Response 102: Match Found

<-- SIP read from 192.168.6.222:5060:
BYE sip:902111111 at 192.168.6.220 SIP/2.0
Via: SIP/2.0/UDP 192.168.6.222:5060;branch=z9hG4bK-6b0d80f5
From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
To: <sip:902111111 at 192.168.6.220>;tag=as715a2601
Call-ID: e793a727-98582c99 at 192.168.6.222
CSeq: 103 BYE
Max-Forwards: 70
Proxy-Authorization: Digest
username="201",realm="asterisk",nonce="36741c67",uri="sip:902111111 at 192.168.6.220",algorithm=MD5,response="94f0139b69bb01ddc4aa362ab3edc130"
User-Agent: Linksys/SPA2100-3.3.6
Content-Length: 0


chan_sip.c:3377 parse_request: Header 0: BYE
sip:902111111 at 192.168.6.220 SIP/2.0 (39)
chan_sip.c:3377 parse_request: Header 1: Via: SIP/2.0/UDP
192.168.6.222:5060;branch=z9hG4bK-6b0d80f5 (59)
chan_sip.c:3377 parse_request: Header 2: From: 201
<sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0 (56)
chan_sip.c:3377 parse_request: Header 3: To:
<sip:902111111 at 192.168.6.220>;tag=as715a2601 (48)
chan_sip.c:3377 parse_request: Header 4: Call-ID:
e793a727-98582c99 at 192.168.6.222 (40)
chan_sip.c:3377 parse_request: Header 5: CSeq: 103 BYE (13)
chan_sip.c:3377 parse_request: Header 6: Max-Forwards: 70 (16)
chan_sip.c:3377 parse_request: Header 7: Proxy-Authorization: Digest
username="201",realm="asterisk",nonce="36741c67",uri="sip:902111111 at 192.168.6.220",algorithm=MD5,response="94f0139b69bb01ddc4aa362ab3edc130"
(168)
chan_sip.c:3377 parse_request: Header 8: User-Agent: Linksys/SPA2100-3.3.6 (33)
chan_sip.c:3377 parse_request: Header 9: Content-Length: 0 (17)
chan_sip.c:3377 parse_request: Header 10:  (0)
chan_sip.c:3209 find_call: = Found Their Call ID:
e793a727-98582c99 at 192.168.6.222 Their Tag c6bf15cfef0f4e11o0 Our tag:
as715a2601
chan_sip.c:11375 handle_request: **** Received BYE (8) - Command in SIP BYE

Sending to 192.168.6.222 : 5060 (non-NAT)
Transmitting (no NAT) to 192.168.6.222:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP
192.168.6.222:5060;branch=z9hG4bK-6b0d80f5;received=192.168.6.222
From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
To: <sip:902111111 at 192.168.6.220>;tag=as715a2601
Call-ID: e793a727-98582c99 at 192.168.6.222
CSeq: 103 BYE
User-Agent: insido
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:902111111 at 192.168.6.220>
Content-Length: 0


channel.c:3366 ast_generic_bridge: Didn't get a frame from channel:
SIP/201-006ec610
channel.c:3647 ast_channel_bridge: Bridge stops bridging channels
SIP/201-006ec610 and Zap/1-1
channel.c:1365 ast_hangup: Hanging up channel 'Zap/1-1'
chan_zap.c:2529 zt_hangup: zt_hangup(Zap/1-1)
chan_zap.c:2562 zt_hangup: Hangup: channel: 1 index = 0, normal = 13,
callwait = -1, thirdcall = -1
chan_zap.c:1619 zt_disable_ec: disabled echo cancellation on channel 1
chan_zap.c:3082 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/1-1
chan_zap.c:1552 update_conf: Updated conferencing on 1, with 0 conference user

    -- Hungup 'Zap/1-1'

app_dial.c:1663 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
 pbx.c:2317 __ast_pbx_run: Spawn extension (faxout,902111111,1) exited
non-zero on 'SIP/201-006ec610'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is
'"201" <201>'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is '201'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is '902111111'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is 'faxout'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is
'SIP/201-006ec610'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is 'Zap/1-1'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is 'Dial'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is
'Zap/g2/902111111'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is
'2006-12-12 12:47:49'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is
'2006-12-12 12:48:00'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is
'2006-12-12 12:48:09'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is '20'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is '9'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is 'ANSWERED'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is
'DOCUMENTATION'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is '(null)'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is
'ipbx100-7395-1165924069.72'
pbx.c:1523 pbx_substitute_variables_helper_full: Function result is '(null)'
channel.c:1365 ast_hangup: Hanging up channel 'SIP/201-006ec610'
chan_sip.c:2421 sip_hangup: Hangup call SIP/201-006ec610, SIP callid
e793a727-98582c99 at 192.168.6.222)
devicestate.c:189 do_state_change: Changing state for Zap/1 - state 1
(Not in use)
chan_sip.c:2429 sip_hangup: update_call_counter(201) - decrement call
limit counter
chan_sip.c:2212 update_call_counter: Updating call counter for incoming call
chan_sip.c:11954 sip_devicestate: Checking device state for peer 201
devicestate.c:189 do_state_change: Changing state for SIP/201 - state
1 (Not in use)
app_queue.c:490 changethread: Device 'Zap/1' changed to state '1' (Not
in use) but we don't care because they're not a member of any queue.
app_queue.c:490 changethread: Device 'SIP/201' changed to state '1'
(Not in use) but we don't care because they're not a member of any
queue.
chan_zap.c:6976 do_monitor: Monitor doohicky got event Polarity
Reversal on channel 1
Destroying call 'e793a727-98582c99 at 192.168.6.222'



>
> -----Original Message-----
> From: asterisk-users-bounces at lists.digium.com
> [mailto:asterisk-users-bounces at lists.digium.com] On Behalf Of Mike Aster
> Sent: Tuesday, 12 December 2006 11:54 PM
> To: asterisk-users at lists.digium.com
> Subject: [asterisk-users] SPA2100 sends an unexpected BYE message
> whentransmitting a FAX
>
> Hi everyone,
>
> I'm trying to send a FAX with the following configuration:
>
> Analog FAX machine (OKI) <----->SPA21000<----->LAN<----->Asterisk<-------->
> PSTN
>
> I'm restricted to use passthru mode for faxing, instead of T.38 protocol,
> because the Asterisk box is running v1.2 and cannot be changed as it is in a
> heavy production environment. Anyway, it "should" work in passthru mode
> (G.711a) as the ATA and the Asterisk are in the same LAN with very low
> traffic. The problem arises when I try to send a fax: the Asterisk server
> initiates the call and, after a few seconds, the Linksys hangs the call by
> sending a BYE message:
>
> DEBUG[7416]: chan_sip.c:11375 handle_request: **** Received ACK (6) -
> Command in SIP ACK
>
> DEBUG[7416]: chan_sip.c:1396 __sip_ack: ** SIP TIMER: Cancelling retransmit
> of packet (reply received) Retransid #258
>
> DEBUG[7416]: chan_sip.c:1407 __sip_ack: Stopping retransmission on
> 'e793a727-98582c99 at 192.168.6.222' of Response 102: Match Found
>
> <-- SIP read from 192.168.6.222:5060:
> BYE sip:9021111111 at 192.168.6.220 SIP/2.0
> Via: SIP/2.0/UDP 192.168.6.222:5060;branch=z9hG4bK-6b0d80f5
> From: 201 <sip:201 at 192.168.6.220>;tag=c6bf15cfef0f4e11o0
> To: <sip:9021111111 at 192.168.6.220>;tag=as715a2601
> Call-ID: e793a727-98582c99 at 192.168.6.222
> CSeq: 103 BYE
> Max-Forwards: 70
> Proxy-Authorization: Digest
> username="201",realm="asterisk",nonce="36741c67",uri="sip:9021111111 at 192.168
> .6.220",algorithm=MD5,response="94f0139b69bb01ddc4aa362ab3edc130"
> User-Agent: Linksys/SPA2100-3.3.6
>
> I'm using the following features:
>
> - Network jitter buffer: very high
> - Jitter buffer adjustment: disable
> - Call Waiting: no
> - 3 Way Calling: no
> - Echo Canceller: no
> - Silence suppression: no
> - Preferred Codec: G711a
> - Use pref. codec only: yes
> - Silence Threshold = medium
> - Echo Canc Enable = no
> - Echo Canc Adapt Enable = no
> - Echo Supp Enable = no
> - FAX CED Detect Enable = no
> - FAX CNG Detect Enable = no
> - FAX Passthru Codec = G711a
> - FAX Passthru Method = NSE
> - FAX Process NSE = yes
> - FAX Disable ECAN = no
> - FAX Codec Symmetric = yes
> - DTMF Tx Method = auto
> - Hook Flash Tx Method = none
> - Release Unused Codec = yes
>
> I have checked the SPA2100's logs, but I can't see anything of interest (and
> I couldn't find any documentation about this logs at Sipura's website).
>
> Has anyone suceed in sending a fax in a scenario like this? I would
> appreciate any help on this point.
>
> Best regards,
> _______________________________________________
> --Bandwidth and Colocation provided by Easynews.com --
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
>    http://lists.digium.com/mailman/listinfo/asterisk-users
>
>
> --
> I am using the free version of SPAMfighter for private users.
> It has removed 3657 spam emails to date.
> Paying users do not have this message in their emails.
> Get the free SPAMfighter here: http://www.spamfighter.com
>
> _______________________________________________
> --Bandwidth and Colocation provided by Easynews.com --
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
>    http://lists.digium.com/mailman/listinfo/asterisk-users
>


More information about the asterisk-users mailing list