12 September 2012, 3:37

Hello,

as in 1.4 mahara 1.5 seems to have problems to execute the cronjob. The cron  worked well until about 20 students joined the mahara. Now it's the same as in the previous version. Cron is not running, although it is set up correctly an was running up to the go live.

Does anybody know a way to get this running?
In case there is no solution or fix, what does a not running cron cause in regard to main functions of mahara?

Mahara 1.5.1
PHP 3.2.16
MySQL 5.1.52

Please excuse, that I am opening an new thread although it is discussed with a former one. But I could not find it, although I tried to.

Thanks for your support
Conrad

12 September 2012, 22:27

Hello Conrad,

Do you think your server resources are adequate?
I believe the mahars cron mostly processes rss feeds from the RSS blocktype and it also helps with the stats on the admin page. Other than that I don't think it does much. Mailing works without it.

13 September 2012, 3:39

Hello Conrad,

The cron job actually does quite a bit and is important in Mahara. If you get the information "Cron is not running", it can actually mean that certain tasks have failed. It does not mean that th entire cron is not running.

We have a very large Mahara instance for example and cron is running just fine. Could you please check your system resources?

Cheers

Kristina

13 September 2012, 6:15

Hello Kristina and Dirk,

the ressources are small but should work: 500MB.

It can not be, that a simple "send message" by using SMTP produces that error message:

Allowed memory size of 524288000 bytes exhausted (tried to allocate 194645 bytes) in /home/.sites/383/site150/web/eportfolio/lib/phpmailer/class.phpmailer.php on line 1983

Can not beliefe, that sending a single message should need 700MB memory.
By using 200 MB the error message claimed for 250MB.

So it seems that there is something going on with the code. But what? And how to bug fix this.
I deleted SMPT setting. So mahara works fine (with the exeption of forum messages - see another post)

Please continue helping me fixing that

Kind Regards, Conrad

13 September 2012, 11:56

Here I send some logfile lines:

