[Spce-user] [km_dbase.c:122]
Daniel Grotti
dgrotti at sipwise.com
Mon Jun 15 05:56:42 EDT 2015
Hi,
6sec to make an update in location table is quite high. isn't ?
Can't really help here, but for sure it looks related to the system
resources/configuration/performances.
---
Daniel Grotti
VoIP Engineer
Sipwise GmbH
Europaring F15 | 2345 Brunn am Gebirge, Austria | www.sipwise.com
On 06/13/2015 03:21 AM, Crexpedio Support Team wrote:
>
>
>
>
> Thank you for the quick response.
>
> This is a Amazon hosted server with 4Gb Ram, 8 Gb SSD HDD.
>
>
> Normal usage of the server shows CPU under 5% and memory usage about 1.5Gb.
>
>
>
>
> root at secure:/# df -h
> Filesystem Size Used Avail Use% Mounted on
> rootfs 7.8G 2.4G 5.1G 32% /
> udev 10M 0 10M 0% /dev
> tmpfs 377M 112K 376M 1% /run
> /dev/xvda 7.8G 2.4G 5.1G 32% /
> tmpfs 5.0M 0 5.0M 0% /run/lock
> tmpfs 753M 0 753M 0% /run/shm
>
> root at secure:/# iostat
> Linux 3.16-0.bpo.3-amd64 (secure) 06/12/2015 _x86_64_(1 CPU)
>
> avg-cpu: %user %nice %system %iowait %steal %idle
> 1.94 0.00 3.08 90.79 4.01 0.18
>
> Device: tps kB_read/s kB_wrtn/s kB_read kB_wrtn
> xvda 23.75 1.94 147.66 342009 26071492
>
>
>
> I’ve read through the lists and found some that you have assisted on,
> but they all seem to be fixes that should not be present in this
> release. Server appears to be running smoothly and SQL is running as it
> should. There are also some duplicate errors in the debug below that
> make me think that there is a data issue: ERROR: db_mysql
> [km_dbase.c:122]: db_mysql_submit_query(): driver error on query:
> Duplicate entry 'uloc-55786194-11a7-b02' for key ‘ruid_idx'
>
> I have googled for all these errors and have come up inconclusive. I
> contacted SIPWISE directly for a 10 ticket (incident) package to see if
> these can get resolved. I’m just very concerned as this is basically a
> fresh install with 20 accounts and I’m having lots of problems.
>
> */var/log/mysql/mysqld.err*
> Shows no relevant information regarding problems
>
> */var/log/mysql.slow-queries.log (this shows continuously throughout the
> log file)*
> # Time: 150612 1:39:04
> # User at Host: kamailio[kamailio] @ localhost []
> # Query_time: 6.225502 Lock_time: 0.000034 Rows_sent: 0 Rows_examined: 1
> SET timestamp=1434094744;
> delete from location where username='88340757' AND
> contact='sip:88340757 at 192.168.4.112:37144;transport=TLS;ob'AND
> domain='secure.crexpedio.com <http://secure.crexpedio.com/>';
> # Time: 150612 1:42:00
> # User at Host: kamailio[kamailio] @ localhost []
> # Query_time: 6.034056 Lock_time: 0.000061 Rows_sent: 0 Rows_examined: 2
> SET timestamp=1434094920;
> update location set
> callid='C0Adq.nYdqcare67Gi4O6JHWHPx.AtJ1',path='<sip:lb at 127.0.0.1;lr;socket=sip:10.237.162.56:5061>',expires='2015-06-12
> 01:56:54',q=-1.00 ,cseq=33483,flags=0,cflags=0,user_agent='Bria
> Stretto Android
> 3.2.1',received=NULL,socket='udp:127.0.0.1:5062',methods=8159,last_modified='2015-06-12
> 01:41:54',ruid='uloc-55786194-11ad-d22',instance=NULL,reg_id=0,contact='sip:5010100101 at 201.191.199.69:41658;transport=TLS;ob'where
> username='5010100101' AND
> contact='sip:5010100101 at 201.191.199.69:41658;transport=TLS;ob'AND
> domain='secure-voip10.ncryptmedia.com
> <http://secure-voip10.ncryptmedia.com/>';
> # Time: 150612 1:42:12
> # User at Host: kamailio[kamailio] @ localhost []
> # Query_time: 5.919136 Lock_time: 0.000054 Rows_sent: 0 Rows_examined: 0
> SET timestamp=1434094932;
> insert into location
> (username,contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified,ruid,instance,reg_id,domain
> ) values
> ('5010100101','sip:5010100101 at 10.133.168.146:41658;transport=TLS;ob','2015-06-1201:57:07',-1.00
> ,'AsCI4bAHub-O2slCsuWLP003SWsVFiJz',36751,0,192,'Bria Stretto
> Android
> 3.2.1','sip:201.191.199.69:41658;transport=tls','<sip:lb at 127.0.0.1;lr;received=sip:201.191.199.69:41658%3Btransport%3Dtls;socket=sip:10.237.162.56:5061>','udp:127.0.0.1:5062',8159,'2015-06-12
> 01:42:07','uloc-55786194-11b3-162','<urn:uuid:bb051b37-84a6-3e06-986a-9d895ee4dea7>',1,'secure-voip10.ncryptmedia.com
> <http://secure-voip10.ncryptmedia.com/>');
> # Time: 150612 1:42:25
> # User at Host: kamailio[kamailio] @ localhost []
> # Query_time: 6.512000 Lock_time: 0.000055 Rows_sent: 0 Rows_examined: 6
> SET timestamp=1434094945;
> update location set expires='2015-06-12 01:57:19',q=-1.00
> ,cseq=48717,flags=0,cflags=192,user_agent='Bria Stretto Android
> 3.2.1',received='sip:201.191.199.69:41658;transport=tls',path='<sip:lb at 127.0.0.1;lr;received=sip:201.191.199.69:41658%3Btransport%3Dtls;socket=sip:10.237.162.56:5061>',socket='udp:127.0.0.1:5062',methods=8159,last_modified='2015-06-1201:42:19',callid='MqV7TKeYQ77X4VTulYWoMGQApIoaJ2A5',contact='sip:5010100101 at 10.133.168.146:41658;transport=TLS;ob'where
> username='5010100101' AND
> instance='<urn:uuid:bb051b37-84a6-3e06-986a-9d895ee4dea7>' AND reg_id=1
> AND domain='secure-voip10.ncryptmedia.com
> <http://secure-voip10.ncryptmedia.com/>';
>
>
>
>
>> On Jun 12, 2015, at 10:35 AM, Daniel Grotti <dgrotti at sipwise.com
>> <mailto:dgrotti at sipwise.com>> wrote:
>>
>> Hello guys,
>> well I saw your message in the mailing list and also saw a couple of
>> asnwer there.
>> Actually is not so easy to say what can cause this problem.
>> The issue is the DB disconnection:
>>
>> Jun 11 21:02:26 secure proxy[4525]: ERROR: db_mysql [km_dbase.c:122]:
>> db_mysql_submit_query(): driver error on query: Lost connection to
>> MySQL server during query
>>
>>
>> All the suggestion you got already are good to check
>> I would check mysql logs in /var/log/mysql and also:
>>
>> - what kind of HDD/RAID does that machine have ?
>> - Do you see high %wa percentage (IO wait) in 'top' ?
>> - What is the disk utilization reported in 'iostat -dx1' during that ?
>> - is it happening only to this customer ?
>>
>> It looks related to the system resources though.
>> I would start to dig in this direction.
>>
>>
>> Daniel
>>
>>
>> ------------------------------------------------------------------------
>> *From: *"Crexpedio Support Team" <jesse at crexpedio.com
>> <mailto:jesse at crexpedio.com>>
>> *To: *"Daniel Grotti" <dgrotti at sipwise.com <mailto:dgrotti at sipwise.com>>
>> *Sent: *Friday, June 12, 2015 6:16:30 PM
>> *Subject: *[km_dbase.c:122]
>>
>> Daniel,
>>
>> I’m sorry to write to you directly but I was hoping you had a minute
>> to look over this problem. I am struggling with this platform which is
>> already in a production stage with 20 customers.
>>
>>
>> I’ve had some issues which I believe are all related to a database
>> issue but haven’t found a fix. Server is installed following
>> documentation and config files have not been manually edited.
>>
>> For example:
>> - subscriber gets failed registration multiple times prior to
>> extension logging in.
>> - no data in Call Distribution report on GUI
>> - CDR’s are empty
>>
>> Enviornment
>> mr3.8.1-1433635162
>>
>> Logs from Kamailio-proxy.log (subscriber number, domain and IP are
>> bogus but logs are real)
>>
>> Jun 11 21:02:20 secure proxy[4537]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=w1vwnvtiLSC4oMtd3cb0NUZN2CrhqcWO
>> Jun 11 21:02:20 secure proxy[4537]: NOTICE: <script>: Authentication
>> failed, no credentials - R=sip:secure.domain.com
>> ID=w1vwnvtiLSC4oMtd3cb0NUZN2CrhqcWO
>> Jun 11 21:02:20 secure proxy[4525]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=w1vwnvtiLSC4oMtd3cb0NUZN2CrhqcWO
>> Jun 11 21:02:26 secure proxy[4525]: ERROR: db_mysql [km_dbase.c:122]:
>> db_mysql_submit_query(): driver error on query: Lost connection to
>> MySQL server during query
>> Jun 11 21:02:26 secure proxy[4525]: ERROR: <core> [db_query.c:235]:
>> db_do_insert_cmd(): error while submitting query
>> Jun 11 21:02:26 secure proxy[4525]: ERROR: usrloc [ucontact.c:629]:
>> db_insert_ucontact(): inserting contact in db failed
>> Jun 11 21:02:26 secure proxy[4525]: ERROR: usrloc [urecord.c:548]:
>> insert_ucontact(): failed to insert in database
>> Jun 11 21:02:26 secure proxy[4525]: ERROR: registrar [save.c:521]:
>> insert_contacts(): failed to insert contact
>> Jun 11 21:02:31 secure proxy[4531]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=FeMkULbvDUDm6B29o92VtjpCpAuD.UXq
>> Jun 11 21:02:31 secure proxy[4531]: NOTICE: <script>: Authentication
>> failed, no credentials - R=sip:secure.domain.com
>> ID=FeMkULbvDUDm6B29o92VtjpCpAuD.UXq
>> Jun 11 21:02:31 secure proxy[4534]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=FeMkULbvDUDm6B29o92VtjpCpAuD.UXq
>> Jun 11 21:02:37 secure proxy[4534]: ERROR: db_mysql [km_dbase.c:122]:
>> db_mysql_submit_query(): driver error on query: Lost connection to
>> MySQL server during query
>> Jun 11 21:02:37 secure proxy[4534]: ERROR: <core> [db_query.c:235]:
>> db_do_insert_cmd(): error while submitting query
>> Jun 11 21:02:37 secure proxy[4534]: ERROR: usrloc [ucontact.c:629]:
>> db_insert_ucontact(): inserting contact in db failed
>> Jun 11 21:02:37 secure proxy[4534]: ERROR: usrloc [urecord.c:548]:
>> insert_ucontact(): failed to insert in database
>> Jun 11 21:02:37 secure proxy[4534]: ERROR: registrar [save.c:521]:
>> insert_contacts(): failed to insert contact
>> Jun 11 21:02:44 secure proxy[4520]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=eBGfI1JFE.oUd.vPpswiXsv8KEtxnlpn
>> Jun 11 21:02:44 secure proxy[4520]: NOTICE: <script>: Authentication
>> failed, no credentials - R=sip:secure.domain.com
>> ID=eBGfI1JFE.oUd.vPpswiXsv8KEtxnlpn
>> Jun 11 21:02:44 secure proxy[4537]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=eBGfI1JFE.oUd.vPpswiXsv8KEtxnlpn
>> Jun 11 21:02:45 secure proxy[4537]: NOTICE: <script>: Contacts
>> successfully saved, expires in 900s - R=sip:secure.domain.com
>> ID=eBGfI1JFE.oUd.vPpswiXsv8KEtxnlpn
>> Jun 11 21:02:45 secure proxy[4519]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=eBGfI1JFE.oUd.vPpswiXsv8KEtxnlpn
>> Jun 11 21:02:45 secure proxy[4525]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=b.Ibsie7kDB0pcL20jjqvTJDLVqpbLgg
>> Jun 11 21:02:45 secure proxy[4525]: NOTICE: <script>: Authentication
>> failed, no credentials - R=sip:secure.domain.com
>> ID=b.Ibsie7kDB0pcL20jjqvTJDLVqpbLgg
>> Jun 11 21:02:45 secure proxy[4522]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=b.Ibsie7kDB0pcL20jjqvTJDLVqpbLgg
>> Jun 11 21:02:48 secure proxy[4519]: NOTICE: <script>: Contacts
>> successfully deleted - R=sip:secure.domain.com
>> ID=eBGfI1JFE.oUd.vPpswiXsv8KEtxnlpn
>> Jun 11 21:02:54 secure proxy[4522]: ERROR: db_mysql [km_dbase.c:122]:
>> db_mysql_submit_query(): driver error on query: Lost connection to
>> MySQL server during query
>> Jun 11 21:02:54 secure proxy[4522]: ERROR: <core> [db_query.c:235]:
>> db_do_insert_cmd(): error while submitting query
>> Jun 11 21:02:54 secure proxy[4522]: ERROR: usrloc [ucontact.c:629]:
>> db_insert_ucontact(): inserting contact in db failed
>> Jun 11 21:02:54 secure proxy[4522]: ERROR: usrloc [urecord.c:548]:
>> insert_ucontact(): failed to insert in database
>> Jun 11 21:02:54 secure proxy[4522]: ERROR: registrar [save.c:521]:
>> insert_contacts(): failed to insert contact
>> Jun 11 21:03:01 secure proxy[4534]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=3tipgKc0nT2Bdw3rxOrFzcikpgcanQKN
>> Jun 11 21:03:01 secure proxy[4534]: NOTICE: <script>: Authentication
>> failed, no credentials - R=sip:secure.domain.com
>> ID=3tipgKc0nT2Bdw3rxOrFzcikpgcanQKN
>> Jun 11 21:03:01 secure proxy[4520]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=3tipgKc0nT2Bdw3rxOrFzcikpgcanQKN
>> Jun 11 21:03:02 secure proxy[4520]: NOTICE: <script>: Contacts
>> successfully saved, expires in 900s - R=sip:secure.domain.com
>> ID=3tipgKc0nT2Bdw3rxOrFzcikpgcanQKN
>> Jun 11 21:03:02 secure proxy[4537]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=3tipgKc0nT2Bdw3rxOrFzcikpgcanQKN
>> Jun 11 21:03:02 secure proxy[4525]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=ySN6jCakYHYrnWtj6eJbJ5COHpbOp9Fe
>> Jun 11 21:03:02 secure proxy[4525]: NOTICE: <script>: Authentication
>> failed, no credentials - R=sip:secure.domain.com
>> ID=ySN6jCakYHYrnWtj6eJbJ5COHpbOp9Fe
>> Jun 11 21:03:02 secure proxy[4519]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=ySN6jCakYHYrnWtj6eJbJ5COHpbOp9Fe
>> Jun 11 21:03:04 secure proxy[4537]: NOTICE: <script>: Contacts
>> successfully deleted - R=sip:secure.domain.com
>> ID=3tipgKc0nT2Bdw3rxOrFzcikpgcanQKN
>> Jun 11 21:03:07 secure proxy[4519]: ERROR: db_mysql [km_dbase.c:122]:
>> db_mysql_submit_query(): driver error on query: Duplicate entry
>> 'uloc-55786194-11a7-b02' for key 'ruid_idx'
>> Jun 11 21:03:07 secure proxy[4519]: ERROR: <core> [db_query.c:235]:
>> db_do_insert_cmd(): error while submitting query
>> Jun 11 21:03:07 secure proxy[4519]: ERROR: usrloc [ucontact.c:629]:
>> db_insert_ucontact(): inserting contact in db failed
>> Jun 11 21:03:07 secure proxy[4519]: ERROR: usrloc [urecord.c:548]:
>> insert_ucontact(): failed to insert in database
>> Jun 11 21:03:07 secure proxy[4519]: ERROR: registrar [save.c:521]:
>> insert_contacts(): failed to insert contact
>> Jun 11 21:03:12 secure proxy[4522]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=objP.SyrDoQJOdyQzCSsutv-PrglhR37
>> Jun 11 21:03:12 secure proxy[4522]: NOTICE: <script>: Authentication
>> failed, no credentials - R=sip:secure.domain.com
>> ID=objP.SyrDoQJOdyQzCSsutv-PrglhR37
>> Jun 11 21:03:12 secure proxy[4528]: NOTICE: <script>: New request on
>> proxy - M=REGISTER R=sip:secure.domain.com
>> F=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>T=sip:88888888 at secure.domain.com
>> <mailto:88888888 at secure.domain.com>IP=200.200.200.200:39999
>> (127.0.0.1:5060) ID=objP.SyrDoQJOdyQzCSsutv-PrglhR37
>> ^C
>>
>> Mysql is running:
>>
>> root at secure:/home/admin# ps aux | grep mysql
>> root 2229 0.0 0.0 4192 1548 ? S Jun10 0:00
>> /bin/sh /usr/bin/mysqld_safe
>> mysql 3312 0.1 3.7 658404 144204 ? Sl Jun10 2:45
>> /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql
>> --plugin-dir=/usr/lib/mysql/plugin --user=mysql
>> --log-error=/var/log/mysql/mysqld.err
>> --pid-file=/var/run/mysqld/mysqld.pid
>> --socket=/var/run/mysqld/mysqld.sock --port=3306
>>
>>
>>
>> root at secure:/home/admin# mysql -u root -p
>> Enter password:
>> Welcome to the MySQL monitor. Commands end with ; or \g.
>> Your MySQL connection id is 71051
>> Server version: 5.5.43-0+deb7u1-log (Debian)
>>
>> Copyright (c) 2000, 2015, Oracle and/or its affiliates. All rights
>> reserved.
>>
>> Oracle is a registered trademark of Oracle Corporation and/or its
>> affiliates. Other names may be trademarks of their respective
>> owners.
>>
>> Type 'help;' or '\h' for help. Type '\c' to clear the current input
>> statement.
>>
>> mysql> show databases;
>> +--------------------+
>> | Database |
>> +--------------------+
>> | information_schema |
>> | accounting |
>> | billing |
>> | carrier |
>> | kamailio |
>> | mysql |
>> | ngcp |
>> | performance_schema |
>> | prosody |
>> | provisioning |
>> | sipstats |
>> | stats |
>> | syslog |
>> +--------------------+
>> 13 rows in set (1.20 sec)
>>
>>
>> Please advise.
>>
>>
>>
>>
>>
>>
>>
>>
>>
>
>
>
> _______________________________________________
> Spce-user mailing list
> Spce-user at lists.sipwise.com
> https://lists.sipwise.com/listinfo/spce-user
>
More information about the Spce-user
mailing list