Task Cronjob Suddenly Triggering Excessive Resource Usage after 4.7.14 Upgrade

[Marc]

9 hours ago, sadams101 said:

I'm the server admin, and so far I've traced this to the update mentioned in this thread. Nothing on my server as far as hardware has changed, and the server is running a low server load with plenty of extra memory, disk storage, etc.

 

12 hours ago, Jim M said:

You can enable slow query logging to see if this is MySQL end. You hosting provider can also advise what else is happening and provide us further data to investigate. 

 

[sadams101]

After manually running this today...as mentioned if fails about once per day now and needs to be manually run, I saw this, which I've never seen before:

[Marc]

We really could do with getting a slow query log running, as mentioned a couple of times above

[sadams101]

I'm not sure how that would impact a busy server like mine...as I understand it could be fairly taxing in size and might cause performance issues, but I will look into this more.

[Jim M]

11 minutes ago, sadams101 said:

I'm not sure how that would impact a busy server like mine...as I understand it could be fairly taxing in size and might cause performance issues, but I will look into this more.

To be blunt here, if you do not wish to enable this, we may never get to the bottom of your issue here as you appear to be the only one reporting this issue. It is up to yourself to live with the current issue or enable slow query logging. You can start at a higher threshold and only log queries which take 10 seconds or longer and if you don't get any (which shouldn't be the case if it is as you state), you can decrease it. Slow query logging when configured correctly on a performant server should not pose any major resource issue but of course, doing anything extra will cause more resource consumption. However, generally, you enable it when you are having a resource issue so the consumption isn't a great concern as you need it to resolve the bigger consumption at hand.

[sadams101]

On 6/13/2024 at 12:01 PM, sadams101 said:

I just want to amend this thread by adding that recently, on a nearly daily basis, the sitemapgenerator task has been "freezing up" and not completing. I am not wanting to create a ticket for this issue, but want to see if anyone else is having this issue. 

Sometimes the "Run Now" will work, but other times I need to go into the Task Manager area and stop the task, then run it. I've tried rebuilding the sitemap a few times, but the issue keeps happening, at least 3-5 times a week now.

