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