Make WordPress Core

Opened 8 years ago

Closed 8 years ago

#37696 closed defect (bug) (fixed)

WP_Comment_Query loses sql_clauses with Object Cache

Reported by: rarst's profile Rarst Owned by: rachelbaker's profile rachelbaker
Milestone: 4.7 Priority: normal
Severity: normal Version: 4.6
Component: Comments Keywords: has-patch needs-testing dev-feedback fixed-major
Focuses: Cc:

Description (last modified by SergeyBiryukov)

Once I updated my live site to WP 4.6 my error log started filling up with following:
> WordPress database error You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'WHERE AND comment_parent IN (266250,266252,266255,266258,266259,266262,266264,2' at line 1 for query SELECT wp_comments.comment_ID, wp_comments.comment_parent WHERE AND comment_parent IN (266250,266252,266255,266258,266259,266262,266264,266267,266269) ORDER BY comment_date_gmt ASC, comment_ID ASC made by require('wp-blog-header.php'), require_once('wp-includes/template-loader.php'), include('/themes/twentysixteen/single.php'), comments_template, WP_Comment_Query->__construct, WP_Comment_Query->query, WP_Comment_Query->get_comments, WP_Comment_Query->fill_descendants, QM_DB->query

Note the highly invalid query, missing parts like FROM altogether.

The immediate cause seems to be sql_clauses property is not meaningfully filled at that point.

Issue goes away if I disable Object Cache (Siteground's Memcached). If I flush cache I see clauses filling up correctly first time, then going blank again on reload.

I would guess this is related to caching changes that shipped, but I cannot reproduce locally with different OC (APCu) or figure out at which point it goes wrong.

Attachments (4)

37696.diff (3.1 KB) - added by boonebgorges 8 years ago.
37696-query-monitor-error-report.png (30.6 KB) - added by Akeif 8 years ago.
Query Monitor plugin - Error report
37966.unit-test.diff (2.4 KB) - added by swissspidy 8 years ago.
37696.2.diff (2.4 KB) - added by boonebgorges 8 years ago.

Download all attachments as: .zip

Change History (50)

#1 follow-up: @boonebgorges
8 years ago

  • Milestone changed from Awaiting Review to 4.6.1
  • Owner set to boonebgorges
  • Status changed from new to reviewing

Possibly related: #36487, #37184

@Rarst Thanks very much for the ticket. It appears that this is the same bug as #36487, but arises when the cache is primed for only a subset of all the matched comments. I'll run some tests.

In case it's relevant, what is QM_DB? I assume this is a db.php drop-in?

#2 in reply to: ↑ 1 @Rarst
8 years ago

Replying to boonebgorges:

In case it's relevant, what is QM_DB? I assume this is a db.php drop-in?

That's from Query Monitor plugin, I think it only does drop-in for the purpose of more thorough logging.

The query goes wrong before it's executed against DB in this case, so shouldn't be relevant I think.

#3 @SergeyBiryukov
8 years ago

  • Description modified (diff)

@boonebgorges
8 years ago

#4 follow-up: @boonebgorges
8 years ago

  • Keywords has-patch needs-testing added

Thanks, @Rarst.

I looked into this a bit more, and it does seem to be related to a partially primed cache. I'm uncertain how this happens in the wild, since all caches are linked to the same 'last_changed' incrementor - meaning that they should all stand or fall together. Clearly, though, there are cases where they can be out of sync, so the query in question should be more resilient.

In 37696.diff, I discarded the technique that relied on the existing SQL clauses, in favor of a fresh call to get_comments(). There's also a test there that contrives a situation that demonstrates the failure.

@Rarst Are you able to test this patch in an environment where you're experiencing the bug?

#5 follow-up: @Rarst
8 years ago

I have applied patch on live site and it seems to resolve the issue, I no longer see errors logged on a load of page with comments.

I had cache-related issues on this site before, for a while every core update was locking me out of admin due to some mismatch in database version between cache and DB.

If you want more insight into that I would recommend to get in touch with SiteGround folks (I have reported issue to them as well, with link to this ticket).

Last edited 8 years ago by Rarst (previous) (diff)

#6 in reply to: ↑ 5 @boonebgorges
8 years ago

Replying to Rarst:

I have applied patch on live site and it seems to resolve the issue, I no longer see errors logged on a load of page with comments.

I had cache-related issues on this site before, for a while every core update was locking me out of admin due to some mismatch in database version between cache and DB.

If you want more insight into that I would recommend to get in touch with SiteGround folks (I have reported issue to them as well, with link to this ticket).

This is really helpful - thanks, @Rarst.

Can I get a sanity check from someone who understands the arcana contained in fill_descendants()? Ping @wonderboymusic, @rachelbaker

#7 @Rarst
8 years ago

SiteGround support was able to reproduce on my account with clean from scratch WP 4.6 install. Doesn’t sound like they got any idea why their caching setup doesn't like it though. And since you got patch posted they closed my ticket. :)

Let me know if I can look into any info necessary about caching kinks. I have a hunch that if this isn't resolved it will keep coming up in different contexts.

#8 follow-up: @danielkanchev
8 years ago

Hey, guys :) Daniel with SiteGround here - if you need a website to test with please ping me - I'll be glad to assist.

