[Freeswitch-users] Lock wait timeout exceeded; try restarting transaction

Sat Jul 27 15:10:46 MSD 2013

If that is the case you should add that index to the code too.

That doesn't excuse all the actual threading issues that are still present
:)
On Jul 27, 2013 5:26 AM, "Steven Ayre" <steveayre at gmail.com> wrote:

> Also given that this is 2 different hosts connecting to a shared database
> this is not a threading issue.
>
> Rather it is queries locking too many rows blocking other concurrent
> connections.
>
>
>
>
>
> On 27 July 2013 11:18, Steven Ayre <steveayre at gmail.com> wrote:
>
>> delete from registrations where expires > 0 and expires <= 1374852304 and
>> hostname='freeswitch_ha0';
>> delete from registrations where expires > 0 and expires <= 1374852306 and
>> hostname='freeswitch_ha1';
>>
>> So it is 2 different servers both removing expired registrations at the
>> same time.
>>
>> I think there's a small flaw in the indexes on the table
>> freeswitch-autocreates.
>>
>> In sip_registrations there is an index on (expires), but it would be
>> better for the above to have a compound index on (hostname,expires). That
>> way the innodb row locking will lock only the entries in that range for the
>> host during the delete instead of locking every entry in that range for all
>> hosts and then scan the range for the hostname.
>>
>> In registrations there are no indexes to help this query at all. The
>> compound index would help there too.
>>
>> It'll also help find the relevant entries faster, especially if you have
>> a lot of servers sharing the db.
>>
>> Try manually making these modifications to the database:
>> ALTER TABLE registrations ADD KEY r_host_expires (hostname,expires);
>> ALTER TABLE sip_registrations ADD KEY host_expires (hostname,expires);
>>
>> -Steve
>>
>>
>>
>> On 26 July 2013 16:30, Ira Tessler <ira at connectmevoice.com> wrote:
>>
>>> I am getting the same problem on my development system today. I just put
>>> up a new version of mysql. Went from 5.1.67 to 5.6.12. Here is the deadlock
>>> section:
>>>
>>>
>>>
>>> ------------------------
>>>
>>> LATEST DETECTED DEADLOCK
>>>
>>> ------------------------
>>>
>>> 2013-07-26 11:23:22 7fd473f1e700
>>>
>>> *** (1) TRANSACTION:
>>>
>>> TRANSACTION 251674, ACTIVE 2 sec fetching rows
>>>
>>> mysql tables in use 1, locked 1
>>>
>>> LOCK WAIT 3 lock struct(s), heap size 376, 3 row lock(s)
>>>
>>> MySQL thread id 38, OS thread handle 0x7fd473fa0700, query id 156782
>>> 192.168.1.27 root updating
>>>
>>> delete from registrations where expires > 0 and expires <= 1374852304
>>> and hostname='freeswitch_ha0'
>>>
>>> *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
>>>
>>> RECORD LOCKS space id 10 page no 3 n bits 96 index `GEN_CLUST_INDEX` of
>>> table `freeswitch`.`registrations` trx id 251674 lock_mode X waiting
>>>
>>> Record lock, heap no 22 PHYSICAL RECORD: n_fields 13; compact format;
>>> info bits 32
>>>
>>>  0: len 6; hex 000000001769; asc      i;;
>>>
>>> 1: len 6; hex 00000003d709; asc       ;;
>>>
>>> 2: len 7; hex 070000015b0352; asc     [ R;;
>>>
>>> 3: len 3; hex 373033; asc 703;;
>>>
>>> 4: len 28; hex 32323535352e7463702e6861312e746573747362636461782e636f6d;
>>> asc 22555.tcp.ha1.testsbcdax.com;;
>>>
>>> 5: len 30; hex
>>> 313030303130342d302d313730333030304034372e32332e3130362e3233; asc
>>> 1000104-0-1703000 at 47.23.106.23; (total 31 bytes);
>>>
>>> 6: len 30; hex
>>> 736f6669612f6861315f696e7465726e616c5f7463702f7369703a373033; asc
>>> sofia/ha1_internal_tcp/sip:703; (total 152 bytes);
>>>
>>> 7: len 4; hex d1f2962a; asc    *;;
>>>
>>> 8: len 12; hex 31302e31302e31302e313032; asc 10.10.10.102;;
>>>
>>> 9: len 5; hex 3230303031; asc 20001;;
>>>
>>> 10: len 3; hex 746370; asc tcp;;
>>>
>>> 11: len 14; hex 667265657377697463685f686131; asc freeswitch_ha1;;
>>>
>>>  12: SQL NULL;
>>>
>>>
>>>
>>> *** (2) TRANSACTION:
>>>
>>> TRANSACTION 251657, ACTIVE 2 sec starting index read
>>>
>>> mysql tables in use 1, locked 1
>>>
>>> 5 lock struct(s), heap size 1248, 5 row lock(s), undo log entries 2
>>>
>>> MySQL thread id 28, OS thread handle 0x7fd473f1e700, query id 156786
>>> 192.168.1.45 root updating
>>>
>>> delete from registrations where expires > 0 and expires <= 1374852306
>>> and hostname='freeswitch_ha1'
>>>
>>> *** (2) HOLDS THE LOCK(S):
>>>
>>> RECORD LOCKS space id 10 page no 3 n bits 96 index `GEN_CLUST_INDEX` of
>>> table `freeswitch`.`registrations` trx id 251657 lock_mode X locks rec but
>>> not gap
>>>
>>> Record lock, heap no 22 PHYSICAL RECORD: n_fields 13; compact format;
>>> info bits 32
>>>
>>>  0: len 6; hex 000000001769; asc      i;;
>>>
>>> 1: len 6; hex 00000003d709; asc       ;;
>>>
>>> 2: len 7; hex 070000015b0352; asc     [ R;;
>>>
>>> 3: len 3; hex 373033; asc 703;;
>>>
>>> 4: len 28; hex 32323535352e7463702e6861312e746573747362636461782e636f6d;
>>> asc 22555.tcp.ha1.testsbcdax.com;;
>>>
>>> 5: len 30; hex
>>> 313030303130342d302d313730333030304034372e32332e3130362e3233; asc
>>> 1000104-0-1703000 at 47.23.106.23; (total 31 bytes);
>>>
>>> 6: len 30; hex
>>> 736f6669612f6861315f696e7465726e616c5f7463702f7369703a373033; asc
>>> sofia/ha1_internal_tcp/sip:703; (total 152 bytes);
>>>
>>> 7: len 4; hex d1f2962a; asc    *;;
>>>
>>> 8: len 12; hex 31302e31302e31302e313032; asc 10.10.10.102;;
>>>
>>> 9: len 5; hex 3230303031; asc 20001;;
>>>
>>> 10: len 3; hex 746370; asc tcp;;
>>>
>>> 11: len 14; hex 667265657377697463685f686131; asc freeswitch_ha1;;
>>>
>>>  12: SQL NULL;
>>>
>>>
>>>
>>> *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
>>>
>>> RECORD LOCKS space id 10 page no 3 n bits 96 index `GEN_CLUST_INDEX` of
>>> table `freeswitch`.`registrations` trx id 251657 lock_mode X waiting
>>>
>>> Record lock, heap no 3 PHYSICAL RECORD: n_fields 13; compact format;
>>> info bits 0
>>>
>>>  0: len 6; hex 0000000016d1; asc       ;;
>>>
>>> 1: len 6; hex 000000033bc4; asc     ; ;;
>>>
>>> 2: len 7; hex d20000022f0110; asc     /  ;;
>>>
>>> 3: len 3; hex 383033; asc 803;;
>>>
>>> 4: len 21; hex 32323535382e636d767465737474656c652e636f6d; asc
>>> 22558.cmvtesttele.com;;
>>>
>>> 5: len 30; hex
>>> 62326365383430342d6438313665303162403139322e3136382e3230302e; asc
>>> b2ce8404-d816e01b at 192.168.200.; (total 33 bytes);
>>>
>>> 6: len 30; hex
>>> 736f6669612f6861305f696e7465726e616c2f7369703a38303340313038; asc
>>> sofia/ha0_internal/sip:803 at 108; (total 46 bytes);
>>>
>>> 7: len 4; hex d1f29d68; asc    h;;
>>>
>>> 8: len 14; hex 3130382e35382e3130302e313432; asc 108.58.100.142;;
>>>
>>> 9: len 4; hex 35303630; asc 5060;;
>>>
>>> 10: len 3; hex 756470; asc udp;;
>>>
>>> 11: len 14; hex 667265657377697463685f686130; asc freeswitch_ha0;;
>>>
>>>  12: SQL NULL;
>>>
>>>
>>>
>>> *** WE ROLL BACK TRANSACTION (1)
>>>
>>> ------------
>>>
>>> TRANSACTIONS
>>>
>>> ------------
>>>
>>> Trx id counter 252611
>>>
>>> Purge done for trx's n:o < 252607 undo n:o < 0 state: running but idle
>>>
>>> History list length 2731
>>>
>>> LIST OF TRANSACTIONS FOR EACH SESSION:
>>>
>>> ---TRANSACTION 252530, not started
>>>
>>> MySQL thread id 127, OS thread handle 0x7fd49c0e4700, query id 157673
>>> 192.168.1.45 root cleaning up
>>>
>>> ---TRANSACTION 252039, not started
>>>
>>> MySQL thread id 126, OS thread handle 0x7fd473e1a700, query id 157059
>>> 192.168.1.45 root cleaning up
>>>
>>> ---TRANSACTION 252344, not started
>>>
>>> MySQL thread id 125, OS thread handle 0x7fd46f12a700, query id 157516
>>> 192.168.1.27 root cleaning up
>>>
>>> ---TRANSACTION 0, not started
>>>
>>> MySQL thread id 117, OS thread handle 0x7fd473e5b700, query id 157835
>>> localhost root init
>>>
>>> show engine innodb status
>>>
>>> ---TRANSACTION 252610, not started
>>>
>>> MySQL thread id 42, OS thread handle 0x7fd46f332700, query id 157834
>>> 192.168.1.27 root cleaning up
>>>
>>> ---TRANSACTION 252382, not started
>>>
>>> MySQL thread id 39, OS thread handle 0x7fd473f5f700, query id 157566
>>> 192.168.1.27 root cleaning up
>>>
>>> ---TRANSACTION 252605, not started
>>>
>>> MySQL thread id 38, OS thread handle 0x7fd473fa0700, query id 157830
>>> 192.168.1.27 root cleaning up
>>>
>>> ---TRANSACTION 252378, not started
>>>
>>> MySQL thread id 37, OS thread handle 0x7fd473edd700, query id 157553
>>> 192.168.1.27 root cleaning up
>>>
>>> ---TRANSACTION 252609, not started
>>>
>>> MySQL thread id 33, OS thread handle 0x7fd46f22e700, query id 157832
>>> 192.168.1.45 root cleaning up
>>>
>>> ---TRANSACTION 252387, not started
>>>
>>> MySQL thread id 30, OS thread handle 0x7fd46f26f700, query id 157592
>>> 192.168.1.45 root cleaning up
>>>
>>> ---TRANSACTION 252396, not started
>>>
>>> MySQL thread id 29, OS thread handle 0x7fd473fe1700, query id 157609
>>> 192.168.1.45 root cleaning up
>>>
>>> ---TRANSACTION 252319, not started
>>>
>>> MySQL thread id 28, OS thread handle 0x7fd473f1e700, query id 157496
>>> 192.168.1.45 root cleaning up
>>>
>>> ---TRANSACTION 252386, not started
>>>
>>> MySQL thread id 27, OS thread handle 0x7fd46f2b0700, query id 157579
>>> 192.168.1.45 root cleaning up
>>>
>>>
>>>
>>> Ira Tessler
>>> Lead Software Engineer
>>> ConnectMe
>>> (732) 490-9007 x2
>>> ira at connectmevoice.com
>>>
>>>
>>>
>>> *From:* freeswitch-users-bounces at lists.freeswitch.org [mailto:
>>> freeswitch-users-bounces at lists.freeswitch.org] *On Behalf Of *Steven
>>> Ayre
>>> *Sent:* Wednesday, July 17, 2013 3:55 PM
>>> *To:* FreeSWITCH Users Help
>>> *Subject:* Re: [Freeswitch-users] Lock wait timeout exceeded; try
>>> restarting transaction
>>>
>>>
>>>
>>> Run 'SHOW ENGINE INNODB STATUS\G'
>>>
>>>
>>>
>>> What does it show in the latest deadlock section?
>>>
>>>
>>>
>>>
>>>
>>> On 17 July 2013 14:16, Lloyd Aloysius <lloyd.aloysius at gmail.com> wrote:
>>>
>>> This is newly installed switch. Only one call and two registrations. I
>>> do not do any queries against the DB. I do not see the problem again in
>>> last 24 hours. But want to know how to solve this issue.
>>>
>>>
>>>
>>> Switch - 2 Quad Core / 24 GB Memory / 15RPM SCSI , DB - 2 Quad Core / 24
>>> GB Memory / 15RPM SCSI . Switch and DB connected through a cross over cable
>>> directly. I do not think this related to a environment issue.
>>>
>>>
>>>
>>> Thanks
>>>
>>> Lloyd
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>> On Tue, Jul 16, 2013 at 7:01 AM, Steven Ayre <steveayre at gmail.com>
>>> wrote:
>>>
>>> +1
>>>
>>>
>>>
>>> The error is the actual MySQL error, so yes it's definitely a lock
>>> timeout.
>>>
>>>
>>>
>>> This means two different queries were trying to access the same data at
>>> the same time. Normally one'll wait until the other is finished, but if it
>>> waits too long you get the lock timeout error.
>>>
>>>
>>>
>>> It can be caused by a query taking too long, or a transaction modifying
>>> the data but then taking too long before commit. To avoid that make sure
>>> MySQL is tuned correctly. Good indexes on the tables and good sizes for the
>>> cache buffers.
>>>
>>>
>>>
>>> Make sure you're using a proper index for the delete operation, I'd also
>>> avoid ORs if possible.
>>>
>>>
>>>
>>> The query is part of mod_sofia, so isn't modifiable. Having a
>>> KEY(hostname,expires) on sip_dialogs may help though if it doesn't already
>>> exist (check with SHOW CREATE TABLE sip_dialogs).
>>>
>>>
>>>
>>> Avoid accessing sip_dialogs from any of your own code to minimise the
>>> number of things that might block each other.
>>>
>>>
>>>
>>> -Steve
>>>
>>>
>>>
>>>
>>>
>>> On 16 July 2013 06:48, Rafal Gwizdala <rafal.gwizdala at gmail.com> wrote:
>>>
>>> I'd bet this is a lock timeout, caused by database operation taking too
>>> long.
>>>
>>> Make sure you're using a proper index for the delete operation, I'd also
>>> avoid ORs if possible.
>>>
>>> R
>>>
>>>
>>>
>>> On Tue, Jul 16, 2013 at 4:21 AM, Lloyd Aloysius <
>>> lloyd.aloysius at gmail.com> wrote:
>>>
>>> Hi,
>>>
>>>
>>>
>>> I got the following error
>>>
>>>
>>>
>>> 2013-07-15 21:47:41.061450 [ERR] switch_odbc.c:514 ERR: [delete from
>>> sip_dialogs where (expires = -1 or (expires > 0 and expires <= 1373939087))
>>> and hostname='mydomain.com']
>>>
>>> [STATE: HY000 CODE 1205 ERROR: [unixODBC][MySQL][ODBC 5.1
>>> Driver][mysqld-5.5.32]Lock wait timeout exceeded; try restarting
>>> transaction]
>>>
>>>
>>>
>>> and the odbcinst.ini
>>>
>>>
>>>
>>> [MySQL]
>>>
>>> Description     = ODBC for MySQL
>>>
>>> Driver          = /usr/lib/libmyodbc5.so
>>>
>>> Setup           = /usr/lib/libodbcmyS.so
>>>
>>> Driver64        = /usr/lib64/libmyodbc5.so
>>>
>>> Setup64         = /usr/lib64/libodbcmyS.so
>>>
>>> FileUsage       = 1
>>>
>>> Threading       = 0
>>>
>>> UsageCount      = 1
>>>
>>>
>>>
>>> This is a mysql memory leak? How can fix this error?
>>>
>>>
>>>
>>> DB Server running with 24 GB memory and 2 Quad Core Xeon
>>>
>>>
>>>
>>>
>>>
>>> Thanks
>>>
>>> Lloyd
>>>
>>>
>>>
>>> _________________________________________________________________________
>>> Professional FreeSWITCH Consulting Services:
>>> consulting at freeswitch.org
>>> http://www.freeswitchsolutions.com
>>>
>>> 
>>> 
>>>
>>> Official FreeSWITCH Sites
>>> http://www.freeswitch.org
>>> http://wiki.freeswitch.org
>>> http://www.cluecon.com
>>>
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
>>>
>>>
>>>
>>>
>>> _________________________________________________________________________
>>> Professional FreeSWITCH Consulting Services:
>>> consulting at freeswitch.org
>>> http://www.freeswitchsolutions.com
>>>
>>> 
>>> 
>>>
>>> Official FreeSWITCH Sites
>>> http://www.freeswitch.org
>>> http://wiki.freeswitch.org
>>> http://www.cluecon.com
>>>
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
>>>
>>>
>>>
>>>
>>> _________________________________________________________________________
>>> Professional FreeSWITCH Consulting Services:
>>> consulting at freeswitch.org
>>> http://www.freeswitchsolutions.com
>>>
>>> 
>>> 
>>>
>>> Official FreeSWITCH Sites
>>> http://www.freeswitch.org
>>> http://wiki.freeswitch.org
>>> http://www.cluecon.com
>>>
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
>>>
>>>
>>>
>>>
>>> _________________________________________________________________________
>>> Professional FreeSWITCH Consulting Services:
>>> consulting at freeswitch.org
>>> http://www.freeswitchsolutions.com
>>>
>>> 
>>> 
>>>
>>> Official FreeSWITCH Sites
>>> http://www.freeswitch.org
>>> http://wiki.freeswitch.org
>>> http://www.cluecon.com
>>>
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
>>>
>>>
>>>
>>> _________________________________________________________________________
>>> Professional FreeSWITCH Consulting Services:
>>> consulting at freeswitch.org
>>> http://www.freeswitchsolutions.com
>>>
>>> 
>>> 
>>>
>>> Official FreeSWITCH Sites
>>> http://www.freeswitch.org
>>> http://wiki.freeswitch.org
>>> http://www.cluecon.com
>>>
>>> FreeSWITCH-users mailing list
>>> FreeSWITCH-users at lists.freeswitch.org
>>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>>> http://www.freeswitch.org
>>>
>>>
>>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> 
> 
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130727/4de68af9/attachment-0001.html 