Re: org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append sequenceId=8689

[anil gupta]

Thanks for the pointers Aaron. We checked hdfs. Its reporting 0
underreplicated or corrupted blocks.

@Ted: we are using Hadoop 2.7.3(EMR5.7.2)

On Thu, Jul 6, 2017 at 4:49 PM, Ted Yu  wrote:

> Which hadoop release are you using ?
>
> In FSOutputSummer.java, I see the following around line 106:
>
> checkClosed();
>
> if (off < 0 || len < 0 || off > b.length - len) {
>   throw new ArrayIndexOutOfBoundsException();
>
> You didn't get ArrayIndexOutOfBoundsException - maybe b was null ?
>
> On Thu, Jul 6, 2017 at 2:08 PM, anil gupta  wrote:
>
>> Hey Ted,
>>
>> This is what i see in one of region server log(NPE at the bottom):
>> 2017-07-06 19:07:07,778 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
>> has an old edit so flush to free WALs after random delay 155739ms
>> 2017-07-06 19:07:17,853 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
>> has an old edit so flush to free WALs after random delay 132731ms
>> 2017-07-06 19:07:28,038 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
>> has an old edit so flush to free WALs after random delay 4316ms
>> 2017-07-06 19:07:37,819 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
>> has an old edit so flush to free WALs after random delay 190960ms
>> 2017-07-06 19:07:47,767 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
>> has an old edit so flush to free WALs after random delay 41231ms
>> 2017-07-06 19:07:57,767 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
>> has an old edit so flush to free WALs after random delay 222748ms
>> 2017-07-06 19:08:07,973 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
>> has an old edit so flush to free WALs after random delay 245966ms
>> 2017-07-06 19:08:18,669 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
>> has an old edit so flush to free WALs after random delay 76257ms
>> 2017-07-06 19:08:28,029 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
>> has an old edit so flush to free WALs after random delay 78310ms
>> 2017-07-06 19:08:38,459 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
>> has an old edit so flush to free WALs after random delay 127828ms
>> 2017-07-06 19:08:48,527 INFO
>> [ip-10-74-5-153.us-west-2.compute.internal,16020,14993202605
>> 01_ChoreService_1]
>> regionserver.HRegionServer:
>> ip-10-74-5-153.us-west-2.compute.internal,16020,149932026050
>> 1-MemstoreFlusherChore
>> requesting flush of
>> SYSTEM.CATALOG,,

Re: org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append sequenceId=8689

[Ted Yu]

Which hadoop release are you using ?

In FSOutputSummer.java, I see the following around line 106:

checkClosed();

if (off < 0 || len < 0 || off > b.length - len) {
  throw new ArrayIndexOutOfBoundsException();

You didn't get ArrayIndexOutOfBoundsException - maybe b was null ?

On Thu, Jul 6, 2017 at 2:08 PM, anil gupta  wrote:

> Hey Ted,
>
> This is what i see in one of region server log(NPE at the bottom):
> 2017-07-06 19:07:07,778 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 155739ms
> 2017-07-06 19:07:17,853 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 132731ms
> 2017-07-06 19:07:28,038 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 4316ms
> 2017-07-06 19:07:37,819 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 190960ms
> 2017-07-06 19:07:47,767 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 41231ms
> 2017-07-06 19:07:57,767 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 222748ms
> 2017-07-06 19:08:07,973 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 245966ms
> 2017-07-06 19:08:18,669 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 76257ms
> 2017-07-06 19:08:28,029 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 78310ms
> 2017-07-06 19:08:38,459 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 127828ms
> 2017-07-06 19:08:48,527 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-
> MemstoreFlusherChore
> requesting flush of
> SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
> has an old edit so flush to free WALs after random delay 38647ms
> 2017-07-06 19:08:58,554 INFO
> [ip-10-74-5-153.us-west-2.compute.internal,16020,
> 1499320260501_ChoreService_1]
> regionserver.HRegionServer:
> ip-10-74-5-153.us-west-2.compute.internal,

Re: org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append sequenceId=8689

[M. Aaron Bossert]

I can't be definitive, but I have had a very similar issue in the past.  The 
root cause was the my NTP server had died and a couple of nodes in the cluster 
got wildly out of sync.  Check your HDFS health And if there are 
under-replicated blocks...this "could" be your issue (though root cause could 
be bad disks or any number of other issues that present with the same 
"symptoms", but again, I would take this advice only as far as needed to either 
rule it out or dig further...don't go down a rabbit hole.  Your errors could 
have been caused by an entirely different problem...I have no other context 
from the error you provided to know where else to look...

Aaron

Sent from my iPhone

> On Jul 6, 2017, at 16:55, Ted Yu  wrote:
> 
> HBASE-16960 mentioned the following :
> 
> Caused by: java.net.SocketTimeoutException: 2 millis timeout while 
> waiting for channel to be ready for read
> 
> Do you see similar line in region server log ?
> 
> Cheers
> 
>> On Thu, Jul 6, 2017 at 1:48 PM, anil gupta  wrote:
>> Hi All,
>> 
>> We are running HBase/Phoenix on EMR5.2(HBase1.2.3 and Phoenix4.7) and we 
>> running into following exception when we are trying to load data into one of 
>> our Phoenix table:
>> 2017-07-06 19:57:57,507 INFO [hconnection-0x60e5272-shared--pool2-t249] 
>> org.apache.hadoop.hbase.client.AsyncProcess: #1, table=DE.CONFIG_DATA, 
>> attempt=30/35 failed=38ops, last exception: 
>> org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: 
>> org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append 
>> sequenceId=8689, requesting roll of WAL
>>  at 
>> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.append(FSHLog.java:1921)
>>  at 
>> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.onEvent(FSHLog.java:1773)
>>  at 
>> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.onEvent(FSHLog.java:1695)
>>  at 
>> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:128)
>>  at 
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>>  at 
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>  at java.lang.Thread.run(Thread.java:745)
>> 
>> We are OK with wiping out this table and rebuilding the dataset. We tried to 
>> drop the table and recreate the table but it didnt fix it. 
>> Can anyone please let us know how can we get rid of above problem? Are we 
>> running into https://issues.apache.org/jira/browse/HBASE-16960?
>> 
>> -- 
>> Thanks & Regards,
>> Anil Gupta
> 

Re: org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append sequenceId=8689

[anil gupta]

Hey Ted,

This is what i see in one of region server log(NPE at the bottom):
2017-07-06 19:07:07,778 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 155739ms
2017-07-06 19:07:17,853 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 132731ms
2017-07-06 19:07:28,038 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 4316ms
2017-07-06 19:07:37,819 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 190960ms
2017-07-06 19:07:47,767 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 41231ms
2017-07-06 19:07:57,767 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 222748ms
2017-07-06 19:08:07,973 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 245966ms
2017-07-06 19:08:18,669 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 76257ms
2017-07-06 19:08:28,029 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 78310ms
2017-07-06 19:08:38,459 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 127828ms
2017-07-06 19:08:48,527 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 38647ms
2017-07-06 19:08:58,554 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 185493ms
2017-07-06 19:09:07,779 INFO
[ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501_ChoreService_1]
regionserver.HRegionServer:
ip-10-74-5-153.us-west-2.compute.internal,16020,1499320260501-MemstoreFlusherChore
requesting flush of
SYSTEM.CATALOG,,1499317930655.a47ffa359aa4588f5f360790ac8e4561. because 0
has an old edit so flush to free WALs after random delay 245608ms
2

Re: Specify maven dependency

[Josh Elser]

The phoenix-client jar is not published. Please see 
https://issues.apache.org/jira/browse/PHOENIX-1567


On 6/29/17 9:26 AM, Juvenn Woo wrote:

Hi all,

For convenience of deployment, I am trying to specify phoenix as maven 
dependency instead of put client jar in the git repo.


While I am able to find phoenix on maven central:

```
|<||dependency||>|
|||<||groupId||>org.apache.phoenix|
|||<||artifactId||>phoenix|
|||<||version||>4.10.0-HBase-1.2|
||
```

Yet it fails to download it, and complains with following error:

```
Caused by: org.sonatype.aether.resolution.ArtifactResolutionException: 
Could not find artifact org.apache.phoenix:phoenix:jar:4.10.0-HBase-1.2 
in central

```

Do I miss anything here? Or is the manual bundling client jar the only 
option?


Thanks!

--
Juvenn Woo
Sent with Sparrow 

Re: org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append sequenceId=8689

[Ted Yu]

HBASE-16960 mentioned the following :

Caused by: java.net.SocketTimeoutException: 2 millis timeout while
waiting for channel to be ready for read

Do you see similar line in region server log ?

Cheers

On Thu, Jul 6, 2017 at 1:48 PM, anil gupta  wrote:

> Hi All,
>
> We are running HBase/Phoenix on EMR5.2(HBase1.2.3 and Phoenix4.7) and we 
> running into following exception when we are trying to load data into one of 
> our Phoenix table:
> 2017-07-06 19:57:57,507 INFO [hconnection-0x60e5272-shared--pool2-t249] 
> org.apache.hadoop.hbase.client.AsyncProcess: #1, table=DE.CONFIG_DATA, 
> attempt=30/35 failed=38ops, last exception: 
> org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: 
> org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append 
> sequenceId=8689, requesting roll of WAL
>   at 
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.append(FSHLog.java:1921)
>   at 
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.onEvent(FSHLog.java:1773)
>   at 
> org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.onEvent(FSHLog.java:1695)
>   at 
> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:128)
>   at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>   at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>   at java.lang.Thread.run(Thread.java:745)
>
> We are OK with wiping out this table and rebuilding the dataset. We tried to 
> drop the table and recreate the table but it didnt fix it.
> Can anyone please let us know how can we get rid of above problem? Are we 
> running into https://issues.apache.org/jira/browse/HBASE-16960?
>
>
> --
> Thanks & Regards,
> Anil Gupta
>

org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append sequenceId=8689

[anil gupta]

Hi All,

We are running HBase/Phoenix on EMR5.2(HBase1.2.3 and Phoenix4.7) and
we running into following exception when we are trying to load data
into one of our Phoenix table:
2017-07-06 19:57:57,507 INFO
[hconnection-0x60e5272-shared--pool2-t249]
org.apache.hadoop.hbase.client.AsyncProcess: #1, table=DE.CONFIG_DATA,
attempt=30/35 failed=38ops, last exception:
org.apache.hadoop.hbase.regionserver.wal.DamagedWALException:
org.apache.hadoop.hbase.regionserver.wal.DamagedWALException: Append
sequenceId=8689, requesting roll of WAL
at 
org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.append(FSHLog.java:1921)
at 
org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.onEvent(FSHLog.java:1773)
at 
org.apache.hadoop.hbase.regionserver.wal.FSHLog$RingBufferEventHandler.onEvent(FSHLog.java:1695)
at 
com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:128)
at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)

