[Serusers] use_dns_cache and call forwarding
caio
elcaio at gmail.com
Thu Jul 24 16:38:06 CEST 2008
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 at 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 at 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 at wsa.lab F=sip:579951 at wsa.lab
T=sip:579915 at wsa.lab IP=<null>i
ID=Y2E0ZGQyZDNjM2IzYzBmZjhmMWI1YjE3NWFiYWQ5YWQ._
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(): '501855 at wsa.lab' 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 at 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 at 127.0.0.1:5061 F=sip:579951 at wsa.lab
T=sip:579915 at wsa.lab IP=<null>i
ID=Y2E0ZGQyZDNjM2IzYzBmZjhmMWI1YjE3NWFiYWQ5YWQ._
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..._
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)_
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 at 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 at 127.0.0.1:5061 --> URI is the forwarding number (???)
F=sip:579951 at wsa.lab --> FROM is our caller (ok)
T=sip:579915 at wsa.lab --> TO field is the subscriber who has callfwd
enabled, (???)
IP=<null> ---> why is it NULL ???
claudio
On Thu, Jul 24, 2008 at 10:32 AM, Miklos Tirpak <miklos at 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 at 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
>>
>>
>>
>
--
caio
More information about the sr-users
mailing list