Redirection and Database Transaction

Redirection and Database Transaction

by Michael Ko -
Number of replies: 12

Hello,

What is the correct way to close the DB connection and stop any running transactions and redirect to a different page in Moodle?

We are currently experiencing a major memory leak on our PostgreSQL Database server due to a header redirection occurring while the database transaction is left hanging - when a certain condition is met, the page is redirected.

Using abort_all_db_transactions() appears to be used by Moodle exceptions, but does this actually end the database transaction (and therefore, eventually reduce current active memory usage on the database server) or does this only rollback the transaction?

Does redirect() end database transactions (I could not see anything that would do this in the code)?

Any help is greatly appreciated!

Average of ratings: -
In reply to Michael Ko

Re: Redirection and Database Transaction

by David Mudrák -
Picture of Core developers Picture of Documentation writers Picture of Moodle HQ Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers Picture of Plugins guardians Picture of Testers Picture of Translators

All open transactions are automatically rolled back on the script shutdown - see core_shutdown_manager class. You should not need to do anything explicit on redirect.

Do you use persistent connection? Check your $CFG->dboptions['dbpersist'] in the config.php and eventually try change that to see the difference.

In reply to David Mudrák

Re: Redirection and Database Transaction

by Michael Ko -

Hi,

Thanks for your response.

As it turns out, we are have $CFG->dboptions = array('dbpersist' => false);

The issue seems to be in pgsql_native_moodle_database.php

What is happening is begin_transaction() is creating a SAVEPOINT, but this SAVEPOINT is never being released. It appears that rollback_transaction() should do this with: $sql = "RELEASE SAVEPOINT moodle_pg_savepoint; ROLLBACK"; (rollback_transaction() is called by abort_all_db_transactions())

However, this is not occurring, so it would appear that the core_shutdown_manager class is not doing its job.

In reply to Michael Ko

Re: Redirection and Database Transaction

by Michael Ko -

These unreleased savepoints are filling up the database server's memory. The database server has been getting very close several times to becoming completely unusable on the live system

In reply to Michael Ko

Re: Redirection and Database Transaction

by David Mudrák -
Picture of Core developers Picture of Documentation writers Picture of Moodle HQ Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers Picture of Plugins guardians Picture of Testers Picture of Translators

Hmm. As far as I can see, the $DB->force_transaction_rollback(); executed by the core_shutdown_manager should actually call rollback_transaction(); which in turn releases the savepoint. Can you perform a bit more debugging of force_transaction_rollback() to see if it is actually executed etc?

In reply to David Mudrák

Re: Redirection and Database Transaction

by Michael Ko -

In lib/dml/moodle_database.php I added the following to the beginning of force_transaction_rollback():


mail('MY EMAIL', 'Force transaction rollback', 'Force transaction rollback'.$_SERVER['REQUEST_URI']); 


Then I went to the page that executes this:

redirect("$CFG->wwwroot/enrol/index.php?id=$course->id");


I did not get any email from that redirect() function - so it seems the shut down is not working properly. However, I did get emails from REQUEST_URIs such as process quiz, so some parts of Moodle are executing $DB->force_trsnaction_rollback but obviously not redirect()

In reply to Michael Ko

Re: Redirection and Database Transaction

by Eloy Lafuente (stronk7) -
Picture of Core developers Picture of Documentation writers Picture of Moodle HQ Picture of Peer reviewers Picture of Plugin developers Picture of Testers
Hi Michael,

I'just have tried this, keeping a transaction open while redirecting and it seems that the shutdown manager is properly catching it and performing the savepoint release and the transaction rollback.

Perhaps mail() is not available so later in the script end of life, but error_log() seems to work.

https://gist.github.com/stronk7/3d812c63b289da9f1acb

It would be great if you can verify that in your sever. Ciao smile
In reply to Eloy Lafuente (stronk7)

Re: Redirection and Database Transaction

by Michael Ko -

A couple of things:

1. I have confirmed that both redirect functions are the same one (in weblib.php and not the one in url_helper.php)