[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_message("Failed to get a recordset: mysql error: [2006: MyS...", 8, true, true) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:109, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_warn("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:749, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * SQLException->__construct("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:484, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_sql("SELECT authname FROM "ep_auth_instance"  WHERE "id...", array(size 1), 0, 2) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:325, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record_sql("SELECT authname FROM "ep_auth_instance"  WHERE "id...", array(size 1)) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:302, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record("auth_instance", "id", "1", null, null, null, null, "authname") at /home/.sites/xxx/sitexxx/web/eportfolio/auth/lib.php:1222, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * AuthFactory::create("1") at /home/.sites/xxx/sitexxx/web/eportfolio/auth/lib.php:399, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * auth_setup() at /home/.sites/xxx/sitexxx/web/eportfolio/init.php:291, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * require("/home/.sites/xxx/sitexxx/web/eportfolio/init.php") at /home/.sites/xxx/sitexxx/web/eportfolio/index.php:32, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] eb (lib/dml.php:484) Failed to get a recordset: mysql error: [2006: MySQL server has gone away] in EXECUTE("SELECT authname FROM "ep_auth_instance"  WHERE "id" = '1'  LIMIT 2"), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] eb (lib/dml.php:484) Command was: SELECT authname FROM "ep_auth_instance"  WHERE "id" = ?  and values was (1), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_sql("SELECT authname FROM "ep_auth_instance"  WHERE "id...", array(size 1), 0, 2) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:325, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record_sql("SELECT authname FROM "ep_auth_instance"  WHERE "id...", array(size 1)) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:302, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record("auth_instance", "id", "1", null, null, null, null, "authname") at /home/.sites/xxx/sitexxx/web/eportfolio/auth/lib.php:1222, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * AuthFactory::create("1") at /home/.sites/xxx/sitexxx/web/eportfolio/auth/lib.php:399, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * auth_setup() at /home/.sites/xxx/sitexxx/web/eportfolio/init.php:291, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * require("/home/.sites/xxx/sitexxx/web/eportfolio/init.php") at /home/.sites/xxx/sitexxx/web/eportfolio/index.php:32, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] eb (lib/errors.php:749) Failed to get a recordset: mysql error: [2006: MySQL server has gone away] in EXECUTE("SELECT * FROM "ep_export_installed" ORDER BY name "), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] eb (lib/errors.php:749) Command was: SELECT * FROM "ep_export_installed" ORDER BY name , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_message("Failed to get a recordset: mysql error: [2006: MyS...", 8, true, true) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:109, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_warn("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:749, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * SQLException->__construct("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:484, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_sql("SELECT * FROM "ep_export_installed" ORDER BY name ", null) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:440, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_select("export_installed", "", null, "name", "*", "", "") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:404, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset("export_installed", "", "", "name", "*", "", "") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:569, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_records_assoc("export_installed", "", "", "name") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/mahara.php:1313, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * plugins_installed("export") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/web.php:2096, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * mahara_standard_nav() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/web.php:2215, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * main_nav() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/web.php:425, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * smarty(array(size 0), array(size 0), array(size 0), array(size 1)) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:581, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * MaharaException->handle_exception() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:472, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * exception(object(SQLException)) at Unknown:0, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] eb (lib/errors.php:590) Exception thrown by smarty call while handling exception, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_message("Exception thrown by smarty call while handling exc...", 8, true, true) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:109, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_warn("Exception thrown by smarty call while handling exc...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:590, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * MaharaException->handle_exception() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:472, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * exception(object(SQLException)) at Unknown:0, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] 94 (lib/errors.php:749) Failed to get a recordset: mysql error: [2006: MySQL server has gone away] in EXECUTE("SELECT * FROM "ep_usr"  WHERE "id" = '2'  LIMIT 2"), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] 94 (lib/errors.php:749) Command was: SELECT * FROM "ep_usr"  WHERE "id" = ?  and values was (2), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_message("Failed to get a recordset: mysql error: [2006: MyS...", 8, true, true) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:109, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_warn("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:749, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * SQLException->__construct("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:484, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_sql("SELECT * FROM "ep_usr"  WHERE "id" = ? ", array(size 1), 0, 2) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:325, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record_sql("SELECT * FROM "ep_usr"  WHERE "id" = ? ", array(size 1)) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:302, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record("usr", "id", "2") at /home/.sites/xxx/sitexxx/web/eportfolio/auth/user.php:1238, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * LiveUser->reload_background_fields() at /home/.sites/xxx/sitexxx/web/eportfolio/auth/user.php:1256, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * LiveUser->commit() at /home/.sites/xxx/sitexxx/web/eportfolio/auth/user.php:1278, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * LiveUser->renew() at /home/.sites/xxx/sitexxx/web/eportfolio/auth/lib.php:439, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * auth_setup() at /home/.sites/xxx/sitexxx/web/eportfolio/init.php:291, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * require("/home/.sites/xxx/sitexxx/web/eportfolio/init.php") at /home/.sites/xxx/sitexxx/web/eportfolio/view/view.php:34, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] 94 (lib/dml.php:484) Failed to get a recordset: mysql error: [2006: MySQL server has gone away] in EXECUTE("SELECT * FROM "ep_usr"  WHERE "id" = '2'  LIMIT 2"), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] 94 (lib/dml.php:484) Command was: SELECT * FROM "ep_usr"  WHERE "id" = ?  and values was (2), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_sql("SELECT * FROM "ep_usr"  WHERE "id" = ? ", array(size 1), 0, 2) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:325, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record_sql("SELECT * FROM "ep_usr"  WHERE "id" = ? ", array(size 1)) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:302, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record("usr", "id", "2") at /home/.sites/xxx/sitexxx/web/eportfolio/auth/user.php:1238, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * LiveUser->reload_background_fields() at /home/.sites/xxx/sitexxx/web/eportfolio/auth/user.php:1256, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * LiveUser->commit() at /home/.sites/xxx/sitexxx/web/eportfolio/auth/user.php:1278, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * LiveUser->renew() at /home/.sites/xxx/sitexxx/web/eportfolio/auth/lib.php:439, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * auth_setup() at /home/.sites/xxx/sitexxx/web/eportfolio/init.php:291, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * require("/home/.sites/xxx/sitexxx/web/eportfolio/init.php") at /home/.sites/xxx/sitexxx/web/eportfolio/view/view.php:34, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] 94 (lib/errors.php:749) Failed to get a recordset: mysql error: [2006: MySQL server has gone away] in EXECUTE("SELECT * FROM "ep_export_installed" ORDER BY name "), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] 94 (lib/errors.php:749) Command was: SELECT * FROM "ep_export_installed" ORDER BY name , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_message("Failed to get a recordset: mysql error: [2006: MyS...", 8, true, true) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:109, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_warn("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:749, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * SQLException->__construct("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:484, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_sql("SELECT * FROM "ep_export_installed" ORDER BY name ", null) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:440, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_select("export_installed", "", null, "name", "*", "", "") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:404, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset("export_installed", "", "", "name", "*", "", "") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:569, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_records_assoc("export_installed", "", "", "name") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/mahara.php:1313, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * plugins_installed("export") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/web.php:2096, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * mahara_standard_nav() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/web.php:2215, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * main_nav() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/web.php:425, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * smarty(array(size 0), array(size 0), array(size 0), array(size 1)) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:581, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * MaharaException->handle_exception() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:472, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * exception(object(SQLException)) at Unknown:0, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] 94 (lib/errors.php:590) Exception thrown by smarty call while handling exception, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_message("Exception thrown by smarty call while handling exc...", 8, true, true) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:109, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_warn("Exception thrown by smarty call while handling exc...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:590, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * MaharaException->handle_exception() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:472, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * exception(object(SQLException)) at Unknown:0, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] d7 (lib/errors.php:749) Failed to get a recordset: mysql error: [2006: MySQL server has gone away] in EXECUTE("SELECT admin,staff FROM "ep_usr"  WHERE "id" = '2'  LIMIT 2"), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] d7 (lib/errors.php:749) Command was: SELECT admin,staff FROM "ep_usr"  WHERE "id" = ?  and values was (2), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_message("Failed to get a recordset: mysql error: [2006: MyS...", 8, true, true) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:109, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_warn("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:749, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * SQLException->__construct("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:484, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_sql("SELECT admin,staff FROM "ep_usr"  WHERE "id" = ? ", array(size 1), 0, 2) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:325, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record_sql("SELECT admin,staff FROM "ep_usr"  WHERE "id" = ? ", array(size 1)) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:302, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record("usr", "id", "2", null, null, null, null, "admin,staff") at /home/.sites/xxx/sitexxx/web/eportfolio/auth/lib.php:420, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * auth_setup() at /home/.sites/xxx/sitexxx/web/eportfolio/init.php:291, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * require("/home/.sites/xxx/sitexxx/web/eportfolio/init.php") at /home/.sites/xxx/sitexxx/web/eportfolio/admin/index.php:35, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] d7 (lib/dml.php:484) Failed to get a recordset: mysql error: [2006: MySQL server has gone away] in EXECUTE("SELECT admin,staff FROM "ep_usr"  WHERE "id" = '2'  LIMIT 2"), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] d7 (lib/dml.php:484) Command was: SELECT admin,staff FROM "ep_usr"  WHERE "id" = ?  and values was (2), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_sql("SELECT admin,staff FROM "ep_usr"  WHERE "id" = ? ", array(size 1), 0, 2) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:325, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record_sql("SELECT admin,staff FROM "ep_usr"  WHERE "id" = ? ", array(size 1)) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:302, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_record("usr", "id", "2", null, null, null, null, "admin,staff") at /home/.sites/xxx/sitexxx/web/eportfolio/auth/lib.php:420, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * auth_setup() at /home/.sites/xxx/sitexxx/web/eportfolio/init.php:291, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * require("/home/.sites/xxx/sitexxx/web/eportfolio/init.php") at /home/.sites/xxx/sitexxx/web/eportfolio/admin/index.php:35, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] d7 (lib/errors.php:749) Failed to get a recordset: mysql error: [2006: MySQL server has gone away] in EXECUTE("SELECT * FROM "ep_artefact_installed" ORDER BY name "), referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] d7 (lib/errors.php:749) Command was: SELECT * FROM "ep_artefact_installed" ORDER BY name , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_message("Failed to get a recordset: mysql error: [2006: MyS...", 8, true, true) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:109, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_warn("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:749, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * SQLException->__construct("Failed to get a recordset: mysql error: [2006: MyS...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:484, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_sql("SELECT * FROM "ep_artefact_installed" ORDER BY nam...", null) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:440, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset_select("artefact_installed", "", null, "name", "*", "", "") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:404, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_recordset("artefact_installed", "", "", "name", "*", "", "") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/dml.php:569, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * get_records_assoc("artefact_installed", "", "", "name") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/mahara.php:1313, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * plugins_installed("artefact") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/web.php:2220, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * main_nav() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/web.php:425, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * smarty(array(size 0), array(size 0), array(size 0), array(size 1)) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:581, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * MaharaException->handle_exception() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:472, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * exception(object(SQLException)) at Unknown:0, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] d7 (lib/errors.php:590) Exception thrown by smarty call while handling exception, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] Call stack (most recent first):, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_message("Exception thrown by smarty call while handling exc...", 8, true, true) at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:109, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * log_warn("Exception thrown by smarty call while handling exc...") at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:590, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * MaharaException->handle_exception() at /home/.sites/xxx/sitexxx/web/eportfolio/lib/errors.php:472, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx]   * exception(object(SQLException)) at Unknown:0, referer: http://www.xxxx.xxx/eportfolio/
[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] , referer: http://www.xxxx.xxx/eportfolio/

