Voice of All wrote:
I can already see some of this by greping wfReadOnly() on /includes. This function simply reads a file on the disk, so it is not cached, nor per-transaction. Therefore it can change in the short time one operation of an a larger set of operations was called, and the next. This can cause broken "transactions" on occasion.
I suspect this is what caused the logging problems. It only occurred during heavy traffic or when someone was rapidly doing something (I got a report from someone using a commons mass deletion script) and somewhat randomly (only a portion of the time). This is consistent with the wfReadOnly() check that used to be in LogPage.php.
The contents of the read-only file is cached in $wgReadOnly. If the file is blank or missing, $wgReadOnly is set to false, suppressing further reads. So it doesn't change.
However, it can change in the load balancer when the reader connection is opened, and with the new LBFactory system, it's possible that that may happen more than once. So that could indeed cause such a problem, but only if a foreign database is accessed between the main operation and the logging operation.
Note that any segfault, deadlock or PHP fatal error which occurs after the main transaction is committed may cause an unlogged operation. Any of these modes of termination lead to all database connections being immediately closed, and thus all open transactions being rolled back. So I don't think it's necessary to look to such exotic causes. For instance, we're logging a lot of memory exhausted errors at the moment, it's possible that some of them are causing half-executed write operations.
-- Tim Starling