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
[email protected]
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 <[email protected]> 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
>> [email protected]
>> 443-718-0098
>> MapR Technologies
>> http://www.mapr.com
