I've repeated the test with DEBUG level logging. The logs seem to indicate
that whatever this problem is, it happens when trying to relay (using
t_relay()) when outbound is in use. Here are the detailed logs:
16(1547) DEBUG: rr [loose.c:86]: is_preloaded(): is_preloaded: Yes
16(1547) DEBUG: <core> [socket_info.c:583]: grep_sock_info():
grep_sock_info - checking if host==us: 27==11 && [
edge01-int.crocodilertc.net] == [10.112.7.76]
16(1547) DEBUG: <core> [socket_info.c:587]: grep_sock_info():
grep_sock_info - checking if port 5060 (advertise 5060) matches port 5080
16(1547) DEBUG: <core> [socket_info.c:583]: grep_sock_info():
grep_sock_info - checking if host==us: 27==11 && [
edge01-int.crocodilertc.net] == [10.112.7.76]
16(1547) DEBUG: <core> [socket_info.c:587]: grep_sock_info():
grep_sock_info - checking if port 80 (advertise 80) matches port 5080
16(1547) DEBUG: <core> [socket_info.c:583]: grep_sock_info():
grep_sock_info - checking if host==us: 27==11 && [
edge01-int.crocodilertc.net] == [10.112.7.76]
16(1547) DEBUG: <core> [socket_info.c:587]: grep_sock_info():
grep_sock_info - checking if port 5060 (advertise 5060) matches port 5080
16(1547) DEBUG: <core> [socket_info.c:583]: grep_sock_info():
grep_sock_info - checking if host==us: 27==11 && [
edge01-int.crocodilertc.net] == [10.112.7.76]
16(1547) DEBUG: <core> [socket_info.c:587]: grep_sock_info():
grep_sock_info - checking if port 5080 (advertise 5080) matches port 5080
16(1547) DEBUG: <core> [socket_info.c:603]: grep_sock_info():
grep_sock_info - checking advertise if host==us: 27==27 && [
edge01-int.crocodilertc.net] == [
edge01-int.crocodilertc.net]
16(1547) DEBUG: rr [loose.c:785]: after_loose(): Topmost route URI:
'sip:RaOAmYgp669h0QYKcAdMAbtamABmhaE=@edge01-int.crocodilertc.net:5080;transport=tcp;lr;ob'
is me
16(1547) DEBUG: rr [loose.c:525]: process_outbound(): "incoming" request
found. Using flow-token forrouting
16(1547) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found
end of header
16(1547) DEBUG: rr [loose.c:181]: find_next_route(): No next Route HF found
16(1547) DEBUG: rr [loose.c:809]: after_loose(): No next URI found
16(1547) DEBUG: tm [t_lookup.c:1372]: t_newtran(): DEBUG: t_newtran: msg
id=1 , global msg id=1 , T on entrance=(nil)
16(1547) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request:
start searching: hash=4829, isACK=0
16(1547) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261
transaction matching failed
16(1547) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG:
t_lookup_request: no transaction found
16(1547) DEBUG: tm [t_hooks.c:374]: run_reqin_callbacks_internal(): DBG:
trans=0x7fe2a1af2080, callback type 1, id 0 entered
16(1547) DEBUG: <core> [md5utils.c:67]: MD5StringArray(): DEBUG: MD5
calculated: 86424f366665cacef83c4e082d9c7167
16(1547) ERROR: <core> [resolve.c:1700]: sip_hostport2su(): ERROR:
sip_hostport2su: could not resolve hostname: "90.152.0.102"
16(1547) ERROR: tm [ut.h:337]: uri2dst2(): failed to resolve "90.152.0.102"
16(1547) ERROR: tm [t_fwd.c:1772]: t_forward_nonack(): ERROR:
t_forward_nonack: failure to add branches
16(1547) DEBUG: tm [t_funcs.c:357]: t_relay_to(): ERROR:tm:t_relay_to:
t_forward_nonack returned error
16(1547) DEBUG: tm [t_funcs.c:374]: t_relay_to(): -478 error reply
generation delayed
16(1547) DEBUG: tm [t_lookup.c:1071]: t_check_msg(): DEBUG: t_check_msg:
msg id=1 global id=1 T start=0x7fe2a1af2080
16(1547) DEBUG: tm [t_lookup.c:1143]: t_check_msg(): DEBUG: t_check_msg: T
already found!
16(1547) DEBUG: <core> [msg_translator.c:204]: check_via_address():
check_via_address(10.185.34.56,
registrar-int.crocodilertc.net, 0)
16(1547) DEBUG: <core> [mem/shm_mem.c:111]: _shm_resize():
WARNING:vqm_resize: resize(0) called
16(1547) DEBUG: tm [t_reply.c:1667]: cleanup_uac_timers(): DEBUG:
cleanup_uac_timers: RETR/FR timers reset
16(1547) DEBUG: <core> [tcp_main.c:2320]: tcpconn_send_put(): tcp_send:
send from reader (1547 (16)), reusing fd
16(1547) DEBUG: <core> [tcp_main.c:2556]: tcpconn_do_send(): tcp_send:
sending...
16(1547) DEBUG: <core> [tcp_main.c:2590]: tcpconn_do_send(): tcp_send:
after real write: c= 0x7fe2a19f1d70 n=651 fd=8
16(1547) DEBUG: <core> [tcp_main.c:2591]: tcpconn_do_send(): tcp_send: buf=
SIP/2.0 430 Flow Failed^M
Does anyone know of any recent TM or resolver changes that would affect
this?
Regards,
Peter
On 2 October 2013 11:49, Peter Dunkley <peter.dunkley(a)crocodilertc.net>wrote;wrote:
Hello,
I am getting the following errors with the latest code:
Oct 2 10:48:00 edge00 kamailio-edge[8847]: ERROR: <core>
[resolve.c:1700]: sip_hostport2su(): ERROR: sip_hostport2su: could not
resolve hostname: "90.152.0.102"
Oct 2 10:48:00 edge00 kamailio-edge[8847]: ERROR: tm [ut.h:337]:
uri2dst2(): failed to resolve "90.152.0.102"
Oct 2 10:48:00 edge00 kamailio-edge[8847]: ERROR: tm [t_fwd.c:1772]:
t_forward_nonack(): ERROR: t_forward_nonack: failure to add branches
Regards,
Peter
--
Peter Dunkley
Technical Director
Crocodile RCS Ltd
--
Peter Dunkley
Technical Director
Crocodile RCS Ltd