error/moodle/locktimeout error while upgrading from 3.4.3 to 3.4.3+

error/moodle/locktimeout error while upgrading from 3.4.3 to 3.4.3+

by Carlo Gandolfi -
Number of replies: 8

I was upgrading my moodle server with git pull from 3.4.3 (Build: 20180517) (2017111303.00) to 3.4.3+ (Build: 20180524) (2017111303.01) when at the and of database upgrade I get "A timeout occurred while waiting for the lock." error. More info about this error link land me to this empty page: https://docs.moodle.org/34/en/error/moodle/locktimeout

I've restored my moodle folder backup and my mysql database dump but nothing. Restart apachectl, mysql and server, but nothing.

I look inside mysql console for some blocking query (following this stackoverflow thread) but nothing.

Increase innodb lock wait timeout with: SET innodb_lock_wait_timeout = 5000; SET GLOBAL innodb_lock_wait_timeout = 5000; but nothing.

I'm running moodle on:

  • macMini 2,6 GHz Intel Core i5, macOS 10.13.4, 8GB ram
  • 5.6.20 MySQL Community Server (GPL)
  • PHP Version 7.1.10

Thanks in advance for your support.

EDIT: my mysql status and processlist: https://pastebin.com/yPkm7qpU

Average of ratings: -
In reply to Carlo Gandolfi

Re: error/moodle/locktimeout error while upgrading from 3.4.3 to 3.4.3+

by Ken Task -
Picture of Particularly helpful Moodlers

First, seems your issue is unusual ... and requires some true DB admin knowledge.   Most folks in here are not true DB admins ... and neither am I.

In trying to find an answer or things to try, searched Moodle's Tracker for the issue, but nothing specifically addressed your situation.   So ... strike one! (baseball season now)

Found a blog where gentleman purposely set up a situation that rendered the same issues:

Ref: http://wagnerbianchi.com/blog/?p=847

His Engine InnoDB status shows:

---TRANSACTION 0, not started
MySQL thread id 7, OS thread handle 0x7f50f05dd700, query id 58 localhost root init
show engine innodb status
---TRANSACTION 1825, ACTIVE 18 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
MySQL thread id 5, OS thread handle 0x7f50f061e700, query id 56 localhost root update
insert into test.t1 set id=3
------- TRX HAS BEEN WAITING 18 SEC FOR THIS LOCK TO BE GRANTED:

Your pastbin results using engine innodb status doesn't show any such thing.

I take it that mysqld can launch, but it seems to be stuck in this locked state ... is that correct?

If so ... have you tried: start transaction; from the mysql prompt?

If that also fails, then in reading up on issues related, have seen a blog that recommended adding some settings to my.cnf

transaction-isolation = READ-COMMITTED
innodb_locks_unsafe_for_binlog = 1 # Optional

Might want to read up on those first before adding to my.cnf.

Are you sure the .sql dumps you have of the moodle taken prior to upgrade attempt are valid?   Can you restore to another mysql server one a another machine to verify?

If you can, then one might have to get drastic (I did tinker one time with slaves and masters on a production server and messed it up ... kept getting errors with reference links that instructed how to fix ... which I tried ... none worked [am not a true DB admin so that was almost to be expected]).

So ... turned to more drastic resolution and you might also have to do the same.   DB server was behind a version so that helped my situation.

I uninstalled the mysql-server and client via yum.   That has a safeguard in that the actual DB files remained in a location where they could be used again should I re-installed.   It also copied my.cnf to my.cnf.rpmsave.

Since the daemon no longer running and I wanted to make sure I eradicated anything I'd done tinkering, I manually removed those files.

Re-installed the next highest version upwards (in your case could reinstall same version).

Got it setup ... just like a fresh install.    Then restored the moodle DB via the SQL dump.

Theory ... that transaction thing should NOT be there at all (my  slave/master issue definitely gone).   Now with a fresh functioning server, test the current version restored.   Everything work?  OK.   Make a backup just to make sure - sql dump as you probably have done before, and then try the upgrade via git again.   Git, BTW, just acquires the code ... doesn't touch DB.   The 'upgrade.php script in moodlecode/admin/cli/ however does.

This time, before the upgrade, manually insert the lines for debugging into config.php before you try your upgrade *and* make sure your MySQL server is logging ... log on a Linux box found in /var/log/  .... the mysqld.log in particular.

In my.cnf:

[mysqld_safe]
log-error=/var/log/mysqld.log

or where ever a Mac would prefer to have the log file.

The one thing you didn't share was the setup of DB server.   What does your my.cnf look like?

Fingers crossed and wishing you luck! ;)

'spirit of sharing', Ken





Average of ratings: -
In reply to Ken Task

Re: error/moodle/locktimeout error while upgrading from 3.4.3 to 3.4.3+

