Hi, On 07/23/2008 05:22 PM, caio wrote: there is no DNS cache in version 0.9.x as I recall, but anyway, your problem does not seem to be related to DNS, but to the UDP message sending: SER fails to send out the UDP packet, "Operation not permitted". Is there no firewall or routing problem at the proxy side? Miklos > What do you recommend? > If you need my ser.cfg I can paste it... > > Thanks.. >

On 07/24/2008 01:11 PM, caio wrote: The config script looks fine, I suppose you see the log messages "LOG: --> appending new branch..." and "LOG: --> Calling route_6..." before the error logs you posted. SER tries to forward the call to wsa.lab. It tries to resolve the SRV record first without success, than resolves the A record (there is no error, so the resolution is ok). I believe there is a routing or firewall problem, because sendto() function returns with error, so the issue is not SER-related in my opinion, try to google for "sendto operation not permitted". Disable iptables or any other firewall you have, verify that the routing is correct, and SER listens on the interface that is used to send out the packet. I would also try to send a call to wsa.lab without failure route with a very simple ser script. Miklos > Thanks your comments.. > > Claudio > > On Thu, Jul 24, 2008 at 4:58 AM, Miklos Tirpak <miklos(a)iptel.org> wrote: >> >> Hi, >> >> On 07/23/2008 05:22 PM, caio wrote: >>> >>> Hi guys, >>> I have a problem with call forwarding (on busy or not answer).., the >>> call fall into the failure_route(1) block, and AVP checking and pushto >>> does its job. >>> >>> Here a snipped of code of failure_route(1) (flag 27 means call fwd if >>> no answer): >>> >>> if (isflagset(27) && t_check_status("408")) { # if fwd no >>> answer is set and reply msg is 408 >>> >>> if (avp_pushto("$ruri", "s:fwdnoanswer")) { >>> avp_delete("s:fwdnoanswer"); >>> resetflag(27); >>> >>> avp_print(); >>> >>> log(1, "LOG: --> appending new branch..."); >>> if (!append_branch()){ >>> t_reply("500", "Too many branches?!"); >>> drop; >>> } >>> >>> log(1, "LOG: --> Calling route_6..."); >>> route(6); >>> break; >>> >>> Route(6) finally calls route(1), where t_relay is called. >>> But have a dns failure..and the call never is forwarded. >>> >>> == ser.log == >>> >>> DEBUG: mk_proxy: doing DNS lookup... >>> get_record: lookup(_sip._udp.wsa.lab, 33) failed_ >>> sip_resolvehost: no SRV record found for wsa.lab, trying 'normal' >>> lookup..._ >>> check_via_address(190.244.33.5, 190.244.33.5, 0)_ >>> ERROR: udp_send: sendto(sock,0x2ab32599c720,910,0,0x2ab325999e68,16): >>> Operation not permitted(1)_ >>> msg_send: ERROR: udp_send failed_ >>> ERROR: t_forward_nonack: sending request failed_ >>> DEBUG: add_to_tail_of_timer[4]: 0x2ab325999e80_ >>> DEBUG: add_to_tail_of_timer[0]: 0x2ab325999ea0_ >>> ERROR: w_t_relay (failure mode): forwarding failed_ >>> >>> A question regarding this trouble.....Can I disable use_dns_cache ? >>> SER version is 0.9.7. >> >> there is no DNS cache in version 0.9.x as I recall, but anyway, your >> problem >> does not seem to be related to DNS, but to the UDP message sending: SER >> fails to send out the UDP packet, "Operation not permitted". Is there >> no >> firewall or routing problem at the proxy side? >> >> Miklos >> >>> What do you recommend? >>> If you need my ser.cfg I can paste it... >>> >>> Thanks.. >>> > > > -- > caio > > >

On 07/24/2008 04:38 PM, caio wrote: This is fine, the RURI is rewritten to the forwarding destination. The RURI no longer contains wsa.lab, it points to 127.0.0.1:5061 Is this what you want? From this it seems that SER still tries to get the IP for wsa.lab, did this is confusing. Try to verify somehow, that the next host SER is trying to send the packet is not 127.0.0.1:5061. If 127.0.0.1:5061 is the next hop, and no process listens on port 5061, than you can get this error I guess. Or if you want SER to forward the request to 127.0.0.1:5061, and this is the correct next hop, than it may happen that the outgoing interface was wrongly determined, try to enable mhomed in the config file. Yes this is correct. The To HF cannot be modified, the RURI should contain the new destination. The destination ip address is probably not yet known at the time the log message is issued, it should not be a problem. Miklos > claudio > > On Thu, Jul 24, 2008 at 10:32 AM, Miklos Tirpak <miklos(a)iptel.org> > wrote: >> >> On 07/24/2008 01:11 PM, caio wrote: >>> >>> Hi Miklos, >>> This happens only when I try to do a call to a subcriber having >>> forwarding enabled. >>> >>> Normal calls success ok. I'm not sure about the append_branch() usage >>> and how to work with 'on busy' and 'no answer' forwarding features. >> >> The config script looks fine, I suppose you see the log messages "LOG: >> --> >> appending new branch..." and "LOG: --> Calling route_6..." before the >> error >> logs you posted. >> >> SER tries to forward the call to wsa.lab. It tries to resolve the SRV >> record >> first without success, than resolves the A record (there is no error, >> so >> the >> resolution is ok). >> >> I believe there is a routing or firewall problem, because sendto() >> function >> returns with error, so the issue is not SER-related in my opinion, try >> to >> google for "sendto operation not permitted". Disable iptables or any >> other >> firewall you have, verify that the routing is correct, and SER listens >> on >> the interface that is used to send out the packet. >> >> I would also try to send a call to wsa.lab without failure route with a >> very >> simple ser script. >> >> Miklos >> >>> Thanks your comments.. >>> >>> Claudio >>> >>> On Thu, Jul 24, 2008 at 4:58 AM, Miklos Tirpak <miklos(a)iptel.org> >>> wrote: >>>> >>>> Hi, >>>> >>>> On 07/23/2008 05:22 PM, caio wrote: >>>>> >>>>> Hi guys, >>>>> I have a problem with call forwarding (on busy or not answer).., the >>>>> call fall into the failure_route(1) block, and AVP checking and >>>>> pushto >>>>> does its job. >>>>> >>>>> Here a snipped of code of failure_route(1) (flag 27 means call fwd >>>>> if >>>>> no answer): >>>>> >>>>> if (isflagset(27) && t_check_status("408")) { # if fwd no >>>>> answer is set and reply msg is 408 >>>>> >>>>> if (avp_pushto("$ruri", "s:fwdnoanswer")) { >>>>> avp_delete("s:fwdnoanswer"); >>>>> resetflag(27); >>>>> >>>>> avp_print(); >>>>> >>>>> log(1, "LOG: --> appending new branch..."); >>>>> if (!append_branch()){ >>>>> t_reply("500", "Too many branches?!"); >>>>> drop; >>>>> } >>>>> >>>>> log(1, "LOG: --> Calling route_6..."); >>>>> route(6); >>>>> break; >>>>> >>>>> Route(6) finally calls route(1), where t_relay is called. >>>>> But have a dns failure..and the call never is forwarded. >>>>> >>>>> == ser.log == >>>>> >>>>> DEBUG: mk_proxy: doing DNS lookup... >>>>> get_record: lookup(_sip._udp.wsa.lab, 33) failed_ >>>>> sip_resolvehost: no SRV record found for wsa.lab, trying 'normal' >>>>> lookup..._ >>>>> check_via_address(190.244.33.5, 190.244.33.5, 0)_ >>>>> ERROR: udp_send: >>>>> sendto(sock,0x2ab32599c720,910,0,0x2ab325999e68,16): >>>>> Operation not permitted(1)_ >>>>> msg_send: ERROR: udp_send failed_ >>>>> ERROR: t_forward_nonack: sending request failed_ >>>>> DEBUG: add_to_tail_of_timer[4]: 0x2ab325999e80_ >>>>> DEBUG: add_to_tail_of_timer[0]: 0x2ab325999ea0_ >>>>> ERROR: w_t_relay (failure mode): forwarding failed_ >>>>> >>>>> A question regarding this trouble.....Can I disable use_dns_cache ? >>>>> SER version is 0.9.7. >>>> >>>> there is no DNS cache in version 0.9.x as I recall, but anyway, your >>>> problem >>>> does not seem to be related to DNS, but to the UDP message sending: >>>> SER >>>> fails to send out the UDP packet, "Operation not permitted". Is there >>>> no >>>> firewall or routing problem at the proxy side? >>>> >>>> Miklos >>>> >>>>> What do you recommend? >>>>> If you need my ser.cfg I can paste it... >>>>> >>>>> Thanks.. >>>>> >>> >>> -- >>> caio >>> >>> >>> > >

On 07/24/2008 07:38 PM, caio wrote: This part of the log is different from the previous one, because there is no SRV lookup. It seems that SER tries to send the call to wsa.lab even if the RURI was rewritten to 127.0.0.1:5061 in case of call forwarding, and in the above log there was probably no DNS lookup at all, just the log message. Do you set the destination URI to wsa.lab in failure_route, or in any other route that is called from there? Could you print out the RURI and the destination URI as well just before t_relay() is called? Miklos > Jul 24 14:14:36 [/usr/sbin/ser] check_via_address(190.244.33.5, > 190.244.33.5, 0)_ > Jul 24 14:14:36 [/usr/sbin/ser] DEBUG: add_to_tail_of_timer[4]: > 0x2b540cf4cee8_ > Jul 24 14:14:36 [/usr/sbin/ser] DEBUG: add_to_tail_of_timer[0]: > 0x2b540cf4cf08_ > Jul 24 14:14:36 [/usr/sbin/ser] SER: new transaction fwd'ed_ > Jul 24 14:14:36 [/usr/sbin/ser] LOG: --> T_RELAY okkkkkkk > > > On Thu, Jul 24, 2008 at 12:16 PM, Miklos Tirpak &lt;miklos(a)iptel.org&gt; > wrote: >> >> On 07/24/2008 04:38 PM, caio wrote: >>> >>> Ok, I understand the dns lookup is working (however no SRV resolution, >>> doesn't matter).. >>> I've disabled iptables (via shorewall) and verify that ser listen on: >>> >>> # netstat -nlp >>> Active Internet connections (only servers) >>> Proto Recv-Q Send-Q Local Address Foreign Address >>> State PID/Program name >>> tcp 0 0 <public_ip>:5060 0.0.0.0:* >>> LISTEN 29557/ser >>> udp 0 0 <public_ip>:5060 0.0.0.0:* >>> 29557/ser >>> >>> But still the same error... >>> Here the log (from when the failure_route begins), you can observe >>> what you've told before, those logs are printed before the "sendto" >>> failure.. >>> >>> Jul 24 11:23:06 [/usr/sbin/ser] LOG: --> FAILURE_ROUTE[1] BLOCK >>> BEGINS.... >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG: t_check: msg id=1 global id=1 T >>> start=0x2b7003fb9d90_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG: t_check: T already found!_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG:t_check_status: checked status >>> is >>> <408>_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG: t_check: msg id=1 global id=1 T >>> start=0x2b7003fb9d90_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG: t_check: T already found!_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG:t_check_status: checked status >>> is >>> <408>_ >>> Jul 24 11:23:06 [/usr/sbin/ser] LOG: --> Forwarding call on NO Answer >>> (isflagset(27) and timedout call)... _ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG:avpops:pushto_avps: 1 avps were >>> processed_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG:avpops:print_avp: >>> p=0x2b7003fb9d48, flags=1_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG:___name=<inv_timeout>_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG:___val_int=<15>_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG:avpops:print_avp: >>> p=0x2b7003fb9ce8, flags=B_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG:___name=<fwdnoanswer>_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG:___val_str=<sip:501855@wsa.lab>_ >>> Jul 24 11:23:06 [/usr/sbin/ser] LOG: --> appending new branch... >>> Jul 24 11:23:06 [/usr/sbin/ser] XLOG: xl_print_log: final buffer >>> length >>> 37_ >>> Jul 24 11:23:06 [/usr/sbin/ser] XLOG: current uri: sip:501855@wsa.lab >>> Jul 24 11:23:06 [/usr/sbin/ser] XLOG: xl_print_log: final buffer >>> length >>> 175_ >>> Jul 24 11:23:06 [/usr/sbin/ser] failure_route - call forward no answer >>> - M=INVITE RURI=sip:501855@wsa.lab F=sip:579951@wsa.lab >>> T=sip:579915@wsa.lab IP=<null>i >>> ID=Y2E0ZGQyZDNjM2IzYzBmZjhmMWI1YjE3NWFiYWQ5YWQ._ >> >> This is fine, the RURI is rewritten to the forwarding destination. >> >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG:avpops:remove_avps: 1 avps were >>> removed_ >>> Jul 24 11:23:06 [/usr/sbin/ser] LOG: --> Calling route_6... >>> Jul 24 11:23:06 [/usr/sbin/ser] lookup(): &#39;501855(a)wsa.lab&#39; Not found >>> in >>> usrloc_ >>> - Last output repeated twice - >>> Jul 24 11:23:06 [/usr/sbin/ser] does_uri_exit(): User in request uri >>> does not exist_ >>> Jul 24 11:23:06 [/usr/sbin/ser] XLOG: xl_print_log: final buffer >>> length >>> 80_ >>> Jul 24 11:23:06 [/usr/sbin/ser] XLOG: After a NEW lookup(location) in >>> route_6 block .. R-URI: sip:501855@wsa.lab >>> Jul 24 11:23:06 [/usr/sbin/ser] LOG: --> Calling Route_5 block >>> Jul 24 11:23:06 [/usr/sbin/ser] LOG: --> Forwarding to Asterisk GW _ >>> Jul 24 11:23:06 [/usr/sbin/ser] XLOG: xl_print_log: final buffer >>> length >>> 158_ >>> Jul 24 11:23:06 [/usr/sbin/ser] XLOG: t_relay: - M=INVITE >>> RURI=sip:501855@127.0.0.1:5061 F=sip:579951@wsa.lab >>> T=sip:579915@wsa.lab IP=<null>i >>> ID=Y2E0ZGQyZDNjM2IzYzBmZjhmMWI1YjE3NWFiYWQ5YWQ._ >> >> The RURI no longer contains wsa.lab, it points to 127.0.0.1:5061 >> Is this what you want? >> >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG: mk_proxy: doing DNS lookup..._ >>> Jul 24 11:23:06 [/usr/sbin/ser] get_record: lookup(_sip._udp.wsa.lab, >>> 33) failed_ >>> Jul 24 11:23:06 [/usr/sbin/ser] sip_resolvehost: no SRV record found >>> for wsa.lab, trying 'normal' lookup..._ >> >> From this it seems that SER still tries to get the IP for wsa.lab, did >> this >> is confusing. >> >>> Jul 24 11:23:06 [/usr/sbin/ser] check_via_address(a.b.c.d, a.b.c.d, >>> 0)_ >>> Jul 24 11:23:06 [/usr/sbin/ser] ERROR: udp_send: >>> sendto(sock,0x2b7003fbc920,908,0,0x2b7003fba070,16): Operation not >>> permitted(1)_ >> >> Try to verify somehow, that the next host SER is trying to send the >> packet >> is not 127.0.0.1:5061. If 127.0.0.1:5061 is the next hop, and no >> process >> listens on port 5061, than you can get this error I guess. >> >> Or if you want SER to forward the request to 127.0.0.1:5061, and this >> is >> the >> correct next hop, than it may happen that the outgoing interface was >> wrongly >> determined, try to enable mhomed in the config file. >> >>> Jul 24 11:23:06 [/usr/sbin/ser] msg_send: ERROR: udp_send failed_ >>> Jul 24 11:23:06 [/usr/sbin/ser] ERROR: t_forward_nonack: sending >>> request >>> failed_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG: add_to_tail_of_timer[4]: >>> 0x2b7003fba088_ >>> Jul 24 11:23:06 [/usr/sbin/ser] DEBUG: add_to_tail_of_timer[0]: >>> 0x2b7003fba0a8_ >>> Jul 24 11:23:06 [/usr/sbin/ser] ERROR: w_t_relay (failure mode): >>> forwarding failed_ >>> Jul 24 11:23:06 [/usr/sbin/ser] LOG: --> T_RELAY failed! fuck... >>> Jul 24 11:23:06 [/usr/sbin/ser] parse_headers: flags=-1_ >>> Jul 24 11:23:06 [/usr/sbin/ser] check_via_address(a.b.c.d, a.b.c.d, >>> 0)_ >>> Jul 24 11:23:06 [/usr/sbin/ser] ERROR: sl_reply_error used: I'm >>> terribly sorry, server error occurred (1/SL)_ >>> >>> Observations: >>> 1) usr_preferences table entries are these: >>> >>> >>> >>> +------+----------+---------+---------------+--------------------+------+---------------------+ >>> | uuid | username | domain | attribute | value | >>> type | modified| >>> >>> >>> >>> +------+----------+---------+---------------+--------------------+------+---------------------+ >>> | | 579915 | wsa.lab | fwdnoanswer | sip:501855@wsa.lab | >>> 0 | 2008-07-24 10:55:37 | >>> >>> where 579915 are a local subscriber, and 501855 is a PSTN-user (via >>> asterisk gw).. >>> >>> 2) check_via_address(a.b.c.d, a.b.c.d, 0) where a.b.c.d is the IP of >>> the caller SIP-UA (xlite softphone) >>> 3) look at the current URI at the moment of t_relay() call...the line >>> before this msg "DEBUG: mk_proxy: doing DNS lookup" >>> Is it well-formed? >>> M=INVITE RURI=sip:501855@127.0.0.1:5061 --> URI is the forwarding >>> number >>> (???) >>> F=sip:579951@wsa.lab --> FROM is our caller (ok) >>> T=sip:579915@wsa.lab --> TO field is the subscriber who has callfwd >>> enabled, (???) >> >> Yes this is correct. The To HF cannot be modified, the RURI should >> contain >> the new destination. >> >>> IP=<null> ---> why is it NULL ??? >> >> The destination ip address is probably not yet known at the time the >> log >> message is issued, it should not be a problem. >> >> Miklos >> >>> claudio >>> >>> On Thu, Jul 24, 2008 at 10:32 AM, Miklos Tirpak &lt;miklos(a)iptel.org&gt; >>> wrote: >>>> >>>> On 07/24/2008 01:11 PM, caio wrote: >>>>> >>>>> Hi Miklos, >>>>> This happens only when I try to do a call to a subcriber having >>>>> forwarding enabled. >>>>> >>>>> Normal calls success ok. I'm not sure about the append_branch() >>>>> usage >>>>> and how to work with 'on busy' and 'no answer' forwarding features. >>>> >>>> The config script looks fine, I suppose you see the log messages >>>> "LOG: >>>> --> >>>> appending new branch..." and "LOG: --> Calling route_6..." before the >>>> error >>>> logs you posted. >>>> >>>> SER tries to forward the call to wsa.lab. It tries to resolve the SRV >>>> record >>>> first without success, than resolves the A record (there is no error, >>>> so >>>> the >>>> resolution is ok). >>>> >>>> I believe there is a routing or firewall problem, because sendto() >>>> function >>>> returns with error, so the issue is not SER-related in my opinion, >>>> try >>>> to >>>> google for "sendto operation not permitted". Disable iptables or any >>>> other >>>> firewall you have, verify that the routing is correct, and SER >>>> listens >>>> on >>>> the interface that is used to send out the packet. >>>> >>>> I would also try to send a call to wsa.lab without failure route with >>>> a >>>> very >>>> simple ser script. >>>> >>>> Miklos >>>> >>>>> Thanks your comments.. >>>>> >>>>> Claudio >>>>> >>>>> On Thu, Jul 24, 2008 at 4:58 AM, Miklos Tirpak &lt;miklos(a)iptel.org&gt; >>>>> wrote: >>>>>> >>>>>> Hi, >>>>>> >>>>>> On 07/23/2008 05:22 PM, caio wrote: >>>>>>> >>>>>>> Hi guys, >>>>>>> I have a problem with call forwarding (on busy or not answer).., >>>>>>> the >>>>>>> call fall into the failure_route(1) block, and AVP checking and >>>>>>> pushto >>>>>>> does its job. >>>>>>> >>>>>>> Here a snipped of code of failure_route(1) (flag 27 means call fwd >>>>>>> if >>>>>>> no answer): >>>>>>> >>>>>>> if (isflagset(27) && t_check_status("408")) { # if fwd no >>>>>>> answer is set and reply msg is 408 >>>>>>> >>>>>>> if (avp_pushto("$ruri", "s:fwdnoanswer")) { >>>>>>> avp_delete("s:fwdnoanswer"); >>>>>>> resetflag(27); >>>>>>> >>>>>>> avp_print(); >>>>>>> >>>>>>> log(1, "LOG: --> appending new branch..."); >>>>>>> if (!append_branch()){ >>>>>>> t_reply("500", "Too many branches?!"); >>>>>>> drop; >>>>>>> } >>>>>>> >>>>>>> log(1, "LOG: --> Calling route_6..."); >>>>>>> route(6); >>>>>>> break; >>>>>>> >>>>>>> Route(6) finally calls route(1), where t_relay is called. >>>>>>> But have a dns failure..and the call never is forwarded. >>>>>>> >>>>>>> == ser.log == >>>>>>> >>>>>>> DEBUG: mk_proxy: doing DNS lookup... >>>>>>> get_record: lookup(_sip._udp.wsa.lab, 33) failed_ >>>>>>> sip_resolvehost: no SRV record found for wsa.lab, trying 'normal' >>>>>>> lookup..._ >>>>>>> check_via_address(190.244.33.5, 190.244.33.5, 0)_ >>>>>>> ERROR: udp_send: >>>>>>> sendto(sock,0x2ab32599c720,910,0,0x2ab325999e68,16): >>>>>>> Operation not permitted(1)_ >>>>>>> msg_send: ERROR: udp_send failed_ >>>>>>> ERROR: t_forward_nonack: sending request failed_ >>>>>>> DEBUG: add_to_tail_of_timer[4]: 0x2ab325999e80_ >>>>>>> DEBUG: add_to_tail_of_timer[0]: 0x2ab325999ea0_ >>>>>>> ERROR: w_t_relay (failure mode): forwarding failed_ >>>>>>> >>>>>>> A question regarding this trouble.....Can I disable use_dns_cache >>>>>>> ? >>>>>>> SER version is 0.9.7. >>>>>> >>>>>> there is no DNS cache in version 0.9.x as I recall, but anyway, >>>>>> your >>>>>> problem >>>>>> does not seem to be related to DNS, but to the UDP message sending: >>>>>> SER >>>>>> fails to send out the UDP packet, "Operation not permitted". Is >>>>>> there >>>>>> no >>>>>> firewall or routing problem at the proxy side? >>>>>> >>>>>> Miklos >>>>>> >>>>>>> What do you recommend? >>>>>>> If you need my ser.cfg I can paste it... >>>>>>> >>>>>>> Thanks.. >>>>>>> >>>>> -- >>>>> caio >>>>> >>>>> >>>>> >>> > >