We are OK with wiping out this table and rebuilding the dataset. We
tried to drop the table and recreate the table but it didnt fix it.
Can anyone please let us know how can we get rid of above problem? Are
we running into https://issues.apache.org/jira/browse/HBASE-16960?


-- 
Thanks & Regards,
Anil Gupta

Re: Exception ERROR 201 (22000): Illegal data. Expected length of at least 8 bytes, but had 4

[Josh Mahonin]

Hi Takashi,

Thanks for the update. Do you think it could be the same issue as
https://issues.apache.org/jira/browse/PHOENIX-3453 ?

If not, it would be great if you could file a new JIRA ticket with as much
detail as possible, and ideally a simple way to reproduce it.

Thanks!

Josh

On Thu, Jul 6, 2017 at 6:36 AM, Takashi Sasaki  wrote:

> Hi Josh,
>
>
> Well, it is difficult soon. I'll execute query directly if I have time.
>
> Information on the table is difficult to post due to confidentiality
> agreement, but negotiate with my boss and provide it if possible.
>
> By the way, changing all local indexes to all global indexes no longer
> causes the exception.
>
> It seems there is a problem with the local index.
>
>
> Thanks,
>
> Takashi
>
>
> 2017-07-05 22:35 GMT+09:00 Josh Mahonin :
> > Hi,
> >
> > From the logs you attached, it appears that you're getting the exception
> on
> > the following query:
> >
> > SELECT trid, tid, frtp, frno, gzid, ontm, onty, onlt, onln,
> > oftm, ofty, oflt, ofln, onwk, onhr, wday, dist, drtn, delf, sntf,
> > cdtm, udtm FROM  trp WHERE  tid = ? AND delf = FALSE ORDER BY oftm
> > DESC NULLS LAST FETCH FIRST 1 ROW ONLY
> >
> > Are you able to reproduce this issue by executing that query directly?
> Given
> > a snippet of your stack trace, I'm not sure if Spark is the culprit
> here, so
> > it'd be nice to try identify the root cause (or maybe correlate it to an
> > existing JIRA ticket)
> >
> > ...
> > Caused by: java.sql.SQLException: ERROR 201 (22000): Illegal data.
> > ERROR 201 (22000): ERROR 201 (22000): Illegal data. Expected length of
> > at least 8 bytes, but had 4
> > TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00,1499228698442.4f312a19bfdc624776516228c9c4f2d5.
> >  at
> > org.apache.phoenix.exception.SQLExceptionCode$Factory$1.
> newException(SQLExceptionCode.java:464)
> >  at
> > org.apache.phoenix.exception.SQLExceptionInfo.buildException(
> SQLExceptionInfo.java:150)
> >  at
> > org.apache.phoenix.util.ServerUtil.parseRemoteException(
> ServerUtil.java:134)
> >  at
> > org.apache.phoenix.util.ServerUtil.parseServerExceptionOrNull(
> ServerUtil.java:123)
> >  at
> > org.apache.phoenix.util.ServerUtil.parseServerException(
> ServerUtil.java:109)
> >  at
> > org.apache.phoenix.iterate.BaseResultIterators.getIterators(
> BaseResultIterators.java:755)
> >  at
> > org.apache.phoenix.iterate.BaseResultIterators.getIterators(
> BaseResultIterators.java:699)
> >  at
> > org.apache.phoenix.iterate.MergeSortResultIterator.getMinHeap(
> MergeSortResultIterator.java:72)
> >  at
> > org.apache.phoenix.iterate.MergeSortResultIterator.minIterator(
> MergeSortResultIterator.java:93)
> >  at
> > org.apache.phoenix.iterate.MergeSortResultIterator.next(
> MergeSortResultIterator.java:58)
> >  at
> > org.apache.phoenix.iterate.MergeSortTopNResultIterator.next(
> MergeSortTopNResultIterator.java:95)
> >  at org.apache.phoenix.jdbc.PhoenixResultSet.next(
> PhoenixResultSet.java:778)
> > ...
> >
> > Also, are you able to post your CREATE TABLE DDL for the 'trp' table
> you're
> > querying?
> >
> > Thanks,
> >
> > Josh
> >
> > On Wed, Jul 5, 2017 at 1:24 AM, Takashi Sasaki 
> wrote:
> >>
> >> Hi,
> >>
> >> I'm using Phoenix4.9.0/HBase1.3.0 with Spark2.1.1 on AWS EMR 5.6.0.
> >>
> >> When one side uses Spark Streaming to write a lot of data and the
> >> other side uses Spark to read data,
> >> I encounter several similar exceptions.
> >>
> >> 17/07/05 04:33:47 ERROR Executor: Exception in task 83.0 in stage
> >> 166.0 (TID 95211)
> >> org.apache.ibatis.exceptions.PersistenceException:
> >> ### Error querying database.  Cause: java.sql.SQLException: ERROR 201
> >> (22000): Illegal data. ERROR 201 (22000): ERROR 201 (22000): Illegal
> >> data. Expected length of at least 8 bytes, but had 4
> >>
> >> TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00,1499228698442.4f312a19bfdc624776516228c9c4f2d5.
> >> ### The error may exist in agp/mapper/TripMapper.java (best guess)
> >> ### The error may involve agp.mapper.TripMapper.selectLast
> >> ### The error occurred while handling results
> >> ### SQL: SELECT trid, tid, frtp, frno, gzid, ontm, onty, onlt, onln,
> >> oftm, ofty, oflt, ofln, onwk, onhr, wday, dist, drtn, delf, sntf,
> >> cdtm, udtm FROM  trp WHERE  tid = ? AND delf = FALSE ORDER BY oftm
> >> DESC NULLS LAST FETCH FIRST 1 ROW ONLY
> >> ### Cause: java.sql.SQLException: ERROR 201 (22000): Illegal data.
> >> ERROR 201 (22000): ERROR 201 (22000): Illegal data. Expected length of
> >> at least 8 bytes, but had 4
> >>
> >> TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\

