David Sfiligoi
2006-Aug-29 18:43 UTC
[asterisk-users] zap fxo to sip fxs intermitently not connecting to each other
Hi list,
On my asterisk based home pbx system, i have 1 zap interface(wildcard x100p) and
1 sipura 2000(which receiver is connected to) and some sip account for my long
distances and incoming calls.
When my call comes from SIP i've got no problem. However when calls comes
from zap, the zap interface picks up immediately(according to my
extensions.conf) and I send it to my sipura via SIP. Sipura rings the line, I
pickup ... the two side doesn't get connected. The problem is reproducable.
When I look at the logs and compare it to the successfull test cases everything
looks normal. Zap pickup the line, gets forwarded to SIP, SIP rings, I pickup
the sip phone.. nobody on the other side.. When the other side is me with my
cellphone, cellphone keeps rining.
Does anybody have a slight idea of what the problem could be. OK Yes I am using
a clone wildcard, but as you can see it does anwser. and Dial SIP which does
ring.
This below is a sample of the logs when the problem was reproduced. And some SIP
log available last.
Thanks
David
Aug 29 20:10:10 DEBUG[20159] chan_zap.c: Monitor doohicky got event Ring Begin
on channel 1
Aug 29 20:10:12 DEBUG[20159] chan_zap.c: Monitor doohicky got event
Ring/Answered on channel 1
Aug 29 20:10:12 DEBUG[20159] dsp.c: dsp busy pattern set to 0,0
Aug 29 20:10:12 DEBUG[20150] devicestate.c: Changing state for Zap/1 - state 2
(In use)
Aug 29 20:10:12 VERBOSE[20176] logger.c: Asterisk Ready.
-- Starting simple switch on 'Zap/1-1'
Aug 29 20:10:12 DEBUG[20177] app_queue.c: Device 'Zap/1' changed to
state '2' (In use)
Aug 29 20:10:16 NOTICE[20176] chan_zap.c: Got event 18 (Ring Begin)...
Aug 29 20:10:16 DEBUG[20176] pbx.c: Launching 'Wait'
Aug 29 20:10:16 VERBOSE[20176] logger.c: -- Executing
Wait("Zap/1-1", "1") in new stack
Aug 29 20:10:17 DEBUG[20176] pbx.c: Launching 'Answer'
Aug 29 20:10:17 VERBOSE[20176] logger.c: -- Executing
Answer("Zap/1-1", "") in new stack
Aug 29 20:10:17 DEBUG[20176] chan_zap.c: Took Zap/1-1 off hook
Aug 29 20:10:17 DEBUG[20150] channel.c: Avoiding initial deadlock for
'Zap/1-1'
Aug 29 20:10:17 DEBUG[20176] chan_zap.c: Enabled echo cancellation on channel 1
Aug 29 20:10:17 DEBUG[20176] chan_zap.c: Engaged echo training on channel 1
Aug 29 20:10:17 DEBUG[20176] pbx.c: Launching 'Dial'
Aug 29 20:10:17 VERBOSE[20176] logger.c: -- Executing
Dial("Zap/1-1", "SIP/2201|40|r") in new stack
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Allocating new SIP dialog for (No
Call-ID) - INVITE (With RTP)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Setting NAT on RTP to 0
Aug 29 20:10:17 DEBUG[20176] channel.c: Not copying variable STACK-default-s-3.
Aug 29 20:10:17 DEBUG[20176] channel.c: Not copying variable STACK-default-s-2.
Aug 29 20:10:17 DEBUG[20176] channel.c: Not copying variable STACK-default-s-1.
Aug 29 20:10:17 DEBUG[20176] channel.c: Not copying variable TRANSFERCAPABILITY.
Aug 29 20:10:17 DEBUG[20150] devicestate.c: Changing state for Zap/1 - state 2
(In use)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Outgoing Call for 2201
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Updating call counter for outgoing call
Aug 29 20:10:17 VERBOSE[20176] logger.c: We're at 10.0.0.4 port 14962
Aug 29 20:10:17 VERBOSE[20176] logger.c: Adding codec 0x4 (ulaw) to SDP
Aug 29 20:10:17 VERBOSE[20176] logger.c: Adding codec 0x8 (alaw) to SDP
Aug 29 20:10:17 DEBUG[20178] app_queue.c: Device 'Zap/1' changed to
state '2' (In use)
Aug 29 20:10:17 VERBOSE[20176] logger.c: Adding non-codec 0x1 (telephone-event)
to SDP
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 0: INVITE
sip:2201@10.0.0.100:5060 SIP/2.0 (39)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 1: Via: SIP/2.0/UDP
10.0.0.4:5060;branch=z9hG4bK7d531cbe;rport (59)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 2: From: "asterisk"
<sip:asterisk@10.0.0.4>;tag=as3f09488f (55)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 3: To:
<sip:2201@10.0.0.100:5060> (30)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 4: Contact:
<sip:asterisk@10.0.0.4> (32)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 5: Call-ID:
20c1d14300b5f9977c52bd593ee31568@10.0.0.4 (50)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 6: CSeq: 102 INVITE (16)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 8: Max-Forwards: 70 (16)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 9: Date: Wed, 30 Aug 2006
00:10:17 GMT (35)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL,
OPTIONS, BYE, REFER, SUBSCRIBE, NOT
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 11: Content-Type:
application/sdp (29)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 12: Content-Length: 232 (19)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Header 13: (0)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Line: v=0 (3)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Line: o=root 20176 20176 IN IP4
10.0.0.4 (34)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Line: s=session (9)
Aug 29 20:10:17 DEBUG[20176] chan_sip.c: Line: c=IN IP4 10.0.0.4 (17)
SIP debug logs
---*CLI> -- Starting simple switch on 'Zap/1-1'
Aug 29 20:10:16 NOTICE[20176]: chan_zap.c:6062 ss_thread: Got event 18 (Ring
Begin)...
-- Executing Wait("Zap/1-1", "1") in new stack
-- Executing Answer("Zap/1-1", "") in new stack
-- Executing Dial("Zap/1-1", "SIP/2201|40|r") in new
stack
We're at 10.0.0.4 port 14962
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
13 headers, 11 lines
Reliably Transmitting (no NAT) to 10.0.0.100:5060:
INVITE sip:2201@10.0.0.100:5060 SIP/2.0
Via: SIP/2.0/UDP 10.0.0.4:5060;branch=z9hG4bK7d531cbe;rport
From: "asterisk" <sip:asterisk@10.0.0.4>;tag=as3f09488f
To: <sip:2201@10.0.0.100:5060>
Contact: <sip:asterisk@10.0.0.4>
Call-ID: 20c1d14300b5f9977c52bd593ee31568@10.0.0.4
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Wed, 30 Aug 2006 00:10:17 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 232
v=0
o=root 20176 20176 IN IP4 10.0.0.4
s=session
c=IN IP4 10.0.0.4
t=0 0
m=audio 14962 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
-- Called 2201
<-- SIP read from 10.0.0.100:5060:
SIP/2.0 100 Trying
To: <sip:2201@10.0.0.100:5060>
From: "asterisk" <sip:asterisk@10.0.0.4>;tag=as3f09488f
Call-ID: 20c1d14300b5f9977c52bd593ee31568@10.0.0.4
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.0.0.4:5060;branch=z9hG4bK7d531cbe
Server: Sipura/SPA2000-2.0.13(g)
Content-Length: 0
--- (8 headers 0 lines)---
<-- SIP read from 10.0.0.100:5060:
SIP/2.0 180 Ringing
To: <sip:2201@10.0.0.100:5060>;tag=4cc2d203bb415c54i0
From: "asterisk" <sip:asterisk@10.0.0.4>;tag=as3f09488f
Call-ID: 20c1d14300b5f9977c52bd593ee31568@10.0.0.4
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.0.0.4:5060;branch=z9hG4bK7d531cbe
Server: Sipura/SPA2000-2.0.13(g)
Content-Length: 0
--- (8 headers 0 lines)---
-- SIP/2201-e2ff is ringing
<-- SIP read from 10.0.0.100:5060:
SIP/2.0 200 OK
To: <sip:2201@10.0.0.100:5060>;tag=4cc2d203bb415c54i0
From: "asterisk" <sip:asterisk@10.0.0.4>;tag=as3f09488f
Call-ID: 20c1d14300b5f9977c52bd593ee31568@10.0.0.4
CSeq: 102 INVITE
Via: SIP/2.0/UDP 10.0.0.4:5060;branch=z9hG4bK7d531cbe
Contact: <sip:2201@10.0.0.100:5060>
Server: Sipura/SPA2000-2.0.13(g)
Content-Length: 235
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp
v=0
o=- 267258876 267258876 IN IP4 10.0.0.100
s=-
c=IN IP4 10.0.0.100
t=0 0
m=audio 16474 RTP/AVP 0 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:100 NSE/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv
--- (12 headers 12 lines)---
Found RTP audio format 0
Found RTP audio format 100
Found RTP audio format 101
Peer audio RTP is at port 10.0.0.100:16474
Found description format PCMU
Found description format NSE
Found description format telephone-event
Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing),
combined - 0x4 (ulaw)
Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1
(telephone-event), combined - 0x1 (telephone-event)
list_route: hop: <sip:2201@10.0.0.100:5060>
set_destination: Parsing <sip:2201@10.0.0.100:5060> for address/port to
send to
set_destination: set destination to 10.0.0.100, port 5060
Transmitting (no NAT) to 10.0.0.100:5060:
ACK sip:2201@10.0.0.100:5060 SIP/2.0
Via: SIP/2.0/UDP 10.0.0.4:5060;branch=z9hG4bK1247594b;rport
From: "asterisk" <sip:asterisk@10.0.0.4>;tag=as3f09488f
To: <sip:2201@10.0.0.100:5060>;tag=4cc2d203bb415c54i0
Contact: <sip:asterisk@10.0.0.4>
Call-ID: 20c1d14300b5f9977c52bd593ee31568@10.0.0.4
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0
---
-- SIP/2201-e2ff answered Zap/1-1
<-- SIP read from 10.0.0.100:5060:
BYE sip:asterisk@10.0.0.4 SIP/2.0
Via: SIP/2.0/UDP 10.0.0.100:5060;branch=z9hG4bK-34b9681b
From: <sip:2201@10.0.0.100:5060>;tag=4cc2d203bb415c54i0
To: "asterisk" <sip:asterisk@10.0.0.4>;tag=as3f09488f
Call-ID: 20c1d14300b5f9977c52bd593ee31568@10.0.0.4
CSeq: 101 BYE
Max-Forwards: 70
User-Agent: Sipura/SPA2000-2.0.13(g)
Content-Length: 0