[SR-Users] is $td.did avp a normal avp?

[Juha Heinanen]

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 at 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 at 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 at 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 at 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 at 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>