by Carlo Gandolfi -
First thanks Ken for your reply. I really had 20 hours of nightmare smile

I always test update on a mirror server before apply to production one getting 3.4.3+ with no problem. (This later save me.)

On my production site I always do a backup of moodle folder and a dump of database before an upgrade; when something goes wrong I just restore both to get prior version, but this time "timeout error" persist. After all attempts described above I also performed a complete restore of all server from a TimeMachine backup. This time I got some other DB errors.

I've to say that I try an upgrade form 3.4.3 to 3.5+ but CSS were not uploaded; I did not perform a cache clean and just restore to 3.4.3 without problem. When upgrade from 3.4.3 to 3.4.3+ my server stuck.

After lots of attempts I solved (with server restored from TimeMachine), restoring moodle folder and DB dump from my mirror server that luckily I'd synced the day before.

My /usr/local/mysql/my.cnf is:

[client]
default-character-set = utf8mb4

[mysqld]
innodb_file_format = Barracuda
innodb_file_per_table = 1
innodb_large_prefix

character-set-server = utf8mb4
collation-server = utf8mb4_unicode_ci
skip-character-set-client-handshake

sql_mode=NO_ENGINE_SUBSTITUTION,STRICT_TRANS_TABLES

[mysql]
default-character-set = utf8mb4

More info: my DB is about 370MB and moodledata folder about 4GB.
My server is running since november 2005 with moodle 1.5.2

Now I'm quite afraid to perform any update.


Average of ratings: -
In reply to Carlo Gandolfi

Re: error/moodle/locktimeout error while upgrading from 3.4.3 to 3.4.3+

by Ken Task -
Picture of Particularly helpful Moodlers

Ok, so you are fixed ... right?  or prod server back to version before the minor upgrade?

I have always found it handy to have the most recently active code backups, DB dump,  and data directory backups right on the server itself in something like /home/backups/

Easily done via tar and mysqldump.

Your site isn't that large, BTW.

While docs for Moodle 3.4 concerning DB are here:

https://docs.moodle.org/34/en/MySQL

https://docs.moodle.org/34/en/MySQL_full_unicode_support

I've found additional tweaking needed.   Can your server run mySQLTuner?   it's a perl script.

Example clips of what tuner might show/recommend:

-------- Performance Metrics

[OK] Maximum reached memory usage: 4.0G (26.13% of installed RAM)
[OK] Maximum possible memory usage: 4.2G (27.14% of installed RAM)
[OK] Overall possible memory usage with other process is compatible with memory available
[OK] Slow queries: 0% (0/5M)
[OK] Highest usage of available connections: 5% (8/151)
[OK] Aborted connections: 0.00%  (0/34153)
[!!] name resolution is active : a reverse na

-------- InnoDB Metrics

[--] InnoDB is enabled.
[--] InnoDB Thread Concurrency: 8
[OK] InnoDB File per table is activated
[OK] InnoDB buffer pool / data size: 4.0G/234.2M
[!!] Ratio InnoDB log file size / InnoDB Buffer pool size (3.125 %): 64.0M * 2/4.0G should be equal 25%
[OK] InnoDB buffer pool instances: 4
[--] Number of InnoDB Buffer Pool Chunk : 32 for 4 Buffer Pool Instance(s)
[OK] Innodb_buffer_pool_size aligned with Innodb_buffer_pool_chunk_size & Innodb_buffer_pool_instances
[OK] InnoDB Read buffer efficiency: 99.98% (78184175 hits/ 78197063 total)
[!!] InnoDB Write Log efficiency: 32.75% (200866 hits/ 613311 total)
[OK] InnoDB log waits: 0.00% (0 waits / 814177 writes)

The above are from production server and yes, I can see I've a couple tweaks I need.

When you performed the git pull and the upgrade.php script, was the site in the maintenance mode?

An upgrade performed with git and the PHP script takes apache service out of the loop.   When performing upgrades on some sites, even though folks have been warned ahead of time ... including admins of the site ... some wanna mess with things.   So, on those sites, not only have I set maintenance mode on ... I've even shutdown apache service ... now they can't mess with server while I'm upgrading.

Can't stay at a version forever ... sooner or later ... one will have to upgrade.   Yes, could be painful, but ....

BTW, since I upgraded the MySQL on that server where I had the problem, been running like a top now ... no issues.

'spirit of sharing', Ken



Average of ratings: -
In reply to Ken Task

Re: error/moodle/locktimeout error while upgrading from 3.4.3 to 3.4.3+

by Carlo Gandolfi -

Ok, so you are fixed ... right? or prod server back to version before the minor upgrade?

Yes fixed, now my prod server is running 3.4.3+

I have always found it handy to have the most recently active code backups, DB dump, and data directory backups right on the server itself in something like /home/backups/

Easily done via tar and mysqldump.

I did it too, but my server stuck despite restoring backup done five minute before, that worried me a lot.