#9 in reply to: ↑ 4 ; follow-up: @dd32
8 years ago

Replying to boonebgorges:

I looked into this a bit more, and it does seem to be related to a partially primed cache. I'm uncertain how this happens in the wild, since all caches are linked to the same 'last_changed' incrementor - meaning that they should all stand or fall together. Clearly, though, there are cases where they can be out of sync, so the query in question should be more resilient.

Caches evict data at different rates, the cached content may be evicted before the expiry, only half the caches related to a bit of code might get evicted at that point in time and others will live on for another year. Caches evict data based on key size, hit rate, usage, how full the underlying bucket it's in is, and seemingly sometimes rand(0,1).
In other words; No code should expect a cached value to exist, even if another piece of data stored at the same time still exists there, "It doesn't exist unless it's in my hands" (or variable as it may be).

#10 in reply to: ↑ 9 @boonebgorges
8 years ago

Replying to dd32:

Caches evict data at different rates, the cached content may be evicted before the expiry, only half the caches related to a bit of code might get evicted at that point in time and others will live on for another year. Caches evict data based on key size, hit rate, usage, how full the underlying bucket it's in is, and seemingly sometimes rand(0,1).
In other words; No code should expect a cached value to exist, even if another piece of data stored at the same time still exists there, "It doesn't exist unless it's in my hands" (or variable as it may be).

Thanks @dd32. This confirms the strategy in 37696.diff.

#11 @b-rad
8 years ago

  • Summary changed from WP_Comment_Query looses sql_clauses with Object Cache to WP_Comment_Query loses sql_clauses with Object Cache

This ticket was mentioned in Slack in #core by akeif. View the logs.


8 years ago

#13 in reply to: ↑ 8 @Akeif
8 years ago

Replying to danielkanchev:

Hey, guys :) Daniel with SiteGround here - if you need a website to test with please ping me - I'll be glad to assist.

Hey @danielkanchev I'd take that offer if you're still around. Let me know how we need to proceed.

#14 @danielkanchev
8 years ago

@Akeif send me a PM on Slack (@daniel_kanchev) and I'll create an account for you that you may use for testing.

#15 @Akeif
8 years ago

  • Keywords needs-testing removed

First: Thanks to @danielkanchev for setting a test account.
Second: I was able to reproduce the problem and apply the patch, which fix the issue.

Watch this screen cast if to see the error and patch in action: https://www.youtube.com/watch?v=SjLC_O-2tfo

I also tested upgrading, downgrading WordPress but haven't seen any problem there.

I'm removing the need-testing keyword since @Rarst and myself were able to confirm the fix.

Here's the SQL error output from Query Monitor plugin (and I'm attaching a screenshot).

SELECT wpbj_comments.comment_ID, wpbj_comments.comment_parent
WHERE
AND comment_parent IN (1,2)
ORDER BY comment_date_gmt ASC, comment_ID ASC	WP_Comment_Query->fill_descendants()
 wp-includes/class-wp-comment-query.php:999
WP_Comment_Query->get_comments()
 wp-includes/class-wp-comment-query.php:471
WP_Comment_Query->query()
 wp-includes/class-wp-comment-query.php:357
WP_Comment_Query->__construct()
 wp-includes/class-wp-comment-query.php:311
comments_template()
 wp-includes/comment-template.php:1407	Core 	You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'WHERE AND comment_parent IN (1,2) ORDER BY comment_date_gmt ASC, comment_ID AS' at line 1

