Hi Juha,

On 4/26/11 12:58 PM, Juha Heinanen wrote:
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)
this tells that the avp list was null. The message is printed 6 times since ser added 5 more avp lists - kamailio used to have 1, the first, corresponding to FROM_URI list in ser notation. So, it looks like all the avps list were null when the core cleaned the received message. If there was an avp in any of the lists and it was not deleted, then the lists are null because they were moved to transaction.

Could it be that this avp is deleted automatically somewhere in a module?

Cheers,
Daniel


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:t...@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:t...@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:t...@test.fi]
Apr 26 13:31:43 sip /usr/sbin/sip-proxy[19854]: DEBUG:<core>  
[parser/msg_parser.c:189]: DEBUG: to body [<sip:t...@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>

_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

--
Daniel-Constantin Mierla
http://www.asipto.com


_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

Reply via email to