Your site isn't that large, BTW.

Thanks, although I'm looking a way to slim it, but this is another thread.

I've found additional tweaking needed. Can your server run mySQLTuner? it's a perl script.

First time I hear for it, I'll test it next days and post here my results. Thank for the tip.

When you performed the git pull and the upgrade.php script, was the site in the maintenance mode?

Yes, ever. I'm the only admin and quite sure nobody browse or login during this upgrade that lasted few minutes.

Can't stay at a version forever ... sooner or later ... one will have to upgrade. Yes, could be painful, but ....

Yes I know, for a long time I was on 3.1.2 and then I've to buy new server machine (replacing an old MacMini online since 2009 till 2017) to update OS, to update PHP to update mySQL and then update moodle to last version. I'm at the end of about six months of step by step updates smile

Average of ratings: -
In reply to Ken Task

Re: error/moodle/locktimeout error while upgrading from 3.4.3 to 3.4.3+

by Carlo Gandolfi -
Here is some of my mysqltuner output; really don't know how to understand it.

[OK] Currently running supported MySQL version 5.6.20
[OK] Operating on 64-bit architecture

-------- Storage Engine Statistics -----------------------------------------------------------------
[--] Status: +ARCHIVE +BLACKHOLE +CSV -FEDERATED +InnoDB +MEMORY +MRG_MYISAM +MyISAM +PERFORMANCE_SCHEMA
[--] Data in InnoDB tables: 372M (Tables: 402)
[--] Data in MyISAM tables: 1K (Tables: 1)
[OK] Total fragmented tables: 0

-------- Performance Metrics -----------------------------------------------------------------------
[--] Up for: 1d 1h 29m 48s (141K q [1.538 qps], 2K conn, TX: 410M, RX: 35M)
[--] Reads / Writes: 84% / 16%
[--] Binary logging is disabled
[--] Physical Memory : 8.0G
[--] Max MySQL memory : 741.5M
[--] Other process memory: 7.6G
[--] Total buffers: 169.0M global + 1.1M per thread (151 max threads)
[--] P_S Max memory usage: 402M
[--] Galera GCache Max memory usage: 0B
[OK] Maximum reached memory usage: 577.3M (7.05% of installed RAM)
[OK] Maximum possible memory usage: 741.5M (9.05% of installed RAM)
[!!] Overall possible memory usage with other process exceeded memory
[OK] Slow queries: 0% (1/141K)
[OK] Highest usage of available connections: 3% (5/151)
[!!] Aborted connections: 3.92% (109/2779)
[!!] name resolution is active : a reverse name resolution is made for each new connection and can reduce performance
[!!] Query cache may be disabled by default due to mutex contention.
[!!] Query cache efficiency: 0.0% (0 cached / 107K selects)
[OK] Query cache prunes per day: 0
[OK] Sorts requiring temporary tables: 0% (44 temp sorts / 20K sorts)
[!!] Joins performed without indexes: 2169
[OK] Temporary tables created on disk: 16% (2K on disk / 13K total)
[OK] Thread cache hit rate: 99% (5 created / 2K connections)
[OK] Table cache hit rate: 47% (895 open / 1K opened)
[OK] Open file limit used: 0% (49/5K)
[OK] Table locks acquired immediately: 100% (185K immediate / 185K locks)

-------- Performance schema ------------------------------------------------------------------------
[--] Memory used by P_S: 402.7M
[--] Sys schema isn't installed.

-------- ThreadPool Metrics ------------------------------------------------------------------------
[--] ThreadPool stat is disabled.

-------- MyISAM Metrics ----------------------------------------------------------------------------
[!!] Key buffer used: 18.2% (1M used / 8M cache)
[OK] Key buffer size / total MyISAM indexes: 8.0M/98.0K
[!!] Read Key buffer hit rate: 90.0% (10 cached / 1 reads)

-------- InnoDB Metrics ----------------------------------------------------------------------------
[--] InnoDB is enabled.
[--] InnoDB Thread Concurrency: 0
[OK] InnoDB File per table is activated
[!!] InnoDB buffer pool / data size: 128.0M/372.1M
[!!] Ratio InnoDB log file size / InnoDB Buffer pool size (75 %): 48.0M * 2/128.0M should be equal 25%
[!!] InnoDB buffer pool <= 1G and Innodb_buffer_pool_instances(!=1).
[--] InnoDB Buffer Pool Chunk Size not used or defined in your version
[OK] InnoDB Read buffer efficiency: 99.93% (14329901 hits/ 14339504 total)
[!!] InnoDB Write Log efficiency: 65.77% (32265 hits/ 49061 total)
[OK] InnoDB log waits: 0.00% (0 waits / 16796 writes)

-------- Replication Metrics -----------------------------------------------------------------------
[--] Galera Synchronous replication: NO
[--] No replication slave(s) for this server.
[--] This is a standalone server.

