[HBASE-25556] Frequent replication "Encountered a malformed edit" warnings

• Type: Bug
• Status: Resolved
• Priority: Minor
• Resolution: Fixed
• Affects Version/s: 2.4.1
• Fix Version/s: 3.0.0-alpha-1, 2.2.7, 2.5.0, 2.3.5, 2.4.2
• Component/s: Operability, Replication
• Hadoop Flags: Reviewed
• Assignee: Andrew Kyle Purtell
• Reporter: Andrew Kyle Purtell
• Created: 06/Feb/21 00:55
• Updated: 11/Apr/21 09:10
• Resolved: 23/Feb/21 22:57

Description

A sequence of two log lines are frequently printed at WARN level when replication is active. Can be several times per minute per regionserver when taking writes with replication active. These can appear after a WAL roll or after the log archiver moves a WAL file.

Is this an off-by one error? (Will have to look at the code.)

If this is expected and harmless, WARN level logging is the wrong thing to do, it will trigger operator concern.

The first:

2021-02-05 16:42:27,269 WARN  [RS_REFRESH_PEER-regionserver/HOST:8120-0.replicationSource,1.replicationSource.wal-reader.HOST%2C8120%2C1612570567906,1]
wal.ProtobufLogReader: Encountered a malformed edit, seeking back to last good position in file, from 134220988 to 134220987
java.io.EOFException: Partial PB while reading WAL, probably an unexpected EOF, ignoring. current offset=134220988
	at org.apache.hadoop.hbase.regionserver.wal.ProtobufLogReader.readNext(ProtobufLogReader.java:370)
	at org.apache.hadoop.hbase.regionserver.wal.ReaderBase.next(ReaderBase.java:97)
	at org.apache.hadoop.hbase.regionserver.wal.ReaderBase.next(ReaderBase.java:85)
	at org.apache.hadoop.hbase.replication.regionserver.WALEntryStream.readNextEntryAndRecordReaderPosition(WALEntryStream.java:263)
	at org.apache.hadoop.hbase.replication.regionserver.WALEntryStream.tryAdvanceEntry(WALEntryStream.java:176)
	at org.apache.hadoop.hbase.replication.regionserver.WALEntryStream.hasNext(WALEntryStream.java:101)
	at org.apache.hadoop.hbase.replication.regionserver.ReplicationSourceWALReader.readWALEntries(ReplicationSourceWALReader.java:220)
	at org.apache.hadoop.hbase.replication.regionserver.ReplicationSourceWALReader.run(ReplicationSourceWALReader.java:137)

The second:

2021-02-05 16:42:27,271 WARN  [RS_REFRESH_PEER-regionserver/HOST:8120-0.replicationSource,1.replicationSource.wal-reader.HOST%2C8120%2C1612570567906,1] 
wal.ProtobufLogReader: Encountered a malformed edit, seeking back to last good position in file, from 134220988 to 134220987
java.io.EOFException: Partial PB while reading WAL, probably an unexpected EOF, ignoring. current offset=134220988
	at org.apache.hadoop.hbase.regionserver.wal.ProtobufLogReader.readNext(ProtobufLogReader.java:370)
	at org.apache.hadoop.hbase.regionserver.wal.ReaderBase.next(ReaderBase.java:97)
	at org.apache.hadoop.hbase.regionserver.wal.ReaderBase.next(ReaderBase.java:85)
	at org.apache.hadoop.hbase.replication.regionserver.WALEntryStream.readNextEntryAndRecordReaderPosition(WALEntryStream.java:263)
	at org.apache.hadoop.hbase.replication.regionserver.WALEntryStream.tryAdvanceEntry(WALEntryStream.java:184)
	at org.apache.hadoop.hbase.replication.regionserver.WALEntryStream.hasNext(WALEntryStream.java:101)
	at org.apache.hadoop.hbase.replication.regionserver.ReplicationSourceWALReader.readWALEntries(ReplicationSourceWALReader.java:220)
	at org.apache.hadoop.hbase.replication.regionserver.ReplicationSourceWALReader.run(ReplicationSourceWALReader.java:137)

Issue Links

• links to: GitHub Pull Request #2965