Re: 6.1.2 content of $avp being zapped after setting $sht

Benoit Panizzon via sr-users <[email protected]> Tue, 26 May 2026 10:07:03 +0200
Newsgroups gmane.comp.voip.ser
Organization ImproWare AG
Message-ID <[email protected]>
Hi Daniel

debug=3 output. 

Code:

                xlog("L_INFO", "$cfg(route): 4 DEST: $avp(destination_e164) \n");
                xlog("L_INFO", "$cfg(route): 4 $var(get_custprofileid) set to $var(xcustprof) \n");
                $var(get_custprofileid) = $var(xcustprof);
                xlog("L_INFO", "$cfg(route): 5 DEST: $avp(destination_e164) \n");
                $sht(custprof=>$var(get_custprofileid)) = $var(xcustprof);
                xlog("L_INFO", "$cfg(route): 6 DEST: $avp(destination_e164) \n");


$sht(custprof=>$var(get_custprofileid)) is a dmq replicated shared variable (containing various settings in the profile of that customer).

$sht(custprof=>1-TP0216-+41315996608) is being set to "to cust_profile_code=1-TP0216-+41315996608;id=6952891;mandate_id=1;lang=de;service_type=single;screening=no;max_channels=4;admin_barring=no;main_tn=+41315996608;blacklist_global=yes;dialplan_group=1;blockset_group=0;li=yes;forking=0;sd_lookup=force;version=9809;changed=1774901390;id=1448070;auth_username=315996608;auth_pw=cde242d5da97123c76b52c66fac93fe3;sig_profile=local;max_reg_contacts=6;supported_codec_group=0;allow_update=yes;allow_prack=yes;disable_ann=no;override_tn;ha1=1;version=9809;changed=1774901390;"

I am aware the password hash is visible in this trace. I noticed the output 'serialized data' looks truncated. I hope this is just the debug output being truncated.

For testing, the dmq peer is down at the moment so I assume the messages about the peer not being reachable can be ignored.

Possibly: xavp_destroy_list(): destroying xavp list is the cause? Why would an avp list get destroyed at this stage?

I'll retest with dmq replication disabled.

2026-05-26T07:51:26.841182+00:00 dev-core01 kamailio[391838]: INFO: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<script>: GET_CUST_PROFILE: 4 DEST: +41800800800 
2026-05-26T07:51:26.841247+00:00 dev-core01 kamailio[391838]: INFO: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<script>: GET_CUST_PROFILE: 4 1-TP0216-+41315996608 set to cust_profile_code=1-TP0216-+41315996608;id=6952891;mandate_id=1;lang=de;service_type=single;screening=no;max_channels=4;admin_barring=no;main_tn=+41315996608;blacklist_global=yes;dialplan_group=1;blockset_group=0;li=yes;forking=0;sd_lookup=force;version=9809;changed=1774901390;id=1448070;auth_username=315996608;auth_pw=cde242d5da97123c76b52c66fac93fe3;sig_profile=local;max_reg_contacts=6;supported_codec_group=0;allow_update=yes;allow_prack=yes;disable_ann=no;override_tn;ha1=1;version=9809;changed=1774901390;

[...]

