domain module sets $td.did at lookup_domain call. $td.did seems to be a normal avp, because i can print its value with xlog by referring to it as $avp(td.did). however, its value is gone at failure route, which makes me suspect that $td.did is not really a normal avp.
in route block i have
$avp(did) = $td.did; xlog("L_INFO", "at t_relay: <td/td.did> = <$avp(did)/$avp(td.did)>\n"); if (t_relay()) exit;
branch route, onreply route, and failure route are set when the above t_relay() takes place.
at the end of branch route block, i have
xlog("L_INFO", "at end of contact branches: <did/td.did> = <$avp(did)/$avp(td.did)>\n");
and at the beginning of onreply route block:
xlog("L_INFO", "at beginning of onreply: <did/td.did> = <$avp(did)/$avp(td.did)>\n");
and at the beginning of failure route block:
xlog("L_INFO", "at beginning of contact failure: <did/td.did = <$avp(did)/$avp(td.did)>\n");
when i make a call, i get to syslog:
Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13706]: INFO: at t_relay: <td/td.did> = <test.fi/test.fi> Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13706]: INFO: at end of contact branches: <did/td.did> = <test.fi/test.fi> Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13708]: INFO: at beginning of onreply: <did/td.did> = <test.fi/<null>> Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13705]: INFO: at beginning of contact failure: <did/td.did = <test.fi/<null>>
why is it that $avp(did) value has been preserved from route/branch route block to onreply/failure blocks, but value of $avp(td.did) is not?
i'll cc to jan in case he is not on this list.
-- juha
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?
Cheers, Daniel
On 4/22/11 3:00 PM, Juha Heinanen wrote:
domain module sets $td.did at lookup_domain call. $td.did seems to be a normal avp, because i can print its value with xlog by referring to it as $avp(td.did). however, its value is gone at failure route, which makes me suspect that $td.did is not really a normal avp.
in route block i have
$avp(did) = $td.did; xlog("L_INFO", "at t_relay:<td/td.did> =<$avp(did)/$avp(td.did)>\n"); if (t_relay()) exit;branch route, onreply route, and failure route are set when the above t_relay() takes place.
at the end of branch route block, i have
xlog("L_INFO", "at end of contact branches:<did/td.did> =<$avp(did)/$avp(td.did)>\n");and at the beginning of onreply route block:
xlog("L_INFO", "at beginning of onreply:<did/td.did> =<$avp(did)/$avp(td.did)>\n");and at the beginning of failure route block:
xlog("L_INFO", "at beginning of contact failure:<did/td.did =<$avp(did)/$avp(td.did)>\n");when i make a call, i get to syslog:
Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13706]: INFO: at t_relay:<td/td.did> =<test.fi/test.fi> Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13706]: INFO: at end of contact branches:<did/td.did> =<test.fi/test.fi> Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13708]: INFO: at beginning of onreply:<did/td.did> =<test.fi/<null>> Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13705]: INFO: at beginning of contact failure:<did/td.did =<test.fi/<null>>
why is it that $avp(did) value has been preserved from route/branch route block to onreply/failure blocks, but value of $avp(td.did) is not?
i'll cc to jan in case he is not on this list.
-- juha
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 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>
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 contactssip: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>
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 writes:
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?
i haven't found that kind of action in s domain module. avps are destroyed only when whole domain is deleted.
-- juha
modules_s/domain$ egrep -i avp *.c domain.c: if (d->attrs) destroy_avp_list(&d->attrs); domain.c: str name_s = STR_STATIC_INIT(AVP_DID); domain.c: if (add_avp_list(&d->attrs, AVP_CLASS_DOMAIN | AVP_NAME_STR | AVP_VAL_STR, domain.c: str avp_val; domain.c: /* Get AVP name */ domain.c: avp_val.s = 0; domain.c: avp_val.len = 0; domain.c: avp_val = rec->fld[2].v.lstr; domain.c: flags = AVP_CLASS_DOMAIN | AVP_NAME_STR; domain.c: if (rec->fld[1].v.int4 == AVP_VAL_STR) { domain.c: /* String AVP */ domain.c: v.s = avp_val; domain.c: flags |= AVP_VAL_STR; domain.c: /* Integer AVP */ domain.c: str2int(&avp_val, (unsigned*)&v.n); domain.c: if (add_avp_list(&d->attrs, flags, name, v) < 0) { domain_mod.c:#include "../../usr_avp.h" domain_mod.c: destroy_avp_list(&d->attrs); domain_mod.c: str name_s = STR_STATIC_INIT(AVP_DID); domain_mod.c: if (flags & AVP_TRACK_FROM) { domain_mod.c: if (add_avp_list(&p->attrs, AVP_CLASS_DOMAIN | AVP_NAME_STR | AVP_VAL_STR, domain_mod.c: set_avp_list((unsigned long)flags, &d->attrs); domain_mod.c: set_avp_list((unsigned long)flags, &d->attrs); domain_mod.c: flags = AVP_TRACK_FROM | AVP_CLASS_DOMAIN; domain_mod.c: flags = AVP_TRACK_TO | AVP_CLASS_DOMAIN; domain_rpc.c: avp_t* a; domain_rpc.c: name = get_avp_name(a); domain_rpc.c: get_avp_val(a, &val); domain_rpc.c: if (a->flags & AVP_VAL_STR) {
Not helping with this issue - but having another question: what is $td.did? Is it a pseudo variable (as it starts with $)? Is it somehow related/derived to/from $td or is the '.' just a character like a-z?
thanks klaus
Juha Heinanen wrote:
domain module sets $td.did at lookup_domain call. $td.did seems to be a normal avp, because i can print its value with xlog by referring to it as $avp(td.did). however, its value is gone at failure route, which makes me suspect that $td.did is not really a normal avp.
in route block i have
$avp(did) = $td.did; xlog("L_INFO", "at t_relay: <td/td.did> = <$avp(did)/$avp(td.did)>\n"); if (t_relay()) exit;branch route, onreply route, and failure route are set when the above t_relay() takes place.
at the end of branch route block, i have
xlog("L_INFO", "at end of contact branches: <did/td.did> = <$avp(did)/$avp(td.did)>\n");and at the beginning of onreply route block:
xlog("L_INFO", "at beginning of onreply: <did/td.did> = <$avp(did)/$avp(td.did)>\n");and at the beginning of failure route block:
xlog("L_INFO", "at beginning of contact failure: <did/td.did = <$avp(did)/$avp(td.did)>\n");when i make a call, i get to syslog:
Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13706]: INFO: at t_relay: <td/td.did> = <test.fi/test.fi> Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13706]: INFO: at end of contact branches: <did/td.did> = <test.fi/test.fi> Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13708]: INFO: at beginning of onreply: <did/td.did> = <test.fi/<null>> Apr 22 15:53:27 sip /usr/sbin/sip-proxy[13705]: INFO: at beginning of contact failure: <did/td.did = <test.fi/<null>>
why is it that $avp(did) value has been preserved from route/branch route block to onreply/failure blocks, but value of $avp(td.did) is not?
i'll cc to jan in case he is not on this list.
-- juha
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
On Tue, Apr 26, 2011 at 7:41 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Not helping with this issue - but having another question: what is $td.did? Is it a pseudo variable (as it starts with $)? Is it somehow related/derived to/from $td or is the '.' just a character like a-z?
This is the SER syntax for AVP names, see http://sip-router.org/wiki/devel/avps-ser
-Jan
Jan Janak wrote:
On Tue, Apr 26, 2011 at 7:41 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Not helping with this issue - but having another question: what is $td.did? Is it a pseudo variable (as it starts with $)? Is it somehow related/derived to/from $td or is the '.' just a character like a-z?
This is the SER syntax for AVP names, see http://sip-router.org/wiki/devel/avps-ser
Aha. But how does sip-router decide if $td is a ser AVP or a Kamailio pseudo variable?
thanks klaus
On Tue, Apr 26, 2011 at 8:42 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Jan Janak wrote:
On Tue, Apr 26, 2011 at 7:41 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Not helping with this issue - but having another question: what is $td.did? Is it a pseudo variable (as it starts with $)? Is it somehow related/derived to/from $td or is the '.' just a character like a-z?
This is the SER syntax for AVP names, see http://sip-router.org/wiki/devel/avps-ser
Aha. But how does sip-router decide if $td is a ser AVP or a Kamailio pseudo variable?
If it starts with ${fu,tu,fd,td,g}. then it is taken as a SER AVPs, otherwise it is a Kamailio pseudo variable.
-Jan
Jan Janak wrote:
On Tue, Apr 26, 2011 at 8:42 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Jan Janak wrote:
On Tue, Apr 26, 2011 at 7:41 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Not helping with this issue - but having another question: what is $td.did? Is it a pseudo variable (as it starts with $)? Is it somehow related/derived to/from $td or is the '.' just a character like a-z?
This is the SER syntax for AVP names, see http://sip-router.org/wiki/devel/avps-ser
Aha. But how does sip-router decide if $td is a ser AVP or a Kamailio pseudo variable?
If it starts with ${fu,tu,fd,td,g}. then it is taken as a SER AVPs, otherwise it is a Kamailio pseudo variable.
Not sure if I got it right. I guess if I use $fu it will be Kamailio's from-URI pseudo variable as there is no ser $fu AVP as $fu is only the prefix and not the full AVP name, a full ser AVP name would be for example $fu.foo.
Is this correct?
klaus
On Tue, Apr 26, 2011 at 9:19 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Jan Janak wrote:
On Tue, Apr 26, 2011 at 8:42 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Jan Janak wrote:
On Tue, Apr 26, 2011 at 7:41 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Not helping with this issue - but having another question: what is $td.did? Is it a pseudo variable (as it starts with $)? Is it somehow related/derived to/from $td or is the '.' just a character like a-z?
This is the SER syntax for AVP names, see http://sip-router.org/wiki/devel/avps-ser
Aha. But how does sip-router decide if $td is a ser AVP or a Kamailio pseudo variable?
If it starts with ${fu,tu,fd,td,g}. then it is taken as a SER AVPs, otherwise it is a Kamailio pseudo variable.
Not sure if I got it right. I guess if I use $fu it will be Kamailio's from-URI pseudo variable as there is no ser $fu AVP as $fu is only the prefix and not the full AVP name, a full ser AVP name would be for example $fu.foo.
Is this correct?
Correct, there is a special case for a small number of well-known SER AVP name prefixes, everything else is considered Kamailio pseudo-variable. This is a temporary measure to make both syntaxes work.
-Jan
Jan Janak wrote:
On Tue, Apr 26, 2011 at 8:42 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Jan Janak wrote:
On Tue, Apr 26, 2011 at 7:41 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Not helping with this issue - but having another question: what is $td.did? Is it a pseudo variable (as it starts with $)? Is it somehow related/derived to/from $td or is the '.' just a character like a-z?
This is the SER syntax for AVP names, see http://sip-router.org/wiki/devel/avps-ser
Aha. But how does sip-router decide if $td is a ser AVP or a Kamailio pseudo variable?
If it starts with ${fu,tu,fd,td,g}. then it is taken as a SER AVPs, otherwise it is a Kamailio pseudo variable.
Not sure if I got it right. I guess if I use $fu it will be Kamailio's from-URI pseudo variable as there is no ser $fu AVP as $fu is only the prefix and not the full AVP name, a full ser AVP name would be for example $fu.foo.
Is this correct?
klaus
On 4/26/11 9:20 PM, Klaus Darilion wrote:
Jan Janak wrote:
On Tue, Apr 26, 2011 at 8:42 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Jan Janak wrote:
On Tue, Apr 26, 2011 at 7:41 PM, Klaus Darilion klaus.mailinglists@pernau.at wrote:
Not helping with this issue - but having another question: what is $td.did? Is it a pseudo variable (as it starts with $)? Is it somehow related/derived to/from $td or is the '.' just a character like a-z?
This is the SER syntax for AVP names, see http://sip-router.org/wiki/devel/avps-ser
Aha. But how does sip-router decide if $td is a ser AVP or a Kamailio pseudo variable?
If it starts with ${fu,tu,fd,td,g}. then it is taken as a SER AVPs, otherwise it is a Kamailio pseudo variable.
Not sure if I got it right. I guess if I use $fu it will be Kamailio's from-URI pseudo variable as there is no ser $fu AVP as $fu is only the prefix and not the full AVP name, a full ser AVP name would be for example $fu.foo.
Is this correct?
actually, to give further clarifications, the script variable lookup for $xyz is like: - search in K-style PV table for 'xyz' name and if found use it - if not found, treat it as AVP
So, $xyz (literally) is practically the same as $avp(xyz). When the integration happened, it was discovered there was no critical overlapping between existing PV names and ser avp lists - as mentioned in this thread, ser had lately several avp classes, using a dot to mark the end of the class and the start of the avp name.
In the past a non-existing PV name in K would have thrown error, now is considered to be classic K AVP (in ser style it is from uri avp).
Now the $avp(...) PV supports all classes, so you can use for example $avp(td.did). If the avp class is missing, then it is the 'f' class, afaik based on some emails sent in the past on the lists -- so these should be equivalent in the config file: - $myavp - $f.myavp - $avp(myavp) - $avp(f.myavp)
However, you better test the above equivalency, since I am using only K-style avps.
Cheers, Daniel
-
Daniel-Constantin Mierla -
Jan Janak -
Juha Heinanen -
Klaus Darilion