@Akeif
8 years ago

Query Monitor plugin - Error report

#16 follow-up: @Rarst
8 years ago

Fix for specific issue aside I would be very interested why it breaks on SiteGround specifically. Is it something they do with caching? Is it some caching edge case in core?

As I mentioned I had caching issues before, but I as far as I can see their setup is pretty typical. Yet some issues come up there, but not elsewhere.

#17 in reply to: ↑ 16 @boonebgorges
8 years ago

Replying to Rarst:

Fix for specific issue aside I would be very interested why it breaks on SiteGround specifically. Is it something they do with caching? Is it some caching edge case in core?

As I mentioned I had caching issues before, but I as far as I can see their setup is pretty typical. Yet some issues come up there, but not elsewhere.

It's possible that it's specific the Memcached config in use at SiteGroup. Memcached sorts data into buckets based on the size of the value being stored, which could result in different rules for invalidation, depending on how Memcached is set up. As @dd32 notes, our caching should be resilient against this kind of thing, so as far as I know SG is not doing anything wrong, but I agree it would be nice to have more details on why it's so easily reproducible there.

This ticket was mentioned in Slack in #core by jeremyfelt. View the logs.


8 years ago

#19 follow-up: @swissspidy
8 years ago

Any update on this? The patch seems to resolve the issue and it should go into trunk rather sooner than later to be considered for 4.6.1.

#20 in reply to: ↑ 19 @boonebgorges
8 years ago

Replying to swissspidy:

Any update on this? The patch seems to resolve the issue and it should go into trunk rather sooner than later to be considered for 4.6.1.

The pre-commit review I was hoping for appears not to be forthcoming. I've done a second review myself, and will commit to trunk to get some testing before branch merge.

#21 @boonebgorges
8 years ago

  • Resolution set to fixed
  • Status changed from reviewing to closed

In 38446:

Comments: Don't do direct SQL query when fetching decendants.

The SQL query was built using the clauses compiled when querying for
top-level comments. But in cases where the top-level comment query
results are already in the cache, the SQL clauses are not built, and
so are unavailable for fill_descendants(). Instead, we call
get_comments(), using modified versions of the parameters passed
to the main WP_Comment_Query class.

Props Akeif, Rarst for testing.
Fixes #37696.

#22 @boonebgorges
8 years ago

  • Keywords fixed-major added; has-patch removed
  • Resolution fixed deleted
  • Status changed from closed to reopened

Reopening for 4.6.1.

#23 @jeremyfelt
8 years ago

I stared at the code around this for a while and the approach looks correct/sane. +1

To log the obvious - The previous manual SQL statement uses SELECT wp_comments.comment_ID, wp_comments.comment_parent. The current get_comments() approach generates SELECT wp_comments.comment_ID. This is okay because the comment parent is instead available in the retrieved comment object.

#24 @jeremyfelt
8 years ago

  • Resolution set to fixed
  • Status changed from reopened to closed

In 38497:

Comments: Don't do direct SQL query when fetching decendants.

The SQL query was built using the clauses compiled when querying for
top-level comments. But in cases where the top-level comment query
results are already in the cache, the SQL clauses are not built, and
so are unavailable for fill_descendants(). Instead, we call
get_comments(), using modified versions of the parameters passed
to the main WP_Comment_Query class.

Merge of [38446] to the 4.6 branch.

Props boonebgorges, Akeif, Rarst for testing.
Fixes #37696.

#25 @remedy17
8 years ago

Hi folks, my site is hosted at SiteGround, have the same issue with a missing strings in SQL query.

.....at line 1]
SELECT wp_comments.comment_ID, wp_comments.comment_parent WHERE AND comment_parent IN (116) ORDER BY comment_date_gmt ASC,....

Is the patch something that I can borrow from you guys at least until WP 4.6.1 or whenever it makes it into core?

#26 @danielkanchev
8 years ago

Hey @remedy17 Daniel with SiteGround here :) The patch that needs to be applied is:

https://core.trac.wordpress.org/attachment/ticket/37696/37696.diff

If you cannot apply it open a support ticket and our support team will apply the patch for you.

#27 @swissspidy
8 years ago

@remedy17 There's also 4.6.1 RC1 you could install on your site: https://wordpress.org/wordpress-4.6.1-RC1.zip

