Intermittent failure of ReadBinLogIT.shouldCaptureSingleWriteUpdateDeleteEvents [DBZ-4755]
- Dominant language
- HTML
- Stars
- 6
- Forks
- 8
- Avg merge
- 2d 19h
- Merged PRs (30d)
- 1
Description
Migrated from [DBZ-4755](https://issues.redhat.com/browse/DBZ-4755)
The test log is
{noformat}
2022-02-16T18:08:40.0941109Z [INFO] Running io.debezium.connector.mysql.ReadBinLogIT
2022-02-16T18:08:40.3498047Z 18:08:40.349 percona-server2022-02-16T18:08:40.348930Z 882 [Note] Aborted connection 882 to db: 'unconnected' user: 'snapper' host: '172.17.0.1' (failed on flush_net())
2022-02-16T18:08:40.3499118Z 2022-02-16 18:08:40,349 INFO || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2022-02-16T18:08:40.3676236Z 18:08:40.366 percona-server2022-02-16T18:08:40.366851Z 887 [Note] Start binlog_dump to master_thread_id(887) slave_server(65534), pos(mysql-bin.000002, 4307183)
2022-02-16T18:08:40.3679990Z Feb 16, 2022 6:08:40 PM com.github.shyiko.mysql.binlog.BinaryLogClient connect
2022-02-16T18:08:40.3682298Z INFO: Connected to localhost:4304 at mysql-bin.000002/4307183 (sid:65534, cid:887)
2022-02-16T18:08:40.3820759Z Ignored event: Event{header=EventHeaderV4{timestamp=0, eventType=ROTATE, serverId=112233, headerLength=19, dataLength=28, nextPosition=0, flags=32}, data=RotateEventData{binlogFilename='mysql-bin.000002', binlogPosition=4307183}}
2022-02-16T18:08:40.3822950Z Ignored event: Event{header=EventHeaderV4{timestamp=1645033562000, eventType=FORMAT_DESCRIPTION, serverId=112233, headerLength=19, dataLength=100, nextPosition=0, flags=0}, data=FormatDescriptionEventData{binlogVersion=4, serverVersion='5.7.36-39-log', headerLength=19, dataLength=95, checksumType=CRC32}}
2022-02-16T18:08:40.3823758Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4307248, flags=0}, data=null}
2022-02-16T18:08:40.3825071Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=146, nextPosition=4307413, flags=4}, data=QueryEventData{threadId=886, executionTime=0, errorCode=0, database='readbinlog_test_sj0597', sql='DROP TABLE IF EXISTS `person` /* generated by server */'}}
2022-02-16T18:08:40.3825802Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4307478, flags=0}, data=null}
2022-02-16T18:08:40.3827743Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=306, nextPosition=4307803, flags=0}, data=QueryEventData{threadId=886, executionTime=0, errorCode=0, database='readbinlog_test_sj0597', sql='CREATE TABLE person ( name VARCHAR(255) primary key, age INTEGER NULL DEFAULT 10, createdAt DATETIME NULL DEFAULT CURRENT_TIMESTAMP, updatedAt DATETIME NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP)'}}
2022-02-16T18:08:40.3903378Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4307868, flags=0}, data=null}
2022-02-16T18:08:40.3904452Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=79, nextPosition=4307966, flags=8}, data=QueryEventData{threadId=886, executionTime=0, errorCode=0, database='readbinlog_test_sj0597', sql='BEGIN'}}
2022-02-16T18:08:40.3905667Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=55, nextPosition=4308040, flags=0}, data=TableMapEventData{tableId=18862, database='readbinlog_test_sj0597', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:40.3943967Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=EXT_WRITE_ROWS, serverId=112233, headerLength=19, dataLength=39, nextPosition=4308098, flags=0}, data=WriteRowsEventData{tableId=18862, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:40.3944774Z [Georgia, 30, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022]
2022-02-16T18:08:40.3945008Z ]}}
2022-02-16T18:08:40.3947844Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4308129, flags=0}, data=XidEventData{xid=93684}}
2022-02-16T18:08:40.3948746Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4308194, flags=0}, data=null}
2022-02-16T18:08:40.3952846Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=79, nextPosition=4308292, flags=8}, data=QueryEventData{threadId=886, executionTime=0, errorCode=0, database='readbinlog_test_sj0597', sql='BEGIN'}}
2022-02-16T18:08:40.3957590Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=55, nextPosition=4308366, flags=0}, data=TableMapEventData{tableId=18862, database='readbinlog_test_sj0597', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:40.3963769Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=EXT_WRITE_ROWS, serverId=112233, headerLength=19, dataLength=38, nextPosition=4308423, flags=0}, data=WriteRowsEventData{tableId=18862, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:40.3964998Z [Janice, 19, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022]
2022-02-16T18:08:40.3965872Z ]}}
2022-02-16T18:08:40.3966480Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4308454, flags=0}, data=XidEventData{xid=93686}}
2022-02-16T18:08:40.4027480Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4308519, flags=0}, data=null}
2022-02-16T18:08:40.4028760Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=79, nextPosition=4308617, flags=8}, data=QueryEventData{threadId=886, executionTime=0, errorCode=0, database='readbinlog_test_sj0597', sql='BEGIN'}}
2022-02-16T18:08:40.4030204Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=55, nextPosition=4308691, flags=0}, data=TableMapEventData{tableId=18862, database='readbinlog_test_sj0597', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:40.4036840Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=EXT_UPDATE_ROWS, serverId=112233, headerLength=19, dataLength=62, nextPosition=4308772, flags=0}, data=UpdateRowsEventData{tableId=18862, includedColumnsBeforeUpdate={0, 1, 2, 3}, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:40.4037749Z {before=[Georgia, 30, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022], after=[Maggie, 30, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022]}
2022-02-16T18:08:40.4038956Z ]}}
2022-02-16T18:08:40.4040293Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4308803, flags=0}, data=XidEventData{xid=93688}}
2022-02-16T18:08:40.4045084Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4308868, flags=0}, data=null}
2022-02-16T18:08:40.4048724Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=79, nextPosition=4308966, flags=8}, data=QueryEventData{threadId=886, executionTime=0, errorCode=0, database='readbinlog_test_sj0597', sql='BEGIN'}}
2022-02-16T18:08:40.4052163Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=55, nextPosition=4309040, flags=0}, data=TableMapEventData{tableId=18862, database='readbinlog_test_sj0597', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:40.4056263Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=EXT_UPDATE_ROWS, serverId=112233, headerLength=19, dataLength=60, nextPosition=4309119, flags=0}, data=UpdateRowsEventData{tableId=18862, includedColumnsBeforeUpdate={0, 1, 2, 3}, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:40.4057291Z {before=[Janice, 19, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022], after=[Jamie, 19, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022]}
2022-02-16T18:08:40.4057958Z ]}}
2022-02-16T18:08:40.4058387Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4309150, flags=0}, data=XidEventData{xid=93690}}
2022-02-16T18:08:40.4102845Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4309215, flags=0}, data=null}
2022-02-16T18:08:40.4107092Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=71, nextPosition=4309305, flags=8}, data=QueryEventData{threadId=886, executionTime=0, errorCode=0, database='readbinlog_test_sj0597', sql='BEGIN'}}
2022-02-16T18:08:40.4111635Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=55, nextPosition=4309379, flags=0}, data=TableMapEventData{tableId=18862, database='readbinlog_test_sj0597', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:40.4116556Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=EXT_DELETE_ROWS, serverId=112233, headerLength=19, dataLength=38, nextPosition=4309436, flags=0}, data=DeleteRowsEventData{tableId=18862, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:40.4117363Z [Maggie, 30, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022]
2022-02-16T18:08:40.4118294Z ]}}
2022-02-16T18:08:40.4119032Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4309467, flags=0}, data=XidEventData{xid=93692}}
2022-02-16T18:08:40.4123289Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4309532, flags=0}, data=null}
2022-02-16T18:08:40.4124705Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=71, nextPosition=4309622, flags=8}, data=QueryEventData{threadId=886, executionTime=0, errorCode=0, database='readbinlog_test_sj0597', sql='BEGIN'}}
2022-02-16T18:08:40.4130652Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=55, nextPosition=4309696, flags=0}, data=TableMapEventData{tableId=18862, database='readbinlog_test_sj0597', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:40.4136129Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=EXT_DELETE_ROWS, serverId=112233, headerLength=19, dataLength=37, nextPosition=4309752, flags=0}, data=DeleteRowsEventData{tableId=18862, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:40.4136907Z [Jamie, 19, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022]
2022-02-16T18:08:40.4137602Z ]}}
2022-02-16T18:08:40.4138041Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4309783, flags=0}, data=XidEventData{xid=93694}}
2022-02-16T18:08:40.4183040Z 2022-02-16 18:08:40,415 INFO || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2022-02-16T18:08:40.6488477Z 18:08:40.648 percona-server2022-02-16T18:08:40.648062Z 887 [Note] Aborted connection 887 to db: 'unconnected' user: 'replicator' host: '172.17.0.1' (failed on flush_net())
2022-02-16T18:08:40.6501288Z 2022-02-16 18:08:40,648 INFO || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2022-02-16T18:08:40.6582775Z 2022-02-16 18:08:40,652 INFO || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2022-02-16T18:08:40.7610766Z 18:08:40.759 percona-server2022-02-16T18:08:40.759579Z 888 [Note] Aborted connection 888 to db: 'mysql' user: 'mysqluser' host: '172.17.0.1' (Got an error reading communication packets)
2022-02-16T18:08:40.7611699Z 18:08:40.759 percona-server2022-02-16T18:08:40.759818Z 884 [Note] Aborted connection 884 to db: 'mysql' user: 'mysqluser' host: '172.17.0.1' (Got an error reading communication packets)
2022-02-16T18:08:40.8782751Z 2022-02-16 18:08:40,877 INFO || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2022-02-16T18:08:40.8852128Z 18:08:40.884 percona-server2022-02-16T18:08:40.884584Z 894 [Note] Start binlog_dump to master_thread_id(894) slave_server(65534), pos(mysql-bin.000002, 4312334)
2022-02-16T18:08:40.8860729Z Feb 16, 2022 6:08:40 PM com.github.shyiko.mysql.binlog.BinaryLogClient connect
2022-02-16T18:08:40.8862456Z INFO: Connected to localhost:4304 at mysql-bin.000002/4312334 (sid:65534, cid:894)
2022-02-16T18:08:40.8987376Z Ignored event: Event{header=EventHeaderV4{timestamp=0, eventType=ROTATE, serverId=112233, headerLength=19, dataLength=28, nextPosition=0, flags=32}, data=RotateEventData{binlogFilename='mysql-bin.000002', binlogPosition=4312334}}
2022-02-16T18:08:40.8990220Z Ignored event: Event{header=EventHeaderV4{timestamp=1645033562000, eventType=FORMAT_DESCRIPTION, serverId=112233, headerLength=19, dataLength=100, nextPosition=0, flags=0}, data=FormatDescriptionEventData{binlogVersion=4, serverVersion='5.7.36-39-log', headerLength=19, dataLength=95, checksumType=CRC32}}
2022-02-16T18:08:40.8991446Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4312399, flags=0}, data=null}
2022-02-16T18:08:40.8993604Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=148, nextPosition=4312566, flags=4}, data=QueryEventData{threadId=893, executionTime=0, errorCode=0, database='readbinlog_test_1aba083', sql='DROP TABLE IF EXISTS `person` /* generated by server */'}}
2022-02-16T18:08:40.8994817Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4312631, flags=0}, data=null}
2022-02-16T18:08:40.8996928Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=308, nextPosition=4312958, flags=0}, data=QueryEventData{threadId=893, executionTime=0, errorCode=0, database='readbinlog_test_1aba083', sql='CREATE TABLE person ( name VARCHAR(255) primary key, age INTEGER NULL DEFAULT 10, createdAt DATETIME NULL DEFAULT CURRENT_TIMESTAMP, updatedAt DATETIME NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP)'}}
2022-02-16T18:08:40.9012057Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4313023, flags=0}, data=null}
2022-02-16T18:08:40.9014353Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=80, nextPosition=4313122, flags=8}, data=QueryEventData{threadId=893, executionTime=0, errorCode=0, database='readbinlog_test_1aba083', sql='BEGIN'}}
2022-02-16T18:08:40.9015878Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=56, nextPosition=4313197, flags=0}, data=TableMapEventData{tableId=18863, database='readbinlog_test_1aba083', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:40.9016636Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=EXT_WRITE_ROWS, serverId=112233, headerLength=19, dataLength=39, nextPosition=4313255, flags=0}, data=WriteRowsEventData{tableId=18863, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:40.9017094Z [Georgia, 30, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022]
2022-02-16T18:08:40.9017312Z ]}}
2022-02-16T18:08:40.9049053Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4313286, flags=0}, data=XidEventData{xid=93753}}
2022-02-16T18:08:40.9050458Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4313351, flags=0}, data=null}
2022-02-16T18:08:40.9051580Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=80, nextPosition=4313450, flags=8}, data=QueryEventData{threadId=893, executionTime=0, errorCode=0, database='readbinlog_test_1aba083', sql='BEGIN'}}
2022-02-16T18:08:40.9053063Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=56, nextPosition=4313525, flags=0}, data=TableMapEventData{tableId=18863, database='readbinlog_test_1aba083', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:40.9054295Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=EXT_UPDATE_ROWS, serverId=112233, headerLength=19, dataLength=62, nextPosition=4313606, flags=0}, data=UpdateRowsEventData{tableId=18863, includedColumnsBeforeUpdate={0, 1, 2, 3}, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:40.9054928Z {before=[Georgia, 30, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022], after=[Maggie, 30, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022]}
2022-02-16T18:08:40.9055213Z ]}}
2022-02-16T18:08:40.9083535Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4313637, flags=0}, data=XidEventData{xid=93755}}
2022-02-16T18:08:40.9084136Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4313702, flags=0}, data=null}
2022-02-16T18:08:40.9085269Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=72, nextPosition=4313793, flags=8}, data=QueryEventData{threadId=893, executionTime=0, errorCode=0, database='readbinlog_test_1aba083', sql='BEGIN'}}
2022-02-16T18:08:40.9086614Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=56, nextPosition=4313868, flags=0}, data=TableMapEventData{tableId=18863, database='readbinlog_test_1aba083', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:40.9087440Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034920000, eventType=EXT_DELETE_ROWS, serverId=112233, headerLength=19, dataLength=38, nextPosition=4313925, flags=0}, data=DeleteRowsEventData{tableId=18863, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:40.9088711Z [Maggie, 30, Wed Feb 16 07:08:40 UTC 2022, Wed Feb 16 07:08:40 UTC 2022]
2022-02-16T18:08:40.9088941Z ]}}
2022-02-16T18:08:40.9133710Z 2022-02-16 18:08:40,913 INFO || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2022-02-16T18:08:41.2095499Z 18:08:41.208 percona-server2022-02-16T18:08:41.208728Z 894 [Note] Aborted connection 894 to db: 'unconnected' user: 'replicator' host: '172.17.0.1' (failed on flush_net())
2022-02-16T18:08:41.2104546Z 2022-02-16 18:08:41,210 INFO || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2022-02-16T18:08:41.2205931Z 18:08:41.220 percona-server2022-02-16T18:08:41.219943Z 898 [Note] Start binlog_dump to master_thread_id(898) slave_server(65534), pos(mysql-bin.000002, 4315227)
2022-02-16T18:08:41.2231986Z Feb 16, 2022 6:08:41 PM com.github.shyiko.mysql.binlog.BinaryLogClient connect
2022-02-16T18:08:41.2232879Z INFO: Connected to localhost:4304 at mysql-bin.000002/4315227 (sid:65534, cid:898)
2022-02-16T18:08:41.2424234Z Ignored event: Event{header=EventHeaderV4{timestamp=0, eventType=ROTATE, serverId=112233, headerLength=19, dataLength=28, nextPosition=0, flags=32}, data=RotateEventData{binlogFilename='mysql-bin.000002', binlogPosition=4315227}}
2022-02-16T18:08:41.2426483Z Ignored event: Event{header=EventHeaderV4{timestamp=1645033562000, eventType=FORMAT_DESCRIPTION, serverId=112233, headerLength=19, dataLength=100, nextPosition=0, flags=0}, data=FormatDescriptionEventData{binlogVersion=4, serverVersion='5.7.36-39-log', headerLength=19, dataLength=95, checksumType=CRC32}}
2022-02-16T18:08:41.2429192Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4315292, flags=0}, data=null}
2022-02-16T18:08:41.2431511Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=146, nextPosition=4315457, flags=4}, data=QueryEventData{threadId=897, executionTime=0, errorCode=0, database='readbinlog_test_2ryc6v', sql='DROP TABLE IF EXISTS `person` /* generated by server */'}}
2022-02-16T18:08:41.2486037Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4315522, flags=0}, data=null}
2022-02-16T18:08:41.2493252Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=306, nextPosition=4315847, flags=0}, data=QueryEventData{threadId=897, executionTime=0, errorCode=0, database='readbinlog_test_2ryc6v', sql='CREATE TABLE person ( name VARCHAR(255) primary key, age INTEGER NULL DEFAULT 10, createdAt DATETIME NULL DEFAULT CURRENT_TIMESTAMP, updatedAt DATETIME NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP)'}}
2022-02-16T18:08:41.2515685Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4315912, flags=0}, data=null}
2022-02-16T18:08:41.2517961Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=79, nextPosition=4316010, flags=8}, data=QueryEventData{threadId=897, executionTime=0, errorCode=0, database='readbinlog_test_2ryc6v', sql='BEGIN'}}
2022-02-16T18:08:41.2520772Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=55, nextPosition=4316084, flags=0}, data=TableMapEventData{tableId=18864, database='readbinlog_test_2ryc6v', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:41.2522456Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=EXT_WRITE_ROWS, serverId=112233, headerLength=19, dataLength=61, nextPosition=4316164, flags=0}, data=WriteRowsEventData{tableId=18864, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:41.2523574Z [Georgia, 30, Wed Feb 16 07:08:41 UTC 2022, Wed Feb 16 07:08:41 UTC 2022],
2022-02-16T18:08:41.2523948Z [Janice, 19, Wed Feb 16 07:08:41 UTC 2022, Wed Feb 16 07:08:41 UTC 2022]
2022-02-16T18:08:41.2524246Z ]}}
2022-02-16T18:08:41.2524867Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4316195, flags=0}, data=XidEventData{xid=93792}}
2022-02-16T18:08:41.2544218Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4316260, flags=0}, data=null}
2022-02-16T18:08:41.2545647Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=79, nextPosition=4316358, flags=8}, data=QueryEventData{threadId=897, executionTime=0, errorCode=0, database='readbinlog_test_2ryc6v', sql='BEGIN'}}
2022-02-16T18:08:41.2547001Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=55, nextPosition=4316432, flags=0}, data=TableMapEventData{tableId=18864, database='readbinlog_test_2ryc6v', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:41.2553255Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=EXT_UPDATE_ROWS, serverId=112233, headerLength=19, dataLength=105, nextPosition=4316556, flags=0}, data=UpdateRowsEventData{tableId=18864, includedColumnsBeforeUpdate={0, 1, 2, 3}, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:41.2555376Z {before=[Georgia, 30, Wed Feb 16 07:08:41 UTC 2022, Wed Feb 16 07:08:41 UTC 2022], after=[Maggie, 30, Wed Feb 16 07:08:41 UTC 2022, Wed Feb 16 07:08:41 UTC 2022]},
2022-02-16T18:08:41.2555893Z {before=[Janice, 19, Wed Feb 16 07:08:41 UTC 2022, Wed Feb 16 07:08:41 UTC 2022], after=[Jamie, 19, Wed Feb 16 07:08:41 UTC 2022, Wed Feb 16 07:08:41 UTC 2022]}
2022-02-16T18:08:41.2556254Z ]}}
2022-02-16T18:08:41.2556884Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4316587, flags=0}, data=XidEventData{xid=93794}}
2022-02-16T18:08:41.2574086Z Ignored event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=ANONYMOUS_GTID, serverId=112233, headerLength=19, dataLength=46, nextPosition=4316652, flags=0}, data=null}
2022-02-16T18:08:41.2580791Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=QUERY, serverId=112233, headerLength=19, dataLength=71, nextPosition=4316742, flags=8}, data=QueryEventData{threadId=897, executionTime=0, errorCode=0, database='readbinlog_test_2ryc6v', sql='BEGIN'}}
2022-02-16T18:08:41.2582285Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=TABLE_MAP, serverId=112233, headerLength=19, dataLength=55, nextPosition=4316816, flags=0}, data=TableMapEventData{tableId=18864, database='readbinlog_test_2ryc6v', table='person', columnTypes=15, 3, 18, 18, columnMetadata=255, 0, 0, 0, columnNullability={1, 2, 3}, eventMetadata=null}}
2022-02-16T18:08:41.2583093Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=EXT_DELETE_ROWS, serverId=112233, headerLength=19, dataLength=59, nextPosition=4316894, flags=0}, data=DeleteRowsEventData{tableId=18864, includedColumns={0, 1, 2, 3}, rows=[
2022-02-16T18:08:41.2583563Z [Jamie, 19, Wed Feb 16 07:08:41 UTC 2022, Wed Feb 16 07:08:41 UTC 2022],
2022-02-16T18:08:41.2583829Z [Maggie, 30, Wed Feb 16 07:08:41 UTC 2022, Wed Feb 16 07:08:41 UTC 2022]
2022-02-16T18:08:41.2584058Z ]}}
2022-02-16T18:08:41.2585242Z Consumed event: Event{header=EventHeaderV4{timestamp=1645034921000, eventType=XID, serverId=112233, headerLength=19, dataLength=12, nextPosition=4316925, flags=0}, data=XidEventData{xid=93796}}
2022-02-16T18:08:41.2588200Z 2022-02-16 18:08:41,258 INFO || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2022-02-16T18:08:41.2680282Z [ERROR] Tests run: 7, Failures: 1, Errors: 0, Skipped: 3, Time elapsed: 1.167 s <<< FAILURE! - in io.debezium.connector.mysql.ReadBinLogIT
{noformat}
Contributor guide
Research direction
Start with ReadBinLogIT.shouldCaptureSingleWriteUpdateDeleteEvents and review the provided MySQL/Percona test log. Run this integration test repeatedly to identify which event or assertion fails intermittently. Done means the test reliably passes and the underlying failure condition is addressed.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java, mysql
- Domain
- databases, testing-qa
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100