[SR-Users] Error in db_mysql while using presence

Henning Westerholt hw at kamailio.org
Thu Jan 10 21:45:20 CET 2019


Am Donnerstag, 10. Januar 2019, 11:01:27 CET schrieb Ravindrakumar Bhatt:
> Thanks Daniel for your suggestion but i am using default database created
> by kamdbctl create so database engine is surely InnoDB.
> As per your suggestion Henning, i have checked query logs of mysql and i
> noticed one strange thing that even kamailio is sending query for watcher
> table it is only locking active_watcher table.
> Also kamailio is constantly firing this query : select
> `presentity_uri`,`callid`,`to_tag`,`from_tag`,`event` from
> `active_watchers` where `updated`=15 AND `event`<>'presence.winfo' for ids
> 0 to 49. what is the perpose if this please explain.

Hello Ravindrakumar,

I noticed that you've set db_subst_mode=0 in the presence module 
configuration. This should disable the database storage normally. Have you 
tried to use the default mode 2?

Another thing, if the locking is somehow not working for you, you can disable 
it with the following parameter:

3.27. db_table_lock_type (integer)   

   Enable (=1) or disable (=0) the Locks for table during an transaction.
   Locking only the "current" table causes problems with a MySQL-Databases
   in "DB-Only" mode.  

   In order to use the Presence-Module in "DB_ONLY"-mode with a
   MySQL-Backend, set this parameter to "0", otherwise the
   MySQL-Operations will fail. The Presence-Module will generate a "500
   Server error" due to the failed MySQL-queries.

   Default value is 1 (Write Lock for the Tables).

   Example 1.27. Set db_table_lock_type parameter
...
modparam("presence", "db_table_lock_type", 0)
...

Best regards,

Henning


