[OpenSIPS-Users] Possible memory leak in PKG
Arto Kuiri
art666 at hotmail.com
Wed Oct 5 07:16:48 UTC 2022
Hi,
I think I have stumbled to some kind of memory leak. I made new opensips server used same opensips.cfg (changed only ip address) as in my older servers and after some time I started to get these to log file:
/usr/sbin/opensips[1145854]: ERROR:core:fm_malloc: not enough free pkg memory (2312 bytes left, need 2472), please increase the "-M" command line parameter!
/usr/sbin/opensips[1145854]: ERROR:core:receive_msg: no pkg mem left for sip_msg
Older servers works fine with much higher load. Old servers are with opensips 3.1.1 and new server is 3.2.7 :
opensips -V
version: opensips 3.1.1 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, HP_MALLOC, DBG_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll, sigio_rt, select.
main.c compiled on with gcc 9
opensips -V
version: opensips 3.2.7 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, HP_MALLOC, DBG_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll, sigio_rt, select.
main.c compiled on with gcc 11
I allocated more memory and changed private memory allocator to F_MALLOC_DBG
After while I checked what process had highest memory useage and I did:
opensips-cli -x mi mem_pkg_dump <pid>
(PID was "SIP receiver udp")
from log file:
dumping summary of all alloc'ed. fragments:
------------+---------------------------------------
total_bytes | num_allocations x [file: func, line]
------------+---------------------------------------
40 : 1 x [acc.c: init_acc_evi, line 1137]
8 : 1 x [drouting.c: dr_init, line 1819]
200 : 7 x [script_var.c: set_var_value, line 101]
128 : 13 x [script_var.c: add_var, line 59]
1432 : 176 x [sip_i.c: pv_parse_isup_param_name, line 242]
335544 : 1 x [io_wait.c: init_io_wait, line 568]
109600 : 4858 x [dlg_vals.c: fetch_dlg_value, line 176]
16 : 1 x [cfg.y: yyparse, line 510]
32 : 1 x [rr_cb.c: register_rrcb, line 57]
1160 : 1 x [my_con.c: db_mysql_new_connection, line 158]
48 : 1 x [parser/parse_to.c: parse_to_param, line 289]
80 : 1 x [sr_module_deps.c: _alloc_module_dep, line 60]
312 : 9 x [sipmsgops.c: fixup_parse_hname, line 670]
1056 : 33 x [transformations.c: tr_parse_nparam, line 2629]
360 : 18 x [map.c: map_get, line 155]
1904 : 34 x [route_struct.c: mk_exp, line 53]
512 : 8 x [route.c: fix_expr, line 1056]
24 : 1 x [ul_evi.c: ul_event_init, line 155]
1342176 : 1 x [io_wait.c: init_io_wait, line 559]
48 : 1 x [ipc.c: ipc_register_handler, line 154]
168 : 3 x [script_var.c: set_var_value, line 112]
48 : 1 x [transformations.c: tr_eval_uri, line 1028]
16 : 1 x [dp_db.c: dp_add_connection, line 848]
624 : 13 x [script_var.c: add_var, line 52]
48 : 1 x [dlg_hash.c: state_changed_event_init, line 1024]
32 : 1 x [map.c: map_create, line 84]
24 : 1 x [ul_evi.c: ul_event_init, line 132]
8 : 1 x [socket_info.c: fix_socket_list, line 615]
96 : 1 x [mi/mi_trace.c: try_load_trace_api, line 53]
160 : 5 x [transformations.c: tr_parse_string, line 2906]
912 : 1 x [transformations.c: tr_eval_nameaddr, line 2375]
640 : 4 x [db/db.c: db_do_init, line 351]
144 : 3 x [sr_module_deps.c: solve_module_dependencies, line 293]
832 : 13 x [mod_fix.c: fixup_regcomp, line 55]
128 : 1 x [prefix_tree.c: init_prefix_tree, line 53]
503320 : 1 x [io_wait.c: init_io_wait, line 621]
40 : 1 x [transformations.c: tr_add_extra, line 109]
15456 : 276 x [route_struct.c: mk_elem, line 69]
112 : 1 x [route.c: fix_actions, line 1338]
88 : 2 x [flags.c: get_flag_id_by_name, line 202]
272 : 2 x [db/db.c: db_do_init, line 314]
41528 : 324 x [pvar.c: pv_parse_format, line 4716]
24 : 1 x [socket_info.c: fix_socket_list, line 760]
400 : 11 x [acc_extra.c: add_extra, line 155]
16 : 1 x [socket_info.c: new_sock_info, line 127]
4104 : 1 x [xlog.c: buf_init, line 124]
24 : 1 x [ul_evi.c: ul_event_init, line 269]
32 : 1 x [acc.c: init_acc_evi, line 1151]
10448 : 1 x [route.c: new_sroutes_holder, line 104]
200 : 5 x [script_cb.c: add_callback, line 60]
320 : 20 x [sipmsgops.c: fixup_method, line 728]
432 : 9 x [sr_module_deps.c: solve_module_dependencies, line 335]
240 : 1 x [acc_extra.c: add_tag, line 110]
8 : 1 x [pvar.c: pv_init_extra_list, line 5223]
5016 : 153 x [mod_fix.c: alloc_gp, line 72]
24 : 1 x [cfg.y: yyparse, line 1301]
168 : 1 x [../../ut.h: pkg_str_extend, line 953]
64 : 2 x [dr_cb.c: register_dr_cb, line 116]
5808 : 1 x [mi/mi.c: register_mi_cmd, line 154]
72 : 1 x [transformations.c: tr_eval_paramlist, line 2088]
680 : 12 x [sr_module_deps.c: add_module_dependency, line 135]
24 : 1 x [ut.h: pkg_str_extend, line 953]
72 : 1 x [db/db_id.c: new_db_id, line 272]
168 : 3 x [parser/parse_param.c: parse_params, line 370]
104 : 1 x [my_con.c: db_mysql_new_connection, line 149]
656 : 2 x [dbase.c: get_new_stmt_ctx, line 492]
140112 : 1 x [pvar.c: init_pvar_support, line 133]
3096 : 64 x [evi/evi_params.c: evi_param_create, line 43]
72 : 1 x [transformations.c: tr_eval_nameaddr, line 2355]
134912 : 544 x [route_struct.c: mk_action, line 105]
224 : 3 x [context.c: register_context_destroy, line 66]
64 : 1 x [cfg.y: mk_listen_id, line 2287]
16 : 1 x [socket_info.c: fix_socket_list, line 666]
1064 : 18 x [map.c: map_get, line 144]
288 : 1 x [socket_info.c: new_sock_info, line 120]
136 : 2 x [context.c: context_alloc, line 119]
2320 : 29 x [pvar.c: pv_add_extra, line 5287]
24 : 1 x [acc.c: init_acc_evi, line 1144]
8 : 1 x [drouting.c: route2_carrier, line 3587]
2064 : 43 x [transformations.c: parse_transformation, line 2491]
104192 : 809 x [cfg.lex: addstr, line 788]
16 : 1 x [io_wait.c: init_io_wait, line 576]
96 : 5 x [db/db_id.c: dupl_string, line 47]
1344 : 21 x [sr_module.c: register_module, line 151]
224 : 7 x [transformations.c: tr_parse_sparam, line 2707]
160 : 1 x [lookup.c: reg_init_lookup, line 39]
24128 : 232 x [cfg.y: yyparse, line 1571]
5952 : 2 x [dbase.c: alloc_new_prepared_stmt, line 548]
80 : 2 x [pvar.c: new_pv_context, line 5362]
64 : 7 x [acc_logic.c: _do_acc_fixup, line 1148]
----------------------------------------------------
and after 18,5h later (after night) I did same and log shows:
dumping summary of all alloc'ed. fragments:
------------+---------------------------------------
total_bytes | num_allocations x [file: func, line]
------------+---------------------------------------
40 : 1 x [acc.c: init_acc_evi, line 1137]
8 : 1 x [drouting.c: dr_init, line 1819]
200 : 7 x [script_var.c: set_var_value, line 101]
128 : 13 x [script_var.c: add_var, line 59]
1432 : 176 x [sip_i.c: pv_parse_isup_param_name, line 242]
335544 : 1 x [io_wait.c: init_io_wait, line 568]
224160 : 9855 x [dlg_vals.c: fetch_dlg_value, line 176]
16 : 1 x [cfg.y: yyparse, line 510]
32 : 1 x [rr_cb.c: register_rrcb, line 57]
1160 : 1 x [my_con.c: db_mysql_new_connection, line 158]
48 : 1 x [parser/parse_to.c: parse_to_param, line 289]
80 : 1 x [sr_module_deps.c: _alloc_module_dep, line 60]
312 : 9 x [sipmsgops.c: fixup_parse_hname, line 670]
1056 : 33 x [transformations.c: tr_parse_nparam, line 2629]
360 : 18 x [map.c: map_get, line 155]
1904 : 34 x [route_struct.c: mk_exp, line 53]
512 : 8 x [route.c: fix_expr, line 1056]
24 : 1 x [ul_evi.c: ul_event_init, line 155]
1342176 : 1 x [io_wait.c: init_io_wait, line 559]
48 : 1 x [ipc.c: ipc_register_handler, line 154]
168 : 3 x [script_var.c: set_var_value, line 112]
48 : 1 x [transformations.c: tr_eval_uri, line 1028]
16 : 1 x [dp_db.c: dp_add_connection, line 848]
624 : 13 x [script_var.c: add_var, line 52]
48 : 1 x [dlg_hash.c: state_changed_event_init, line 1024]
32 : 1 x [map.c: map_create, line 84]
24 : 1 x [ul_evi.c: ul_event_init, line 132]
8 : 1 x [socket_info.c: fix_socket_list, line 615]
96 : 1 x [mi/mi_trace.c: try_load_trace_api, line 53]
160 : 5 x [transformations.c: tr_parse_string, line 2906]
912 : 1 x [transformations.c: tr_eval_nameaddr, line 2375]
640 : 4 x [db/db.c: db_do_init, line 351]
144 : 3 x [sr_module_deps.c: solve_module_dependencies, line 293]
832 : 13 x [mod_fix.c: fixup_regcomp, line 55]
128 : 1 x [prefix_tree.c: init_prefix_tree, line 53]
503320 : 1 x [io_wait.c: init_io_wait, line 621]
40 : 1 x [transformations.c: tr_add_extra, line 109]
15456 : 276 x [route_struct.c: mk_elem, line 69]
112 : 1 x [route.c: fix_actions, line 1338]
88 : 2 x [flags.c: get_flag_id_by_name, line 202]
272 : 2 x [db/db.c: db_do_init, line 314]
41528 : 324 x [pvar.c: pv_parse_format, line 4716]
24 : 1 x [socket_info.c: fix_socket_list, line 760]
400 : 11 x [acc_extra.c: add_extra, line 155]
16 : 1 x [socket_info.c: new_sock_info, line 127]
4104 : 1 x [xlog.c: buf_init, line 124]
24 : 1 x [ul_evi.c: ul_event_init, line 269]
32 : 1 x [acc.c: init_acc_evi, line 1151]
10448 : 1 x [route.c: new_sroutes_holder, line 104]
200 : 5 x [script_cb.c: add_callback, line 60]
320 : 20 x [sipmsgops.c: fixup_method, line 728]
432 : 9 x [sr_module_deps.c: solve_module_dependencies, line 335]
240 : 1 x [acc_extra.c: add_tag, line 110]
8 : 1 x [pvar.c: pv_init_extra_list, line 5223]
5016 : 153 x [mod_fix.c: alloc_gp, line 72]
24 : 1 x [cfg.y: yyparse, line 1301]
168 : 1 x [../../ut.h: pkg_str_extend, line 953]
64 : 2 x [dr_cb.c: register_dr_cb, line 116]
5808 : 1 x [mi/mi.c: register_mi_cmd, line 154]
72 : 1 x [transformations.c: tr_eval_paramlist, line 2088]
680 : 12 x [sr_module_deps.c: add_module_dependency, line 135]
24 : 1 x [ut.h: pkg_str_extend, line 953]
72 : 1 x [db/db_id.c: new_db_id, line 272]
168 : 3 x [parser/parse_param.c: parse_params, line 370]
104 : 1 x [my_con.c: db_mysql_new_connection, line 149]
656 : 2 x [dbase.c: get_new_stmt_ctx, line 492]
140112 : 1 x [pvar.c: init_pvar_support, line 133]
3096 : 64 x [evi/evi_params.c: evi_param_create, line 43]
72 : 1 x [transformations.c: tr_eval_nameaddr, line 2355]
134912 : 544 x [route_struct.c: mk_action, line 105]
224 : 3 x [context.c: register_context_destroy, line 66]
64 : 1 x [cfg.y: mk_listen_id, line 2287]
16 : 1 x [socket_info.c: fix_socket_list, line 666]
1064 : 18 x [map.c: map_get, line 144]
288 : 1 x [socket_info.c: new_sock_info, line 120]
136 : 2 x [context.c: context_alloc, line 119]
2320 : 29 x [pvar.c: pv_add_extra, line 5287]
24 : 1 x [acc.c: init_acc_evi, line 1144]
8 : 1 x [drouting.c: route2_carrier, line 3587]
2064 : 43 x [transformations.c: parse_transformation, line 2491]
104192 : 809 x [cfg.lex: addstr, line 788]
16 : 1 x [io_wait.c: init_io_wait, line 576]
96 : 5 x [db/db_id.c: dupl_string, line 47]
1344 : 21 x [sr_module.c: register_module, line 151]
224 : 7 x [transformations.c: tr_parse_sparam, line 2707]
160 : 1 x [lookup.c: reg_init_lookup, line 39]
24128 : 232 x [cfg.y: yyparse, line 1571]
5952 : 2 x [dbase.c: alloc_new_prepared_stmt, line 548]
80 : 2 x [pvar.c: new_pv_context, line 5362]
64 : 7 x [acc_logic.c: _do_acc_fixup, line 1148]
----------------------------------------------------
So it looks like [dlg_vals.c: fetch_dlg_value, line 176] starts to eat memory? What I could check next?
We do not use any perl_exec (noticed that 3.28 changelog had entry that it had PKG memory leak).
Best regards,
Arto Kuiri
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20221005/9c26680f/attachment-0001.html>
More information about the Users
mailing list