28 April 2014, 17:43

Hi Robert,

the only error which I have noticed in the error log file is connected with the PHP GD-PNG library, and with the generation of the backend site statistics diagram. I haven't noticed any other warnings/errors in the error log file.

[24-Apr-2014 23:49:20 Europe/Berlin] [INF] c4 (D:\inetpub\wwwroot\mahara\lib\cron.php:168) ---------- cron finished Thu, 24 Apr 2014 23:49:20 +0200 ----------
[24-Apr-2014 23:51:24 Europe/Berlin] [INF] b7 (D:\inetpub\wwwroot\mahara\lib\cron.php:30) ---------- cron running Thu, 24 Apr 2014 23:51:24 +0200 ----------
[24-Apr-2014 23:51:24 Europe/Berlin] [INF] b7 (D:\inetpub\wwwroot\mahara\lib\cron.php:137) Running core cron activity_process_queue
[24-Apr-2014 23:51:24 Europe/Berlin] [INF] b7 (D:\inetpub\wwwroot\mahara\lib\cron.php:137) Running core cron user_login_tries_to_zero
[24-Apr-2014 23:51:24 Europe/Berlin] [INF] b7 (D:\inetpub\wwwroot\mahara\lib\cron.php:137) Running core cron rebuild_artefact_parent_cache_dirty
[24-Apr-2014 23:51:24 Europe/Berlin] [INF] b7 (D:\inetpub\wwwroot\mahara\lib\cron.php:137) Running core cron check_imap_for_bounces
[24-Apr-2014 23:51:24 Europe/Berlin] [INF] b7 (D:\inetpub\wwwroot\mahara\lib\cron.php:137) Running core cron cron_site_data_daily
[24-Apr-2014 23:51:25 Europe/Berlin] [WAR] b7 (D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125) imagepng(): gd-png:  fatal libpng error: Wrote palette index exceeding num_palette
[24-Apr-2014 23:51:25 Europe/Berlin] Call stack (most recent first):
[24-Apr-2014 23:51:25 Europe/Berlin]   * log_message("imagepng(): gd-png:  fatal libpng error: Wrote pal...", 8, true, true, "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125) at D:\inetpub\wwwroot\mahara\lib\errors.php:430
[24-Apr-2014 23:51:25 Europe/Berlin]   * error(2, "imagepng(): gd-png:  fatal libpng error: Wrote pal...", "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125, array(size 1)) at Unknown:0
[24-Apr-2014 23:51:25 Europe/Berlin]   * imagepng(resource(#6963), "D:\maharadata/images/grouptypes.png") at D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Canvas_GD_PNG->save(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:865
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->_done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:787
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\registration.php:1164
[24-Apr-2014 23:51:25 Europe/Berlin]   * group_type_graph() at D:\inetpub\wwwroot\mahara\lib\registration.php:2163
[24-Apr-2014 23:51:25 Europe/Berlin]   * graph_site_data_daily() at D:\inetpub\wwwroot\mahara\lib\mahara.php:3014
[24-Apr-2014 23:51:25 Europe/Berlin]   * cron_site_data_daily() at D:\inetpub\wwwroot\mahara\lib\cron.php:142
[24-Apr-2014 23:51:25 Europe/Berlin]
[24-Apr-2014 23:51:25 Europe/Berlin] [WAR] b7 (D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125) imagepng(): gd-png error: setjmp returns error condition
[24-Apr-2014 23:51:25 Europe/Berlin] Call stack (most recent first):
[24-Apr-2014 23:51:25 Europe/Berlin]   * log_message("imagepng(): gd-png error: setjmp returns error con...", 8, true, true, "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125) at D:\inetpub\wwwroot\mahara\lib\errors.php:430
[24-Apr-2014 23:51:25 Europe/Berlin]   * error(2, "imagepng(): gd-png error: setjmp returns error con...", "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125, array(size 1)) at Unknown:0
[24-Apr-2014 23:51:25 Europe/Berlin]   * imagepng(resource(#6963), "D:\maharadata/images/grouptypes.png") at D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Canvas_GD_PNG->save(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:865
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->_done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:787
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\registration.php:1164
[24-Apr-2014 23:51:25 Europe/Berlin]   * group_type_graph() at D:\inetpub\wwwroot\mahara\lib\registration.php:2163
[24-Apr-2014 23:51:25 Europe/Berlin]   * graph_site_data_daily() at D:\inetpub\wwwroot\mahara\lib\mahara.php:3014
[24-Apr-2014 23:51:25 Europe/Berlin]   * cron_site_data_daily() at D:\inetpub\wwwroot\mahara\lib\cron.php:142
[24-Apr-2014 23:51:25 Europe/Berlin]
[24-Apr-2014 23:51:25 Europe/Berlin] [WAR] b7 (D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125) imagepng(): gd-png:  fatal libpng error: Wrote palette index exceeding num_palette
[24-Apr-2014 23:51:25 Europe/Berlin] Call stack (most recent first):
[24-Apr-2014 23:51:25 Europe/Berlin]   * log_message("imagepng(): gd-png:  fatal libpng error: Wrote pal...", 8, true, true, "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125) at D:\inetpub\wwwroot\mahara\lib\errors.php:430
[24-Apr-2014 23:51:25 Europe/Berlin]   * error(2, "imagepng(): gd-png:  fatal libpng error: Wrote pal...", "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125, array(size 1)) at Unknown:0
[24-Apr-2014 23:51:25 Europe/Berlin]   * imagepng(resource(#6973), "D:\maharadata/images/viewtypes.png") at D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Canvas_GD_PNG->save(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:865
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->_done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:787
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\registration.php:1338
[24-Apr-2014 23:51:25 Europe/Berlin]   * view_type_graph() at D:\inetpub\wwwroot\mahara\lib\registration.php:2164
[24-Apr-2014 23:51:25 Europe/Berlin]   * graph_site_data_daily() at D:\inetpub\wwwroot\mahara\lib\mahara.php:3014
[24-Apr-2014 23:51:25 Europe/Berlin]   * cron_site_data_daily() at D:\inetpub\wwwroot\mahara\lib\cron.php:142
[24-Apr-2014 23:51:25 Europe/Berlin]
[24-Apr-2014 23:51:25 Europe/Berlin] [WAR] b7 (D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125) imagepng(): gd-png error: setjmp returns error condition
[24-Apr-2014 23:51:25 Europe/Berlin] Call stack (most recent first):
[24-Apr-2014 23:51:25 Europe/Berlin]   * log_message("imagepng(): gd-png error: setjmp returns error con...", 8, true, true, "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125) at D:\inetpub\wwwroot\mahara\lib\errors.php:430
[24-Apr-2014 23:51:25 Europe/Berlin]   * error(2, "imagepng(): gd-png error: setjmp returns error con...", "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125, array(size 1)) at Unknown:0
[24-Apr-2014 23:51:25 Europe/Berlin]   * imagepng(resource(#6973), "D:\maharadata/images/viewtypes.png") at D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Canvas_GD_PNG->save(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:865
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->_done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:787
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\registration.php:1338
[24-Apr-2014 23:51:25 Europe/Berlin]   * view_type_graph() at D:\inetpub\wwwroot\mahara\lib\registration.php:2164
[24-Apr-2014 23:51:25 Europe/Berlin]   * graph_site_data_daily() at D:\inetpub\wwwroot\mahara\lib\mahara.php:3014
[24-Apr-2014 23:51:25 Europe/Berlin]   * cron_site_data_daily() at D:\inetpub\wwwroot\mahara\lib\cron.php:142
[24-Apr-2014 23:51:25 Europe/Berlin]
[24-Apr-2014 23:51:25 Europe/Berlin] [INF] b7 (D:\inetpub\wwwroot\mahara\lib\cron.php:137) Running core cron cron_institution_data_daily
[24-Apr-2014 23:51:25 Europe/Berlin] [WAR] b7 (D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125) imagepng(): gd-png:  fatal libpng error: Wrote palette index exceeding num_palette
[24-Apr-2014 23:51:25 Europe/Berlin] Call stack (most recent first):
[24-Apr-2014 23:51:25 Europe/Berlin]   * log_message("imagepng(): gd-png:  fatal libpng error: Wrote pal...", 8, true, true, "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125) at D:\inetpub\wwwroot\mahara\lib\errors.php:430
[24-Apr-2014 23:51:25 Europe/Berlin]   * error(2, "imagepng(): gd-png:  fatal libpng error: Wrote pal...", "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125, array(size 1)) at Unknown:0
[24-Apr-2014 23:51:25 Europe/Berlin]   * imagepng(resource(#6996), "D:\maharadata/images/moodle_viewtypes.png") at D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Canvas_GD_PNG->save(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:865
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->_done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:787
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\registration.php:1526
[24-Apr-2014 23:51:25 Europe/Berlin]   * institution_view_type_graph(array(size 5)) at D:\inetpub\wwwroot\mahara\lib\registration.php:2254
[24-Apr-2014 23:51:25 Europe/Berlin]   * graph_institution_data_daily(array(size 5)) at D:\inetpub\wwwroot\mahara\lib\mahara.php:3074
[24-Apr-2014 23:51:25 Europe/Berlin]   * cron_institution_data_daily() at D:\inetpub\wwwroot\mahara\lib\cron.php:142
[24-Apr-2014 23:51:25 Europe/Berlin]
[24-Apr-2014 23:51:25 Europe/Berlin] [WAR] b7 (D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125) imagepng(): gd-png error: setjmp returns error condition
[24-Apr-2014 23:51:25 Europe/Berlin] Call stack (most recent first):
[24-Apr-2014 23:51:25 Europe/Berlin]   * log_message("imagepng(): gd-png error: setjmp returns error con...", 8, true, true, "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125) at D:\inetpub\wwwroot\mahara\lib\errors.php:430
[24-Apr-2014 23:51:25 Europe/Berlin]   * error(2, "imagepng(): gd-png error: setjmp returns error con...", "D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD...", 125, array(size 1)) at Unknown:0
[24-Apr-2014 23:51:25 Europe/Berlin]   * imagepng(resource(#6996), "D:\maharadata/images/moodle_viewtypes.png") at D:\inetpub\wwwroot\mahara\lib\pear\Image\Canvas\GD\PNG.php:125
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Canvas_GD_PNG->save(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:865
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->_done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\pear\Image\Graph.php:787
[24-Apr-2014 23:51:25 Europe/Berlin]   * Image_Graph->done(array(size 1)) at D:\inetpub\wwwroot\mahara\lib\registration.php:1526
[24-Apr-2014 23:51:25 Europe/Berlin]   * institution_view_type_graph(array(size 5)) at D:\inetpub\wwwroot\mahara\lib\registration.php:2254
[24-Apr-2014 23:51:25 Europe/Berlin]   * graph_institution_data_daily(array(size 5)) at D:\inetpub\wwwroot\mahara\lib\mahara.php:3074
[24-Apr-2014 23:51:25 Europe/Berlin]   * cron_institution_data_daily() at D:\inetpub\wwwroot\mahara\lib\cron.php:142
[24-Apr-2014 23:51:25 Europe/Berlin]
[24-Apr-2014 23:51:25 Europe/Berlin] [INF] b7 (D:\inetpub\wwwroot\mahara\lib\cron.php:501) Skipping long-running cron job core_import_process_queue (Thu, 24 Apr 2014 10:25:43 +0200).
[24-Apr-2014 23:51:25 Europe/Berlin] [INF] b7 (D:\inetpub\wwwroot\mahara\lib\cron.php:168) ---------- cron finished Thu, 24 Apr 2014 23:51:25 +0200 ----------
[24-Apr-2014 23:53:14 Europe/Berlin] [INF] 9f (D:\inetpub\wwwroot\mahara\lib\cron.php:30) ---------- cron running Thu, 24 Apr 2014 23:53:14 +0200 ----------

02 May 2014, 21:22

Hi Paul and Robert

We have just solved this problem - the time zone/daylight savings information needed updating - I'm in the eastern states of Australia and a few weeks ago we went back to non-daylight savings time.  

To actually work out this was the problem was a fairly long process, here is the details.

Although cron was saying in the application it was not running when we checked the logs it was running and the only problem appeared to be long running process Skipping long-running cron job core_import_process_queue.   Unfortunately our cron logs were being replaced each time cron ran so we weren't able to see a complete picture of what happening.  To give us a better idea, we trigged an email to be sent each time cron ran with the details of the log file.  For about 48 hours we got an email every 15 minutes from Mahara with the details of the cron log.  From these emails we realised that eventually the system removes the lock on the long running process and deletes the expired import records and all is ok again.  This lasts a while then the long running process would come back. This didnt really tell us what was causing the problem, but it made us look further into the process that consistently wasn't running properly.

At about the same time; we realised the time detailed in the cron logs was out by an hour (due to daylight savings time change), and we read the code for core_import_process_queue (its in import/lib.php).  This process used the time on the server, thus it seemed like it could be the cause of the problem. 

We then updated the tzdata package, added the -c switch for the PHP CLI executable to ensure it uses the same PHP.ini file as Apache, and checked the correct time zone was specified in that PHP.ini file (date.timezone)

After that we deleted the long running process and its all been running well for about 10 hours now.

Hopefully this info will be helpful for you and anyone else who encounters a similar problem.

Cheers

Anita

02 May 2014, 23:37

Dear Anita,

it is really a very promising news. Could you only describe more precisely the step with updating the tzdata package. I dont understand what do you mean by that. I have a slightly different configuration as you have - my web server works on Windows 2012 R2 and IIS. Nevertheless thank you for sharing this great news with us.

Hopefully it will work stable from now on.

05 May 2014, 12:08

Hi Paul

I've just asked for more details about this from my colleague who does the Technical Admin for our Mahara site; they provided me the following info:

Hope this helps.  Let us know how you go.

Cheers

Anita

05 May 2014, 21:00

Dear Anita,

thank you for asking your colleague about any additional hint. In seems that in my case it will be more complicated issue to solve this. However right know, I'm sure that this problem is directly connected with the PHP date.timezone parameter in php.ini file. In my Mahara installation I'm getting additionally this message in the administration panel:

"PHP on your website host does not return a useful value for the timezone identifier (%z) - certain date formatting, such as the Leap2A export, will be broken. %z is a PHP date formatting code. This problem is usually due to a limitation in running PHP on Windows."

Without doubt the problem with hanging cron is directly connected with the date.timezone format. Maybe someone know a solution for this which works under Windows.

06 May 2014, 11:06

Hi Paul,

I took a look into that warning. I don't think that particular warning should affect your Moodle/Mahara connection. The only place the "%z" string formatter is used, is for printing timestamps in Leap2a archives.

The warning refers to the fact that in Windows, the "%z" modifier returns the time zone name instead of the time zone offset. (As described here: https://php.net/strftime ).

Cheers,

Aaron

06 May 2014, 17:49

Dear Aaron,

thanks for sharing your opinion. Maybe I should come to the major topic of this discussion, which is related with hanging cron job. Do you, or any others Mahara-Gurus have any idea what can be the reason of this issue? As I have already mentioned in my first post, only after deleting the following line in the config table of the mahara database: _cron_lock_core_import_process_queue, the cron starts to work.

I will appreciate for any suggestions, or ideas where to look for possible cause of this issue.

Warm regards,

Paul