> LOGS:
> 2019-01-10T06:51:07.356897Z    67 Query SET autocommit=0
> 2019-01-10T06:51:07.357157Z    67 Query LOCK TABLES active_watchers WRITE
> 2019-01-10T06:51:07.357461Z    67 Query select
> `presentity_uri`,`callid`,`to_tag`,`from_tag`,`event` from
> `active_watchers` where `updated`=15 AND `event`<>'presence.winfo'
> 2019-01-10T06:51:07.357796Z    67 Query ROLLBACK
> 2019-01-10T06:51:07.357916Z    67 Query SET autocommit=1
> 2019-01-10T06:51:07.358047Z    67 Query UNLOCK TABLES
> 2019-01-10T06:51:07.358162Z    67 Query SET autocommit=0
> 2019-01-10T06:51:07.358261Z    67 Query LOCK TABLES active_watchers WRITE
> 2019-01-10T06:51:07.358470Z    67 Query select
> `presentity_uri`,`callid`,`to_tag`,`from_tag`,`event` from
> `active_watchers` where `updated`=15 AND `event`='presence.winfo'
> 2019-01-10T06:51:07.358689Z    67 Query ROLLBACK
> 2019-01-10T06:51:07.359066Z    67 Query SET autocommit=1
> 2019-01-10T06:51:07.359191Z    67 Query UNLOCK TABLES
> ########################### NO locking of tables for this two queires
> #################################
> 2019-01-10T06:51:07.390846Z    61 Query select
> `username`,`domain`,`etag`,`event` from `presentity` where
> `expires`<1547103067 AND `expires`>0 order by username
> 2019-01-10T06:51:07.391516Z    61 Query delete from `watchers` where
> `inserted_time`<1547016667 AND `status`=2
> ############################################################################
> ########### 2019-01-10T06:51:07.391779Z    61 Query SET autocommit=0
> 2019-01-10T06:51:07.391930Z    61 Query LOCK TABLES active_watchers WRITE
> ##### LOCKS table active watcher ????
> 2019-01-10T06:51:07.392276Z    61 Query select `callid`,`to_tag`,`from_tag`
> from `active_watchers` where `expires`<1547103067 AND `updated`=-1
> 2019-01-10T06:51:07.392617Z    61 Query COMMIT
> 2019-01-10T06:51:07.392790Z    61 Query SET autocommit=1
> 2019-01-10T06:51:07.392936Z    61 Query UNLOCK TABLES
> 2019-01-10T06:51:07.459480Z    67 Query SET autocommit=0
> 2019-01-10T06:51:07.459651Z    67 Query LOCK TABLES active_watchers WRITE
> 2019-01-10T06:51:07.459926Z    67 Query select
> `presentity_uri`,`callid`,`to_tag`,`from_tag`,`event` from
> `active_watchers` where `updated`=16 AND `event`<>'presence.winfo'
> 2019-01-10T06:51:07.460225Z    67 Query ROLLBACK
> 2019-01-10T06:51:07.460322Z    67 Query SET autocommit=1
> 2019-01-10T06:51:07.460445Z    67 Query UNLOCK TABLES
> 2019-01-10T06:51:03.369484Z    53 Query SET autocommit=0
> 2019-01-10T06:51:03.369760Z    53 Query LOCK TABLES active_watchers WRITE
> ##### LOCKS table active watcher ????
> 2019-01-10T06:51:03.369962Z    67 Query SET autocommit=0
> 2019-01-10T06:51:03.370104Z    67 Query LOCK TABLES active_watchers WRITE
> 2019-01-10T06:51:03.371851Z    53 Query select `status`,`reason` from
> `watchers` where `presentity_uri`='sip:4040 at 172.16.16.149' AND
> `watcher_username`='3030' AND `watcher_domain`='172.16.16.149' AND
> `event`='presence'
> 2019-01-10T06:51:03.376684Z    53 Query ROLLBACK
> 2019-01-10T06:51:03.376836Z    53 Query SET autocommit=1
> 2019-01-10T06:51:03.377321Z    53 Query UNLOCK TABLES
> 2019-01-10T06:51:03.379047Z    67 Query select
> `presentity_uri`,`callid`,`to_tag`,`from_tag`,`event` from
> `active_watchers` where `updated`=26 AND `event`<>'presence.winfo'
> 2019-01-10T06:51:03.379571Z    67 Query ROLLBACK
> 2019-01-10T06:51:03.380294Z    67 Query SET autocommit=1
> 2019-01-10T06:51:03.383371Z    67 Query UNLOCK TABLES
> 
> On Thu, Jan 10, 2019 at 2:16 AM Henning Westerholt <hw at kamailio.org> wrote:
> > Am Mittwoch, 9. Januar 2019, 09:47:07 CET schrieb Ravindrakumar Bhatt:
> > >  I tried on command line with LOCK TABLES watchers write; and it works
> > > 
> > > fine. also i am usinf root at localhost with all permissions still same
> > 
> > errors
> > 
> > > show continuously. please tell if any more details are required for
> > > same.
> > 
> > > Errors:
> > Hello Ravindrakumar,
> > 
> > I would suggest then to enable mysql query logging and have a look to the
> > actual query that is executed from the module and match to the errors
> > below.
> > 
> > Please keep the sr-users list in CC.
> > 
> > Best regards,
> > 
> > Henning
> > 
> > > Jan  9 00:11:23 client1 /usr/local/sbin/kamailio[2704]: ERROR: {1 1
> > > SUBSCRIBE NGFiMGJmM2VlYWQyNTQ5NWJjNmVmYTExY2ZhMWM1NDQ.} db_mysql
> > > [km_dbase.c:128]: db_mysql_submit_query(): driver error on query: Table
> > > 'watchers' was not locked with LOCK TABLES (1100)
> > > Jan  9 00:11:23 client1 /usr/local/sbin/kamailio[2704]: ERROR: {1 1
> > > SUBSCRIBE NGFiMGJmM2VlYWQyNTQ5NWJjNmVmYTExY2ZhMWM1NDQ.} <core>
> > > [db_query.c:132]: db_do_query_internal(): error while submitting query
> > > Jan  9 00:11:23 client1 /usr/local/sbin/kamailio[2704]: ERROR: {1 1
> > > SUBSCRIBE NGFiMGJmM2VlYWQyNTQ5NWJjNmVmYTExY2ZhMWM1NDQ.} presence
> > > [subscribe.c:2827]: get_db_subs_auth(): while querying watchers table
> > > Jan  9 00:11:23 client1 /usr/local/sbin/kamailio[2704]: ERROR: {1 1
> > > SUBSCRIBE NGFiMGJmM2VlYWQyNTQ5NWJjNmVmYTExY2ZhMWM1NDQ.} presence
> > > [subscribe.c:1217]: handle_subscribe(): getting subscription status from
> > > watchers table
> > > Jan  9 00:11:56 client1 /usr/local/sbin/kamailio[2713]: ERROR: db_mysql
> > > [km_dbase.c:128]: db_mysql_submit_query(): driver error on query: Table
> > > 'active_watchers' was not locked with LOCK TABLES (1100)
> > > Jan  9 00:11:56 client1 /usr/local/sbin/kamailio[2713]: ERROR: <core>
> > > [db_query.c:132]: db_do_query_internal(): error while submitting query
> > > Jan  9 00:11:56 client1 /usr/local/sbin/kamailio[2713]: ERROR: presence
> > > [notify.c:1370]: publ_notify_notifier(): Can't query db
> > > Jan  9 00:11:56 client1 /usr/local/sbin/kamailio[2713]: ERROR: presence
> > > [publish.c:178]: msg_presentity_clean(): Updating watcher records
> > > Jan  9 00:12:36 client1 /usr/local/sbin/kamailio[2713]: ERROR: db_mysql
> > > [km_dbase.c:128]: db_mysql_submit_query(): driver error on query: Table
> > > 'active_watchers' was not locked with LOCK TABLES (1100)
> > > Jan  9 00:12:36 client1 /usr/local/sbin/kamailio[2713]: ERROR: <core>
> > > [db_query.c:132]: db_do_query_internal(): error while submitting query
> > > Jan  9 00:12:36 client1 /usr/local/sbin/kamailio[2713]: ERROR: presence
> > > [notify.c:1370]: publ_notify_notifier(): Can't query db
> > > Jan  9 00:12:36 client1 /usr/local/sbin/kamailio[2713]: ERROR: presence
> > > [publish.c:178]: msg_presentity_clean(): Updating watcher records
> > > Jan  9 00:13:16 client1 /usr/local/sbin/kamailio[2713]: ERROR: db_mysql
> > > [km_dbase.c:128]: db_mysql_submit_query(): driver error on query: Table
> > > 'active_watchers' was not locked with LOCK TABLES (1100)
> > > Jan  9 00:13:16 client1 /usr/local/sbin/kamailio[2713]: ERROR: <core>
> > > [db_query.c:132]: db_do_query_internal(): error while submitting query
> > > Jan  9 00:13:16 client1 /usr/local/sbin/kamailio[2713]: ERROR: presence
> > > [notify.c:1370]: publ_notify_notifier(): Can't query db
> > > Jan  9 00:13:16 client1 /usr/local/sbin/kamailio[2713]: ERROR: presence
> > > [publish.c:178]: msg_presentity_clean(): Updating watcher records
> > > 
> > > On Wed, Jan 9, 2019 at 1:55 AM Henning Westerholt <hw at kamailio.org>
> > 
> > wrote:
> > > > Am Dienstag, 8. Januar 2019, 14:57:21 CET schrieb Ravindrakumar Bhatt:
> > > > > I am using latest kamailio stable version. i have used it for
> > 
> > presenece
> > 
> > > > and
> > > > 
> > > > > BLF. i am facing issue in presence related method when i am setting
> > > > > sub_db_mode to any db related mode like 3.
> > > > 
> > > > Hello Ravindrakumar,
> > > > 
> > > > the presence module uses a database LOCK TABLE command and this fails.
> > 
> > Can
> > 
> > > > you
> > > > check if the database user that is used from Kamailio has the
> > 
> > appropriate
> > 
> > > > permissions to issue this command on the database? You can try e.g.
> > 
> > with
> > 
> > > > mysql
> > > > command line client.
> > > > 
> > > > > Version :
> > > > > version: kamailio 5.2.0 (x86_64/linux) 535e13
> > > > > 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: 535e13
> > > > > compiled on 06:32:22 Jan  8 2019 with gcc 4.8.5
> > > > > 
> > > > > Kamailio.cfg setup:
> > > > > modparam("presence|presence_xml", "db_url", DBURL)
> > > > > modparam("presence", "server_address", "sip:XX.XX.XX.XX:5050")
> > > > > modparam("presence", "send_fast_notify", 0)
> > > > > modparam("presence", "db_update_period", 20)
> > > > > modparam("presence", "clean_period", 40)
> > > > > modparam("presence", "subs_db_mode", 0)
> > > > > modparam("presence", "fetch_rows", 1000)
> > > > > 
> > > > > # ----- presence_xml params -----
> > > > > #modparam("presence_xml", "db_url", DBURL)
> > > > > modparam("presence_xml", "force_active", 1)
> > > > > 
> > > > > # ----- pua params -----
> > > > > modparam("pua", "db_url", DBURL)
> > > > > modparam("pua", "db_mode", 2)
> > > > > modparam("pua", "update_period", 60)
> > > > > modparam("pua", "dlginfo_increase_version", 0)
> > > > > modparam("pua", "reginfo_increase_version", 0)
> > > > > modparam("pua", "check_remote_contact", 1)
> > > > > modparam("pua", "fetch_rows", 1000)
> > > > > 
> > > > > # ----- pua_dialoginfo params -----
> > > > > modparam("pua_dialoginfo", "include_callid", 1)
> > > > > modparam("pua_dialoginfo", "send_publish_flag", FLT_DLGINFO)
> > > > > modparam("pua_dialoginfo", "caller_confirmed", 0)
> > > > > modparam("pua_dialoginfo", "include_tags", 1)
> > > > > modparam("pua_dialoginfo", "override_lifetime", 124)
> > > > > 
> > > > > # ----- dialog params -----
> > > > > modparam("dialog", "db_url", DBURL)
> > > > > modparam("dialog", "enable_stats", 1)
> > > > > modparam("dialog", "db_mode", 1)
> > > > > modparam("dialog", "dlg_flag", FLT_DLG)
> > > > > modparam("presence_dialoginfo", "force_single_dialog", 0)
> > > > > Error:
> > > > > Jan  8 04:34:37 client1 /usr/local/sbin/kamailio[19523]: {1 1
> > > > > PUBLISH
> > > > > MzQ4ZjNhOGRlYWZlY2QyMDQwMGZlZjg0N2JlZGE2YWM.} ERROR: db_mysql
> > 
> > > > > [km_dbase.c:128]: db_mysql_submit_query(): driver error on query:
> > Table
> > 
> > > > > 'active_watchers' was not locked with LOCK TABLES (1100)
> > > > > Jan  8 04:34:37 client1 /usr/local/sbin/kamailio[19523]: {1 1
> > > > > PUBLISH
> > > > > MzQ4ZjNhOGRlYWZlY2QyMDQwMGZlZjg0N2JlZGE2YWM.} ERROR: <core>
> > > > > [db_query.c:132]: db_do_query_internal(): error while submitting
> > 
> > query
> > 
> > > > > Jan  8 04:34:37 client1 /usr/local/sbin/kamailio[19523]: {1 1
> > > > > PUBLISH
> > > > > MzQ4ZjNhOGRlYWZlY2QyMDQwMGZlZjg0N2JlZGE2YWM.} ERROR: presence
> > > > > [notify.c:1369]: publ_notify_notifier(): Can't query db
> > > > > Jan  8 04:34:37 client1 /usr/local/sbin/kamailio[19523]: {1 1
> > > > > PUBLISH
> > > > > MzQ4ZjNhOGRlYWZlY2QyMDQwMGZlZjg0N2JlZGE2YWM.} ERROR: presence
> > > > > [presentity.c:1152]: update_presentity(): updating watcher records
> > > > > Jan  8 04:34:37 client1 /usr/local/sbin/kamailio[19527]: {1 1
> > 
> > SUBSCRIBE
> > 
> > > > > MTlkYjI2NTBhYTFlMTBjYmYyMDgzNzQxYTM3OTE4OGE.} ERROR: db_mysql
> > 
> > > > > [km_dbase.c:128]: db_mysql_submit_query(): driver error on query:
> > Table
> > 
> > > > > 'watchers' was not locked with LOCK TABLES (1100)
> > > > > Jan  8 04:34:37 client1 /usr/local/sbin/kamailio[19527]: {1 1
> > 
> > SUBSCRIBE
> > 
> > > > > MTlkYjI2NTBhYTFlMTBjYmYyMDgzNzQxYTM3OTE4OGE.} ERROR: <core>
> > > > > [db_query.c:132]: db_do_query_internal(): error while submitting
> > 
> > query
> > 
> > > > > Jan  8 04:34:37 client1 /usr/local/sbin/kamailio[19527]: {1 1
> > 
> > SUBSCRIBE
> > 
> > > > > MTlkYjI2NTBhYTFlMTBjYmYyMDgzNzQxYTM3OTE4OGE.} ERROR: presence
> > > > > [subscribe.c:2827]: get_db_subs_auth(): while querying watchers
> > > > > table
> > > > > Jan  8 04:34:37 client1 /usr/local/sbin/kamailio[19527]: {1 1
> > 
> > SUBSCRIBE
> > 
> > > > > MTlkYjI2NTBhYTFlMTBjYmYyMDgzNzQxYTM3OTE4OGE.} ERROR: presence
> > > > > [subscribe.c:1217]: handle_subscribe(): getting subscription status
> > 
> > from
> > 
> > > > > watchers table
> > > > > Jan  8 04:34:37 client1 /usr/local/sbin/kamailio[19523]: {1 1
> > > > > PUBLISH
> > > > > MzQ4ZjNhOGRlYWZlY2QyMDQwMGZlZjg0N2JlZGE2YWM.} ERROR: presence
> > > > > [publish.c:499]: ki_handle_publish_uri(): when updating presentity
> > > > > 
> > > > > I am currently using presence with memory only db_mode but for
> > > > 
> > > > persistence
> > > > 
> > > > > i would like to use db_only mode which is not possible due to this
> > > > > issue.
> > > > > Any idea or suggetions for this issue.

-- 
Henning Westerholt - https://skalatan.de/blog/
Kamailio services - https://skalatan.de/services
Kamailio security assessment - https://skalatan.de/de/assessment



More information about the sr-users mailing list