Topic on Project:Support desk

Ubuntu 20.04, Apache 2.4, PHP 7.4.3, MySQL 8.0 & MediaWiki 1.35.7

Howdy,

usually the binlogs match (roughly) with the activities shown in the recent changes page. Sometimes within the last days I encountered a mysterious phenomenon; the binlog grows rapidly while there is only few activity in the wiki for some hours.

Example:

-rw-r-----  1 mysql mysql    3697808 Sep 22 01:25 mysql-bin.001100

-rw-r-----  1 mysql mysql  157288660 Sep 22 18:53 mysql-bin.001101

-rw-r-----  1 mysql mysql  157372133 Sep 22 20:50 mysql-bin.001102

-rw-r-----  1 mysql mysql  157311099 Sep 22 21:25 mysql-bin.001103

-rw-r-----  1 mysql mysql  157388609 Sep 22 21:50 mysql-bin.001104

-rw-r-----  1 mysql mysql  157291160 Sep 22 22:07 mysql-bin.001105

-rw-r-----  1 mysql mysql  157367584 Sep 22 22:34 mysql-bin.001106

-rw-r-----  1 mysql mysql  157343097 Sep 22 22:42 mysql-bin.001107

-rw-r-----  1 mysql mysql  157383979 Sep 22 22:50 mysql-bin.001108

-rw-r-----  1 mysql mysql  157354101 Sep 22 22:57 mysql-bin.001109

-rw-r-----  1 mysql mysql  157420107 Sep 22 23:17 mysql-bin.001110

-rw-r-----  1 mysql mysql  157487073 Sep 22 23:37 mysql-bin.001111

-rw-r-----  1 mysql mysql  157536460 Sep 22 23:55 mysql-bin.001112

-rw-r-----  1 mysql mysql  130376490 Sep 23 00:13 mysql-bin.001113

-rw-r-----  1 mysql mysql  157559320 Sep 23 00:35 mysql-bin.001114

-rw-r-----  1 mysql mysql  157322415 Sep 23 01:02 mysql-bin.001115

-rw-r-----  1 mysql mysql   72729153 Sep 23 01:25 mysql-bin.001116

On September 22th, from 0:01 am till 20:50 pm, I count approx. 130 changes. I don't quite understand why this few changes can produce 2 x 150 MB binlogs, but even worse: from 20:50 pm - 23:55 pm there are no more than 31 edits <-> 10 x 150 MB binlogs!?

Does anyone have any ideas WHAT the database is doing here?

I would suggest looking in the binlogs and seeing which tables are being modified.

There are some initializations like

# The proper term is pseudo_replica_mode, but we use this compatibility alias

# to make the statement usable on server versions 8.0.24 and older.

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;

/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;

DELIMITER /*!*/;

# at 4

#220926 18:39:36 server id 1  end_log_pos 126 CRC32 0x29358cf7  Start: binlog v 4, server v 8.0.30-0ubuntu0.20.04.2 created

220926 18:39:36

BINLOG '

yNUxYw8BAAAAegAAAH4AAAAAAAQAOC4wLjMwLTB1YnVudHUwLjIwLjA0LjIAAAAAAAAAAAAAAAAA

......

/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;

......

SET TIMESTAMP=1664210377/*!*/;

SET @@session.pseudo_thread_id=1176709/*!*/;

...........

BEGIN

/*!*/;

# at 320

#220926 18:39:37 server id 1  end_log_pos 386 CRC32 0xf526a6b3  Table_map: `ppdb`.`objectcache` mapped to number 105

# at 386

#220926 18:39:37 server id 1  end_log_pos 318739 CRC32 0x5d08e762       Update_rows: table id 105 flags: STMT_END_F

BINLOG '

ydUxYxMBAAAAQgAAAIIBAAAAAGkAAAAAAAEABHBwZGIAC29iamVjdGNhY2hlAAMP/BIE/AMDAAYD

after that, there are thousands of lines of unreadable hexcodes. Of course I cannot view the whole file.

Is there a way to exclude the objectcache table from the binary log?

It would probably be better to ask mysql specific questions on a mysql forum

Of course you're completely right. Only I thought you might have an idea why there is so much database activity on the objectcache table while there is nearly no activity within the wiki ...?

Could be lots of reasons. Maybe you wiki isn't as inactive as you think it is. At the very least, it would be helpful to know the keyname field of the rows that are being updated.

The objectcache contains 100-300 records only with keyname like "ppdb:MWSession:pa7s5jqeu84bfnchcm5bh5i67jpb87fg". The contents of the value columns are like " 0x4D8EC10E82300C86DF654F ....." but only a few lines per record. Whatever the binlog is logging, it's something else and I cannot interpret it because actually the first objectcache entry within the binlog is thousands of lines. Awkward. I have disabled binary logging now, necessarily.