18 September 2012, 0:55

Hi Conrad,

These lines are probably the important ones to see:

[Thu Sep 13 16:42:21 2012] [error] [client 86.xx.xx.xxx] [WAR] eb (lib/dml.php:484) Failed to get a recordset: mysql error: [2006: MySQL server has gone away] in EXECUTE("SELECT authname FROM "ep_auth_instance"  WHERE "id" = '1'  LIMIT 2"), referer: http://www.xxxx.xxx/eportfolio/

MySQL seems to be shutting down for some reason. I don't know why that would be, but you should check that out.

Thanks,
Melissa.

19 September 2012, 13:35

Hi Melissa,

thanks for checking the error messages and giving mit your support.  I asked my webhoster to check timeout on MySQL.

Perhaps you can help me towards a problem using SMTP - may be that this one corresponds with that.
See my message in this thread (next to the loglines): https://mahara.org/interaction/forum/topic.php?id=4860#post21341 .

The system obviously is working hard burning lots of memory and than shutting down.  The 1.4 Version is working within the same setting without any problems. So I don't think, this is caused by ressources or system performance.

Would be great if you figured out the bug.

Thanks in advance
an Kind Regards
Conrad

20 September 2012, 1:23

Hi Conrad,

"Allowed memory size of 524288000 bytes exhausted (tried to allocate 194645 bytes)"

