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.