2026-05-26T07:51:26.841382+00:00 dev-core01 kamailio[391838]: INFO: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<script>: GET_CUST_PROFILE: 5 DEST: +41800800800 
2026-05-26T07:51:26.841451+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]htable [ht_var.c:89]: pv_set_ht_cell(): set value for $sht(custprof=>cust_profile_code=1-TP0216-+41315996608;id=6952891;mandate_id=1;lang=de;service_type=single;screening=no;max_channels=4;admin_barring=no;main_tn=+41315996608;blacklist_global=yes;dialplan_group=1;blockset_group=0;li=yes;forking=0;sd_lookup=force;version=9809;changed=1774901390;id=1448070;auth_username=315996608;auth_pw=cde242d5da97123c76b52c66fac93fe3;sig_profile=local;max_reg_contacts=6;supported_codec_group=0;allow_update=yes;allow_prack=yes;disable_ann=no;override_tn;ha1=1;version=9809;changed=1774901390;)
2026-05-26T07:51:26.841473+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]htable [ht_dmq.c:372]: ht_dmq_replicate_action(): replicating action to dmq peers...
2026-05-26T07:51:26.841492+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]htable [ht_dmq.c:404]: ht_dmq_replicate_action(): sending serialized data {"action":2,"htname":"custprof","cname":"cust_profile_code=1-TP0216-+41315996608;id=6952891;mandate_id=1;lang=de;service_type=single;screening=no;max_channels=4;admin_barring=no;main_tn=+41315996608;blacklist_global=yes;dialplan_group=1;blockset_group=0;li=yes;forking=0;sd_lookup=force;version=9809;changed=1774901390;id=1448070;auth_username=315996608;auth_pw=cde242d5da97123c76b52c66fac93fe3;sig_profile=local;max_reg_contacts=6;supported_codec_group=0;allow_update=yes;allow_prack=yes;disable_ann=no;override_tn;ha1=1;version=9809;changed=1774901390;","type":2,"strval":"cust_profile_code=1-TP0216-+41315996608;id=6952891;mandate_id=1;lang=de;service_type=single;screening=no;max_channels=4;admin_barring=no;main_tn=+41315996608;blacklist_global=yes;dialplan_group=1;blockset_group=0;li=yes;forking=0;sd_lookup=force;version=9809;changed=1774901390;id=1448070;auth_username=315996608;auth_pw=cde242d5da97123c76b52c66fac93fe3;sig_profile=local;max_reg_contacts=6;supported_codec_group=0;allow_update=yes;allow_prack=yes;disable_ann=no;override_tn;ha1=1;version=9809;changed=1774901390;","mode":1}
2026-05-26T07:51:26.841525+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]htable [ht_dmq.c:250]: ht_dmq_send(): sending dmq broadcast...
2026-05-26T07:51:26.841538+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]dmq [dmq_funcs.c:176]: bcast_dmq_message1(): trying to acquire dmq_node_list->lock
2026-05-26T07:51:26.841551+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]dmq [dmq_funcs.c:178]: bcast_dmq_message1(): acquired dmq_node_list->lock
2026-05-26T07:51:26.841558+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/socket_info.c:744]: grep_sock_info(): checking if host==us: 12==12 && [157.161.23.2] == [157.161.23.2]
2026-05-26T07:51:26.841565+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/socket_info.c:748]: grep_sock_info(): checking if port 8080 (advertise 0) matches port 8080
2026-05-26T07:51:26.841573+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]tm [h_table.c:587]: tm_xdata_replace(): replace existing list in backup xd from new xd
2026-05-26T07:51:26.841579+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]tm [h_table.c:420]: build_cell(): created new cell 0x7cc3dd7f66e0
2026-05-26T07:51:26.841585+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]tm [h_table.c:575]: tm_xdata_replace(): restore X/AVP msg context from backup data
2026-05-26T07:51:26.841591+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]tm [uac.c:522]: t_uac_prepare(): next_hop=<sip:[email protected]:8080;transport=tcp>
2026-05-26T07:51:26.841597+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]tm [uac.c:162]: dlg2hash(): hashid 59357
2026-05-26T07:51:26.841603+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/tcp_main.c:2188]: tcp_send(): no open tcp connection found, opening new one
2026-05-26T07:51:26.841609+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/ip_addr.c:624]: print_ip(): tcpconn_new: new tcp connection: 157.161.23.3
2026-05-26T07:51:26.841615+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/tcp_main.c:1269]: tcpconn_new(): on port 8080, type 2, socket -1
2026-05-26T07:51:26.841621+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/tcp_main.c:1666]: tcpconn_add(): hashes: 249:3886:0, 2
2026-05-26T07:51:26.841627+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/tcp_main.c:374]: init_sock_opt(): Set TCP_USER_TIMEOUT=10000 ms
2026-05-26T07:51:26.841633+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/tcp_main.c:3083]: tcpconn_1st_send(): pending write on new connection 0x7cc3dd7f90d0 sock 13 (-1/1553 bytes written) (err: 11 - Resource temporarily unavailable)
2026-05-26T07:51:26.841639+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/parser/parse_fline.c:249]: parse_first_line(): first line type 1 (request) flags 1
2026-05-26T07:51:26.841645+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/parser/msg_parser.c:725]: parse_msg(): SIP Request:
2026-05-26T07:51:26.841651+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/parser/msg_parser.c:726]: parse_msg():  method:  <KDMQ>
2026-05-26T07:51:26.841657+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/parser/msg_parser.c:728]: parse_msg():  uri:     <sip:[email protected]:8080;transport=tcp>
2026-05-26T07:51:26.841663+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/parser/msg_parser.c:730]: parse_msg():  version: <SIP/2.0>
2026-05-26T07:51:26.841669+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/parser/parse_hname2.c:317]: parse_sip_header_name(): parsed header name [Via] type 1
2026-05-26T07:51:26.841675+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/parser/parse_via.c:1311]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKdd7e.bf8dbb92000000000000000000000000.0>; state=16
2026-05-26T07:51:26.841682+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/parser/parse_via.c:2665]: parse_via(): end of header reached, state=5
2026-05-26T07:51:26.841688+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/parser/msg_parser.c:595]: parse_headers(): Via found, flags=2
2026-05-26T07:51:26.841694+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/parser/msg_parser.c:597]: parse_headers(): this is the first via
2026-05-26T07:51:26.841699+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/usr_avp.c:656]: destroy_avp_list(): destroying list 0x7cc3dd7f4800
2026-05-26T07:51:26.841705+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/usr_avp.c:656]: destroy_avp_list(): destroying list (nil)
2026-05-26T07:51:26.841730+00:00 dev-core01 kamailio[391838]: message repeated 4 times: [ DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/usr_avp.c:656]: destroy_avp_list(): destroying list (nil)]
2026-05-26T07:51:26.841735+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/xavp.c:651]: xavp_destroy_list(): destroying xavp list 0x7cc3dd7f5ed0
2026-05-26T07:51:26.841742+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/xavp.c:651]: xavp_destroy_list(): destroying xavp list 0x7cc3dd7f5e00
2026-05-26T07:51:26.841747+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/xavp.c:651]: xavp_destroy_list(): destroying xavp list (nil)
2026-05-26T07:51:26.841754+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/xavp.c:651]: xavp_destroy_list(): destroying xavp list (nil)
2026-05-26T07:51:26.841760+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/usr_avp.c:656]: destroy_avp_list(): destroying list (nil)
2026-05-26T07:51:26.841789+00:00 dev-core01 kamailio[391838]: message repeated 5 times: [ DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/usr_avp.c:656]: destroy_avp_list(): destroying list (nil)]
2026-05-26T07:51:26.841795+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/xavp.c:651]: xavp_destroy_list(): destroying xavp list (nil)
2026-05-26T07:51:26.841807+00:00 dev-core01 kamailio[391838]: message repeated 2 times: [ DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/xavp.c:651]: xavp_destroy_list(): destroying xavp list (nil)]
2026-05-26T07:51:26.841813+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]siptrace [siptrace.c:2499]: siptrace_net_data_sent(): skipping processing message due to drop
2026-05-26T07:51:26.841819+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]tm [uac.c:773]: send_prepared_request_impl(): uac: 0x7cc3dd7f69b0  branch: 0  to 157.161.23.3:8080
2026-05-26T07:51:26.841825+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<core> [core/onsend.c:52]: run_onsend(): required parameters are not available - ignoring
2026-05-26T07:51:26.841831+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]dmq [dmq_funcs.c:188]: bcast_dmq_message1(): skipping node sip:157.161.23.2:8080;transport=tcp
2026-05-26T07:51:26.841837+00:00 dev-core01 kamailio[391838]: DEBUG: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]dmq [dmq_funcs.c:201]: bcast_dmq_message1(): released dmq_node_list->lock
2026-05-26T07:51:26.841843+00:00 dev-core01 kamailio[391838]: INFO: [1 0315996608 SDune6a01-57c4b577d03afb675cf080ede88024da-tc8lgn3 1313476553 INVITE]<script>: GET_CUST_PROFILE: 6 DEST: <null>


Mit freundlichen Grüssen

-Benoît Panizzon-
-- 
I m p r o W a r e   A G    -    Leiter Commerce Kunden
______________________________________________________

Zurlindenstrasse 29             Tel  +41 61 826 93 00
CH-4133 Pratteln                Fax  +41 61 826 93 01
Schweiz                         Web  http://www.imp.ch
______________________________________________________
__________________________________________________________
Kamailio - Users Mailing List - Non Commercial Discussions -- [email protected]
To unsubscribe send an email to [email protected]
Important: keep the mailing list in the recipients, do not reply only to the sender!