accumulo-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Keys Botzum <kbot...@maprtech.com>
Subject Re: Accumulo on MapR Continued - LargeRowTest
Date Wed, 11 Apr 2012 13:48:24 GMT
Keith,

Thanks for the suggestion.  I made the change to the source as you suggested and rebuilt it
using Maven (surprisingly easy).

Here's the log from tserver now. Does this help at all? I can of course provide the complete
log or logs if useful to you. I can also provide the temporary tables and such if that's useful.


10 15:44:07,786 [cache.LruBlockCache] DEBUG: Block cache LRU eviction completed. Freed 2494168
bytes.  Priority Sizes: Single=3.2550507MB (3413168), Multi=1
3.89547MB (14570456),Memory=0.0MB (0)
10 15:44:07,798 [rfile.RelativeKey] DEBUG: len : 131072
10 15:44:07,799 [rfile.RelativeKey] DEBUG: data : Z"?7-,mE:5Di&ou.4/4.i+9zGo0K8%%TsSt#!&a!&s
:OKl:2"cp>]yT(ZeP
10 15:44:07,799 [rfile.RelativeKey] DEBUG: len : 0
10 15:44:07,799 [rfile.RelativeKey] DEBUG: data : 
10 15:44:07,799 [rfile.RelativeKey] DEBUG: len : 0
10 15:44:07,799 [rfile.RelativeKey] DEBUG: data : 
10 15:44:07,799 [rfile.RelativeKey] DEBUG: len : 0
10 15:44:07,799 [rfile.RelativeKey] DEBUG: data : 
10 15:44:07,799 [tabletserver.TabletServer] DEBUG: ScanSess tid 10.250.99.204:52572 2 1 entries
in 0.03 secs, nbTimes = [25 25 25.00 1] 
10 15:44:07,828 [rfile.RelativeKey] DEBUG: len : 65
10 15:44:07,828 [rfile.RelativeKey] DEBUG: data : SjC)$OQ7U!9Ng:i1#2Sxl.a"(d=Js>d!1u`)WAFAs{>n=7H<tM?.tP"RsUOI
10 15:44:07,828 [rfile.RelativeKey] DEBUG: len : 47
10 15:44:07,833 [problems.ProblemReports] DEBUG: Filing problem report 2 FILE_READ /user/mapr/accumulo-SE-test-04-18004/tables/2/t-0000000/F000000p.rf
10 15:44:07,834 [tabletserver.TabletServer] WARN : exception while scanning tablet 2;%9e.07Zx{t*taPSI\\;I4z*77vIG[Oa&(Dw?4_N(!OIA#Z(ZE%"v3gI9Q{ZlGNAGL@...
T
RUNCATED<
java.io.EOFException
        at java.io.DataInputStream.readFully(DataInputStream.java:180)
        at java.io.DataInputStream.readFully(DataInputStream.java:152)
        at org.apache.accumulo.core.file.rfile.RelativeKey.read(RelativeKey.java:381)
        at org.apache.accumulo.core.file.rfile.RelativeKey.readFields(RelativeKey.java:135)
        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader._next(RFile.java:584)
        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader.next(RFile.java:556)
        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
        at org.apache.accumulo.server.problems.ProblemReportingIterator.next(ProblemReportingIterator.java:77)
        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
        at org.apache.accumulo.core.iterators.system.DeletingIterator.next(DeletingIterator.java:58)
        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
        at org.apache.accumulo.core.iterators.user.VersioningIterator.skipRowColumn(VersioningIterator.java:103)
        at org.apache.accumulo.core.iterators.user.VersioningIterator.next(VersioningIterator.java:53)
        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.readNext(SourceSwitchingIterator.java:120)
        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.next(SourceSwitchingIterator.java:105)
        at org.apache.accumulo.server.tabletserver.Tablet.nextBatch(Tablet.java:1766)
        at org.apache.accumulo.server.tabletserver.Tablet.access$3200(Tablet.java:143)
        at org.apache.accumulo.server.tabletserver.Tablet$Scanner.read(Tablet.java:1883)
        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler$NextBatchTask.run(TabletServer.java:905)
        at org.apache.accumulo.cloudtrace.instrument.TraceRunnable.run(TraceRunnable.java:47)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)


It appears to be attempting to read 47 bytes but isn't succeeding. Out of curiosity I changed
the code to read what it could and print a warning. Here's the new code version:


And this is a snippet of the exception which occurs with that change. Everything else is the
same. As you can see my hack gets us past the read of the key, but then the next read fails.

11 06:42:32,254 [rfile.RelativeKey] DEBUG: data : 
11 06:42:32,254 [tabletserver.TabletServer] DEBUG: ScanSess tid 10.250.99.204:47993 2 1 entries
in 0.02
 secs, nbTimes = [23 23 23.00 1] 
11 06:42:32,283 [rfile.RelativeKey] DEBUG: len : 65
11 06:42:32,283 [rfile.RelativeKey] DEBUG: data : SjC)$OQ7U!9Ng:i1#2Sxl.a"(d=Js>d!1u`)WAFAs{>n=7H<tM?.t
P"RsUOI
11 06:42:32,283 [rfile.RelativeKey] DEBUG: len : 47
11 06:42:32,283 [rfile.RelativeKey] DEBUG: MISSING BYTES!!: read 45
11 06:42:32,283 [rfile.RelativeKey] DEBUG: data : )vRS>4 ?c>$Sgn#[QcscA!HAYcF;M_Jg3d&Jzc85$)6Y7^@^@
11 06:42:32,288 [problems.ProblemReports] DEBUG: Filing problem report 2 FILE_READ /user/mapr/accumulo-
SE-test-04-32318/tables/2/t-0000000/F000000q.rf
11 06:42:32,289 [tabletserver.TabletServer] WARN : exception while scanning tablet 2;%9e.07Zx{t*taPSI\\
;I4z*77vIG[Oa&(Dw?4_N(!OIA#Z(ZE%"v3gI9Q{ZlGNAGL@... TRUNCATED<
java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:375)
        at org.apache.accumulo.core.data.Value.readFields(Value.java:156)
        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader._next(RFile.java:585)
        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader.next(RFile.java:556)
        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
        at org.apache.accumulo.server.problems.ProblemReportingIterator.next(ProblemReportingIterator.j
       …..

So it looks like we are missing quite a bit of data.

Any help or ideas appreciated.

Thanks,
Keys
________________________________
Keys Botzum
Senior Principal Technologist
WW Systems Engineering
kbotzum@maprtech.com
443-718-0098
MapR Technologies
http://www.mapr.com



On Apr 10, 2012, at 5:23 PM, Keith Turner wrote:

> Keys,
> 
> Looking at the test, it writes out random rows that 128k in len.  The
> column family and column qualifier it writes out are 0 bytes long.
> When the non compression test failed, it was trying to read a column
> qualifier.  If we assume that it was reading a column qualifier from
> the test table then it should be calling readFully() with a zero
> length array.
> 
> Trying to think how to debug this.  One way may be to change the code
> in RelativeKey to the following and run the test.  This will show us
> what its trying to do right before it hits the eof, but it will also
> generate a lot of noise as things scan the metadata table.
> 
>  private byte[] read(DataInput in) throws IOException {
>    int len = WritableUtils.readVInt(in);
>    Logger.getLogger(RelativeKey.class.getName()).debug("len : " + len);
>    byte[] data = new byte[len];
>    in.readFully(data);
>    Logger.getLogger(RelativeKey.class.getName()).debug("data : " +
> new String(data).substring(0, Math.min(data.length, 60)));
>    return data;
>  }
> 
> Keith
> 
> On Tue, Apr 10, 2012 at 2:08 PM, Keys Botzum <kbotzum@maprtech.com> wrote:
>> At this point all but two of the Accumulo test/system/auto tests have completed successfully.
This test is failing and I'm not quite sure why: org.apache.accumulo.server.test.functional.LargeRowTest
>> 
>> When I run it, this is the output I see:
>> ./run.py -t largerowtest -d -v10
>> ….
>> 09:45:18 runTest (simple.largeRow.LargeRowTest) ............................. DEBUG:test.auto:localhost:
/opt/accumulo-1.4.0/bin/accumulo org.apache.accumulo.server.test.functional.FunctionalTest
-m localhost -u root -p secret -i SE-test-04-22187 org.apache.accumulo.server.test.functional.LargeRowTest
getConfig
>> DEBUG:test.auto:{
>> 'tserver.compaction.major.delay':'1',
>> }
>> 
>> DEBUG:test.auto:
>> INFO:test.auto:killing accumulo processes everywhere
>> DEBUG:test.auto:localhost: /opt/accumulo-1.4.0/test/system/auto/pkill.sh 9 1000 SE-test-04-22187.*org.apache.accumulo.start
>> DEBUG:test.auto:localhost: hadoop fs -rmr /user/mapr/accumulo-SE-test-04-22187
>> INFO:test.auto:Error output from command: rmr: cannot remove /user/mapr/accumulo-SE-test-04-22187:
No such file or directory.
>> DEBUG:test.auto:Exit code: 255
>> DEBUG:test.auto:localhost: /opt/accumulo-1.4.0/bin/accumulo init --clear-instance-name
>> DEBUG:test.auto:Output from command: 10 09:45:20,539 [util.Initialize] INFO : Hadoop
Filesystem is maprfs:///
>> 10 09:45:20,541 [util.Initialize] INFO : Accumulo data dir is /user/mapr/accumulo-SE-test-04-22187
>> 10 09:45:20,541 [util.Initialize] INFO : Zookeeper server is SE-test-00:5181,SE-test-01:5181,SE-test-02:5181
>> Instance name : SE-test-04-22187
>> Enter initial password for root: ******
>> Confirm initial password for root: ******
>> 10 09:45:21,442 [util.NativeCodeLoader] INFO : Loaded the native-hadoop library
>> 10 09:45:21,562 [security.ZKAuthenticator] INFO : Initialized root user with username:
root at the request of user !SYSTEM
>> DEBUG:test.auto:Exit code: 0
>> DEBUG:test.auto:localhost: /opt/accumulo-1.4.0/bin/accumulo logger
>> DEBUG:test.auto:localhost: /opt/accumulo-1.4.0/bin/accumulo tserver
>> DEBUG:test.auto:localhost: /opt/accumulo-1.4.0/bin/accumulo monitor
>> DEBUG:test.auto:localhost: /opt/accumulo-1.4.0/bin/accumulo org.apache.accumulo.server.master.state.SetGoalState
NORMAL
>> DEBUG:test.auto:Output from command: 10 09:45:22,529 [server.Accumulo] INFO : Attempting
to talk to zookeeper
>> 10 09:45:22,750 [server.Accumulo] INFO : Zookeeper connected and initialized, attemping
to talk to HDFS
>> 10 09:45:23,009 [server.Accumulo] INFO : Connected to HDFS
>> DEBUG:test.auto:Exit code: 0
>> DEBUG:test.auto:localhost: /opt/accumulo-1.4.0/bin/accumulo master
>> DEBUG:test.auto:localhost: /opt/accumulo-1.4.0/bin/accumulo org.apache.accumulo.server.test.functional.FunctionalTest
-m localhost -u root -p secret -i SE-test-04-22187 org.apache.accumulo.server.test.functional.LargeRowTest
setup
>> DEBUG:test.auto:
>> DEBUG:test.auto:
>> DEBUG:test.auto:localhost: /opt/accumulo-1.4.0/bin/accumulo org.apache.accumulo.server.test.functional.FunctionalTest
-m localhost -u root -p secret -i SE-test-04-22187 org.apache.accumulo.server.test.functional.LargeRowTest
run
>> DEBUG:test.auto:Waiting for /opt/accumulo-1.4.0/bin/accumulo org.apache.accumulo.server.test.functional.FunctionalTest
-m localhost -u root -p secret -i SE-test-04-22187 org.apache.accumulo.server.test.functional.LargeRowTest
run to stop in 240 secs
>> DEBUG:test.auto:err: Thread "org.apache.accumulo.server.test.functional.FunctionalTest"
died null
>> DEBUG:test.auto:err: java.lang.reflect.InvocationTargetException
>>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>>        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>> DEBUG:test.auto:err:    at java.lang.reflect.Method.invoke(Method.java:597)
>>        at org.apache.accumulo.start.Main$1.run(Main.java:89)
>>        at java.lang.Thread.run(Thread.java:662)
>> Caused by: java.lang.RuntimeException: org.apache.accumulo.core.client.impl.AccumuloServerException:
Error on server 10.250.99.204:39253
>> DEBUG:test.auto:err:
>>        at org.apache.accumulo.core.client.impl.ScannerIterator.hasNext(ScannerIterator.java:186)
>>        at org.apache.accumulo.server.test.functional.LargeRowTest.verify(LargeRowTest.java:165)
>>        at org.apache.accumulo.server.test.functional.LargeRowTest.basicTest(LargeRowTest.java:143)
>>        at org.apache.accumulo.server.test.functional.LargeRowTest.test2(LargeRowTest.java:104)
>>        at org.apache.accumulo.server.test.functional.LargeRowTest.run(LargeRowTest.java:87)
>>        at org.apache.accumulo.server.test.functional.FunctionalTest.main(FunctionalTest.java:312)
>>        ... 6 more
>> DEBUG:test.auto:err: Caused by: org.apache.accumulo.core.client.impl.AccumuloServerException:
Error on server 10.250.99.204:39253
>>        at org.apache.accumulo.core.client.impl.ThriftScanner.scan(ThriftScanner.java:302)
>>        at org.apache.accumulo.core.client.impl.ScannerIterator$Reader.run(ScannerIterator.java:94)
>>        at org.apache.accumulo.core.client.impl.ScannerIterator.hasNext(ScannerIterator.java:176)
>>        ... 11 more
>> Caused by: org.apache.thrift.TApplicationException: Internal error processing startScan
>>        at org.apache.thrift.TApplicationException.read(TApplicationException.java:108)
>>        at org.apache.accumulo.core.tabletserver.thrift.TabletClientService$Client.recv_startScan(TabletClientService.java:184)
>>        at org.apache.accumulo.core.tabletserver.thrift.TabletClientService$Client.startScan(TabletClientService.java:157)
>>        at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
>>        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>        at java.lang.reflect.Method.invoke(Method.java:597)
>> DEBUG:test.auto:err:
>>        at org.apache.accumulo.cloudtrace.instrument.thrift.TraceWrap$2.invoke(TraceWrap.java:84)
>>        at $Proxy1.startScan(Unknown Source)
>>        at org.apache.accumulo.core.client.impl.ThriftScanner.scan(ThriftScanner.java:415)
>>        at org.apache.accumulo.core.client.impl.ThriftScanner.scan(ThriftScanner.java:295)
>>        ... 13 more
>> ERROR:test.auto:This looks like a stack trace: Thread "org.apache.accumulo.server.test.functional.FunctionalTest"
died null
>> java.lang.reflect.InvocationTargetException
>>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>>        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>        at java.lang.reflect.Method.invoke(Method.java:597)
>>        at org.apache.accumulo.start.Main$1.run(Main.java:89)
>>        at java.lang.Thread.run(Thread.java:662)
>> Caused by: java.lang.RuntimeException: org.apache.accumulo.core.client.impl.AccumuloServerException:
Error on server 10.250.99.204:39253
>>        at org.apache.accumulo.core.client.impl.ScannerIterator.hasNext(ScannerIterator.java:186)
>>        at org.apache.accumulo.server.test.functional.LargeRowTest.verify(LargeRowTest.java:165)
>>        at org.apache.accumulo.server.test.functional.LargeRowTest.basicTest(LargeRowTest.java:143)
>>        at org.apache.accumulo.server.test.functional.LargeRowTest.test2(LargeRowTest.java:104)
>>        at org.apache.accumulo.server.test.functional.LargeRowTest.run(LargeRowTest.java:87)
>>        at org.apache.accumulo.server.test.functional.FunctionalTest.main(FunctionalTest.java:312)
>>        ... 6 more
>> Caused by: org.apache.accumulo.core.client.impl.AccumuloServerException: Error on
server 10.250.99.204:39253
>>        at org.apache.accumulo.core.client.impl.ThriftScanner.scan(ThriftScanner.java:302)
>>        at org.apache.accumulo.core.client.impl.ScannerIterator$Reader.run(ScannerIterator.java:94)
>>        at org.apache.accumulo.core.client.impl.ScannerIterator.hasNext(ScannerIterator.java:176)
>>        ... 11 more
>> Caused by: org.apache.thrift.TApplicationException: Internal error processing startScan
>>        at org.apache.thrift.TApplicationException.read(TApplicationException.java:108)
>>        at org.apache.accumulo.core.tabletserver.thrift.TabletClientService$Client.recv_startScan(TabletClientService.java:184)
>>        at org.apache.accumulo.core.tabletserver.thrift.TabletClientService$Client.startScan(TabletClientService.java:157)
>>        at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
>>        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>        at java.lang.reflect.Method.invoke(Method.java:597)
>>        at org.apache.accumulo.cloudtrace.instrument.thrift.TraceWrap$2.invoke(TraceWrap.java:84)
>>        at $Proxy1.startScan(Unknown Source)
>>        at org.apache.accumulo.core.client.impl.ThriftScanner.scan(ThriftScanner.java:415)
>>        at org.apache.accumulo.core.client.impl.ThriftScanner.scan(ThriftScanner.java:295)
>>        ... 13 more
>> 
>> FAIL
>> ======================================================================
>> FAIL: runTest (simple.largeRow.LargeRowTest)
>> ----------------------------------------------------------------------
>> Traceback (most recent call last):
>>  File "/opt/accumulo-1.4.0/test/system/auto/JavaTest.py", line 57, in runTest
>>    self.waitForStop(handle, self.maxRuntime)
>>  File "/opt/accumulo-1.4.0/test/system/auto/TestUtils.py", line 368, in waitForStop
>>    self.assert_(self.processResult(out, err, handle.returncode))
>> AssertionError: False is not true
>> 
>> 
>> ======================================================================
>> FAIL: runTest (simple.largeRow.LargeRowTest)
>> ----------------------------------------------------------------------
>> Traceback (most recent call last):
>>  File "/opt/accumulo-1.4.0/test/system/auto/JavaTest.py", line 57, in runTest
>>    self.waitForStop(handle, self.maxRuntime)
>>  File "/opt/accumulo-1.4.0/test/system/auto/TestUtils.py", line 368, in waitForStop
>>    self.assert_(self.processResult(out, err, handle.returncode))
>> AssertionError: False is not true
>> 
>> ----------------------------------------------------------------------
>> Ran 1 test in 43.014s
>> 
>> FAILED (failures=1)
>> 
>> 
>> The only log that seems to have any relevant output is the tserver_xxxx.log file.
In it I found this error:
>> Note that the timestamps here do not match the previous timestamps. This is just
because I forgot to capture the data from the run that corresponds exactly to this run.
>> 
>> 
>> 09 06:14:22,466 [tabletserver.TabletServer] INFO : Adding 1 logs for extent 2;F]\\;J^>ioHJ*gs[4TwSIQeN_C^]1!w@7e<wL<p.xE&TR\\g!lt6+c^0a3U7%Eo'Ji
... TRUNCATED;CJlc"pWa)g<$Gg(\\U0Kl<)ffOYm1{h@E1"nV$)z'7'8KNWt- .BISxZoDI^[?7jR... TRUNCATED
as alias 16
>> 09 06:14:25,018 [tabletserver.TabletServer] WARN : exception while scanning tablet
2;h&["[>Er>fnBdhzAR_'I!Htot>R/hNK_vNG)Y1a%$DJWg#QyQHFZ RaUAF3[p!eb... TRUNCATED;\\]jx?h@XRt8nDO%{>vT-Et-P$b.<,-4b2osta{ZE\\$u9k2T-MpdF
_^<q\\M`X\\Er... TRUNCATED
>> java.io.IOException: invalid distance too far back
>>        at org.apache.hadoop.io.compress.zlib.ZlibDecompressor.inflateBytesDirect(Native
Method)
>>        at org.apache.hadoop.io.compress.zlib.ZlibDecompressor.decompress(ZlibDecompressor.java:221)
>>        at org.apache.hadoop.io.compress.DecompressorStream.decompress(DecompressorStream.java:81)
>>        at org.apache.hadoop.io.compress.DecompressorStream.read(DecompressorStream.java:75)
>>        at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
>>        at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
>>        at java.io.FilterInputStream.read(FilterInputStream.java:66)
>>        at java.io.DataInputStream.readByte(DataInputStream.java:248)
>>        at org.apache.accumulo.core.file.rfile.RelativeKey.readFields(RelativeKey.java:116)
>>        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader._next(RFile.java:584)
>>        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader.next(RFile.java:556)
>>        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
>>        at org.apache.accumulo.server.problems.ProblemReportingIterator.next(ProblemReportingIterator.java:77)
>>        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
>>        at org.apache.accumulo.core.iterators.system.DeletingIterator.next(DeletingIterator.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.user.VersioningIterator.skipRowColumn(VersioningIterator.java:103)
>>        at org.apache.accumulo.core.iterators.user.VersioningIterator.next(VersioningIterator.java:53)
>>        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.readNext(SourceSwitchingIterator.java:120)
>>        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.next(SourceSwitchingIterator.java:105)
>>        at org.apache.accumulo.server.tabletserver.Tablet.nextBatch(Tablet.java:1766)
>>        at org.apache.accumulo.server.tabletserver.Tablet.access$3200(Tablet.java:143)
>>        at org.apache.accumulo.server.tabletserver.Tablet$Scanner.read(Tablet.java:1883)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler$NextBatchTask.run(TabletServer.java:905)
>>        at org.apache.accumulo.cloudtrace.instrument.TraceRunnable.run(TraceRunnable.java:47)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        at java.lang.Thread.run(Thread.java:662)
>> 09 06:14:25,020 [tabletserver.TabletServer] INFO : Adding 1 logs for extent !0<;~
as alias 2
>> 09 06:14:25,022 [thrift.TabletClientService$Processor] ERROR: Internal error processing
startScan
>> java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.io.IOException:
invalid distance too far back
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler.continueScan(TabletServer.java:1155)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler.startScan(TabletServer.java:1110)
>>        at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
>>        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>        at java.lang.reflect.Method.invoke(Method.java:597)
>>        at org.apache.accumulo.cloudtrace.instrument.thrift.TraceWrap$1.invoke(TraceWrap.java:59)
>>        at $Proxy0.startScan(Unknown Source)
>>        at org.apache.accumulo.core.tabletserver.thrift.TabletClientService$Processor$startScan.process(TabletClientService.java:2059)
>>        at org.apache.accumulo.core.tabletserver.thrift.TabletClientService$Processor.process(TabletClientService.java:2037)
>>        at org.apache.accumulo.server.util.TServerUtils$TimedProcessor.process(TServerUtils.java:154)
>>        at org.apache.thrift.server.TNonblockingServer$FrameBuffer.invoke(TNonblockingServer.java:631)
>>        at org.apache.accumulo.server.util.TServerUtils$THsHaServer$Invocation.run(TServerUtils.java:202)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        at org.apache.accumulo.core.util.LoggingRunnable.run(LoggingRunnable.java:34)
>>        at java.lang.Thread.run(Thread.java:662)
>> Caused by: java.util.concurrent.ExecutionException: java.io.IOException: invalid
distance too far back
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ScanTask.get(TabletServer.java:662)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler.continueScan(TabletServer.java:1146)
>>        ... 15 more
>> Caused by: java.io.IOException: invalid distance too far back
>>        at org.apache.hadoop.io.compress.zlib.ZlibDecompressor.inflateBytesDirect(Native
Method)
>>        at org.apache.hadoop.io.compress.zlib.ZlibDecompressor.decompress(ZlibDecompressor.java:221)
>>        at org.apache.hadoop.io.compress.DecompressorStream.decompress(DecompressorStream.java:81)
>>        at org.apache.hadoop.io.compress.DecompressorStream.read(DecompressorStream.java:75)
>>        at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
>>        at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
>>        at java.io.FilterInputStream.read(FilterInputStream.java:66)
>>        at java.io.DataInputStream.readByte(DataInputStream.java:248)
>>        at org.apache.accumulo.core.file.rfile.RelativeKey.readFields(RelativeKey.java:116)
>>        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader._next(RFile.java:584)
>>        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader.next(RFile.java:556)
>>        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
>>        at org.apache.accumulo.server.problems.ProblemReportingIterator.next(ProblemReportingIterator.java:77)
>>        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
>>        at org.apache.accumulo.core.iterators.system.DeletingIterator.next(DeletingIterator.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.user.VersioningIterator.skipRowColumn(VersioningIterator.java:103)
>>        at org.apache.accumulo.core.iterators.user.VersioningIterator.next(VersioningIterator.java:53)
>>        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.readNext(SourceSwitchingIterator.java:120)
>>        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.next(SourceSwitchingIterator.java:105)
>>        at org.apache.accumulo.server.tabletserver.Tablet.nextBatch(Tablet.java:1766)
>>        at org.apache.accumulo.server.tabletserver.Tablet.access$3200(Tablet.java:143)
>>        at org.apache.accumulo.server.tabletserver.Tablet$Scanner.read(Tablet.java:1883)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler$NextBatchTask.run(TabletServer.java:905)
>>        at org.apache.accumulo.cloudtrace.instrument.TraceRunnable.run(TraceRunnable.java:47)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        ... 1 more
>> 
>> 
>> After guessing that the zlib error might be hiding the "real" error, I decided to
disable compression in Accumulo (compression in MapR is transparent and the results are not
affected by whether it is on or off). Normally I'd set table.file.compress.type to none in
the accumulo-site.xml file but that doesn't work for the tests as they generate they own site
files automatically. I hand edited TestUtil.py to generate a site file with that property
set.
>> 
>> When I rerun the test, I get the same output from run.py, but the server error in
tserver_xxx.log is very different:
>> 
>> 10 09:45:51,650 [tabletserver.TabletServer] INFO : Adding 1 logs for extent 2;(8{]laDN>C?'1D\\;K]l:fS\\lVXKOWq[_'&8".>-wL$Y,x-k<18_#t:7CHMH:\\)Zga...
TRUNCATED;%9e.07Zx{t*taPSI\\;I4z*77vIG[Oa&(Dw?4_N(!OIA#Z(ZE%"v3gI9Q{ZlGNAGL@... TRUNCATED
as alias 8
>> 10 09:45:51,693 [tabletserver.TabletServer] INFO : Adding 1 logs for extent 2;k9TF\\;hI"]Ij'4\\P.t&'pJm3"\\;C0qd:Q>%G3>I6!5[pVN$5R0g1LwmPUg
5-fX4jG... TRUNCATED;h&["[>Er>fnBdhzAR_'I!Htot>R/hNK_vNG)Y1a%$DJWg#QyQHFZ RaUAF3[p!eb...
TRUNCATED as alias 22
>> 10 09:45:51,748 [tabletserver.TabletServer] INFO : Adding 1 logs for extent 2;F]\\;J^>ioHJ*gs[4TwSIQeN_C^]1!w@7e<wL<p.xE&TR\\g!lt6+c^0a3U7%Eo'Ji
... TRUNCATED;CJlc"pWa)g<$Gg(\\U0Kl<)ffOYm1{h@E1"nV$)z'7'8KNWt- .BISxZoDI^[?7jR... TRUNCATED
as alias 16
>> 10 09:46:00,996 [tabletserver.TabletServer] WARN : exception while scanning tablet
2;%9e.07Zx{t*taPSI\\;I4z*77vIG[Oa&(Dw?4_N(!OIA#Z(ZE%"v3gI9Q{ZlGNAGL@... TRUNCATED<
>> java.io.EOFException
>>        at java.io.DataInputStream.readFully(DataInputStream.java:180)
>>        at java.io.DataInputStream.readFully(DataInputStream.java:152)
>>        at org.apache.accumulo.core.file.rfile.RelativeKey.read(RelativeKey.java:378)
>>        at org.apache.accumulo.core.file.rfile.RelativeKey.readFields(RelativeKey.java:134)
>>        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader._next(RFile.java:584)
>>        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader.next(RFile.java:556)
>>        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
>>        at org.apache.accumulo.server.problems.ProblemReportingIterator.next(ProblemReportingIterator.java:77)
>>        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
>>        at org.apache.accumulo.core.iterators.system.DeletingIterator.next(DeletingIterator.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.user.VersioningIterator.skipRowColumn(VersioningIterator.java:103)
>>        at org.apache.accumulo.core.iterators.user.VersioningIterator.next(VersioningIterator.java:53)
>>        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.readNext(SourceSwitchingIterator.java:120)
>>        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.next(SourceSwitchingIterator.java:105)
>>        at org.apache.accumulo.server.tabletserver.Tablet.nextBatch(Tablet.java:1766)
>>        at org.apache.accumulo.server.tabletserver.Tablet.access$3200(Tablet.java:143)
>>        at org.apache.accumulo.server.tabletserver.Tablet$Scanner.read(Tablet.java:1883)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler$NextBatchTask.run(TabletServer.java:905)
>>        at org.apache.accumulo.cloudtrace.instrument.TraceRunnable.run(TraceRunnable.java:47)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        at java.lang.Thread.run(Thread.java:662)
>> 10 09:46:00,999 [tabletserver.TabletServer] INFO : Adding 1 logs for extent !0<;~
as alias 2
>> 10 09:46:01,000 [thrift.TabletClientService$Processor] ERROR: Internal error processing
startScan
>> java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.io.EOFException
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler.continueScan(TabletServer.java:1155)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler.startScan(TabletServer.java:1110)
>>        at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
>>        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>        at java.lang.reflect.Method.invoke(Method.java:597)
>>        at org.apache.accumulo.cloudtrace.instrument.thrift.TraceWrap$1.invoke(TraceWrap.java:59)
>>        at $Proxy0.startScan(Unknown Source)
>>        at org.apache.accumulo.core.tabletserver.thrift.TabletClientService$Processor$startScan.process(TabletClientService.java:2059)
>>        at org.apache.accumulo.core.tabletserver.thrift.TabletClientService$Processor.process(TabletClientService.java:2037)
>>        at org.apache.accumulo.server.util.TServerUtils$TimedProcessor.process(TServerUtils.java:154)
>>        at org.apache.thrift.server.TNonblockingServer$FrameBuffer.invoke(TNonblockingServer.java:631)
>>        at org.apache.accumulo.server.util.TServerUtils$THsHaServer$Invocation.run(TServerUtils.java:202)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        at org.apache.accumulo.core.util.LoggingRunnable.run(LoggingRunnable.java:34)
>>        at java.lang.Thread.run(Thread.java:662)
>> Caused by: java.util.concurrent.ExecutionException: java.io.EOFException
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ScanTask.get(TabletServer.java:662)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler.continueScan(TabletServer.java:1146)
>>        ... 15 more
>> Caused by: java.io.EOFException
>>        at java.io.DataInputStream.readFully(DataInputStream.java:180)
>>        at java.io.DataInputStream.readFully(DataInputStream.java:152)
>>        at org.apache.accumulo.core.file.rfile.RelativeKey.read(RelativeKey.java:378)
>>        at org.apache.accumulo.core.file.rfile.RelativeKey.readFields(RelativeKey.java:134)
>>        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader._next(RFile.java:584)
>>        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader.next(RFile.java:556)
>>        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
>>        at org.apache.accumulo.server.problems.ProblemReportingIterator.next(ProblemReportingIterator.java:77)
>>        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
>>        at org.apache.accumulo.core.iterators.system.DeletingIterator.next(DeletingIterator.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.user.VersioningIterator.skipRowColumn(VersioningIterator.java:103)
>>        at org.apache.accumulo.core.iterators.user.VersioningIterator.next(VersioningIterator.java:53)
>>        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.readNext(SourceSwitchingIterator.java:120)
>>        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.next(SourceSwitchingIterator.java:105)
>>        at org.apache.accumulo.server.tabletserver.Tablet.nextBatch(Tablet.java:1766)
>>        at org.apache.accumulo.server.tabletserver.Tablet.access$3200(Tablet.java:143)
>>        at org.apache.accumulo.server.tabletserver.Tablet$Scanner.read(Tablet.java:1883)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler$NextBatchTask.run(TabletServer.java:905)
>>        at org.apache.accumulo.cloudtrace.instrument.TraceRunnable.run(TraceRunnable.java:47)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        at java.lang.Thread.run(Thread.java:662)
>> 10 09:46:00,999 [tabletserver.TabletServer] INFO : Adding 1 logs for extent !0<;~
as alias 2
>> 10 09:46:01,000 [thrift.TabletClientService$Processor] ERROR: Internal error processing
startScan
>> java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.io.EOFException
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler.continueScan(TabletServer.java:1155)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler.startScan(TabletServer.java:1110)
>>        at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
>>        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>        at java.lang.reflect.Method.invoke(Method.java:597)
>>        at org.apache.accumulo.cloudtrace.instrument.thrift.TraceWrap$1.invoke(TraceWrap.java:59)
>>        at $Proxy0.startScan(Unknown Source)
>>        at org.apache.accumulo.core.tabletserver.thrift.TabletClientService$Processor$startScan.process(TabletClientService.java:2059)
>>        at org.apache.accumulo.core.tabletserver.thrift.TabletClientService$Processor.process(TabletClientService.java:2037)
>>        at org.apache.accumulo.server.util.TServerUtils$TimedProcessor.process(TServerUtils.java:154)
>>        at org.apache.thrift.server.TNonblockingServer$FrameBuffer.invoke(TNonblockingServer.java:631)
>>        at org.apache.accumulo.server.util.TServerUtils$THsHaServer$Invocation.run(TServerUtils.java:202)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        at org.apache.accumulo.core.util.LoggingRunnable.run(LoggingRunnable.java:34)
>>        at java.lang.Thread.run(Thread.java:662)
>> Caused by: java.util.concurrent.ExecutionException: java.io.EOFException
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ScanTask.get(TabletServer.java:662)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler.continueScan(TabletServer.java:1146)
>>        ... 15 more
>> Caused by: java.io.EOFException
>>        at java.io.DataInputStream.readFully(DataInputStream.java:180)
>>        at java.io.DataInputStream.readFully(DataInputStream.java:152)
>>        at org.apache.accumulo.core.file.rfile.RelativeKey.read(RelativeKey.java:378)
>>        at org.apache.accumulo.core.file.rfile.RelativeKey.readFields(RelativeKey.java:134)
>>        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader._next(RFile.java:584)
>>        at org.apache.accumulo.core.file.rfile.RFile$LocalityGroupReader.next(RFile.java:556)
>>        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
>>        at org.apache.accumulo.server.problems.ProblemReportingIterator.next(ProblemReportingIterator.java:77)
>>        at org.apache.accumulo.core.iterators.system.HeapIterator.next(HeapIterator.java:80)
>>        at org.apache.accumulo.core.iterators.system.DeletingIterator.next(DeletingIterator.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.Filter.next(Filter.java:58)
>>        at org.apache.accumulo.core.iterators.WrappingIterator.next(WrappingIterator.java:87)
>>        at org.apache.accumulo.core.iterators.user.VersioningIterator.skipRowColumn(VersioningIterator.java:103)
>>        at org.apache.accumulo.core.iterators.user.VersioningIterator.next(VersioningIterator.java:53)
>>        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.readNext(SourceSwitchingIterator.java:120)
>>        at org.apache.accumulo.core.iterators.system.SourceSwitchingIterator.next(SourceSwitchingIterator.java:105)
>>        at org.apache.accumulo.server.tabletserver.Tablet.nextBatch(Tablet.java:1766)
>>        at org.apache.accumulo.server.tabletserver.Tablet.access$3200(Tablet.java:143)
>>        at org.apache.accumulo.server.tabletserver.Tablet$Scanner.read(Tablet.java:1883)
>>        at org.apache.accumulo.server.tabletserver.TabletServer$ThriftClientHandler$NextBatchTask.run(TabletServer.java:905)
>>        at org.apache.accumulo.cloudtrace.instrument.TraceRunnable.run(TraceRunnable.java:47)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        ... 1 more
>> 
>> 
>> So the error would seem to be related to reading past the end of the file. What I
can't determine is what is the reason. From examining the Accumulo source, it's clear that
Accumulo has read the length of a key (I think) and is now trying to read the key value. That
second read is what is failing. The question is why? Some ideas:
>> 1) the file was originally written incorrectly by the writer,
>> 2) the reader is reading too far
>> 
>> This could be caused by a issue in Accumulo or in MapR. It might be that MapR more
strongly enforces end of file reads than stock Hadoop.
>> 
>> If anyone has suggestions on how to look into this further from the Accumulo side,
I'd really appreciate it.
>> 
>> Thanks,
>> Keys
>> ________________________________
>> Keys Botzum
>> Senior Principal Technologist
>> WW Systems Engineering
>> kbotzum@maprtech.com
>> 443-718-0098
>> MapR Technologies
>> http://www.mapr.com


Mime
View raw message