2. I used mail() instead of error_log because our error log files are getting large (due to the database transaction error message in process quiz attempt, but I was told this is harmless here: https://moodle.org/mod/forum/discuss.php?d=263351).


I updated $DB->force_transaction_rollback to record the log with error_log() and ran that code you posted. The redirect to index.php worked correctly, and the active database transaction detected during request shutdown error message was logged. But I did not get the log that I added to $DB->force_transaction_rollback which was:

error_log('force_transaction_rollback() executed from '.$_SERVER['REQUEST_URI']); (on line 2370 of lib/dml/moodle_database.php)


So it appears in this example that the shut down manager's shutdown_handler() function is being called, but $DB->force_transaction_rollback() function is not being called, which seems very strange because in shutdown_manager.php the force transaction rollback is directly after error_log('Potential coding error.....')


Can I also confirm, does this error message (active database transaction detected during request shutdown) mean that the SAVEPOINT has been released? So if the shutdown manager is running but not the force transaction rollback, is the SAVEPOINT being released?




In reply to Michael Ko

Re: Redirection and Database Transaction

by Michael Ko -

EDIT:

Ok the error message that I logged in force_transaction_rollback() is now being logged when executing that GitHub code. So that is working correctly after $DB->start_delegated_transaction().

In reply to Michael Ko

Re: Redirection and Database Transaction

by Eloy Lafuente (stronk7) -
Picture of Core developers Picture of Documentation writers Picture of Moodle HQ Picture of Peer reviewers Picture of Plugin developers Picture of Testers

Aha,

so the shutdown manager is doing its job (at least the PHP is executed).

Next step should be to verify that both the "release savepoint" and the "rollback" are being executed. Surely you can do that by enabling logging in the database a looking for them.

Talking about memory leaks... I also found this issue. So an immediate check would be to upgrade to a newer PostgreSQL version, just in case you are able to do so.

BTW, I've been looking for some catalog tables providing information about active savepoints and I've been unable to find any... that has raised a question here... how do you know (in your original question) that savepoints are the "culprit" causing the memory problems in your server?

And that's all I can imagine. I don't think those savepoints can really be there, unreleased, especially if you are not using persistent connections (PHP has the good habit of closing all connections, and that should be enough, at last resort, to kill everything in the RDMS side). And I'm pretty sure that if a problem was there, happening usually, we should have detected it ages ago.

No matter of that, I agree that everything is possible, so it would be really interesting to, finally, understand what is going wrong in your server, just in case that helps other people out there. So, let's try to discover it.

Ciao smile

In reply to Eloy Lafuente (stronk7)

Re: Redirection and Database Transaction

by Michael Ko -

So after all of that, it seems that the shutdown manager is working correctly. The first time I checked to see if rollback was running, the page did not a have a DB delegated_transaction, it only had a regular query, therefore the check was never going to work.

I added logging to the functions that create, commit and rollback a savepoint. Every time a savepoint was started, either a commit occurred properly, or the roll back was executed every time the request was shut down with the savepoint still there.

The issue with the PostgreSQL server (we are using 9.2.8) is that the memory used by the checkpointer process is constantly increasing (1 GB after 24 hours, 2.1 GB after 72 hours). We are worried that eventually the server will run out of memory and start swapping (and become useless). We don't know when/if the server will crash but this is a very important time for our customers to have uninterrupted access. The server crashed a couple of weeks ago due to running out of memory, and we have been able to reduce the memory dramatically by using connection pooling and limiting the max connections to 300.

When we used Moodle 2.1, the memory used by the checkpointer process never behaved like this (so we do not think that the pgsql version has a bug and instead focused on the changes to Moodle). We are also using memcached and opcache.

We saw in the code that Moodle 2.6 uses SAVEPOINTs and Moodle 2.1 does not, and our error log was full of messages every 5 minutes about DB transactions being aborted, therefore this is the area we focused on. It was suggested to us that our custom parts were the cause of this problem (assuming that Moodle would not have a problem causing large memory leaks) and therefore we thought that a redirection we made was causing a SAVEPOINT to be left unreleased.

We started the database logging and I asked to be sent the database logs and we will analyse them as soon as they arrive.


Also we are getting another error message (far less frequently): 2014-07-10 10:56:20: (mod_fastcgi.c.2676) FastCGI-stderr: PHP message: Cannot find session record hgugllcqdq5eq22frahjn69737 for user 90716, creating new session.

This error message was recorded 28 times at 2014-07-10 10:56:20. From my understanding this leads back to \core\session\manager::start(); in setup.php. We have updated the execution of the error logging function to include a backtrace, so we can get some idea of where this is actually happening.


It seems that neither of these 2 errors are causing a database memory leak, but the available memory is still disappearing.

In reply to Michael Ko

Re: Redirection and Database Transaction

by Tim Hunt -
Picture of Core developers Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers

Just to note that a lot of big sites use Postgres, and don't see these problems. E.g. The Open University uses Moodle 2.6.x and Postgres 9.0, with large amounts of traffic, and our site does not crash.

In reply to Michael Ko

Re: Redirection and Database Transaction

by Michael Ko -

Is it possible that Moodle 2.6's use of SAVEPOINTs (even though they are released) is causing PSQL's checkpointer process memory usage to increase (as Moodle 2.1 did not use SAVEPOINTs and it did not use memory like this)?