Discussion:
[sr-dev] [kamailio/kamailio] kamailio 5.4.5 crash after dialog [dlg_hash.c:1182]: next_state_dlg(): bogus event 2 in state 5 for dlg (#2757)
themsley-voiceflex
2021-06-02 18:19:36 UTC
Permalink
### Description
kamailio 5.4.5 crashes with a segfault shortly after producing messages in the log like

Jun 1 10:12:14 thissystem /usr/sbin/kamailio[20001]: CRITICAL: {2 1 INVITE 6787142-3831531134-***@some.telco.domain} dialog [dlg_hash.c:1182]: next_state_dlg(): bogus event 2 in state 5 for dlg 0x7fae153d3cf0 [3973:6059] with clid '82608924-3831089984-***@some.telco.domain' and tags '3831089984-684203260' ''

Every time it crashes there is a corresponding "bogus event 2 in state 5" in the log and every time it issues that message it crashes.

### Troubleshooting
Installed matching kamailio-debuginfo rpm and obtained a core dump.

#### Reproduction
Cannot reproduce on demand but happens frequently enough so it's just a matter of time.

#### Debugging Data
(gdb) bt full
#0 0x00007f9c3a5da34b in update_dialog_dbinfo_unsafe (cell=0x7f9c30413998) at dlg_db_handler.c:879
i = 17
var = 0x0
jdoc = {root = 0x0, flags = 0, buf = {s = 0x0, len = 0}, malloc_fn = 0x41b550 <***@plt>, free_fn = 0x41aeb0 <***@plt>}
values = {{type = DB1_INT, nul = 0, free = 0, val = {int_val = 579, ll_val = 579, double_val = 2.8606400894208175e-321, time_val = 579,
string_val = 0x243 <Address 0x243 out of bounds>, str_val = {s = 0x243 <Address 0x243 out of bounds>, len = 7194536}, blob_val = {
s = 0x243 <Address 0x243 out of bounds>, len = 7194536}, bitmap_val = 579, uint_val = 579, ull_val = 579}}, {type = DB1_INT, nul = 0,
free = 1194072, val = {int_val = 8082, ll_val = 8082, double_val = 3.9930385496889546e-320, time_val = 8082,
string_val = 0x1f92 <Address 0x1f92 out of bounds>, str_val = {s = 0x1f92 <Address 0x1f92 out of bounds>, len = 8}, blob_val = {
s = 0x1f92 <Address 0x1f92 out of bounds>, len = 8}, bitmap_val = 8082, uint_val = 8082, ull_val = 8082}}, {type = DB1_STR, nul = 0,
free = 8504131, val = {int_val = 809581320, ll_val = 140308801207048, double_val = 6.9321758485571243e-310, time_val = 140308801207048,
string_val = 0x7f9c30413b08 "331873271-3831608037-***@sbc-uk-l-nws01a.uk.sdin.bt.net", str_val = {
s = 0x7f9c30413b08 "331873271-3831608037-***@sbc-uk-l-nws01a.uk.sdin.bt.net", len = 60}, blob_val = {
s = 0x7f9c30413b08 "331873271-3831608037-***@sbc-uk-l-nws01a.uk.sdin.bt.net", len = 60}, bitmap_val = 809581320,
uint_val = 809581320, ull_val = 140308801207048}}, {type = DB1_STR, nul = 0, free = 1085088656, val = {int_val = 809581381,
ll_val = 140308801207109, double_val = 6.9321758485601381e-310, time_val = 140308801207109,
string_val = 0x7f9c30413b45 "sip:+***@uk.sdin.bt.net;user=phone", str_val = {
s = 0x7f9c30413b45 "sip:+***@uk.sdin.bt.net;user=phone", len = 43}, blob_val = {
s = 0x7f9c30413b45 "sip:+***@uk.sdin.bt.net;user=phone", len = 43}, bitmap_val = 809581381, uint_val = 809581381,
ull_val = 140308801207109}}, {type = DB1_STR, nul = 0, free = 7116492, val = {int_val = 826702352, ll_val = 140308818328080,
double_val = 6.9321766944484975e-310, time_val = 140308818328080, string_val = 0x7f9c31467a10 "3831608037-1237727804\177", str_val = {
s = 0x7f9c31467a10 "3831608037-1237727804\177", len = 21}, blob_val = {s = 0x7f9c31467a10 "3831608037-1237727804\177", len = 21},
bitmap_val = 826702352, uint_val = 826702352, ull_val = 140308818328080}}, {type = DB1_STR, nul = 0, free = 8504131, val = {
int_val = 809581425, ll_val = 140308801207153, double_val = 6.932175848562312e-310, time_val = 140308801207153,
string_val = 0x7f9c30413b71 "sip:+***@inh.voiceflex.com;user=phone", str_val = {
s = 0x7f9c30413b71 "sip:+***@inh.voiceflex.com;user=phone", len = 46}, blob_val = {
s = 0x7f9c30413b71 "sip:+***@inh.voiceflex.com;user=phone", len = 46}, bitmap_val = 809581425, uint_val = 809581425,
ull_val = 140308801207153}}, {type = DB1_STR, nul = 0, free = 7477445, val = {int_val = 809768592, ll_val = 140308801394320,
double_val = 6.9321758578095904e-310, time_val = 140308801394320, string_val = 0x7f9c30441690 "***@172.16.128.200:5090",
str_val = {s = 0x7f9c30441690 "***@172.16.128.200:5090", len = 10}, blob_val = {
s = 0x7f9c30441690 "***@172.16.128.200:5090", len = 10}, bitmap_val = 809768592, uint_val = 809768592,
ull_val = 140308801394320}}, {type = DB1_STR, nul = 0, free = 803684352, val = {int_val = 1086075056, ll_val = 140309077700784,
double_val = 6.9321895091627491e-310, time_val = 140309077700784, string_val = 0x7f9c40bc30b0 "@", str_val = {s = 0x7f9c40bc30b0 "@",
len = 815282368}, blob_val = {s = 0x7f9c40bc30b0 "@", len = 815282368}, bitmap_val = 1086075056, uint_val = 1086075056,
ull_val = 140309077700784}}, {type = DB1_STR, nul = 0, free = 979051415, val = {int_val = 979748736, ll_val = 140308971374464,
double_val = 6.932184255944553e-310, time_val = 140308971374464, string_val = 0x7f9c3a65c780 <__FUNCTION__.14488> "populate_leg_info",
str_val = {s = 0x7f9c3a65c780 <__FUNCTION__.14488> "populate_leg_info", len = 979733912}, blob_val = {
s = 0x7f9c3a65c780 <__FUNCTION__.14488> "populate_leg_info", len = 979733912}, bitmap_val = 979748736, uint_val = 979748736,
ull_val = 140308971374464}}, {type = DB1_INT, nul = 0, free = 1085054992, val = {int_val = 1622619239, ll_val = 5917586535,
double_val = 2.9236762132362393e-314, time_val = 5917586535, string_val = 0x160b73467 <Address 0x160b73467 out of bounds>, str_val = {
s = 0x160b73467 <Address 0x160b73467 out of bounds>, len = -1417213536}, blob_val = {
s = 0x160b73467 <Address 0x160b73467 out of bounds>, len = -1417213536}, bitmap_val = 1622619239, uint_val = 1622619239,
ull_val = 5917586535}}, {type = DB1_INT, nul = 0, free = -1417213568, val = {int_val = 3, ll_val = 140720308486147,
double_val = 6.9525070095187664e-310, time_val = 140720308486147, string_val = 0x7ffc00000003 <Address 0x7ffc00000003 out of bounds>,
str_val = {s = 0x7ffc00000003 <Address 0x7ffc00000003 out of bounds>, len = 809580952}, blob_val = {
s = 0x7ffc00000003 <Address 0x7ffc00000003 out of bounds>, len = 809580952}, bitmap_val = 3, uint_val = 3,
ull_val = 140720308486147}}, {type = DB1_INT, nul = 0, free = 1086231760, val = {int_val = 1538940139, ll_val = 27308743915,
double_val = 1.3492312199477687e-313, time_val = 27308743915, string_val = 0x65bba5ceb <Address 0x65bba5ceb out of bounds>, str_val = {
s = 0x65bba5ceb <Address 0x65bba5ceb out of bounds>, len = 979706976}, blob_val = {
s = 0x65bba5ceb <Address 0x65bba5ceb out of bounds>, len = 979706976}, bitmap_val = 1538940139, uint_val = 1538940139,
ull_val = 27308743915}}, {type = DB1_STR, nul = 0, free = 1086248480, val = {int_val = 1, ll_val = 1,
double_val = 4.9406564584124654e-324, time_val = 1, string_val = 0x1 <Address 0x1 out of bounds>, str_val = {
s = 0x1 <Address 0x1 out of bounds>, len = 807487484}, blob_val = {s = 0x1 <Address 0x1 out of bounds>, len = 807487484},
bitmap_val = 1, uint_val = 1, ull_val = 1}}, {type = DB1_STR, nul = 0, free = 1085054992, val = {int_val = 2400, ll_val = 2400,
double_val = 1.1857575500189917e-320, time_val = 2400, string_val = 0x960 <Address 0x960 out of bounds>, str_val = {
s = 0x960 <Address 0x960 out of bounds>, len = 1086248656}, blob_val = {s = 0x960 <Address 0x960 out of bounds>, len = 1086248656},
bitmap_val = 2400, uint_val = 2400, ull_val = 2400}}, {type = DB1_STR, nul = 0, free = 0, val = {int_val = 8207672, ll_val = 8207672,
double_val = 4.0551287675331157e-317, time_val = 8207672, string_val = 0x7d3d38 "", str_val = {s = 0x7d3d38 "", len = 30}, blob_val = {
s = 0x7d3d38 "", len = 30}, bitmap_val = 8207672, uint_val = 8207672, ull_val = 8207672}}, {type = DB1_STR, nul = 0, free = 8504131,
val = {int_val = -1417213408, ll_val = 140723186240032, double_val = 6.9526491894519429e-310, time_val = 140723186240032,
string_val = 0x7ffcab870a20 "\360\v\207\253\374\177", str_val = {s = 0x7ffcab870a20 "\360\v\207\253\374\177", len = 979234888},
blob_val = {s = 0x7ffcab870a20 "\360\v\207\253\374\177", len = 979234888}, bitmap_val = 2877753888, uint_val = 2877753888,
ull_val = 140723186240032}}, {type = DB1_STR, nul = 0, free = 0, val = {int_val = -1417213424, ll_val = 140723186240016,
double_val = 6.9526491894511524e-310, time_val = 140723186240016, string_val = 0x7ffcab870a10 " :<A\234\177", str_val = {
s = 0x7ffcab870a10 " :<A\234\177", len = 979084403}, blob_val = {s = 0x7ffcab870a10 " :<A\234\177", len = 979084403},
bitmap_val = 2877753872, uint_val = 2877753872, ull_val = 140723186240016}}, {type = DB1_STR, nul = 32668, free = 813201384, val = {
int_val = 1, ll_val = 1, double_val = 4.9406564584124654e-324, time_val = 1, string_val = 0x1 <Address 0x1 out of bounds>, str_val = {
s = 0x1 <Address 0x1 out of bounds>, len = 807487484}, blob_val = {s = 0x1 <Address 0x1 out of bounds>, len = 807487484},
bitmap_val = 1, uint_val = 1, ull_val = 1}}, {type = DB1_INT, nul = 0, free = 807487484, val = {int_val = -1417213680,
ll_val = 7172720912, double_val = 3.5437949898262949e-314, time_val = 7172720912,
string_val = 0x1ab870910 <Address 0x1ab870910 out of bounds>, str_val = {s = 0x1ab870910 <Address 0x1ab870910 out of bounds>,
len = 807487484}, blob_val = {s = 0x1ab870910 <Address 0x1ab870910 out of bounds>, len = 807487484}, bitmap_val = 2877753616,
uint_val = 2877753616, ull_val = 7172720912}}, {type = DB1_STR, nul = 32764, free = 979026405, val = {int_val = -1417213664,
ll_val = 28647557408, double_val = 1.4153773952557707e-313, time_val = 28647557408,
string_val = 0x6ab870920 <Address 0x6ab870920 out of bounds>, str_val = {s = 0x6ab870920 <Address 0x6ab870920 out of bounds>,
len = 979706976}, blob_val = {s = 0x6ab870920 <Address 0x6ab870920 out of bounds>, len = 979706976}, bitmap_val = 2877753632,
uint_val = 2877753632, ull_val = 28647557408}}, {type = DB1_STR, nul = 6, free = 0, val = {int_val = -1417213440,
ll_val = 140723186240000, double_val = 6.9526491894503619e-310, time_val = 140723186240000, string_val = 0x7ffcab870a00 "8=}",
str_val = {s = 0x7ffcab870a00 "8=}", len = -1417213104}, blob_val = {s = 0x7ffcab870a00 "8=}", len = -1417213104},
bitmap_val = 2877753856, uint_val = 2877753856, ull_val = 140723186240000}}, {type = DB1_STR, nul = 1, free = 829901784, val = {
int_val = 1086063344, ll_val = 140309077689072, double_val = 6.9321895085840994e-310, time_val = 140309077689072,
string_val = 0x7f9c40bc02f0 "m\002\005", str_val = {s = 0x7f9c40bc02f0 "m\002\005", len = 809580952}, blob_val = {
s = 0x7f9c40bc02f0 "m\002\005", len = 809580952}, bitmap_val = 1086063344, uint_val = 1086063344, ull_val = 140309077689072}}, {
type = DB1_INT, nul = 3, free = 3, val = {int_val = 1086063344, ll_val = 140309077689072, double_val = 6.9321895085840994e-310,
time_val = 140309077689072, string_val = 0x7f9c40bc02f0 "m\002\005", str_val = {s = 0x7f9c40bc02f0 "m\002\005", len = 809580952},
blob_val = {s = 0x7f9c40bc02f0 "m\002\005", len = 809580952}, bitmap_val = 1086063344, uint_val = 1086063344,
ull_val = 140309077689072}}}
insert_keys = {0x7f9c3a86f8e0 <h_entry_column>, 0x7f9c3a86f8d0 <h_id_column>, 0x7f9c3a86f880 <call_id_column>,
0x7f9c3a86f890 <from_uri_column>, 0x7f9c3a86f8a0 <from_tag_column>, 0x7f9c3a86f8b0 <to_uri_column>, 0x7f9c3a86f8c0 <to_tag_column>,
0x7f9c3a86f990 <from_sock_column>, 0x7f9c3a86f980 <to_sock_column>, 0x7f9c3a86f900 <start_time_column>, 0x7f9c3a86f8f0 <state_column>,
0x7f9c3a86f910 <timeout_column>, 0x7f9c3a86f930 <from_cseq_column>, 0x7f9c3a86f920 <to_cseq_column>, 0x7f9c3a86f970 <from_contact_column>,
0x7f9c3a86f960 <to_contact_column>, 0x7f9c3a86f950 <from_route_column>, 0x7f9c3a86f940 <to_route_column>, 0x7f9c3a86f9a0 <sflags_column>,
0x7f9c3a86f9c0 <toroute_name_column>, 0x7f9c3a86f9d0 <req_uri_column>, 0x7f9c3a86f9e0 <xdata_column>, 0x7f9c3a86f9b0 <iflags_column>}
__FUNCTION__ = "update_dialog_dbinfo_unsafe"
#1 0x00007f9c3a5db0bf in update_dialog_dbinfo (cell=0x7f9c30413998) at dlg_db_handler.c:977
No locals.
#2 0x00007f9c3a5e2d4d in dlg_onreply (t=0x7f9c31774bd8, type=1048576, param=0x7ffcab870d60) at dlg_handlers.c:546
dlg = 0x7f9c30413998
iuid = 0x7f9c3025faf0
new_state = 3
old_state = 5
unref = 0
event = 3
tag = {
s = 0xad0d27 <buf.7141+391> "as7527953a\r\nCall-ID: 11481241-3831608038-***@sbc-uk-l-far07b.uk.sdin.bt.net\r\nCSeq: 1 INVITE\r\nServer: Voiceflex\r\nAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH"..., len = 10}
req = 0x7f9c307877e8
rpl = 0x7f9c40bc02f0
__FUNCTION__ = "dlg_onreply"
#3 0x00007f9c3d4408a4 in run_trans_callbacks_internal (cb_lst=0x7f9c31774c50, type=1048576, trans=0x7f9c31774bd8, params=0x7ffcab870d60)
at t_hooks.c:258
cbp = 0x7f9c30fce308
backup_from = 0xb879b0 <def_list+16>
backup_to = 0xb879b8 <def_list+24>
backup_dom_from = 0xb879c0 <def_list+32>
backup_dom_to = 0xb879c8 <def_list+40>
backup_uri_from = 0xb879a0 <def_list>
backup_uri_to = 0xb879a8 <def_list+8>
backup_xavps = 0xb2c988 <_xavp_list_head>
backup_xavus = 0xb2c990 <_xavu_list_head>
backup_xavis = 0xb2c998 <_xavi_list_head>
__FUNCTION__ = "run_trans_callbacks_internal"
#4 0x00007f9c3d440abc in run_trans_callbacks_with_buf (type=1048576, rbuf=0x7f9c31774ca8, req=0x7f9c307877e8, repl=0x7f9c40bc02f0, flags=0)
at t_hooks.c:303
params = {req = 0x7f9c307877e8, rpl = 0x7f9c40bc02f0, param = 0x7f9c30fce318, code = 200, flags = 0, branch = 0, t_rbuf = 0x7f9c31774ca8,
dst = 0x7f9c31774cf8, send_buf = {
s = 0x7f9c302db310 "SIP/2.0 200 OK\r\nVia: SIP/2.0/UDP 193.113.183.202:5060;branch=z9hG4bKdd6a6cbff3b1c256626bd914fd8db551\r\nRecord-Route: <sip:93.95.124.34;lr;did=342.29f1>\r\nFrom: <sip:***@uk.sdin.bt.net;user=phone>;"..., len = 935}}
trans = 0x7f9c31774bd8
#5 0x00007f9c3d3cc07d in relay_reply (t=0x7f9c31774bd8, p_msg=0x7f9c40bc02f0, branch=0, msg_status=200, cancel_data=0x7ffcab871250, do_put_on_wait=1)
at t_reply.c:2096
relay = 0
save_clone = 0
buf = 0x7f9c40bed0f8 "SIP/2.0 200 OK\r\nVia: SIP/2.0/UDP 193.113.183.202:5060;branch=z9hG4bKdd6a6cbff3b1c256626bd914fd8db551\r\nRecord-Route: <sip:93.95.124.34;lr;did=342.29f1>\r\nFrom: <sip:***@uk.sdin.bt.net;user=phone>;"...
res_len = 935
relayed_code = 200
relayed_msg = 0x7f9c40bc02f0
reply_bak = 0x7f9c31774e20
bm = {to_tag_val = {s = 0x7ffcab870fc0 "\200\023\207\253\374\177", len = 5217506}}
totag_retr = 0
reply_status = RPS_COMPLETED
uas_rb = 0x7f9c31774ca8
to_tag = 0x0
reason = {s = 0xbba28 <Address 0xbba28 out of bounds>, len = 0}
onsend_params = {req = 0x7f9c40becdf0, rpl = 0x7ffcab871090, param = 0x7f9c40bc02f0, code = 1086072408, flags = 32668, branch = 0,
t_rbuf = 0x7ffcab870f00, dst = 0x4f4ca1 <futex_release+29>, send_buf = {s = 0x800000 "<core> [core/tcp_main.c:2999]: ", len = 803921760}}
ip = {af = 1094466080, len = 32668, u = {addrl = {8504131, 140723186241472}, addr32 = {8504131, 0, 2877755328, 32764}, addr16 = {49987, 129,
0, 0, 4032, 43911, 32764, 0}, addr = "CÁ\000\000\000\000\000\300\017\207\253\374\177\000"}}
__FUNCTION__ = "relay_reply"
#6 0x00007f9c3d3d1751 in reply_received (p_msg=0x7f9c40bc02f0) at t_reply.c:2682
msg_status = 200
last_uac_status = 180
ack = 0x81c343 "INFO"
ack_len = 2877756064
branch = 0
reply_status = 1086230768
onreply_route = 1
cancel_data = {cancel_bitmap = 0, reason = {cause = 200, u = {text = {s = 0x0, len = 30}, e2e_cancel = 0x0, packed_hdrs = {s = 0x0,
len = 30}}}}
uac = 0x7f9c31774e68
t = 0x7f9c31774bd8
lack_dst = {send_sock = 0xad0fb2 <buf.7141+1042>, to = {s = {sa_family = 0, sa_data = "\000\000\000\000\000\000\070=}\000\000\000\000"},
sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, sin_zero = "8=}\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0,
sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = "8=}\000\000\000\000\000\036\000\000\000\000\000\000", __u6_addr16 = {15672,
125, 0, 0, 30, 0, 0, 0}, __u6_addr32 = {8207672, 0, 30, 0}}}, sin6_scope_id = 1094466080}, sas = {ss_family = 0,
__ss_padding = "\000\000\000\000\000\000\070=}\000\000\000\000\000\036\000\000\000\000\000\000\000 :<A\234\177\000\000CÁ\000\000\000\000\000 \023\207\253\374\177\000\000]\261\247<\234\177\000\000`\022\271", '\000' <repeats 13 times>, "\262\017\255\000\000\000\000\000\201\r\255", '\000' <repeats 13 times>, "\360\220\276@\234\177\000\000\262\017\255\000\000\000\000\000\260\024\207\253\374\177\000", __ss_align = 140309077856352}},
id = -1417210704, send_flags = {f = 32764, blst_imask = 0}, proto = 80 'P', proto_pad0 = 43 '+', proto_pad1 = 16572}
backup_user_from = 0xb879b0 <def_list+16>
backup_user_to = 0xb879b8 <def_list+24>
backup_domain_from = 0xb879c0 <def_list+32>
backup_domain_to = 0xb879c8 <def_list+40>
backup_uri_from = 0xb879a0 <def_list>
backup_uri_to = 0xb879a8 <def_list+8>
backup_xavps = 0xb2c988 <_xavp_list_head>
backup_xavus = 0xb2c990 <_xavu_list_head>
backup_xavis = 0xb2c998 <_xavi_list_head>
replies_locked = 1
branch_ret = 0
prev_branch = 0
blst_503_timeout = 7583887
hf = 0x859150
onsend_params = {req = 0x7ffcab8712b0, rpl = 0x6c72b3 <qm_malloc+2479>, param = 0xad0eb0 <buf.7141+784>, code = 7564075, flags = 0,
branch = 0, t_rbuf = 0x7f9c40becd80, dst = 0xad0fb2 <buf.7141+1042>, send_buf = {s = 0x0, len = 11341488}}
ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {0, -4259732974664084315, 8207672, 30, 140309086091808, 8504131,
-4259732974771039067, 4259056081323627685}, __mask_was_saved = 0, __saved_mask = {__val = {140309024319992, 140309076697584, 0,
8388608, 7653592, 18446744073709551615, 140309077689072, 1322664, 8, 140723186242212, 2877756072, 140307991625729, 140309077689072,
0, 21483478416, 1304}}}}}
bctx = 0x7f9c40bc02f0
keng = 0x0
ret = 32764
evname = {s = 0x7f9c3d472dcc "on_sl_reply", len = 11}
__FUNCTION__ = "reply_received"
#7 0x000000000058c08b in do_forward_reply (msg=0x7f9c40bc02f0, mode=0) at core/forward.c:764
new_buf = 0x0
dst = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {
s_addr = 0}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {
__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}},
sin6_scope_id = 0}, sas = {ss_family = 0, __ss_padding = '\000' <repeats 117 times>, __ss_align = 0}}, id = 0, send_flags = {f = 0,
blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0}
new_len = 0
r = 1
ip = {af = 8192053, len = 0, u = {addrl = {0, 8207672}, addr32 = {0, 0, 8207672, 0}, addr16 = {0, 0, 0, 0, 15672, 125, 0, 0},
addr = "\000\000\000\000\000\000\000\000\070=}\000\000\000\000"}}
s = 0x7d3d38 ""
len = 0
__FUNCTION__ = "do_forward_reply"
#8 0x000000000058dd71 in forward_reply (msg=0x7f9c40bc02f0) at core/forward.c:865
No locals.
#9 0x00000000005ef38f in receive_msg (
buf=0xad0ba0 <buf.7141> "SIP/2.0 200 OK\r\nVia: SIP/2.0/UDP 93.95.124.34;branch=z9hG4bKa726.2c6f345ef9f158b5a47c15a263fb7d03.0;received=93.95.124.34\r\nVia: SIP/2.0/UDP 193.113.183.202:5060;branch=z9hG4bKdd6a6cbff3b1c256626bd914f"..., len=1042, rcv_info=0x7ffcab871b80) at core/receive.c:509
msg = 0x7f9c40bc02f0
ctx = {rec_lev = 0, run_flags = 0, last_retcode = 1, jmp_env = {{__jmpbuf = {0, -4259732975544888155, 8207672, 30, 140309086091808, 8504131,
-4259732975383407451, 4259056081323627685}, __mask_was_saved = 0, __saved_mask = {__val = {0, 16797685758500035936, 2147483648, 0,
274877906944, 0, 0, 16789419411038535680, 2147483648, 219043332192, 0, 0, 0, 1065151889463, 459561500749, 8224}}}}}
bctx = 0x0
ret = 1
tvb = {tv_sec = 0, tv_usec = 0}
tve = {tv_sec = 0, tv_usec = 0}
diff = 0
inb = {
s = 0xad0ba0 <buf.7141> "SIP/2.0 200 OK\r\nVia: SIP/2.0/UDP 93.95.124.34;branch=z9hG4bKa726.2c6f345ef9f158b5a47c15a263fb7d03.0;received=93.95.124.34\r\nVia: SIP/2.0/UDP 193.113.183.202:5060;branch=z9hG4bKdd6a6cbff3b1c256626bd914f"..., len = 1042}
netinfo = {data = {s = 0x0, len = 0}, rcv = 0x0, dst = 0x0}
keng = 0x0
evp = {data = 0x7ffcab8716b0, obuf = {s = 0x0, len = 0}, rcv = 0x7ffcab871b80, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0}
cidlockidx = 0
cidlockset = 0
errsipmsg = 0
exectime = 0
__FUNCTION__ = "receive_msg"
#10 0x00000000004d144c in udp_rcv_loop () at core/udp_server.c:543
len = 1042
buf = "SIP/2.0 200 OK\r\nVia: SIP/2.0/UDP 93.95.124.34;branch=z9hG4bKa726.2c6f345ef9f158b5a47c15a263fb7d03.0;received=93.95.124.34\r\nVia: SIP/2.0/UDP 193.113.183.202:5060;branch=z9hG4bKdd6a6cbff3b1c256626bd914f"...
tmp = 0x7f9c2feadc88 ""
fromaddr = 0x7f9c40bc3000
fromaddrlen = 16
rcvi = {src_ip = {af = 2, len = 4, u = {addrl = {1803312989, 0}, addr32 = {1803312989, 0, 0, 0}, addr16 = {24413, 27516, 0, 0, 0, 0, 0, 0},
addr = "]_|k", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {578576221, 0}, addr32 = {578576221, 0, 0, 0},
addr16 = {24413, 8828, 0, 0, 0, 0, 0, 0}, addr = "]_|\"", '\000' <repeats 11 times>}}, src_port = 5060, dst_port = 5060,
proto_reserved1 = 0, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\023\304]_|k\000\000\000\000\000\000\000"}, sin = {
sin_family = 2, sin_port = 50195, sin_addr = {s_addr = 1803312989}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2,
sin6_port = 50195, sin6_flowinfo = 1803312989, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0,
0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}, sas = {ss_family = 2,
__ss_padding = "\023\304]_|k", '\000' <repeats 111 times>, __ss_align = 0}}, bind_address = 0x7f9c40b5aa70, proto = 1 '\001',
proto_pad0 = 0 '\000', proto_pad1 = 0}
evp = {data = 0x0, obuf = {s = 0x0, len = 0}, rcv = 0x0, dst = 0x0, req = 0x0, rpl = 0x0, rplcode = 0, mode = 0}
printbuf = "\000\000\000\000\003\000\000\000\220\062\267@\234\177", '\000' <repeats 90 times>, "\234Hc0\234\177\000\000\070=}\000\004\000\000\00
0\220\366\200\000\003\000\000\000 :<A\234\177\000\000CÁ\000\000\000\000\000\320\032\207\253\374\177\000\000\203\204Y", '\000' <repeats 93 times>...
i = -1
j = 72960
l = 1
__FUNCTION__ = "udp_rcv_loop"
#11 0x0000000000429f5b in main_loop () at main.c:1711
i = 2
pid = 0
si = 0x7f9c40b5aa70
si_desc = "udp receiver child=2 sock=93.95.124.34:5060\000\234\177\000\000\233\205\177", '\000' <repeats 13 times>, "\060#\207\253\374\177\000\000\070=}\000\000\000\000\000\036\000\000\000\000\000\000\000 :<A\234\177\000\000CÁ\000\000\000\000\000\257:<A\234\177\000\000\340\271A\000\000\000\000\000\220C\274@\234\177\000"
nrprocs = 8
woneinit = 1
__FUNCTION__ = "main_loop"
#12 0x000000000043423e in main (argc=10, argv=0x7ffcab872418) at main.c:2942
cfg_stream = 0x21e8040
c = -1
r = 0
tmp = 0x7ffcab872f05 ""
tmp_len = 0
port = 0
proto = 0
ahost = 0x0
aport = 0
options = 0x7d69b8 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:"
ret = -1
seed = 3932459496
rfd = 4
debug_save = 0
debug_flag = 0
dont_fork_cnt = 2
n_lst = 0xff00000000ff00
p = 0x0
st = {st_dev = 19, st_ino = 12063, st_nlink = 2, st_mode = 16832, st_uid = 996, st_gid = 993, __pad0 = 0, st_rdev = 0, st_size = 40,
st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1621869721, tv_nsec = 871018353}, st_mtim = {tv_sec = 1622542335,
tv_nsec = 169887496}, st_ctim = {tv_sec = 1622542335, tv_nsec = 169887496}, __unused = {0, 0, 0}}
tbuf = ".N=\366\000\000\000\000\273-\334A\234\177\000\000\000\000\000\000\000\000\000\000\300\037\207\253\374\177\000\000\210\353,A\234\177\000\000\350\263-A\234\177\000\000\320 \207\253\374\177\000\000\300 \207\253\374\177\000\000.", '\000' <repeats 23 times>, "\320\n\375A\234\177\000\000\310\004\375A\234\177\000\000\274\016A\000\000\000\000\000п-A\234\177\000\000\bA@\000\000\000\000\000\000\000\000\000\001\000\000\000D\b\000\000\001", '\000' <repeats 11 times>, "\210!\207\253\374\177\000\000`!\207\253\374\177\000\000\001\000\000\000\000\000\000\000\320\n\375A\234\177\000\000\250\304\375A\234\177\000\000P\301\375A\234\177\000\000\237"...
option_index = 0
long_options = {{name = 0x7d8cef "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x7d4194 "version", has_arg = 0, flag = 0x0, val = 118},
{name = 0x7d8cf4 "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x7d8cfa "subst", has_arg = 1, flag = 0x0, val = 1025}, {
name = 0x7d8d00 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x7d8d09 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {
name = 0x7d8d13 "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x7d8d1d "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {
name = 0x7d8d28 "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x7d8d31 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {
name = 0x7d8d3c "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x7d8d42 "atexit", has_arg = 1, flag = 0x0, val = 1034}, {
name = 0x0, has_arg = 0, flag = 0x0, val = 0}}
__FUNCTION__ = "main"
(gdb)
(gdb) list
874 cell->bind_addr[DLG_CALLER_LEG]->sock_str.len,
875 cell->bind_addr[DLG_CALLER_LEG]->sock_str.s,
876 cell->bind_addr[DLG_CALLEE_LEG]->sock_str.len,
877 cell->bind_addr[DLG_CALLEE_LEG]->sock_str.s);
878
879 SET_STR_VALUE(values+7, cell->bind_addr[DLG_CALLER_LEG]->sock_str);
880 SET_STR_VALUE(values+8, cell->bind_addr[DLG_CALLEE_LEG]->sock_str);
881
882 SET_STR_VALUE(values+12, cell->cseq[DLG_CALLER_LEG]);
883 SET_STR_VALUE(values+13, cell->cseq[DLG_CALLEE_LEG]);
(gdb) info locals
cfg_stream = 0x21e8040
c = -1
r = 0
tmp = 0x7ffcab872f05 ""
tmp_len = 0
port = 0
proto = 0
ahost = 0x0
aport = 0
options = 0x7d69b8 ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:Y:"
ret = -1
seed = 3932459496
rfd = 4
debug_save = 0
debug_flag = 0
dont_fork_cnt = 2
n_lst = 0xff00000000ff00
p = 0x0
st = {st_dev = 19, st_ino = 12063, st_nlink = 2, st_mode = 16832, st_uid = 996, st_gid = 993, __pad0 = 0, st_rdev = 0, st_size = 40,
st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1621869721, tv_nsec = 871018353}, st_mtim = {tv_sec = 1622542335, tv_nsec = 169887496},
st_ctim = {tv_sec = 1622542335, tv_nsec = 169887496}, __unused = {0, 0, 0}}
tbuf = ".N=\366\000\000\000\000\273-\334A\234\177\000\000\000\000\000\000\000\000\000\000\300\037\207\253\374\177\000\000\210\353,A\234\177\000\000\350\263-A\234\177\000\000\320 \207\253\374\177\000\000\300 \207\253\374\177\000\000.", '\000' <repeats 23 times>, "\320\n\375A\234\177\000\000\310\004\375A\234\177\000\000\274\016A\000\000\000\000\000п-A\234\177\000\000\bA@\000\000\000\000\000\000\000\000\000\001\000\000\000D\b\000\000\001", '\000' <repeats 11 times>, "\210!\207\253\374\177\000\000`!\207\253\374\177\000\000\001\000\000\000\000\000\000\000\320\n\375A\234\177\000\000\250\304\375A\234\177\000\000P\301\375A\234\177\000\000\237"...
option_index = 0
long_options = {{name = 0x7d8cef "help", has_arg = 0, flag = 0x0, val = 104}, {name = 0x7d4194 "version", has_arg = 0, flag = 0x0, val = 118}, {
name = 0x7d8cf4 "alias", has_arg = 1, flag = 0x0, val = 1024}, {name = 0x7d8cfa "subst", has_arg = 1, flag = 0x0, val = 1025}, {
name = 0x7d8d00 "substdef", has_arg = 1, flag = 0x0, val = 1026}, {name = 0x7d8d09 "substdefs", has_arg = 1, flag = 0x0, val = 1027}, {
name = 0x7d8d13 "server-id", has_arg = 1, flag = 0x0, val = 1028}, {name = 0x7d8d1d "loadmodule", has_arg = 1, flag = 0x0, val = 1029}, {
name = 0x7d8d28 "modparam", has_arg = 1, flag = 0x0, val = 1030}, {name = 0x7d8d31 "log-engine", has_arg = 1, flag = 0x0, val = 1031}, {
name = 0x7d8d3c "debug", has_arg = 1, flag = 0x0, val = 1032}, {name = 0x7d8d42 "atexit", has_arg = 1, flag = 0x0, val = 1034}, {name = 0x0,
has_arg = 0, flag = 0x0, val = 0}}
__FUNCTION__ = "main"
(gdb)

(gdb) p cell->callid
$1 = {s = 0x7f9c30413b08 "331873271-3831608037-***@sbc-uk-l-nws01a.uk.sdin.bt.net", len = 60}
(gdb) p cell->bind_addr[0]
$2 = (struct socket_info *) 0x0
(gdb) p cell->bind_addr[1]
$3 = (struct socket_info *) 0x7f9c40b5aa70
(gdb) p cell->cseq[0]
$4 = {s = 0x7f9c30e50d78 "1%", len = 1}
(gdb) p cell->contact[0]
$5 = {s = 0x7f9c304b7368 "sip:+***@62.239.9.26:5060F1\234\177", len = 34}
(gdb) p cell->route_set[0]
$6 = {s = 0x7f9c30c8c698 "", len = 0}
(gdb) p cell->tag[0]
$7 = {s = 0x7f9c31467a10 "3831608037-1237727804\177", len = 21}
(gdb) p cell->bind_addr[1]->sock_str
$8 = {s = 0x7f9c40bcd6a8 "udp:93.95.124.34:5060", len = 21}

#### Log Messages
see above

#### SIP Traffic
If you need this I will need to get one of our sip guys to provide it. It should all be logged in homer.

### Possible Solutions

### Additional Information
version: kamailio 5.4.5 (x86_64/linux) c46342
flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: c46342
compiled on 23:39:39 Apr 25 2021 with gcc 4.8.5

* **Operating System**:
CentOS 7.9
Linux kamibt01.voiceflex.com 3.10.0-1160.25.1.el7.x86_64 #1 SMP Wed Apr 28 21:49:45 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux


--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757
Daniel-Constantin Mierla
2021-06-02 19:33:07 UTC
Permalink
Can you get also from gdb:

```
p *cell
```

I am interested on a few other fields to see if the cell was somehow in process of being destroyed.

Getting the pcap with all sip messages of this call would be very useful, the time difference between packets helps to figure out if some timer routines conflict somehow.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853328502
themsley-voiceflex
2021-06-02 19:35:49 UTC
Permalink
(gdb) p *cell
$3 = {ref = 3, next = 0x7f9c302d0068, prev = 0x0, h_id = 8082, h_entry = 579, state = 3, lifetime = 0, init_ts = 1622619237, start_ts = 1622619239, end_ts = 0, dflags = 513, iflags = 64, sflags = 0, toroute = 0, toroute_name = {s = 0x0, len = 0}, from_rr_nb = 0, tl = {next = 0x0, prev = 0x0, timeout = 0},
callid = {s = 0x7f9c30413b08 "331873271-3831608037-***@sbc-uk-l-nws01a.uk.sdin.bt.net", len = 60}, from_uri = {s = 0x7f9c30413b45 "sip:+***@uk.sdin.bt.net;user=phone", len = 43}, to_uri = {s = 0x7f9c30413b71 "sip:+***@inh.voiceflex.com;user=phone", len = 46}, req_uri = {
s = 0x7f9c30413ba0 "sip:+***@inh.voiceflex.com;user=phone", len = 46}, tag = {{s = 0x7f9c31467a10 "3831608037-1237727804\177", len = 21}, {s = 0x7f9c30441690 "***@172.16.128.200:5090", len = 10}}, cseq = {{s = 0x7f9c30e50d78 "1%", len = 1}, {
s = 0x7f9c304c3e60 "0ip:+***@193.113.183.202:5060", len = 1}}, route_set = {{s = 0x7f9c30c8c698 "", len = 0}, {s = 0x7f9c309838c0 "\244\324`:\234\177", len = 0}}, contact = {{s = 0x7f9c304b7368 "sip:+***@62.239.9.26:5060F1\234\177", len = 34}, {
s = 0x7f9c30ad65c0 "sip:+***@93.95.124.107:5060", len = 36}}, bind_addr = {0x0, 0x7f9c40b5aa70}, cbs = {first = 0x0, types = 0}, profile_links = 0x0, vars = 0x7f9c31451dc0, ka_src_counter = 0, ka_dst_counter = 0}
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853330093
themsley-voiceflex
2021-06-02 19:41:10 UTC
Permalink
file:///home/trevor/Downloads/2757_scrubbed.zip
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853333170
Daniel-Constantin Mierla
2021-06-02 19:42:27 UTC
Permalink
The attachment was not uploaded, is only the path to it in the comment.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853333998
Daniel-Constantin Mierla
2021-06-02 19:43:48 UTC
Permalink
And the log message `... bogus event 2 in state 5 for ...` is not directly related to the dialog causing the crash, the print of the `*cell` shows it is in state 3, not 5.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853334736
themsley-voiceflex
2021-06-02 19:44:16 UTC
Permalink
I don't seem to be able to add attachments here. I drag and drop and I either get nothing at all or it inserts a file:// link pointing to my local file. I can mail this direct to you if that would work?
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853334977
themsley-voiceflex
2021-06-02 19:46:26 UTC
Permalink
The bogus state message may not be directly related but it's a one to one correspondence between that message and the crash and it occurs within < 1s of it being issued.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853336184
themsley-voiceflex
2021-06-02 19:55:58 UTC
Permalink
# zgrep -h "bogus event 2 in state 5" /var/log/kamailio.log*
Jun 1 10:12:14 kamibt01 /usr/sbin/kamailio[20001]: CRITICAL: {2 1 INVITE 6787142-3831531134-***@sbc-uk-l-far07b.uk.sdin.bt.net} dialog [dlg_hash.c:1182]: next_state_dlg(): bogus event 2 in state 5 for dlg 0x7fae153d3cf0 [3973:6059] with clid '82608924-3831089984-***@sbc-uk-l-far07a.uk.sdin.bt.net' and tags '3831089984-684203260' ''
Jun 2 07:33:59 kamibt01 /usr/sbin/kamailio[3789]: CRITICAL: {2 1 INVITE 11481241-3831608038-***@sbc-uk-l-far07b.uk.sdin.bt.net} dialog [dlg_hash.c:1182]: next_state_dlg(): bogus event 2 in state 5 for dlg 0x7f9c30413998 [579:8082] with clid '331873271-3831608037-***@sbc-uk-l-nws01a.uk.sdin.bt.net' and tags '3831608037-1237727804' ''
# grep segfault /var/log/messages
Jun 1 10:12:14 kamibt01 kernel: [914047.335442] kamailio[20000]: segfault at f0 ip 00007fae1f07f34b sp 00007ffd33f4c0c0 error 4 in dialog.so[7fae1f047000+cd000]
Jun 2 07:33:59 kamibt01 kernel: [990952.027386] kamailio[3788]: segfault at f0 ip 00007f9c3a5da34b sp 00007ffcab870510 error 4 in dialog.so[7f9c3a5a2000+cd000]
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853341862
themsley-voiceflex
2021-06-02 20:05:19 UTC
Permalink
[***@kamibh01 ~]# zgrep -h "bogus event 2 in state 5" /var/log/kamailio.log*
May 27 07:39:47 kamibh01 /usr/sbin/kamailio[11320]: CRITICAL: {2 1 INVITE 240487810-3831089987-***@sbc-uk-gw-th01b.uk.sdin.bt.net} dialog [dlg_hash.c:1182]: next_state_dlg(): bogus event 2 in state 5 for dlg 0x7f4887eb8420 [2002:9497] with clid '228609061-3830856817-***@sbc-uk-gw-th01b.uk.sdin.bt.net' and tags '3830856817-660210341' ''
[***@kamibh01 ~]# zgrep -h segfault /var/log/messages*
May 27 07:39:47 kamibh01 kernel: [2300614.036738] kamailio[11324]: segfault at f0 ip 00007f4891cbb34b sp 00007ffc1a7096b0 error 4 in dialog.so[7f4891c83000+cd000]
[***@kamibh01 ~]#
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853347311
nathanronchetti
2021-06-02 20:19:23 UTC
Permalink
[2757_scrubbed.zip](https://github.com/kamailio/kamailio/files/6587206/2757_scrubbed.zip)
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853355801
Daniel-Constantin Mierla
2021-06-03 11:14:05 UTC
Permalink
I got the pcap via email, the call-id matches the `bt full` output, but does not match the output of `p *cell`. Maybe you used a different corefile, can you get the output from the same corefile as for `bt full`? Otherwise, I cannot correlate the data between them.

Also, the `(gdb) p cell->callid` in the first comment, after `bt full` show a different call-id.

What I noticed in the call pcap is that the processing of 200ok (INVITE) takes over 6 seconds, do you have any blocking operations done during 200ok? For example, accounting can happen at that time, you should check if database server is slow for some reason when inserting records in acc table (you can also enable latency core parameters to get logs on slow actions/database statements).
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853790269
Daniel-Constantin Mierla
2021-06-03 11:23:30 UTC
Permalink
Btw, do you do dialog replication via dmq?
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853795330
themsley-voiceflex
2021-06-03 11:25:04 UTC
Permalink
That's a yes to the dialog replication question. Am checking the p *cell output now. I have two core dumps so it's possible I mixed them up.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853796164
themsley-voiceflex
2021-06-03 11:28:16 UTC
Permalink
< (gdb) p *cell
$1 = {ref = 3, next = 0x7fae15a524a8, prev = 0x0, h_id = 6059, h_entry = 3973, state = 3, lifetime = 0, init_ts = 1622101184, start_ts = 1622542334, end_ts = 0, dflags = 513, iflags = 64, sflags = 0, toroute = 0, toroute_name = {s = 0x0, len = 0}, from_rr_nb = 0, tl = {next = 0x0, prev = 0x0, timeout = 0},
callid = {s = 0x7fae153d3e60 "82608924-3831089984-***@sbc-uk-l-far07a.uk.sdin.bt.net", len = 61}, from_uri = {s = 0x7fae153d3e9e "sip:+***@uk.sdin.bt.net;user=phone", len = 43}, to_uri = {s = 0x7fae153d3eca "sip:+***@inh.voiceflex.com;user=phone", len = 46}, req_uri = {
s = 0x7fae153d3ef9 "sip:+***@inh.voiceflex.com;user=phone", len = 46}, tag = {{s = 0x7fae15034620 "3831089984-6842032602\177", len = 20}, {s = 0x7fae14f26750 "***@172.16.128.199:5090", len = 10}}, cseq = {{s = 0x7fae1528b448 "1\036", len = 1}, {
s = 0x7fae1612c480 "0ip:***@172.16.128.200:5090", len = 1}}, route_set = {{s = 0x7fae15126010 "\313\017", len = 0}, {s = 0x7fae14e69f50 "sip:172.16.128.199:5090", len = 0}}, contact = {{s = 0x7fae1583ea98 "sip:+***@193.113.183.202:5060", len = 38}, {
s = 0x7fae154471e8 "sip:+***@93.95.124.77:5060\026\256\177", len = 35}}, bind_addr = {0x0, 0x7fae255ffa70}, cbs = {first = 0x0, types = 0}, profile_links = 0x0, vars = 0x7fae15f66a18, ka_src_counter = 0, ka_dst_counter = 0}
this is the p *cell from the other core dump but I do not think this is the correct one, all the other info came from the other core dump.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853797983
Daniel-Constantin Mierla
2021-06-03 11:28:35 UTC
Permalink
If there is dialog replication via dmq, can you paste here all the modparams you set for dialog and dmq modules (hide/replace sensitive data, such as passwords, ips, ... if it is the case). It can be a conflict on dialog matching due to replication.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853798136
themsley-voiceflex
2021-06-03 11:38:57 UTC
Permalink
[***@kamibt01 ~]# grep -iE "dialog|dmq" /etc/kamailio/kamailio.cfg
loadmodule "dmq.so"
loadmodule "dialog.so"
# -- dialog params --
modparam("dialog", "enable_dmq", 1)
modparam("dialog", "db_url", DBURL)
modparam("dialog", "db_mode", 1)
modparam("dialog", "dlg_match_mode", 1)
modparam("dialog", "enable_stats", 1)
modparam("dialog", "rr_param", "did")
modparam("dialog", "send_bye", 1)
modparam("dialog", "dlg_extra_hdrs", "Hint: inactivity timeout\r\n")
modparam("dialog", "track_cseq_updates", 1)
modparam("dialog", "profiles_no_value", "inbound ; outbound")
modparam("dialog", "profiles_with_value", "callerin ; callerout")
# ---- dmq params ----
modparam("dmq", "server_address", DMQLST)
modparam("dmq", "notification_address", DMQTG)
modparam("dmq", "multi_notify", 1)
modparam("dmq", "num_workers", 4)
modparam("dmq", "ping_interval", 90)
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853803697
Daniel-Constantin Mierla
2021-06-03 12:39:43 UTC
Permalink
You have to set `h_id_start` and `h_id_step` for all servers in the replication group so the generated ids do not overlap:

* https://www.kamailio.org/docs/modules/stable/modules/dialog.html#dialog.p.h_id_start

Likely the issue was caused by matching a dialog with same `h_id`, which was generated by a different server and not in the state that was the corresponding dialog for the processed sip message.

Eventually you can also set `dlg_match_mode=2`.

I will also add checks for the socket str, in case of replication might be safer.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-853836689
themsley-voiceflex
2021-06-04 08:47:48 UTC
Permalink
We've made the changes for h_id_start and h_id_step and bounced everything. Will monitor and hope that the problem is resolved. Thanks for all the help. Will update in a week or two with results either way.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2757#issuecomment-854491390
Loading...