Page MenuHomePhabricator

AbuseFilter statistics wildly inaccurate after saving filter
Closed, ResolvedPublicBUG REPORT

Description

Steps to replicate the issue (include links if applicable):

  1. On a busy wiki, find a filter that's reporting lots of recent hits in the "Statistics" line at the to, e.g. enwiki filter 260.
  2. Make a dummy edit, e.g. change something in the notes
  3. Immediately go back to the filter page

What happens?:

Some impossible numbers are reported, e.g.: "Of the last 12 actions, this filter has matched 34 (283.33%). On average, its run time is 4,310.45 ms, and it consumes 23,958.6 conditions of the condition limit."

What should have happened instead?:

The actual numbers are reported, e.g. 0 hits and a few conditions used.

Event Timeline

Recently there was an overhaul to storing profiling results (T310662). It looks as if only the 'count' entry had been reset at that moment, whereas the reset for 'matches', 'total-time', and 'total-cond' was still pending. @tstarling Is that possible? Do you see a (simple) way to avoid it?

For the record, now I can see:

Of the last 132,755 actions, this filter has matched 32 (0.02%). On average, its run time is 0.21 ms, and it consumes 2.3 conditions of the condition limit.

So it should recover in a while.

enwiki still has wmf.19 which uses OPT_BUFFER_WRITES instead of noreply for async deletes.

I modified filter 260 with X-Wikimedia-Debug enabled. In the debug log, I saw an appropriate deleteMulti() command. In tcpdump, I saw all the delete commands and a "quit" command in a single packet sent to mcrouter. There was an ACK packet from mcrouter, then the client closed the connection. mcrouter responded with a single NOT_FOUND but got a RST from the client since the client half of the connection was already closed. So no more responses were sent.

I ran the same deleteMulti() from eval.php while watching for memcached traffic out of mcrouter, but there was apparently nothing. I ran it again, and there were only two deletes sent out. It would appear that mcrouter stops processing the buffer when the client resets the connection.

I expect that https://gerrit.wikimedia.org/r/c/mediawiki/core/+/812980 will fix this issue, and it is in wmf.21 which is scheduled to go out to enwiki later today.

tstarling claimed this task.

Looks like it's fixed now.