You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "Andrew Kyle Purtell (Jira)" <ji...@apache.org> on 2021/02/19 22:28:00 UTC

[jira] [Comment Edited] (HBASE-25556) Frequent replication "Encountered a malformed edit" warnings

    [ https://issues.apache.org/jira/browse/HBASE-25556?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17287401#comment-17287401 ] 

Andrew Kyle Purtell edited comment on HBASE-25556 at 2/19/21, 10:27 PM:
------------------------------------------------------------------------

Came back to this today. 

I think this behavior is expected given the stacktrace is a call arc through _tryAdvanceEntry_:

{code}
readWALEntries() {
    hasNext() {
*        tryAdvanceEntry() {*
             readNextEntryAndRecordReaderPosition() {
                 next() {
                     readNext(); <--- exception thrown here
                 }
             }
         }
     }
}
{code}

A tryXXX method is expected to fail when conditions are not ready by convention, which is the case here too, so we should be suppressing this WARN. 


was (Author: apurtell):
Came back to this today. 

I think this behavior is expected given the stacktrace is a call arc through _tryAdvanceEntry_:

{code}
readWALEntries() {
    hasNext() {
*        tryAdvanceEntry() {*
             readNextEntryAndRecordReaderPosition() {
                 next() {
                     readNext(); <--- exception thrown here
                 }
             }
         }
     }
}
{code}

A tryXXX method is expected to fail when conditions are not ready by convention, which is the case here too, so we should be suppressing this WARN. The WARN log is emitted from ProtobufLogReader.readNext, the innermost code. I think we are going to have to disable or change the log category of this log line. 

> Frequent replication "Encountered a malformed edit" warnings
> ------------------------------------------------------------
>
>                 Key: HBASE-25556
>                 URL: https://issues.apache.org/jira/browse/HBASE-25556
>             Project: HBase
>          Issue Type: Bug
>          Components: Operability, Replication
>    Affects Versions: 2.4.1
>            Reporter: Andrew Kyle Purtell
>            Assignee: Andrew Kyle Purtell
>            Priority: Minor
>             Fix For: 3.0.0-alpha-1, 2.5.0, 2.4.2
>
>
> 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:
> {noformat}
> 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)
> {noformat}
> The second:
> {noformat}
> 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)
> {noformat}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)