Daniel-Constantin Mierla writes:
afaik, the list should be saved for tm lifetime. If
you run with high
debug level, do you see any message when the list is destroyed?
daniel,
plenty, but they don't tell me anything. what does this mean?
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
below is what comes to syslog when request is forwarded in route block
and when reply is received.
i have called t_newtrans() before i call t_relay() if that could explain
anything.
-- juha
when request if forwarded:
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: INFO: Routing INVITE to contacts
<sip:test@192.98.102.10:5074;transport=udp> and <<null>>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: tm [t_lookup.c:1379]: DEBUG:
t_newtran: msg id=28 , global msg id=28 , T on entrance=0xb49932e8
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: tm [t_lookup.c:1384]: DEBUG:
t_newtran: transaction already in process 0xb49932e8
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core> [select.c:424]:
Calling SELECT 0xb73e5dd0
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: permissions [address.c:395]:
looking for <2, a6662c0, 5074>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core> [dns_cache.c:3392]:
dns_sip_resolve(192.98.102.10, 0, 0), ip, ret=0
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core>
[msg_translator.c:204]: check_via_address(192.98.102.10, 192.98.102.10, 0)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: tm [t_funcs.c:388]: SER: new
transaction fwd'ed
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19855]: DEBUG: <core> [xavp.c:423]:
destroying xavp list (nil)
when 180 reply is received:
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/msg_parser.c:640]: SIP Reply (status):
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core> [receive.c:146]: After
parse_msg...
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/msg_parser.c:642]: version: <SIP/2.0>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_lookup.c:1081]: DEBUG:
t_check_msg: msg id=29 global id=28 T start=0xffffffff
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/msg_parser.c:644]: status: <180>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core>
[parser/parse_to.c:803]: end of header reached, state=10
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/msg_parser.c:646]: reason: <Ringing>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core>
[parser/msg_parser.c:187]: DEBUG: get_hdr_field: <To> [20]; uri=[sip:test@test.fi]
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/parse_via.c:1287]: Found param type 232, <branch> =
<z9hG4bK358f.316a3396f38bbae0398336dc8ee68999.0>; state=9
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core>
[parser/msg_parser.c:189]: DEBUG: to body [<sip:test@test.fi>#015#012]
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/parse_via.c:2343]: parse_via: next_via
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core>
[parser/msg_parser.c:167]: get_hdr_field: cseq <CSeq>: <794> <INVITE>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/parse_via.c:1287]: Found param type 235, <rport> = <5074>; state=6
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_lookup.c:967]: DEBUG:
t_reply_matching: hash 63571 label 0 branch 0
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/parse_via.c:1287]: Found param type 232, <branch> = <z9hG4bKypzwzcfe>;
state=16
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_lookup.c:1018]: DEBUG:
t_reply_matching: reply matched (T=0xb49932e8)!
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/parse_via.c:2300]: end of header reached, state=5
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/msg_parser.c:515]: parse_headers: Via found, flags=2
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_hooks.c:288]: DBG:
trans=0xb49932e8, callback type 2, id 0 entered
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/msg_parser.c:517]: parse_headers: this is the first via
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_lookup.c:1150]: DEBUG:
t_check_msg: msg id=29 global id=29 T end=0xb49932e8
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core> [receive.c:146]: After
parse_msg...
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_lookup.c:1081]: DEBUG:
t_check_msg: msg id=35 global id=34 T start=0xffffffff
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/parse_to.c:174]: DEBUG: add_param: tag=llpls
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_reply.c:2017]: DEBUG:
reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=1)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/parse_to.c:803]: end of header reached, state=29
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_lookup.c:1081]: DEBUG:
t_check_msg: msg id=29 global id=29 T start=0xb49932e8
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/msg_parser.c:187]: DEBUG: get_hdr_field: <To> [30]; uri=[sip:test@test.fi]
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/msg_parser.c:189]: DEBUG: to body [<sip:test@test.fi>]
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_lookup.c:1153]: DEBUG:
t_check_msg: T already found!
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: <core>
[parser/msg_parser.c:167]: get_hdr_field: cseq <CSeq>: <794> <INVITE>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [tm.c:968]:
DEBUG:t_check_status: checked status is <100>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_lookup.c:967]: DEBUG:
t_reply_matching: hash 63571 label 0 branch 0
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_lookup.c:1018]: DEBUG:
t_reply_matching: reply matched (T=0xb49932e8)!
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_lookup.c:1081]: DEBUG:
t_check_msg: msg id=29 global id=29 T start=0xb49932e8
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_hooks.c:288]: DBG:
trans=0xb49932e8, callback type 2, id 0 entered
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_lookup.c:1153]: DEBUG:
t_check_msg: T already found!
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_lookup.c:1150]: DEBUG:
t_check_msg: msg id=35 global id=35 T end=0xb49932e8
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [tm.c:968]:
DEBUG:t_check_status: checked status is <100>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_reply.c:2017]: DEBUG:
reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=1)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_reply.c:1132]:
->>>>>>>>> T_code=0, new_code=100
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: tm [t_reply.c:1634]: DEBUG:
relay_reply: branch=0, save=0, relay=-1
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_lookup.c:1081]: DEBUG:
t_check_msg: msg id=35 global id=35 T start=0xb49932e8
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_lookup.c:1153]: DEBUG:
t_check_msg: T already found!
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [tm.c:968]:
DEBUG:t_check_status: checked status is <180>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_lookup.c:1081]: DEBUG:
t_check_msg: msg id=35 global id=35 T start=0xb49932e8
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_lookup.c:1153]: DEBUG:
t_check_msg: T already found!
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [tm.c:968]:
DEBUG:t_check_status: checked status is <180>
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_lookup.c:1081]: DEBUG:
t_check_msg: msg id=35 global id=35 T start=0xb49932e8
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core> [usr_avp.c:646]:
DEBUG:destroy_avp_list: destroying list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [t_lookup.c:1153]: DEBUG:
t_check_msg: T already found!
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19853]: DEBUG: <core> [xavp.c:423]:
destroying xavp list (nil)
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG: tm [tm.c:968]:
DEBUG:t_check_status: checked status is <180>