``` version: kamailio 4.4.0-dev5 (i386/linux) 9251a6 flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, 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_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 9251a6 compiled on 11:10:30 Oct 22 2015 with gcc 4.9.2 ```
I use db_postgres.
Kamailio crashes with the following messages in logs:
``` [...] Oct 22 14:46:18 system /usr/local/sbin/kamailio[26484]: DEBUG: <core> [receive.c:278]: receive_msg(): cleaning up Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:272]: db_postgres_submit_query(): sending query ok: 0xb659ab2c (1) - [LOCK TABLE pua IN EXCLUSIVE MODE Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 32 bytes for result set at 0xb659b628 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:552]: db_postgres_store_result(): 0xb659ab2c PQresultStatus(PGRES_COMMAND_OK) PQgetResult(0x88c62e0) Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:433]: db_postgres_free_query(): PQclear(0x88c62e0) result set Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 0 columns Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0xb659b628 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: pua [send_subscribe.c:310]: subs_cback_func(): completed with status 202 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [parser/msg_parser.c:187]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: pua [send_subscribe.c:383]: subs_cback_func(): lexpire= 3600 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [parser/parse_addr_spec.c:172]: parse_to_param(): DEBUG: add_param: tag=925159b1c018b9f775ed54c55b81927f-c2db Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=29 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: pua [send_subscribe.c:437]: subs_cback_func(): 'To' header ALREADY PARSED: sip:alice@proxy.example.com:5060 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: pua [send_subscribe.c:674]: subs_cback_func(): record for subscribe from sip:reginfo@example.com:5060 to sip:alice@proxy.example.com:5060 inserted in datatbase Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:272]: db_postgres_submit_query(): sending query ok: 0xb659ab2c (1) - [COMMIT] Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 32 bytes for result set at 0xb659bd60 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:552]: db_postgres_store_result(): 0xb659ab2c PQresultStatus(PGRES_COMMAND_OK) PQgetResult(0x88c62e0) Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:433]: db_postgres_free_query(): PQclear(0x88c62e0) result set Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 0 columns Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0xb659bd60 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:272]: db_postgres_submit_query(): sending query ok: 0xb659ab2c (1) - [BEGIN] Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 32 bytes for result set at 0xb659bd60 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:552]: db_postgres_store_result(): 0xb659ab2c PQresultStatus(PGRES_COMMAND_OK) PQgetResult(0x88c62e0) Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:433]: db_postgres_free_query(): PQclear(0x88c62e0) result set Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 0 columns Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0xb659bd60 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:272]: db_postgres_submit_query(): sending query ok: 0xb659ab2c (1) - [LOCK TABLE pua IN EXCLUSIVE MODE Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 32 bytes for result set at 0xb659beec Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:552]: db_postgres_store_result(): 0xb659ab2c PQresultStatus(PGRES_COMMAND_OK) PQgetResult(0x88c62e0) Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: db_postgres [km_dbase.c:433]: db_postgres_free_query(): PQclear(0x88c62e0) result set Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 0 columns Oct 22 14:46:21 system /usr/local/sbin/kamailio[26483]: DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0xb659beec Oct 22 14:46:21 system /usr/local/sbin/kamailio[26522]: CRITICAL: <core> [pass_fd.c:275]: receive_fd(): EOF on 8 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26522]: DEBUG: <core> [tcp_main.c:3448]: handle_ser_child(): dead child 2, pid 26482 (shutting down?) Oct 22 14:46:21 system /usr/local/sbin/kamailio[26522]: DEBUG: <core> [io_wait.h:598]: io_watch_del(): DBG: io_watch_del (0x841fe40, 8, -1, 0x0) fd_no=21 called Oct 22 14:46:21 system /usr/local/sbin/kamailio[26471]: ALERT: <core> [main.c:738]: handle_sigs(): child process 26482 exited by a signal 11 Oct 22 14:46:21 system /usr/local/sbin/kamailio[26471]: ALERT: <core> [main.c:741]: handle_sigs(): core was generated [...] ```
This is not the only thing happening in the same time but I suspect the following:
1 Some entity is sending a not very well formed REGISTER (without expiration value), here is an example:
``` REGISTER sip:example.com SIP/2.0. Via: SIP/2.0/UDP 10.37.145.129;branch=z9hG4bKc5af.bf143451000000000000000000000000.0. To: sip:alice@example.com. From: sip:proxy.example.com;tag=73b08d5bebdaf32004cf12d15b90246a-2710. CSeq: 10 REGISTER. Call-ID: 67cff7c9. Max-Forwards: 70. Content-Length: 0. User-Agent: kamailio (4.4.0-dev5 (i386/linux)). Contact: sip:alice@proxy.example.com:5060. Authorization: Digest username="2291511132",realm="example.com",integrity-protected="auth-done",uri="sip:example.com",nonce="",response="". . ``` 2 Kamailio receives it and performs a reginfo subscribe on contact header ($ct) for my obscure needs:
``` reginfo_subscribe("$ct"); ```
3 Kamailio crashes
With the following backtrace:
``` Program terminated with signal 11, Segmentation fault. #0 0xb65374c0 in get_hash1_raw () at ../../hashes.h:109 109 hash_update_str(s, s+len, p, v, h); (gdb) backtrace #0 0xb65374c0 in get_hash1_raw () at ../../hashes.h:109 #1 0xb6542ba1 in db_postgres_replace () from /usr/local/lib/kamailio/modules/db_postgres.so #2 0xad30819c in convert_temporary_dialog_puadb () from /usr/local/lib/kamailio/modules/pua.so #3 0xad32c7bc in subs_cback_func () from /usr/local/lib/kamailio/modules/pua.so #4 0xadab8fa4 in run_trans_callbacks_internal () from /usr/local/lib/kamailio/modules/tm.so #5 0xadab90b5 in run_trans_callbacks () from /usr/local/lib/kamailio/modules/tm.so #6 0xadb11ec5 in local_reply () from /usr/local/lib/kamailio/modules/tm.so #7 0xadb14205 in reply_received () from /usr/local/lib/kamailio/modules/tm.so #8 0x080d1455 in do_forward_reply () #9 0x080d2ba5 in forward_reply () #10 0x0814ca62 in receive_msg () #11 0x08248d27 in udp_rcv_loop () #12 0x080eb1ee in main_loop () #13 0x080f19dc in main () ```
Here is the PUA module configuration: ``` #!ifdef WITH_PUA modparam("pua", "db_url" , DBURL ) modparam("pua", "db_mode" , 2 ) modparam("pua", "db_table" , "pua" ) modparam("pua", "min_expires" , 0 ) modparam("pua", "default_expires" , 3600 ) modparam("pua", "update_period" , 100 ) modparam("pua", "check_remote_contact", 0 ) modparam("pua", "hash_size" , 9 )
#!ifdef WITH_PUA_REGINFO modparam("pua_reginfo", "default_domain" , "SERVER_DOMAIN" ) modparam("pua_reginfo", "publish_reginfo", 1 ) modparam("pua_reginfo", "server_address" , "sip:reginfo@SERVER_INT_IP:SERVER_INT_PORT" ) #!endif
#!ifdef WITH_PUA_USRLOC modparam("pua_usrloc" , "default_domain" , "SERVER_DOMAIN") #!endif ```
I will try with MySQL to see if I get the same results (if issue is related to DBMS).
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377
Issue maybe related to DBMS, no segfault with MySQL and the same scenario.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#issuecomment-150247458
It might be related to the columns of the postgres result -- there was a patch attempting to fix it, but didn't seem right, so it was reverted. There was no follow up on it afterwards. Perhaps I can make the patch, but because I don't use postgress, I won't be able to test it, so I need someone else to do it.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#issuecomment-150264483
Hello Daniel,
After your commit:
``` commit 56cd7a0d38c8bbee6cc3e981b7a2b78b6d47257d Author: Daniel-Constantin Mierla <****@****> Date: Thu Oct 22 23:08:44 2015 +0200
db_postgres: don't free pg query structure in store result function
- it is done when freeing the result
diff --git a/modules/db_postgres/km_dbase.c b/modules/db_postgres/km_dbase.c index 50ffd7f..816a512 100644 --- a/modules/db_postgres/km_dbase.c +++ b/modules/db_postgres/km_dbase.c @@ -602,7 +602,6 @@ int db_postgres_store_result(const db1_con_t* _con, db1_res_t** _r) }
done: - db_postgres_free_query(_con); return (rc); } ```
Kamailio doesn't crash anymore in my testing scenario.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#issuecomment-150552222
You were fast, or better said, I was slow -- didn't have the time to ask you for testing after my patch. Anyhow, thanks for testing and reporting back, I will backport to 4.3.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#issuecomment-150553272
Closed #377.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#event-443728235
I managed to catch the issue again on another test. Same backtrace:
``` Program terminated with signal 11, Segmentation fault. #0 0xb64c24c0 in get_hash1_raw () at ../../hashes.h:109 109 hash_update_str(s, s+len, p, v, h); #0 0xb64c24c0 in get_hash1_raw () at ../../hashes.h:109 #1 0xb64cdb96 in db_postgres_replace () from /usr/local/lib/kamailio/modules/db_postgres.so #2 0xad1a219c in convert_temporary_dialog_puadb () from /usr/local/lib/kamailio/modules/pua.so #3 0xad1c67bc in subs_cback_func () from /usr/local/lib/kamailio/modules/pua.so #4 0xada43fa4 in run_trans_callbacks_internal () from /usr/local/lib/kamailio/modules/tm.so #5 0xada440b5 in run_trans_callbacks () from /usr/local/lib/kamailio/modules/tm.so #6 0xada9cec5 in local_reply () from /usr/local/lib/kamailio/modules/tm.so #7 0xada9f205 in reply_received () from /usr/local/lib/kamailio/modules/tm.so #8 0x080d1455 in do_forward_reply () #9 0x080d2ba5 in forward_reply () #10 0x0814ca62 in receive_msg () #11 0x08248d27 in udp_rcv_loop () #12 0x080eb1ee in main_loop () #13 0x080f19dc in main () ```
Nearly the same scenario (with some re-transmissions for bad conditions simulation). And now sometimes (not always) I catch also this in logs:
``` Oct 23 14:34:47 banshee1 /usr/local/sbin/kamailio[14253]: ERROR: db_postgres [km_dbase.c:290]: db_postgres_submit_query(): 0xb6686c68 PQsendQuery Error: Query: LOCK TABLE pua IN EXCLUSIVE MODE Oct 23 14:34:47 banshee1 /usr/local/sbin/kamailio[14253]: ERROR: <core> [db_query.c:181]: db_do_raw_query(): error while submitting query Oct 23 14:34:47 banshee1 /usr/local/sbin/kamailio[14253]: ERROR: db_postgres [km_dbase.c:771]: db_postgres_start_transaction(): executing raw_query Oct 23 14:34:47 banshee1 /usr/local/sbin/kamailio[14253]: ERROR: pua [send_subscribe.c:305]: subs_cback_func(): in start_transaction Oct 23 14:34:49 banshee1 /usr/local/sbin/kamailio[14283]: CRITICAL: <core> [pass_fd.c:275]: receive_fd(): EOF on 7 Oct 23 14:34:49 banshee1 /usr/local/sbin/kamailio[14240]: ALERT: <core> [main.c:738]: handle_sigs(): child process 14250 exited by a signal 11 Oct 23 14:34:49 banshee1 /usr/local/sbin/kamailio[14240]: ALERT: <core> [main.c:741]: handle_sigs(): core was generated ```
No problems with MySQL again, only when using PostgreSQL instead and only with pua/pua_reginfo
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#issuecomment-150560415
Reopened #377.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#event-443776089
Can you install the debug symbols and paste here the output in gdb of 'bt full'?
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#issuecomment-150564299
Ok, I recompiled Kamailio with all debug symbols, here is the full backtrace of another test run, same crash, same log messages:
``` Program terminated with signal 11, Segmentation fault. #0 0xb652b2e4 in get_hash1_raw (s=0x0, len=0) at ../../hashes.h:109 109 hash_update_str(s, s+len, p, v, h); #0 0xb652b2e4 in get_hash1_raw (s=0x0, len=0) at ../../hashes.h:109 p = 0x0 v = 3216927696 h = 0 #1 0xb65358ff in db_postgres_replace (_h=0xb6601c68, _k=0xbfbe6a20, _v=0xbfbe6a68, _n=18, _un=4, _m=0) at km_dbase.c:908 pos = 0 i = 0 __FUNCTION__ = "db_postgres_replace" #2 0xad36d0a4 in convert_temporary_dialog_puadb (pres=0xade949e4) at pua_db.c:639 query_cols = {0xad3a64d8, 0xad3a64d0, 0xad3a6508, 0xad3a6518, 0xad3a64e0, 0xad3a6550, 0xad3a64e8, 0xad3a6510, 0xad3a6520, 0xad3a6530, 0xad3a6538, 0xad3a6540, 0xad3a6558, 0xad3a6548, 0xad3a6528, 0xad3a6500, 0xad3a64f0, 0xad3a64f8} query_vals = {{type = DB1_STR, nul = 0, free = 149715680, val = {int_val = 0, ll_val = 0, double_val = 0, time_val = 0, string_val = 0x0, str_val = {s = 0x0, len = 0}, blob_val = { s = 0x0, len = 0}, bitmap_val = 0}}, {type = DB1_STR, nul = 0, free = -1078039608, val = {int_val = -1377219976, ll_val = 187601341048, double_val = 9.2687377725564076e-313, time_val = -1377219976, string_val = 0xade94a78 "sip:sync@proxy.example.com:5060\253J\351\255(", str_val = { s = 0xade94a78 "sip:sync@proxy.example.com:5060\253J\351\255(", len = 43}, blob_val = { s = 0xade94a78 "sip:sync@proxy.example.com:5060\253J\351\255(", len = 43}, bitmap_val = 2917747320}}, {type = DB1_STR, nul = 0, free = 0, val = { int_val = -1377219885, ll_val = 127471798995, double_val = 6.2979436697010237e-313, time_val = -1377219885, string_val = 0xade94ad3 "7ffd5ae0-27489@192.168.37.1324260ae64576ca2ee5520eccf59d42b8c-7a92925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", str_val = { s = 0xade94ad3 "7ffd5ae0-27489@192.168.37.1324260ae64576ca2ee5520eccf59d42b8c-7a92925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", len = 29}, blob_val = { s = 0xade94ad3 "7ffd5ae0-27489@192.168.37.1324260ae64576ca2ee5520eccf59d42b8c-7a92925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", len = 29}, bitmap_val = 2917747411}}, {type = DB1_STR, nul = 0, free = -1235865612, val = {int_val = -1377219819, ll_val = 161831537429, double_val = 7.9955403057340748e-313, time_val = -1377219819, string_val = 0xade94b15 "925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", str_val = {s = 0xade94b15 "925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", len = 37}, blob_val = { s = 0xade94b15 "925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", len = 37}, bitmap_val = 2917747477}}, {type = DB1_INT, nul = 0, free = 149715680, val = {int_val = 1445613228, ll_val = -5305192084164424020, double_val = -8.8519990737449712e-47, time_val = 1445613228, string_val = 0x562a4eac <Address 0x562a4eac out of bounds>, str_val = {s = 0x562a4eac <Address 0x562a4eac out of bounds>, len = -1235211288}, blob_val = { s = 0x562a4eac <Address 0x562a4eac out of bounds>, len = -1235211288}, bitmap_val = 1445613228}}, {type = DB1_INT, nul = 0, free = -1235865612, val = {int_val = 1445613228, ll_val = 586261830463803052, double_val = 1.7812435429641302e-269, time_val = 1445613228, string_val = 0x562a4eac <Address 0x562a4eac out of bounds>, str_val = { s = 0x562a4eac <Address 0x562a4eac out of bounds>, len = 136499719}, blob_val = {s = 0x562a4eac <Address 0x562a4eac out of bounds>, len = 136499719}, bitmap_val = 1445613228}}, {type = DB1_INT, nul = 0, free = -1236092955, val = {int_val = 8192, ll_val = 21474844672, double_val = 1.0609983002212132e-313, time_val = 8192, string_val = 0x2000 <Address 0x2000 out of bounds>, str_val = {s = 0x2000 <Address 0x2000 out of bounds>, len = 5}, blob_val = {s = 0x2000 <Address 0x2000 out of bounds>, len = 5}, bitmap_val = 8192}}, {type = DB1_STR, nul = 0, free = -1235865612, val = {int_val = -1377219856, ll_val = 161831537392, double_val = 7.9955403039060319e-313, time_val = -1377219856, string_val = 0xade94af0 "4260ae64576ca2ee5520eccf59d42b8c-7a92925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", str_val = {s = 0xade94af0 "4260ae64576ca2ee5520eccf59d42b8c-7a92925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", len = 37}, blob_val = { s = 0xade94af0 "4260ae64576ca2ee5520eccf59d42b8c-7a92925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", len = 37}, bitmap_val = 2917747440}}, {type = DB1_INT, nul = 0, free = -1235215256, val = {int_val = 10, ll_val = -5305195074907275254, double_val = -8.846182999227664e-47, time_val = 10, string_val = 0xa <Address 0xa out of bounds>, str_val = {s = 0xa <Address 0xa out of bounds>, len = -1235211984}, blob_val = { s = 0xa <Address 0xa out of bounds>, len = -1235211984}, bitmap_val = 10}}, {type = DB1_STR, nul = 0, free = -1078039056, val = {int_val = 0, ll_val = 0, double_val = 0, time_val = 0, string_val = 0x0, str_val = {s = 0x0, len = 0}, blob_val = {s = 0x0, len = 0}, bitmap_val = 0}}, {type = DB1_STR, nul = 0, free = -1078039672, val = { int_val = -1377219782, ll_val = 174716439354, double_val = 8.6321390448516994e-313, time_val = -1377219782, string_val = 0xade94b3a "sip:reginfo@example.com:5060\004", str_val = {s = 0xade94b3a "sip:reginfo@example.com:5060\004", len = 40}, blob_val = { s = 0xade94b3a "sip:reginfo@example.com:5060\004", len = 40}, bitmap_val = 2917747514}}, {type = DB1_STR, nul = 0, free = -1236057559, val = { int_val = -1377220344, ll_val = 183306373384, double_val = 9.0565381752782646e-313, time_val = -1377220344, string_val = 0xade94908 "sip:presence@proxy.example.comxyp", str_val = {s = 0xade94908 "sip:presence@proxy.example.comxyp", len = 42}, blob_val = { s = 0xade94908 "sip:presence@proxy.example.comxyp", len = 42}, bitmap_val = 2917746952}}, {type = DB1_INT, nul = 0, free = 776, val = {int_val = 0, ll_val = -4630145135030566912, double_val = -0.11882829666137695, time_val = 0, string_val = 0x0, str_val = {s = 0x0, len = -1078039672}, blob_val = {s = 0x0, len = -1078039672}, bitmap_val = 0}}, {type = DB1_STR, nul = 0, free = 0, val = {int_val = -1388722637, ll_val = 2906244659, double_val = 1.4358756444215083e-314, time_val = -1388722637, string_val = 0xad39c633 "", str_val = {s = 0xad39c633 "", len = 0}, blob_val = {s = 0xad39c633 "", len = 0}, bitmap_val = 2906244659}}, { type = DB1_INT, nul = 0, free = -1235211256, val = {int_val = 64, ll_val = -5305209128040267712, double_val = -8.8188539800670763e-47, time_val = 64, string_val = 0x40 <Address 0x40 out of bounds>, str_val = {s = 0x40 <Address 0x40 out of bounds>, len = -1235215256}, blob_val = {s = 0x40 <Address 0x40 out of bounds>, len = -1235215256}, bitmap_val = 64}}, {type = DB1_STR, nul = 0, free = -1236056798, val = {int_val = -1377219925, ll_val = 174716439211, double_val = 8.6321390377865607e-313, time_val = -1377219925, string_val = 0xade94aab "sip:reginfo@example.com:50607ffd5ae0-27489@192.168.37.1324260ae64576ca2ee5520eccf59d42b8c-7a92925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", str_val = { s = 0xade94aab "sip:reginfo@example.com:50607ffd5ae0-27489@192.168.37.1324260ae64576ca2ee5520eccf59d42b8c-7a92925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", len = 40}, blob_val = { s = 0xade94aab "sip:reginfo@example.com:50607ffd5ae0-27489@192.168.37.1324260ae64576ca2ee5520eccf59d42b8c-7a92925159b1c018b9f775ed54c55b81927f-875bsip:reginfo@example.com:5060\004", len = 40}, bitmap_val = 2917747371}}, {type = DB1_STR, nul = 0, free = -1235916731, val = {int_val = 0, ll_val = 0, double_val = 0, time_val = 0, string_val = 0x0, str_val = {s = 0x0, len = 0}, blob_val = {s = 0x0, len = 0}, bitmap_val = 0}}, {type = DB1_STR, nul = 0, free = 25, val = {int_val = 0, ll_val = 0, double_val = 0, time_val = 0, string_val = 0x0, str_val = {s = 0x0, len = 0}, blob_val = {s = 0x0, len = 0}, bitmap_val = 0}}} n_query_cols = 18 __FUNCTION__ = "convert_temporary_dialog_puadb" #3 0xad38e60d in subs_cback_func (t=0xade95698, cb_type=1024, ps=0xbfbe6f8c) at send_subscribe.c:696 msg = 0xb6602290 lexpire = 3600 cseq = 10 presentity = 0xade949e4 hentity = 0xade92fd0 pto = 0xb66027c8 TO = {error = 0, body = {s = 0x0, len = 0}, uri = {s = 0x0, len = 0}, display = {s = 0x0, len = 0}, tag_value = {s = 0x0, len = 0}, parsed_uri = {user = {s = 0x0, len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x0, len = 0}, params = {s = 0x0, len = 0}, sip_params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, flags = 0, transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 0}, method = {s = 0x0, len = 0}, lr = {s = 0x0, len = 0}, r2 = {s = 0x0, len = 0}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x0, len = 0}, user_param_val = {s = 0x0, len = 0}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x0, len = 0}, lr_val = {s = 0x0, len = 0}, r2_val = {s = 0x0, len = 0}, gr_val = { s = 0x0, len = 0}}, param_lst = 0x0, last_param = 0x0} pfrom = 0xb6602c8c size = 382 hash_code = 0 flag = 8192 record_route = {s = 0x0, len = 0} rt = -1078039192 contact = {s = 0x842e640 "sip:presence@proxy.example.com>\r\nServer: kamailio (4.4.0-dev5 (i386/linux))\r\nContent-Length: 0\r\n\r\n", len = 42} initial_request = 1 end_transaction = 1 __FUNCTION__ = "subs_cback_func" #4 0xadac6163 in run_trans_callbacks_internal (cb_lst=0xade956d8, type=1024, trans=0xade95698, params=0xbfbe6f8c) at t_hooks.c:268 cbp = 0xade931e0 backup_from = 0x843e510 backup_to = 0x843e514 backup_dom_from = 0x843e518 backup_dom_to = 0x843e51c backup_uri_from = 0x843e508 backup_uri_to = 0x843e50c backup_xavps = 0x843e59c __FUNCTION__ = "run_trans_callbacks_internal" #5 0xadac6265 in run_trans_callbacks (type=1024, trans=0xade95698, req=0x0, rpl=0xb6602290, code=202) at t_hooks.c:295 params = {req = 0x0, rpl = 0xb6602290, param = 0xade931ec, code = 202, flags = 0, branch = 0, t_rbuf = 0x0, dst = 0x0, send_buf = {s = 0x0, len = 0}} #6 0xadb194dd in local_reply (t=0xade95698, p_msg=0xb6602290, branch=0, msg_status=202, cancel_data=0xbfbe7108) at t_reply.c:2074 local_store = 0 local_winner = 0 reply_status = RPS_COMPLETED winning_msg = 0xb6602290 winning_code = 202 totag_retr = 0 __FUNCTION__ = "local_reply" #7 0xadb1b8cc in reply_received (p_msg=0xb6602290) at t_reply.c:2441 msg_status = 202 last_uac_status = 0 ack = 0xbfbe7124 "" ack_len = 0 branch = 0 reply_status = 0 onreply_route = 0 cancel_data = {cancel_bitmap = 0, reason = {cause = 202, u = {text = {s = 0x0, len = 0}, e2e_cancel = 0x0, packed_hdrs = {s = 0x0, len = 0}}}} uac = 0xade957f0 t = 0xade95698 lack_dst = {send_sock = 0x0, to = {s = {sa_family = 58674, sa_data = "B\b\256\346B\b\000\000\000\000\310+`\266"}, sin = {sin_family = 58674, sin_port = 2114, sin_addr = { s_addr = 138602158}, sin_zero = "\000\000\000\000\310+`\266"}, sin6 = {sin6_family = 58674, sin6_port = 2114, sin6_flowinfo = 138602158, sin6_addr = {__in6_u = { __u6_addr8 = "\000\000\000\000\310+`\266\062\345B\b\b@V\266", __u6_addr16 = {0, 0, 11208, 46688, 58674, 2114, 16392, 46678}, __u6_addr32 = {0, 3059755976, 138601778, 3059105800}}}, sin6_scope_id = 3059105800}}, id = 138601680, proto = 72 'H', send_flags = {f = 114 'r', blst_imask = 190 '\276'}} backup_user_from = 0xace8f8ac backup_user_to = 0xb769a825 backup_domain_from = 0xadbf1ff4 backup_domain_to = 0xb6564008 backup_uri_from = 0x1c backup_uri_to = 0xb6564008 backup_xavps = 0xbfbe7144 replies_locked = 1 branch_ret = -1391589755 prev_branch = -1394018132 blst_503_timeout = -1394018132 hf = 0x0 onsend_params = {req = 0x1c, rpl = 0xadbed0e4, param = 0x9ec18, code = 16777216, flags = 5276, branch = 246, t_rbuf = 0xb6564008, dst = 0x9eb64, send_buf = { s = 0x9ee34 <Address 0x9ee34 out of bounds>, len = -1078038152}} ctx = {rec_lev = -1380003514, run_flags = -1235861496, last_retcode = -1078038188, jmp_env = {{__jmpbuf = {-1078038104, -1380003612, 0, 16777216, 16127460, 513280}, __mask_was_saved = 649756, __saved_mask = {__val = {650804, 4, 18, 0, 3077154853, 2914983924, 136510306, 138602158, 3216929192, 136783105, 138601679, 10, 480, 0, 3059105800, 3059753976, 138601680, 3216929336, 136723299, 138601678, 480, 13, 2914963684, 2, 0, 2914983924, 136510306, 3216929300, 3077154853, 2, 0, 14}}}}} __FUNCTION__ = "reply_received" #8 0x080c6a7e in do_forward_reply (msg=0xb6602290, mode=0) at forward.c:747 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}}, id = 0, proto = 0 '\000', send_flags = {f = 0 '\000', blst_imask = 0 '\000'}} new_len = 3216929416 r = 0 ip = {af = 14, len = 1, u = {addrl = {138601680, 3216929544, 136496554, 917509}, addr32 = {138601680, 3216929544, 136496554, 917509}, addr16 = {58576, 2114, 29448, 49086, 50602, 2082, 5, 14}, addr = "\320\344B\b\bs\276\277\252\305"\b\005\000\016"}} s = 0xbfbe72c8 "" len = 136581138 __FUNCTION__ = "do_forward_reply" #9 0x080c7f3d in forward_reply (msg=0xb6602290) at forward.c:849 No locals. #10 0x08136990 in receive_msg ( buf=0x842e4c0 "SIP/2.0 202 OK\r\nVia: SIP/2.0/UDP 192.168.37.132;branch=z9hG4bK417c.e46c9ce2", '0' <repeats 24 times>, ".0;rport=5060\r\nTo: sip:sync@proxy.example.com:5060;tag=4260ae64576ca2ee5520eccf59d42b8c"..., len=494, rcv_info=0xbfbe74bc) at receive.c:255 msg = 0xb6602290 ctx = {rec_lev = -1216976176, run_flags = -1217334472, last_retcode = 1, jmp_env = {{__jmpbuf = {1, 0, 0, -1, 0, -1078037544}, __mask_was_saved = 0, __saved_mask = {__val = { 134554356, 138207808, 3077990680, 1, 0, 3075943976, 3077991120, 3077632824, 1, 142125701, 3216930752, 3216930704, 3216929880, 0, 1024, 3216929832, 3216929832, 3077173663, 142125701, 136407902, 50195, 3059753276, 4, 1, 3059105800, 142125701, 3216929880, 136412567, 2915136256, 3077936816, 3059753272, 3216930104}}}}} ret = 16777216 inb = { s = 0x842e4c0 "SIP/2.0 202 OK\r\nVia: SIP/2.0/UDP 192.168.37.132;branch=z9hG4bK417c.e46c9ce2", '0' <repeats 24 times>, ".0;rport=5060\r\nTo: sip:sync@proxy.example.com:5060;tag=4260ae64576ca2ee5520eccf59d42b8c"..., len = 494} __FUNCTION__ = "receive_msg" #11 0x0821d075 in udp_rcv_loop () at udp_server.c:495 len = 494 buf = "SIP/2.0 202 OK\r\nVia: SIP/2.0/UDP 192.168.37.132;branch=z9hG4bK417c.e46c9ce2", '0' <repeats 24 times>, ".0;rport=5060\r\nTo: sip:sync@proxy.example.com:5060;tag=4260ae64576ca2ee5520eccf59d42b8c-7a92\r\nFrom: <"... tmp = 0xbfbe7528 "hv\276\277\205\252x\b\300w\276\277\220w\276\277hv\276\277\223\341\r\bhm\330\ax\202譸u\276\277\214`]\266" from = 0xb6602138 fromlen = 16 ri = {src_ip = {af = 2, len = 4, u = {addrl = {2173773066, 2915136256, 0, 134554356}, addr32 = {2173773066, 2915136256, 0, 134554356}, addr16 = {9482, 33169, 29440, 44481, 0, 0, 8948, 2053}, addr = "\n%\221\201\000s\301\255\000\000\000\000\364"\005\b"}}, dst_ip = {af = 2, len = 4, u = {addrl = {2217060544, 0, 0, 0}, addr32 = {2217060544, 0, 0, 0}, addr16 = {43200, 33829, 0, 0, 0, 0, 0, 0}, addr = "\300\250%\204", '\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\n%\221\201\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 50195, sin_addr = {s_addr = 2173773066}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 50195, sin6_flowinfo = 2173773066, 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}}, bind_address = 0xb65854a0, proto = 1 '\001'} __FUNCTION__ = "udp_rcv_loop" #12 0x080de193 in main_loop () at main.c:1589 i = 2 pid = 0 si = 0xb65854a0 si_desc = "udp receiver child=2 sock=192.168.37.132:5060\000\276\277\205\252x\b\300w\276\277\220w\276\277\070v\276\277\034^\025\b\024\237^\266&H1\b\005\000\000\000ނ\021\b\345\003\000\000\220w\276\277\a", '\000' <repeats 11 times>"\377, \377\377\377hv\276\277\357^\025\b0>D\b4eX\266\001\000\000" r = 136495894 nrprocs = 4 woneinit = 1 __FUNCTION__ = "main_loop" #13 0x080e41c2 in main (argc=15, argv=0xbfbe7854) at main.c:2591 cfg_stream = 0x8db5008 c = -1 r = 0 tmp = 0xbfbe87ec "" tmp_len = 0 port = 38 proto = -1218873971 options = 0x830b24c ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:" s = 0x842e4c0 "SIP/2.0 202 OK\r\nVia: SIP/2.0/UDP 192.168.37.132;branch=z9hG4bK417c.e46c9ce2", '0' <repeats 24 times>, ".0;rport=5060\r\nTo: sip:sync@proxy.example.com:5060;tag=4260ae64576ca2ee5520eccf59d42b8c"..., len = 494} __FUNCTION__ = "receive_msg" #11 0x0821d075 in udp_rcv_loop () at udp_server.c:495 len = 494 buf = "SIP/2.0 202 OK\r\nVia: SIP/2.0/UDP 192.168.37.132;branch=z9hG4bK417c.e46c9ce2", '0' <repeats 24 times>, ".0;rport=5060\r\nTo: sip:sync@proxy.example.com:5060;tag=4260ae64576ca2ee5520eccf59d42b8c-7a92\r\nFrom: <"... tmp = 0xbfbe7528 "hv\276\277\205\252x\b\300w\276\277\220w\276\277hv\276\277\223\341\r\bhm\330\ax\202譸u\276\277\214`]\266" from = 0xb6602138 fromlen = 16 ri = {src_ip = {af = 2, len = 4, u = {addrl = {2173773066, 2915136256, 0, 134554356}, addr32 = {2173773066, 2915136256, 0, 134554356}, addr16 = {9482, 33169, 29440, 44481, 0, 0, 8948, 2053}, addr = "\n%\221\201\000s\301\255\000\000\000\000\364"\005\b"}}, dst_ip = {af = 2, len = 4, u = {addrl = {2217060544, 0, 0, 0}, addr32 = {2217060544, 0, 0, 0}, addr16 = {43200, 33829, 0, 0, 0, 0, 0, 0}, addr = "\300\250%\204", '\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\n%\221\201\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 50195, sin_addr = {s_addr = 2173773066}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 50195, sin6_flowinfo = 2173773066, 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}}, bind_address = 0xb65854a0, proto = 1 '\001'} __FUNCTION__ = "udp_rcv_loop" #12 0x080de193 in main_loop () at main.c:1589 i = 2 pid = 0 si = 0xb65854a0 si_desc = "udp receiver child=2 sock=192.168.37.132:5060\000\276\277\205\252x\b\300w\276\277\220w\276\277\070v\276\277\034^\025\b\024\237^\266&H1\b\005\000\000\000ނ\021\b\345\003\000\000\220w\276\277\a", '\000' <repeats 11 times>"\377, \377\377\377hv\276\277\357^\025\b0>D\b4eX\266\001\000\000" r = 136495894 nrprocs = 4 woneinit = 1 __FUNCTION__ = "main_loop" #13 0x080e41c2 in main (argc=15, argv=0xbfbe7854) at main.c:2591 cfg_stream = 0x8db5008 c = -1 r = 0 tmp = 0xbfbe87ec "" tmp_len = 0 port = 38 proto = -1218873971 options = 0x830b24c ":f:cm:M:dVIhEeb:l:L:n:vKrRDTN:W:w:t:u:g:P:G:SQ:O:a:A:x:X:" ret = -1 seed = 3172264804 rfd = 4 debug_save = 0 debug_flag = 0 dont_fork_cnt = 0 n_lst = 0xb774eed9 p = 0x1 <Address 0x1 out of bounds> st = {st_dev = 15, __pad1 = 0, st_ino = 27224, st_mode = 16877, st_nlink = 2, st_uid = 120, st_gid = 121, st_rdev = 0, __pad2 = 0, st_size = 60, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1445512598, tv_nsec = 705699721}, st_mtim = {tv_sec = 1445608091, tv_nsec = 594896377}, st_ctim = {tv_sec = 1445608091, tv_nsec = 594896377}, __unused4 = 0, __unused5 = 0} __FUNCTION__ = "main" ```
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#issuecomment-150589049
Can you try with commit 9cd4aef84d8e7a079486ff73285a9bd6a15e8db3 ?
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#issuecomment-150632938
Hello Daniel,
I have done some extensive testing this time to be sure and it looks like Kamailio doesn't crash anymore, which is good. So issue solved, thank you.
I have only these errors in logs, which are normal and I think I can handle them:
``` Oct 26 09:48:51 system /usr/local/sbin/kamailio[11856]: INFO: <script>: REGISTRAR: registrar successful, status 1, contacts inserted: M=REGISTER RURI=sip:example.com F=sip:proxy.example.com T=sip:alice@example.com IP=10.37.145.129 destination - UA=kamailio (4.4.0-dev5 (i386/linux)) Oct 26 09:48:51 system /usr/local/sbin/kamailio[11855]: WARNING: db_postgres [km_dbase.c:277]: db_postgres_submit_query(): postgres result check failed with code 7 (PGRES_FATAL_ERROR) Oct 26 09:48:51 system /usr/local/sbin/kamailio[11855]: WARNING: db_postgres [km_dbase.c:281]: db_postgres_submit_query(): postgres query command failed, connection status 0, error [ERROR: duplicate key value violates unique constraint "pua_pua_idx"#012DETAIL: Key (etag, tuple_id, call_id, from_tag)=(, , 7fb9d7fe-11854, 925159b1c018b9f775ed54c55b81927f-1383) already exists.#012] Oct 26 09:48:51 system /usr/local/sbin/kamailio[11855]: ERROR: db_postgres [km_dbase.c:290]: db_postgres_submit_query(): 0xb6606c68 PQsendQuery Error: ERROR: duplicate key value violates unique constraint "pua_pua_idx"#012DETAIL: Key (etag, tuple_id, call_id, from_tag)=(, , 7fb9d7fe-11854, 925159b1c018b9f775ed54c55b81927f-1383) already exists.#012 Query: insert into pua (pres_id,pres_uri,call_id,from_tag,expires,desired_expires,flag,to_tag,cseq,record_route,contact,remote_contact,version,extra_headers,event,watcher_uri,etag,tuple_id ) values ('','sip:sync@proxy.example.com:5060','7fb9d7fe-11854','925159b1c018b9f775ed54c55b81927f-1383',1445852931,1445852931,8192,'4260ae64576ca2ee5520eccf59d42b8c-c6c6',10,'','sip:reginfo@example.com:5060','sip:presence@proxy.example.com',0,'',64,'sip:reginfo@example.com:5060','','') Oct 26 09:48:51 system /usr/local/sbin/kamailio[11855]: ERROR: <core> [db_query.c:235]: db_do_insert_cmd(): error while submitting query Oct 26 09:48:51 system /usr/local/sbin/kamailio[11855]: ERROR: db_postgres [km_dbase.c:580]: db_postgres_store_result(): invalid query, execution aborted Oct 26 09:48:51 system /usr/local/sbin/kamailio[11855]: ERROR: db_postgres [km_dbase.c:581]: db_postgres_store_result(): driver error: PGRES_FATAL_ERROR, ERROR: duplicate key value violates unique constraint "pua_pua_idx"#012DETAIL: Key (etag, tuple_id, call_id, from_tag)=(, , 7fb9d7fe-11854, 925159b1c018b9f775ed54c55b81927f-1383) already exists.#012 Oct 26 09:48:51 system /usr/local/sbin/kamailio[11855]: WARNING: db_postgres [km_dbase.c:627]: db_postgres_insert(): unexpected result returned Oct 26 09:48:51 system /usr/local/sbin/kamailio[11855]: ERROR: db_postgres [km_dbase.c:934]: db_postgres_replace(): insert failed Oct 26 09:48:51 system /usr/local/sbin/kamailio[11855]: ERROR: pua [pua_db.c:642]: convert_temporary_dialog_puadb(): Failed replace db Oct 26 09:48:51 system /usr/local/sbin/kamailio[11855]: ERROR: pua [send_subscribe.c:698]: subs_cback_func(): Could not convert temporary dialog into a dialog ```
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#issuecomment-151066985
The errors are related to a duplicate key in db database.
I am closing this one related to the crash, if it proves not to be config related, then open a new issue.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#issuecomment-153013185
Closed #377.
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/377#event-451944410
-
Daniel-Constantin Mierla -
foucse