This doesn't mean that one single message is 500mb big, it means that the script being run to send the mail has been given 500mb of data to send already and the database wanted to give it even more; and it could not take that much more.

The message the script was trying to add to the pile there was just 190kb big, but if there were 3000 emails to send and that was the average size per email, the server may be overloaded.

How many people are using this mahara? Are they sending lots of very very long forum posts or feedbacks, for example?

Your Mahara 1.4 site may not be trying to send such a large amount of email, which may be why it is not having this issue.

Thanks,
Melissa

20 September 2012, 5:53

Hi Melissa,

thanks for replying.

It was only me at this time sending a message. And the message was "test sending message using SMTP" (less than 190kb). At this time I was the only logged in User.

My course counts about 40 students and they are not using the e-portfolio extensively ;-)  - because this is the only course at the university working with an e-portfolio system. None of them has sent a message at all, yet.

So I don't think that this problem has something to do with mass email.  Working without SMTP settings all works fine. Messages are sent properly and without any delay. So there "must" have been some changes in 1.5.1 that causes this bug. But I have no clue what.

Thanks and Kind Regards
Conrad

20 September 2012, 21:36

Conrad,

If you could provide some context with that line, similar to the amount of output you had for that big paste of logs in this thread, I might be able to see what's using up all the memory.

I can't extrapolate from that single line, however.

Thanks,
Melissa.