-------- Recommendations ---------------------------------------------------------------------------
General recommendations:
Dedicate this server to your database for highest performance.
Reduce or eliminate unclosed connections and network issues
Configure your accounts with ip or subnets only, then update your configuration with skip-name-resolve=1
Adjust your join queries to always utilize indexes
Consider installing Sys schema from https://github.com/mysql/mysql-sys
Variables to adjust:
query_cache_size (=0)
query_cache_type (=0)
query_cache_limit (> 1M, or use smaller result sets)
join_buffer_size (> 256.0K, or always use indexes with joins)
innodb_buffer_pool_size (>= 372M) if possible.
innodb_log_file_size * innodb_log_files_in_group should be equal to 1/4 of buffer pool size (=64M) if possible.
innodb_buffer_pool_instances (=1)
Average of ratings: -
In reply to Carlo Gandolfi

Re: error/moodle/locktimeout error while upgrading from 3.4.3 to 3.4.3+

by Ken Task -
Picture of Particularly helpful Moodlers

When one runs a moodle as a standalone ... any platform/OS ... where web service and DB server on same box, it's a balancing act between apache/web service and DB server/service.   DB servers like to have as much as it can in memory .... less, RW IO then.

Tuner offers some suggestions at the very end .... and you might definitely consider adding them to my.cnf.

Server has 8 gig memory?

[--] Physical Memory : 8.0G
[--] Max MySQL memory : 741.5M

I'll suggest a few ... that stand out to me, but you do need to research so that know for sure ... it's your server!

[!!] InnoDB buffer pool / data size: 128.0M/372.1M

The data in the DB larger than the pool.

The recommendation by tuner at the bottom:

innodb_buffer_pool_size (>= 372M) if possible

add 2 lines to my.cnf ...

innodb_buffer_pool_size=1G

innodb_buffer_pool_instances=1

Restart MySQL

rule is 1 instance per Gig

After making those additions, restart mysql.   The let it run a day ... come back and run tuner again.

This

[!!] Aborted connections: 3.92% (109/2779)

may have been a result of the issues you were having earlier and fixed and should 'disappear'.

Site your size should not have aborted connections, me thinks.

Like a said before .... am teaching you to fish here ... so research the other recommendations tuner has made via Google.

'spirit of sharing', Ken

Average of ratings: -
In reply to Ken Task

Re: error/moodle/locktimeout error while upgrading from 3.4.3 to 3.4.3+

by Carlo Gandolfi -

I appraciate a lot your effort to teach me fishing.

Yes, my server has 8GB RAM. I've phisical access to it.

I googled a little an dI get this post: http://www.videoarts.eu/articoli/ottimizzare_mysql_con_mysqltuner.107.it.html. I know it it in italian but is full of links to good documentations.

I get rid of:

query_cache_size (=0)  
query_cache_type (=0)  
query_cache_limit (&gt; 1M, or use smaller result sets)

adding to my.cnf file:

query_cache_size = 0  
query_cache_type = 0  
query_cache_limit = 1M

I've also added:

innodb_buffer_pool_size=1G
innodb_buffer_pool_instances=1

but I get this memory problem:

[--] Physical Memory     : 8.0G
[--] Max MySQL memory    : 21.0G
*** MySQL's maximum memory usage is dangerously high ***
*** Add RAM before increasing MySQL buffer variables ***
innodb_log_file_size * innodb_log_files_in_group should be equal to 1/4 of buffer pool size (=512M) if possible.`

I found this Incorrect suggestion for ratio InnoDB log file size / InnoDB buffer pool size to calculate sizes. (25*1024/64/100=4). This are my results I added to my.cnf:

innodb_buffer_pool_size = 1G
innodb_log_file_size = 64M
innodb_log_files_in_group = 4
innodb_buffer_pool_instances = 1

Now only join_buffer_size (&gt; 256.0K, or always use indexes with joins) is left. I let run it for few days to see for other problems, then I'll come back.

Thanks for all.

Average of ratings: -
In reply to Carlo Gandolfi

Re: error/moodle/locktimeout error while upgrading from 3.4.3 to 3.4.3+

by Ken Task -
Picture of Particularly helpful Moodlers

Only way I could help was for you to learn to fish! smile

Like I said ... balancing act .... but think you are gaining on the db side of things.

Don't forget to check into config of Apache ... might be able to reduce apache presence/footprint memory wise that then could be used for DB.   Also learn about 'top' and how to use it on a Mac server.  While not ideal, your small site might do well enough when/if using SWAP space for DB - that's something server will do ... not really anything for you to tweak.

Am sure 'shingled' DB admins would shutter at that last statement, but when one has only what one has .... got to work with what ya got! smile

'spirit of sharing', Ken


Average of ratings: -