This ticket was mentioned in Slack in #core by jeremyfelt. View the logs.


8 years ago

#29 @jeremyfelt
8 years ago

In 38537:

Comments: Revert [38497]

Restore direct SQL query when fetching descendants.

See #37696, #37966.

#30 @swissspidy
8 years ago

  • Keywords needs-patch added; fixed-major removed
  • Resolution fixed deleted
  • Status changed from closed to reopened

#31 @swissspidy
8 years ago

#37966 was marked as a duplicate.

#32 @swissspidy
8 years ago

  • Milestone changed from 4.6.1 to 4.7

#33 @boonebgorges
8 years ago

Reopening this ticket because of #37966, which shows that [38497] introduced a bug related to threaded comments on pages other than 1. I'm pretty sure that this is because the argument array for the descendant query isn't resetting the 'number' and/or 'offset' parameters from the original query args.

Unfortunately, the bug was discovered just before the scheduled release of 4.6.1. In order not to hold up 4.6.1, we're moving this ticket out of the milestone.

@boonebgorges
8 years ago

#34 @boonebgorges
8 years ago

  • Keywords has-patch needs-testing dev-feedback added; needs-patch removed

The problem reported in #37966 is fixed by 37696.2.diff. Here's the logic, which I hope is clear enough to get a review :)

  • To minimize SQL queries, comment trees are fetched one level at a time. So if A and B are top-level comments, with children A1, A2, B1, a query that fetches A and B will do two queries. The first will grab A and B (parent=0) and the second will fetch A1, A2, B1 (parent IN (A,B)). That's what fill_descendants() is for.
  • The descendant query should be similar to the parent query. For example, if you get_comments( 'exclude=1,2,3' ), you expect 1, 2, and 3 to be excluded from top-level comments as well as descendants. But the descendant query cannot match exactly, because it needs to override the parent__in parameter; and parent__in should override other hierarchy-related parameters passed to WP_Comment_Query.
  • Prior to [38497], the descendant query was being built by parsing and modifying the SQL string for the parent query. This broke, because the SQL string is not available in all cases.
  • [38497] changed the strategy so that the descendant query calls get_comments() instead. The parameters passed to get_comments() are those passed to WP_Comment_Query, with some necessary modifications to ensure that we're fetching only the hierarchy level we intend to be fetching.
  • What was missed in [38497], and what was reported in #37966, is that the 'offset' and 'number' parameters are not being reset for the descendant query. As such, if you passed offset=1&number=1 to WP_Comment_Query, the descendant query would *also* only fetch a single comment, with an offset of 1. This is incorrect: the descendant query should always have an offset of 0 and no limits on the number of results returned. That's what 37696.2.diff adds.

#35 @jeremyfelt
8 years ago

  • Milestone changed from 4.7 to 4.6.2

This ticket was mentioned in Slack in #core by jeremyfelt. View the logs.


8 years ago

This ticket was mentioned in Slack in #core by jeffpaul. View the logs.


8 years ago

This ticket was mentioned in Slack in #core by helen. View the logs.


8 years ago

#39 @rachelbaker
8 years ago

  • Owner changed from boonebgorges to rachelbaker
  • Status changed from reopened to assigned

@boonebgorges I will try to get to this over the weekend.

This ticket was mentioned in Slack in #core by helen. View the logs.


8 years ago

This ticket was mentioned in Slack in #core by helen. View the logs.


8 years ago

#42 @boonebgorges
8 years ago

I've done yet another self-review here, and I think the logic is good, so let's go with it.

#43 @boonebgorges
8 years ago

In 39274:

Comments: Query used to fill comment descendants should reset 'offset' and 'number' params.

Descendant queries should not inherit the 'offset' and 'number'
parameters of the parent query, or descendants will be missed.

Previously: [38497].

See #37696.

#44 @boonebgorges
8 years ago

I'm going to leave this ticket open on the assumption that there may be a 4.6.2. If there is, both [38497] and [39274] must be ported to the 4.6 branch. If there is no 4.6.2 before 4.7 is released, then this ticket can be closed as fixed.

#45 @helen
8 years ago

  • Keywords fixed-major added

#46 @helen
8 years ago

  • Milestone changed from 4.7.1 to 4.7
  • Resolution set to fixed
  • Status changed from assigned to closed
Note: See TracTickets for help on using tickets.