[sr-dev] [kamailio/kamailio] Terminated Websocket connection keeps logging "forcibly closing connection" (#1886)

pwakano notifications at github.com
Tue Mar 12 05:12:34 CET 2019


<!--
Kamailio Project uses GitHub Issues only for bugs in the code or feature requests. Please use this template only for bug reports.

If you have questions about using Kamailio or related to its configuration file, ask on sr-users mailing list:

  * http://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

If you have questions about developing extensions to Kamailio or its existing C code, ask on sr-dev mailing list:

  * http://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-dev

Please try to fill this template as much as possible for any issue. It helps the developers to troubleshoot the issue.

If there is no content to be filled in a section, the entire section can be removed.

You can delete the comments from the template sections when filling.

You can delete next line and everything above before submitting (it is a comment).
-->

### Description
In my WebRTC setup, I have Kamailio receiving connections from the WebRTC clients (JSSip and SIPML5). Very frequently the logs starts showing the error messages below. These messages happen every second, so it flood the log files with this message. 
Besides that, since it keeps repeating for a very long time, it is also a concern that Kamailio didn't properly cleaned some internal data, and actually falls under a situation it can't do that anymore. This could consume resources and lead to some performance impact.
```
Mar 12 03:30:31 dev1-sbcaio-01 /usr/sbin/kamailio[6785]: WARNING: websocket [ws_frame.c:813]: ws_keepalive(): forcibly closing connection
Mar 12 03:30:31 dev1-sbcaio-01 /usr/sbin/kamailio[6785]: ERROR: websocket [ws_conn.c:377]: wsconn_close_now(): getting TCP/TLS connection
```

<!--
Explain what you did, what you expected to happen, and what actually happened.
-->

### Troubleshooting
>From investigation it is not 100% sure, but it looks like the problem happens when the websocket connection is abruptly terminated (not from the browser).
The kamcmd ws.dump command shows no active connections.

#### Reproduction
Register to Kamailio via websocket connection with JSSIP (https://tryit.jssip.net/) or SIPML5 (https://www.doubango.org/sipml5/call.htm) clients. After registered and with connection opened, put the computer to sleep. Some time after that the "ws_keepalive(): forcibly closing connection" will start happening in the logs.
Unfortunately, sometimes this procedure does not cause the problem (I guess the browser properly terminates the websocket connection), but was the closest I got to reproducing the error.

<!--
If the issue can be reproduced, describe how it can be done.
-->


#### Log Messages

<!--
Check the syslog file and if there are relevant log messages printed by Kamailio, add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site).
-->
Logs for debug=3
```
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [8]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375617b30] refcnt [10627]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: WARNING: websocket [ws_frame.c:813]: ws_keepalive(): forcibly closing connection
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:333]: wsconn_rm(): wsconn_rm for [0x7fe375617b30] refcnt [10627]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe375617b30] refcnt [10627]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe375617b30] refcnt [10626]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: ERROR: websocket [ws_conn.c:377]: wsconn_close_now(): getting TCP/TLS connection
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [8]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375617b30] refcnt [10627]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [5]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe3755bf3f8] refcnt [23851]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [5]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe3755bf3f8] refcnt [23852]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [7]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe3755f59d8] refcnt [20786]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [7]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe3755f59d8] refcnt [20787]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [12]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375647ea8] refcnt [19629]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [12]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375647ea8] refcnt [19630]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [6]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe3755e58b0] refcnt [20803]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [6]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe3755e58b0] refcnt [20804]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [1]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375555858] refcnt [24906]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [1]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375555858] refcnt [24907]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [10]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375637d80] refcnt [19978]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [10]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375637d80] refcnt [19979]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [9]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375627c58] refcnt [20051]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [9]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375627c58] refcnt [20052]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [3]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375580708] refcnt [24018]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [3]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe375580708] refcnt [24019]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [13]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe37565d590] refcnt [17224]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [13]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe37565d590] refcnt [17225]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [4]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe3755a2860] refcnt [23904]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:452]: wsconn_get(): wsconn_get for id [4]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:459]: wsconn_get(): wsconn_get returns wsc [0x7fe3755a2860] refcnt [23905]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:653]: wsconn_put_list_ids(): wsconn put list id [0x7fe39338b538]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [8]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe375617b30] refcnt [10627]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe375617b30] refcnt [10627]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe375617b30] refcnt [10626]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [5]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe3755bf3f8] refcnt [23852]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe3755bf3f8] refcnt [23852]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe3755bf3f8] refcnt [23851]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [7]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe3755f59d8] refcnt [20787]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe3755f59d8] refcnt [20787]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe3755f59d8] refcnt [20786]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [12]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe375647ea8] refcnt [19630]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe375647ea8] refcnt [19630]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe375647ea8] refcnt [19629]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [6]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe3755e58b0] refcnt [20804]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe3755e58b0] refcnt [20804]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe3755e58b0] refcnt [20803]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [1]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe375555858] refcnt [24907]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe375555858] refcnt [24907]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe375555858] refcnt [24906]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [10]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe375637d80] refcnt [19979]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe375637d80] refcnt [19979]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe375637d80] refcnt [19978]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [9]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe375627c58] refcnt [20052]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe375627c58] refcnt [20052]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe375627c58] refcnt [20051]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [3]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe375580708] refcnt [24019]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe375580708] refcnt [24019]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe375580708] refcnt [24018]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [13]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe37565d590] refcnt [17225]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe37565d590] refcnt [17225]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe37565d590] refcnt [17224]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:476]: wsconn_put_id(): wsconn put id [4]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:482]: wsconn_put_id(): wsc [0x7fe3755a2860] refcnt [23905]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:417]: wsconn_put_mode(): wsconn_put start for [0x7fe3755a2860] refcnt [23905]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6785]: DEBUG: websocket [ws_conn.c:431]: wsconn_put_mode(): wsconn_put end for [0x7fe3755a2860] refcnt [23904]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_dbase.c:250]: db_postgres_submit_query(): sending query ok: 0x7fe3934149a8 (2) - [select received,contact,socket,cflags,path,ruid from location where expires>'2019-03-12 03:30:36' AND partition=104]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:120]: db_new_result(): allocate 56 bytes for result set at 0x7fe39338b538
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_dbase.c:250]: db_postgres_submit_query(): sending query ok: 0x7fe3934149a8 (2) - [select received,contact,socket,cflags,path,ruid from location where expires>'2019-03-12 03:30:36' AND partition=224]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_dbase.c:532]: db_postgres_store_result(): 0x7fe3934149a8 PQresultStatus(PGRES_TUPLES_OK) PQgetResult(0x1bff100)
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:120]: db_new_result(): allocate 56 bytes for result set at 0x7fe39338b538
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:95]: db_postgres_get_columns(): 6 columns returned from the query
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_dbase.c:532]: db_postgres_store_result(): 0x7fe3934149a8 PQresultStatus(PGRES_TUPLES_OK) PQgetResult(0x1bff100)
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:95]: db_postgres_get_columns(): 6 columns returned from the query
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:158]: db_allocate_columns(): allocate 48 bytes for result names at 0x7fe393425758
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:158]: db_allocate_columns(): allocate 48 bytes for result names at 0x7fe39341d1b8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:169]: db_allocate_columns(): allocate 24 bytes for result types at 0x7fe39364b6e8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:169]: db_allocate_columns(): allocate 24 bytes for result types at 0x7fe39364b6e8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fe39338c678
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fe3934bc480
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe39338c678)[0]=[received]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe3934bc480)[0]=[received]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:154]: db_postgres_get_columns(): use DB1_STRING result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[1] at 0x7fe393374450
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:154]: db_postgres_get_columns(): use DB1_STRING result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe393374450)[1]=[contact]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:154]: db_postgres_get_columns(): use DB1_STRING result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[1] at 0x7fe3934dcfc8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[2] at 0x7fe3934257f8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe3934257f8)[2]=[socket]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe3934dcfc8)[1]=[contact]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:154]: db_postgres_get_columns(): use DB1_STRING result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:154]: db_postgres_get_columns(): use DB1_STRING result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[3] at 0x7fe39325a550
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe39325a550)[3]=[cflags]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[2] at 0x7fe39338c678
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:126]: db_postgres_get_columns(): use DB1_INT result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[4] at 0x7fe3934be938
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe39338c678)[2]=[socket]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe3934be938)[4]=[path]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:154]: db_postgres_get_columns(): use DB1_STRING result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:154]: db_postgres_get_columns(): use DB1_STRING result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[5] at 0x7fe3934bc480
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[3] at 0x7fe393374450
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe3934bc480)[5]=[ruid]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:154]: db_postgres_get_columns(): use DB1_STRING result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe393374450)[3]=[cflags]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_res.c:200]: db_postgres_convert_rows(): no rows returned from the query
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:126]: db_postgres_get_columns(): use DB1_INT result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 6 columns
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[4] at 0x7fe3934257f8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fe39338c678
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[1] at 0x7fe393374450
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe3934257f8)[4]=[path]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[2] at 0x7fe3934257f8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:154]: db_postgres_get_columns(): use DB1_STRING result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[3] at 0x7fe39325a550
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[4] at 0x7fe3934be938
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:113]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[5] at 0x7fe39325a550
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[5] at 0x7fe3934bc480
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:120]: db_postgres_get_columns(): RES_NAMES(0x7fe39325a550)[5]=[ruid]
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:96]: db_free_columns(): freeing result names at 0x7fe39341d1b8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:101]: db_free_columns(): freeing result types at 0x7fe39364b6e8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: <core> [db_res.c:138]: db_free_result(): freeing result set at 0x7fe39338b538
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6788]: DEBUG: db_postgres [km_dbase.c:412]: db_postgres_free_query(): PQclear(0x1bff100) result set
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:154]: db_postgres_get_columns(): use DB1_STRING result type
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_res.c:200]: db_postgres_convert_rows(): no rows returned from the query
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 6 columns
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fe3934bc480
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[1] at 0x7fe3934dcfc8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[2] at 0x7fe39338c678
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[3] at 0x7fe393374450
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[4] at 0x7fe3934257f8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[5] at 0x7fe39325a550
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:96]: db_free_columns(): freeing result names at 0x7fe393425758
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:101]: db_free_columns(): freeing result types at 0x7fe39364b6e8
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: <core> [db_res.c:138]: db_free_result(): freeing result set at 0x7fe39338b538
Mar 12 03:30:36 kamailio-sbc /usr/sbin/kamailio[6787]: DEBUG: db_postgres [km_dbase.c:412]: db_postgres_free_query(): PQclear(0x1bff100) result set
```

### Possible Solutions
Message goes away after some time (could not confirm how much time, but it is hours)

<!--
If you found a solution or workaround for the issue, describe it. Ideally, provide a pull request with a fix.
-->

### Additional Information

  * **Kamailio Version** - output of `kamailio -v`

```
# yum info kamailio
Loaded plugins: fastestmirror
Loading mirror speeds from cached hostfile
 * base: centos.melbourneitmirror.net
 * epel: fedora.mirror.serversaustralia.com.au
 * extras: centos.melbourneitmirror.net
 * remi: remi.conetix.com.au
 * remi-safe: remi.conetix.com.au
 * updates: centos.melbourneitmirror.net
Installed Packages
Name        : kamailio
Arch        : x86_64
Version     : 5.2.1
Release     : 3.el7.centos
Size        : 25 M
Repo        : installed
>From repo   : home_kamailio_v5.2.x-rpms
Summary     : Kamailio (former OpenSER) - the Open Source SIP Server
URL         : http://kamailio.org/
License     : GPL-2.0
Description : Kamailio (former OpenSER) is an Open Source SIP Server released under GPL, able
            : to handle thousands of call setups per second. Among features: asynchronous TCP,
            : UDP and SCTP, secure communication via TLS for VoIP (voice, video); IPv4 and
            : IPv6; SIMPLE instant messaging and presence with embedded XCAP server and MSRP
            : relay; ENUM; DID and least cost routing; load balancing; routing fail-over;
            : accounting, authentication and authorization; support for many backend systems
            : such as MySQL, Postgres, Oracle, Radius, LDAP, Redis, Cassandra; XMLRPC control
            : interface, SNMP monitoring. It can be used to build large VoIP servicing
            : platforms or to scale up SIP-to-PSTN gateways, PBX systems or media servers
            : like Asteriskâ„¢, FreeSWITCHâ„¢ or SEMS.

# kamailio -v
version: kamailio 5.2.1 (x86_64/linux) 947769
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_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: 947769 
compiled on 20:48:14 Feb 26 2019 with gcc 4.8.5

```

* **Operating System**:

<!--
Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04, CentOS 7.1, ...), MacOS, xBSD, Solaris, ...;
Kernel details (output of `uname -a`)
-->

```
# cat /etc/redhat-release 
CentOS Linux release 7.6.1810 (Core) 
# uname -a
Linux kamailio-sbc 3.10.0-957.5.1.el7.x86_64 #1 SMP Fri Feb 1 14:54:57 UTC 2019 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/1886
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20190312/cb009d9e/attachment-0001.html>


More information about the sr-dev mailing list