I suspect (but can't prove) that the changes in the code that you made to the sitemap is causing both issues mentioned in this thread--the excessive resource usage (which I believe is triggered by this task), and now task failing, and sometimes getting stuck running for 8+ hours.

 

This issue continues to happen on my board, and below are my long query logs for over 10 seconds. There seems to be two long queries that are logged, and the one I suspect to be the issue is archive cron job, which archives all of my >5 years old posts. As you can see, this archiving function seems to sometimes take 20-50 seconds. Any insights here as to what could be going on?

 

Quote

/usr/sbin/mariadbd, Version: 10.6.18-MariaDB-log (MariaDB Server). started with:
Tcp port: 0  Unix socket: (null)
Time            Id Command    Argument

# Time: 240719  2:06:46
# User@Host: root[root] @ localhost []
# Thread_id: 128916  Schema: database_forum_03  QC_hit: No
# Query_time: 33.041087  Lock_time: 0.000045  Rows_sent: 950143  Rows_examined: 950143
# Rows_affected: 0  Bytes_sent: 1973155158
use database_forum_03;
SET timestamp=1721380006;
SELECT /*!40001 SQL_NO_CACHE */ `archive_id`, `archive_author_id`, `archive_author_name`, `archive_ip_address`, `archive_content_date`, `archive_content`, `archive_queued`, `archive_topic_id`, `archive_is_first`, `archive_bwoptions`, `archive_attach_key`, `archive_html_mode`, `archive_show_edited_by`, `archive_edit_time`, `archive_edit_name`, `archive_edit_reason`, `archive_added`, `archive_restored`, `archive_forum_id`, `archive_field_int`, `archive_content_backup` FROM `ibf_forums_archive_posts`;

# Time: 240719  3:35:13
# User@Host: root[root] @ localhost []
# Thread_id: 144078  Schema: database_forum_03  QC_hit: No
# Query_time: 25.411173  Lock_time: 0.000000  Rows_sent: 950145  Rows_examined: 950145
# Rows_affected: 0  Bytes_sent: 1973156361
SET timestamp=1721385313;
SELECT /*!40001 SQL_NO_CACHE */ `archive_id`, `archive_author_id`, `archive_author_name`, `archive_ip_address`, `archive_content_date`, `archive_content`, `archive_queued`, `archive_topic_id`, `archive_is_first`, `archive_bwoptions`, `archive_attach_key`, `archive_html_mode`, `archive_show_edited_by`, `archive_edit_time`, `archive_edit_name`, `archive_edit_reason`, `archive_added`, `archive_restored`, `archive_forum_id`, `archive_field_int`, `archive_content_backup` FROM `ibf_forums_archive_posts`;

# Time: 240719 11:23:50
# User@Host: site_forum[site_forum] @ localhost []
# Thread_id: 270920  Schema: database_forum_03  QC_hit: No
# Query_time: 11.151348  Lock_time: 0.000033  Rows_sent: 17  Rows_examined: 22996
# Rows_affected: 0  Bytes_sent: 262144
SET timestamp=1721413430;
/*database_forum_03::site_forum::IPS\Theme\class_cms_database_supergrid_frontpage::index:142*/ SELECT cms_custom_database_2.*, author.*, last_commenter.*, core_tags_cache.tag_cache_text FROM `ibf_cms_custom_database_2` AS `cms_custom_database_2`  LEFT JOIN `ibf_cms_database_categories` AS `cms_database_categories` ON cms_custom_database_2.category_id=cms_database_categories.category_id  LEFT JOIN `ibf_core_tags_cache` AS `core_tags_cache` ON tag_cache_key=MD5(CONCAT('cms;records2;',cms_custom_database_2.primary_id_field))  LEFT JOIN `ibf_core_members` AS `author` ON author.member_id = cms_custom_database_2.member_id  LEFT JOIN `ibf_core_members` AS `last_commenter` ON last_commenter.member_id = cms_custom_database_2.record_last_comment_by WHERE ( category_can_view_others=1 OR cms_custom_database_2.member_id IS NULL ) AND cms_custom_database_2.record_approved=1 AND cms_custom_database_2.record_future_date=0 AND cms_custom_database_2.category_id NOT IN (151) ORDER BY record_pinned DESC, record_publish_date desc LIMIT 0,17;

# Time: 240719 11:25:13
# User@Host: site_forum[site_forum] @ localhost []
# Thread_id: 271397  Schema: database_forum_03  QC_hit: No
# Query_time: 10.505374  Lock_time: 0.000055  Rows_sent: 17  Rows_examined: 22996
# Rows_affected: 0  Bytes_sent: 262144
SET timestamp=1721413513;
/*database_forum_03::site_forum::IPS\Theme\class_cms_database_supergrid_frontpage::index:142*/ SELECT cms_custom_database_2.*, author.*, last_commenter.*, core_tags_cache.tag_cache_text FROM `ibf_cms_custom_database_2` AS `cms_custom_database_2`  LEFT JOIN `ibf_cms_database_categories` AS `cms_database_categories` ON cms_custom_database_2.category_id=cms_database_categories.category_id  LEFT JOIN `ibf_core_tags_cache` AS `core_tags_cache` ON tag_cache_key=MD5(CONCAT('cms;records2;',cms_custom_database_2.primary_id_field))  LEFT JOIN `ibf_core_members` AS `author` ON author.member_id = cms_custom_database_2.member_id  LEFT JOIN `ibf_core_members` AS `last_commenter` ON last_commenter.member_id = cms_custom_database_2.record_last_comment_by WHERE ( category_can_view_others=1 OR cms_custom_database_2.member_id IS NULL ) AND cms_custom_database_2.record_approved=1 AND cms_custom_database_2.record_future_date=0 AND cms_custom_database_2.category_id NOT IN (151) ORDER BY record_pinned DESC, record_publish_date desc LIMIT 0,17;

# Time: 240719 11:25:20
# User@Host: site_forum[site_forum] @ localhost []
# Thread_id: 271420  Schema: database_forum_03  QC_hit: No
# Query_time: 13.176171  Lock_time: 0.000034  Rows_sent: 17  Rows_examined: 22996
# Rows_affected: 0  Bytes_sent: 262144
SET timestamp=1721413520;
/*database_forum_03::site_forum::IPS\Theme\class_cms_database_supergrid_frontpage::index:142*/ SELECT cms_custom_database_2.*, author.*, last_commenter.*, core_tags_cache.tag_cache_text FROM `ibf_cms_custom_database_2` AS `cms_custom_database_2`  LEFT JOIN `ibf_cms_database_categories` AS `cms_database_categories` ON cms_custom_database_2.category_id=cms_database_categories.category_id  LEFT JOIN `ibf_core_tags_cache` AS `core_tags_cache` ON tag_cache_key=MD5(CONCAT('cms;records2;',cms_custom_database_2.primary_id_field))  LEFT JOIN `ibf_core_members` AS `author` ON author.member_id = cms_custom_database_2.member_id  LEFT JOIN `ibf_core_members` AS `last_commenter` ON last_commenter.member_id = cms_custom_database_2.record_last_comment_by WHERE ( category_can_view_others=1 OR cms_custom_database_2.member_id IS NULL ) AND cms_custom_database_2.record_approved=1 AND cms_custom_database_2.record_future_date=0 AND cms_custom_database_2.category_id NOT IN (151) ORDER BY record_pinned DESC, record_publish_date desc LIMIT 0,17;

# Time: 240719 11:25:39
# User@Host: site_forum[site_forum] @ localhost []
# Thread_id: 271511  Schema: database_forum_03  QC_hit: No
# Query_time: 11.343138  Lock_time: 0.000037  Rows_sent: 17  Rows_examined: 22996
# Rows_affected: 0  Bytes_sent: 262144
SET timestamp=1721413539;
/*database_forum_03::site_forum::IPS\Theme\class_cms_database_supergrid_frontpage::index:142*/ SELECT cms_custom_database_2.*, author.*, last_commenter.*, core_tags_cache.tag_cache_text FROM `ibf_cms_custom_database_2` AS `cms_custom_database_2`  LEFT JOIN `ibf_cms_database_categories` AS `cms_database_categories` ON cms_custom_database_2.category_id=cms_database_categories.category_id  LEFT JOIN `ibf_core_tags_cache` AS `core_tags_cache` ON tag_cache_key=MD5(CONCAT('cms;records2;',cms_custom_database_2.primary_id_field))  LEFT JOIN `ibf_core_members` AS `author` ON author.member_id = cms_custom_database_2.member_id  LEFT JOIN `ibf_core_members` AS `last_commenter` ON last_commenter.member_id = cms_custom_database_2.record_last_comment_by WHERE ( category_can_view_others=1 OR cms_custom_database_2.member_id IS NULL ) AND cms_custom_database_2.record_approved=1 AND cms_custom_database_2.record_future_date=0 AND cms_custom_database_2.category_id NOT IN (151) ORDER BY record_pinned DESC, record_publish_date desc LIMIT 0,17;

# Time: 240720  2:01:22
# User@Host: root[root] @ localhost []
# Thread_id: 517265  Schema: database_forum_03  QC_hit: No
# Query_time: 49.668203  Lock_time: 0.000046  Rows_sent: 950155  Rows_examined: 950155
# Rows_affected: 0  Bytes_sent: 1973166620
SET timestamp=1721466082;
SELECT /*!40001 SQL_NO_CACHE */ `archive_id`, `archive_author_id`, `archive_author_name`, `archive_ip_address`, `archive_content_date`, `archive_content`, `archive_queued`, `archive_topic_id`, `archive_is_first`, `archive_bwoptions`, `archive_attach_key`, `archive_html_mode`, `archive_show_edited_by`, `archive_edit_time`, `archive_edit_name`, `archive_edit_reason`, `archive_added`, `archive_restored`, `archive_forum_id`, `archive_field_int`, `archive_content_backup` FROM `ibf_forums_archive_posts`;

# Time: 240720  3:35:13
# User@Host: root[root] @ localhost []
# Thread_id: 531743  Schema: database_forum_03  QC_hit: No
# Query_time: 25.723650  Lock_time: 0.000000  Rows_sent: 950159  Rows_examined: 950159
# Rows_affected: 0  Bytes_sent: 1973167691
use database_forum_03;
SET timestamp=1721471713;
SELECT /*!40001 SQL_NO_CACHE */ `archive_id`, `archive_author_id`, `archive_author_name`, `archive_ip_address`, `archive_content_date`, `archive_content`, `archive_queued`, `archive_topic_id`, `archive_is_first`, `archive_bwoptions`, `archive_attach_key`, `archive_html_mode`, `archive_show_edited_by`, `archive_edit_time`, `archive_edit_name`, `archive_edit_reason`, `archive_added`, `archive_restored`, `archive_forum_id`, `archive_field_int`, `archive_content_backup` FROM `ibf_forums_archive_posts`;
 

 

[Marc]

That will indeed be doing some intensive work. Its essentially archiving and unarchiving data based on rules that you have set (your 5 years there). Have you recently switched this on?

[sadams101]

No, it's been running for years and never had issues. I will say that my I still suspect what I mentioned in my original post in this thread--my upgrade from 4.7.13 to 4.7.14 which included new sitemap coding. I believe the extra resources needed to run the sitemap now are somehow causing the issue when the archive cron runs, and this likely only affects sites with a larger number of posts & threads.

[Jim M]

9 minutes ago, sadams101 said:

No, it's been running for years and never had issues. I will say that my I still suspect what I mentioned in my original post in this thread--my upgrade from 4.7.13 to 4.7.14 which included new sitemap coding. I believe the extra resources needed to run the sitemap now are somehow causing the issue when the archive cron runs, and this likely only affects sites with a larger number of posts & threads.

Unfortunately, there is no evidence of this happening. If this was the case, we'd be seeing something here with the slow query log or some other means of logging.

I would advise upgrading to the latest release though as there have been some performance upgrades since the release you mentioned there.

[sadams101]

I am on the latest release 4.7.17, and only mentioned that upgrade as the point where I first noticed sitemap resource issues from my server.

Please double check your sitemap code changes in that update. I suspect there is an issue.

[Jim M]

38 minutes ago, sadams101 said:

Please double check your sitemap code changes in that update. I suspect there is an issue.

While I understand you believe there is an issue there, there are no others encountering issues there. We deal with communities in the millions of posts and members and they are not having the issue either. Without further information pointing towards a specific problem, we cannot investigate the issue further.

If you would like to provide us access to your installation, we can further investigate there but short of getting some guided approach that we were hoping for from the Slow Query log, it may be something completely specific to your community.