Re: Exception ERROR 201 (22000): Illegal data. Expected length of at least 8 bytes, but had 4

[Takashi Sasaki]

Hi Josh,


Well, it is difficult soon. I'll execute query directly if I have time.

Information on the table is difficult to post due to confidentiality
agreement, but negotiate with my boss and provide it if possible.

By the way, changing all local indexes to all global indexes no longer
causes the exception.

It seems there is a problem with the local index.


Thanks,

Takashi


2017-07-05 22:35 GMT+09:00 Josh Mahonin :
> Hi,
>
> From the logs you attached, it appears that you're getting the exception on
> the following query:
>
> SELECT trid, tid, frtp, frno, gzid, ontm, onty, onlt, onln,
> oftm, ofty, oflt, ofln, onwk, onhr, wday, dist, drtn, delf, sntf,
> cdtm, udtm FROM  trp WHERE  tid = ? AND delf = FALSE ORDER BY oftm
> DESC NULLS LAST FETCH FIRST 1 ROW ONLY
>
> Are you able to reproduce this issue by executing that query directly? Given
> a snippet of your stack trace, I'm not sure if Spark is the culprit here, so
> it'd be nice to try identify the root cause (or maybe correlate it to an
> existing JIRA ticket)
>
> ...
> Caused by: java.sql.SQLException: ERROR 201 (22000): Illegal data.
> ERROR 201 (22000): ERROR 201 (22000): Illegal data. Expected length of
> at least 8 bytes, but had 4
> TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00,1499228698442.4f312a19bfdc624776516228c9c4f2d5.
>  at
> org.apache.phoenix.exception.SQLExceptionCode$Factory$1.newException(SQLExceptionCode.java:464)
>  at
> org.apache.phoenix.exception.SQLExceptionInfo.buildException(SQLExceptionInfo.java:150)
>  at
> org.apache.phoenix.util.ServerUtil.parseRemoteException(ServerUtil.java:134)
>  at
> org.apache.phoenix.util.ServerUtil.parseServerExceptionOrNull(ServerUtil.java:123)
>  at
> org.apache.phoenix.util.ServerUtil.parseServerException(ServerUtil.java:109)
>  at
> org.apache.phoenix.iterate.BaseResultIterators.getIterators(BaseResultIterators.java:755)
>  at
> org.apache.phoenix.iterate.BaseResultIterators.getIterators(BaseResultIterators.java:699)
>  at
> org.apache.phoenix.iterate.MergeSortResultIterator.getMinHeap(MergeSortResultIterator.java:72)
>  at
> org.apache.phoenix.iterate.MergeSortResultIterator.minIterator(MergeSortResultIterator.java:93)
>  at
> org.apache.phoenix.iterate.MergeSortResultIterator.next(MergeSortResultIterator.java:58)
>  at
> org.apache.phoenix.iterate.MergeSortTopNResultIterator.next(MergeSortTopNResultIterator.java:95)
>  at org.apache.phoenix.jdbc.PhoenixResultSet.next(PhoenixResultSet.java:778)
> ...
>
> Also, are you able to post your CREATE TABLE DDL for the 'trp' table you're
> querying?
>
> Thanks,
>
> Josh
>
> On Wed, Jul 5, 2017 at 1:24 AM, Takashi Sasaki  wrote:
>>
>> Hi,
>>
>> I'm using Phoenix4.9.0/HBase1.3.0 with Spark2.1.1 on AWS EMR 5.6.0.
>>
>> When one side uses Spark Streaming to write a lot of data and the
>> other side uses Spark to read data,
>> I encounter several similar exceptions.
>>
>> 17/07/05 04:33:47 ERROR Executor: Exception in task 83.0 in stage
>> 166.0 (TID 95211)
>> org.apache.ibatis.exceptions.PersistenceException:
>> ### Error querying database.  Cause: java.sql.SQLException: ERROR 201
>> (22000): Illegal data. ERROR 201 (22000): ERROR 201 (22000): Illegal
>> data. Expected length of at least 8 bytes, but had 4
>>
>> TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00,1499228698442.4f312a19bfdc624776516228c9c4f2d5.
>> ### The error may exist in agp/mapper/TripMapper.java (best guess)
>> ### The error may involve agp.mapper.TripMapper.selectLast
>> ### The error occurred while handling results
>> ### SQL: SELECT trid, tid, frtp, frno, gzid, ontm, onty, onlt, onln,
>> oftm, ofty, oflt, ofln, onwk, onhr, wday, dist, drtn, delf, sntf,
>> cdtm, udtm FROM  trp WHERE  tid = ? AND delf = FALSE ORDER BY oftm
>> DESC NULLS LAST FETCH FIRST 1 ROW ONLY
>> ### Cause: java.sql.SQLException: ERROR 201 (22000): Illegal data.
>> ERROR 201 (22000): ERROR 201 (22000): Illegal data. Expected length of
>> at least 8 bytes, but had 4
>>
>> TRP,\x0B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00,1499228698442.4f312a19bfdc624776516228c9c4f2d5.
>>  at
>> org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
>>  at
>> org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:150)
>>  at
>> org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)
>>  at
>> org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:77)
>>  at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:82)
>>  at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy