Uploaded image for project: 'Accumulo'
  1. Accumulo
  2. ACCUMULO-3645

Iterators not run at compaction when tablets are empty

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • 1.6.1
    • 1.7.0
    • client, mini, tserver
    • None
    • Ubuntu 14.04, Accumulo 1.6.1, Hadoop 2.6.0, Zookeeper 3.4.6

    Description

      When an iterator is configured to run during a one-time manual major compaction on a tablet that is empty, the iterator never runs. It seems as if Accumulo never constructs the SKVI stack at all, because it tries to optimize by eliminating "unnecessary" tablet compactions. Also true of MiniAccumulo.

      This is bad for "generator" iterators that emit keys (in sorted order) not present in the tablet's data. They never have a chance to run.

      A workaround is for the client to insert "dummy data" into the tablets he wants to compact, before starting a compaction with "generator" iterators. Note that any data is sufficient, even delete keys, to ensure the SKVI stack is built and run through.

      Test file: InjectTest

      • method testInjectOnCompact_Empty fails because no data is in the tablets
      • method testInjectOnCompact passes because data is written into the tablets before initiating compaction.

      Two logs follow. Both have a DebugIterator set after an InjectIterator, an SKVI which "generates" hard-coded entries. The root user scans the table after flush and compact.

      Logs when no data in the tablets:

      2015-03-05 06:58:04,914 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:04,974 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.01 secs, nbTimes = [4 4 4.00 1] 
      2015-03-05 06:58:04,992 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:60455 15 entries in 0.01 secs (lookup_time:0.01 secs tablets:1 ranges:1) 
      2015-03-05 06:58:05,018 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:60455 2 entries in 0.00 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      2015-03-05 06:58:05,052 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 4 entries in 0.00 secs, nbTimes = [2 2 2.00 1] 
      2015-03-05 06:58:05,054 [tserver.TabletServer] DEBUG: Got compact message from user: !SYSTEM
      2015-03-05 06:58:05,135 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:60455 15 entries in 0.01 secs (lookup_time:0.01 secs tablets:1 ranges:1) 
      2015-03-05 06:58:05,138 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:36422 2 entries in 0.00 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      2015-03-05 06:58:05,384 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:36422 2 entries in 0.00 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      2015-03-05 06:58:05,386 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:60455 15 entries in 0.01 secs (lookup_time:0.01 secs tablets:1 ranges:1) 
      2015-03-05 06:58:05,504 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:60455 2 entries in 0.00 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      2015-03-05 06:58:05,509 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:36422 15 entries in 0.01 secs (lookup_time:0.01 secs tablets:1 ranges:1) 
      2015-03-05 06:58:06,069 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.01 secs, nbTimes = [3 3 3.00 1] 
      2015-03-05 06:58:06,158 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36456; 
      2015-03-05 06:58:06,158 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36456; 
      2015-03-05 06:58:06,168 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:36456 2 entries in 0.01 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      2015-03-05 06:58:06,174 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36456; 
      2015-03-05 06:58:06,174 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36456; action: scan; targetTable: test_InjectTest_testInjectOnCompact_Empty; authorizations: ; range: {5m;f<=[(-inf,f%00; : [] 9223372036854775807 false)]}; columns: []; iterators: []; iteratorOptions: {};
      2015-03-05 06:58:06,174 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36478; 
      2015-03-05 06:58:06,174 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36456; 
      2015-03-05 06:58:06,174 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36478; action: scan; targetTable: test_InjectTest_testInjectOnCompact_Empty; authorizations: ; range: {5m<;f=[[f%00; : [] 9223372036854775807 false,+inf)]}; columns: []; iterators: []; iteratorOptions: {};
      2015-03-05 06:58:06,175 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36478; 
      2015-03-05 06:58:06,176 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:36478 0 entries in 0.00 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      2015-03-05 06:58:06,176 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:36456 0 entries in 0.00 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      

      Logs when data is in the tablets:

      2015-03-05 06:58:31,673 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:31,674 [tserver.NativeMap] DEBUG: Allocated native map 0x000000000300ac20
      2015-03-05 06:58:31,674 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:60455 17 entries in 0.01 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      2015-03-05 06:58:31,676 [tserver.Tablet] DEBUG: MinC initiate lock 0.00 secs
      2015-03-05 06:58:31,676 [tserver.NativeMap] DEBUG: Allocated native map 0x000000000300acc0
      2015-03-05 06:58:31,676 [tserver.Tablet] DEBUG: MinC initiate lock 0.00 secs
      2015-03-05 06:58:31,684 [tserver.MinorCompactor] DEBUG: Begin minor compaction hdfs://localhost:9000/accumulo/tables/5n/t-00001h5/F00001h6.rf_tmp 5n;f<
      2015-03-05 06:58:31,691 [tserver.MinorCompactor] DEBUG: Begin minor compaction hdfs://localhost:9000/accumulo/tables/5n/default_tablet/F00001h7.rf_tmp 5n<;f
      2015-03-05 06:58:31,725 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [1 1 1.00 1] 
      2015-03-05 06:58:31,726 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:31,766 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:60455 2 entries in 0.00 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      2015-03-05 06:58:31,779 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [1 1 1.00 1] 
      2015-03-05 06:58:31,780 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:31,833 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [1 1 1.00 1] 
      2015-03-05 06:58:31,834 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:31,886 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [1 1 1.00 1] 
      2015-03-05 06:58:31,887 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:31,939 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [1 1 1.00 1] 
      2015-03-05 06:58:31,940 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:31,992 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [1 1 1.00 1] 
      2015-03-05 06:58:31,993 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:32,046 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [0 0 0.00 1] 
      2015-03-05 06:58:32,047 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:32,099 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [1 1 1.00 1] 
      2015-03-05 06:58:32,100 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:32,147 [tserver.Compactor] DEBUG: Compaction 5n;f< 1 read | 1 written | 2,147,483,647 entries/sec |  0.000 secs
      2015-03-05 06:58:32,148 [tserver.Compactor] DEBUG: Compaction 5n<;f 2 read | 2 written | 2,147,483,647 entries/sec |  0.000 secs
      2015-03-05 06:58:32,153 [tserver.Tablet] DEBUG: Logs for memory compacted: 5n;f< localhost:9997/hdfs://localhost:9000/accumulo/wal/localhost+9997/706df902-2745-4c08-86bf-dfd4e9b8c729
      2015-03-05 06:58:32,153 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [2 2 2.00 1] 
      2015-03-05 06:58:32,153 [tserver.Tablet] DEBUG: Logs to be destroyed: 5n;f< localhost:9997/hdfs://localhost:9000/accumulo/wal/localhost+9997/706df902-2745-4c08-86bf-dfd4e9b8c729
      2015-03-05 06:58:32,155 [tserver.Tablet] DEBUG: Logs for memory compacted: 5n<;f localhost:9997/hdfs://localhost:9000/accumulo/wal/localhost+9997/706df902-2745-4c08-86bf-dfd4e9b8c729
      2015-03-05 06:58:32,155 [tserver.Tablet] DEBUG: Logs to be destroyed: 5n<;f localhost:9997/hdfs://localhost:9000/accumulo/wal/localhost+9997/706df902-2745-4c08-86bf-dfd4e9b8c729
      2015-03-05 06:58:32,155 [tserver.TabletServer] DEBUG: Got flush message from user: !SYSTEM
      2015-03-05 06:58:32,172 [log.TabletServerLogger] DEBUG:  wrote MinC finish  400: writeTime:10ms 
      2015-03-05 06:58:32,173 [tserver.Tablet] TABLET_HIST: 5n;f< MinC [memory] -> hdfs://localhost:9000/accumulo/tables/5n/t-00001h5/F00001h6.rf
      2015-03-05 06:58:32,173 [tserver.Tablet] DEBUG: MinC finish lock 0.00 secs 5n;f<
      2015-03-05 06:58:32,173 [tserver.NativeMap] DEBUG: Deallocating native map 0x00000000037a1720
      2015-03-05 06:58:32,178 [log.TabletServerLogger] DEBUG:  wrote MinC finish  401: writeTime:11ms 
      2015-03-05 06:58:32,178 [tserver.Tablet] TABLET_HIST: 5n<;f MinC [memory] -> hdfs://localhost:9000/accumulo/tables/5n/default_tablet/F00001h7.rf
      2015-03-05 06:58:32,178 [tserver.Tablet] DEBUG: MinC finish lock 0.00 secs 5n<;f
      2015-03-05 06:58:32,178 [tserver.NativeMap] DEBUG: Deallocating native map 0x000000000300aaa0
      2015-03-05 06:58:32,208 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [1 1 1.00 1] 
      2015-03-05 06:58:32,253 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 4 entries in 0.00 secs, nbTimes = [1 1 1.00 1] 
      2015-03-05 06:58:32,254 [tserver.TabletServer] DEBUG: Got compact message from user: !SYSTEM
      2015-03-05 06:58:32,256 [tserver.Tablet] DEBUG: Major compaction plan: null propogate deletes : false
      2015-03-05 06:58:32,256 [tserver.Tablet] DEBUG: MajC initiate lock 0.00 secs, wait 0.00 secs
      2015-03-05 06:58:32,256 [tserver.Tablet] DEBUG: Major compaction plan: null propogate deletes : false
      2015-03-05 06:58:32,256 [tserver.Tablet] DEBUG: MajC initiate lock 0.00 secs, wait 0.00 secs
      2015-03-05 06:58:32,257 [tserver.Tablet] DEBUG: Starting MajC 5n<;f (USER) [hdfs://localhost:9000/accumulo/tables/5n/default_tablet/F00001h7.rf] --> hdfs://localhost:9000/accumulo/tables/5n/default_tablet/A00001h8.rf_tmp  [name:InjectIterator, priority:15, class:edu.mit.ll.graphulo.InjectIterator, properties:{}, name:DebugIterator, priority:16, class:org.apache.accumulo.core.iterators.DebugIterator, properties:{}]
      2015-03-05 06:58:32,257 [tserver.Tablet] DEBUG: Starting MajC 5n;f< (USER) [hdfs://localhost:9000/accumulo/tables/5n/t-00001h5/F00001h6.rf] --> hdfs://localhost:9000/accumulo/tables/5n/t-00001h5/A00001h9.rf_tmp  [name:InjectIterator, priority:15, class:edu.mit.ll.graphulo.InjectIterator, properties:{}, name:DebugIterator, priority:16, class:org.apache.accumulo.core.iterators.DebugIterator, properties:{}]
      2015-03-05 06:58:32,270 [graphulo.BranchIterator] INFO : class edu.mit.ll.graphulo.InjectIterator: init on scope majc fullScan=true
      2015-03-05 06:58:32,270 [iterators.DebugIterator] DEBUG: init(edu.mit.ll.graphulo.InjectIterator@20a11899, {}, org.apache.accumulo.tserver.TabletIteratorEnvironment@3055f58b)
      2015-03-05 06:58:32,271 [iterators.DebugIterator] DEBUG: 0x5B6B9177 seek([f%00; : [] 9223372036854775807 false,+inf), [], false)
      2015-03-05 06:58:32,272 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> true
      2015-03-05 06:58:32,272 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopKey() --> kTablet2 :cq [] 1425556711614 false
      2015-03-05 06:58:32,272 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> true
      2015-03-05 06:58:32,272 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopKey() --> kTablet2 :cq [] 1425556711614 false
      2015-03-05 06:58:32,272 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> true
      2015-03-05 06:58:32,272 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopKey() --> kTablet2 :cq [] 1425556711614 false
      2015-03-05 06:58:32,272 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopValue() --> 7
      2015-03-05 06:58:32,272 [iterators.DebugIterator] DEBUG: 0x5B6B9177 next()
      2015-03-05 06:58:32,272 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> true
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopKey() --> m1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> true
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopKey() --> m1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> true
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopKey() --> m1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopValue() --> 1
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 next()
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> true
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopKey() --> zTablet2 :cq [] 1425556711614 false
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> true
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopKey() --> zTablet2 :cq [] 1425556711614 false
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> true
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopKey() --> zTablet2 :cq [] 1425556711614 false
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 getTopValue() --> 7
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 next()
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> false
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> false
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> false
      2015-03-05 06:58:32,273 [iterators.DebugIterator] DEBUG: 0x5B6B9177 hasTop() --> false
      2015-03-05 06:58:32,275 [graphulo.BranchIterator] INFO : class edu.mit.ll.graphulo.InjectIterator: init on scope majc fullScan=true
      2015-03-05 06:58:32,275 [iterators.DebugIterator] DEBUG: init(edu.mit.ll.graphulo.InjectIterator@6b76817, {}, org.apache.accumulo.tserver.TabletIteratorEnvironment@7312c172)
      2015-03-05 06:58:32,275 [iterators.DebugIterator] DEBUG: 0x545A5E63 seek((-inf,f%00; : [] 9223372036854775807 false), [], false)
      2015-03-05 06:58:32,276 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,276 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> a1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,276 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> a1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopValue() --> 1
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 next()
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> aTablet1 :cq [] 1425556711614 false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> aTablet1 :cq [] 1425556711614 false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> aTablet1 :cq [] 1425556711614 false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopValue() --> 7
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 next()
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> c1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> c1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> c1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopValue() --> 1
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 next()
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> m1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> m1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> true
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopKey() --> m1 colF3:colQ3 [] 1425553534769 false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 getTopValue() --> 1
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 next()
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> false
      2015-03-05 06:58:32,277 [iterators.DebugIterator] DEBUG: 0x545A5E63 hasTop() --> false
      2015-03-05 06:58:32,307 [tserver.Compactor] DEBUG: Compaction 5n<;f 2 read | 3 written |    181 entries/sec |  0.011 secs
      2015-03-05 06:58:32,320 [tserver.TabletServer] INFO : Adding 1 logs for extent !0<;~ as alias 3
      2015-03-05 06:58:32,340 [tserver.Tablet] DEBUG: MajC finish lock 0.00 secs
      2015-03-05 06:58:32,340 [tserver.Tablet] TABLET_HIST: 5n<;f MajC [hdfs://localhost:9000/accumulo/tables/5n/default_tablet/F00001h7.rf] --> hdfs://localhost:9000/accumulo/tables/5n/default_tablet/A00001h8.rf
      2015-03-05 06:58:32,612 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:36422 2 entries in 0.00 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      2015-03-05 06:58:32,612 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:60455 17 entries in 0.01 secs (lookup_time:0.01 secs tablets:1 ranges:1) 
      2015-03-05 06:58:32,718 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36525; 
      2015-03-05 06:58:32,722 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36525; 
      2015-03-05 06:58:32,725 [tserver.Compactor] DEBUG: Compaction 5n;f< 1 read | 4 written |     71 entries/sec |  0.014 secs
      2015-03-05 06:58:32,736 [tserver.TabletServer] DEBUG: UpSess 127.0.0.1:36525 59 in 0.018s, at=[0 0 0.00 1] ft=0.013s(pt=0.000s lt=0.013s ct=0.000s)
      2015-03-05 06:58:32,749 [tserver.Tablet] DEBUG: MajC finish lock 0.00 secs
      2015-03-05 06:58:32,749 [tserver.Tablet] TABLET_HIST: 5n;f< MajC [hdfs://localhost:9000/accumulo/tables/5n/t-00001h5/F00001h6.rf] --> hdfs://localhost:9000/accumulo/tables/5n/t-00001h5/A00001h9.rf
      2015-03-05 06:58:33,269 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:60455 !0 6 entries in 0.00 secs, nbTimes = [4 4 4.00 1] 
      2015-03-05 06:58:33,361 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36506; 
      2015-03-05 06:58:33,361 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36526; 
      2015-03-05 06:58:33,362 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36506; action: scan; targetTable: test_InjectTest_testInjectOnCompact; authorizations: ; range: {5n;f<=[(-inf,f%00; : [] 9223372036854775807 false)]}; columns: []; iterators: []; iteratorOptions: {};
      2015-03-05 06:58:33,362 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36526; action: scan; targetTable: test_InjectTest_testInjectOnCompact; authorizations: ; range: {5n<;f=[[f%00; : [] 9223372036854775807 false,+inf)]}; columns: []; iterators: []; iteratorOptions: {};
      2015-03-05 06:58:33,362 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36506; 
      2015-03-05 06:58:33,362 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36526; 
      2015-03-05 06:58:33,378 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:36526 3 entries in 0.02 secs (lookup_time:0.01 secs tablets:1 ranges:1) 
      2015-03-05 06:58:33,378 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:36506 3 entries in 0.02 secs (lookup_time:0.01 secs tablets:1 ranges:1) 
      2015-03-05 06:58:33,459 [tserver.TabletServer] DEBUG: ScanSess tid 127.0.0.1:36530 !0 0 entries in 0.00 secs, nbTimes = [0 0 0.00 1] 
      2015-03-05 06:58:33,493 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36525; 
      2015-03-05 06:58:33,495 [Audit   ] INFO : operation: permitted; user: root; client: 127.0.0.1:36525; 
      2015-03-05 06:58:33,505 [tserver.TabletServer] DEBUG: UpSess 127.0.0.1:36525 4 in 0.011s, at=[1 1 1.00 1] ft=0.008s(pt=0.000s lt=0.008s ct=0.000s)
      2015-03-05 06:58:33,580 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:60455 2 entries in 0.00 secs (lookup_time:0.00 secs tablets:1 ranges:1) 
      2015-03-05 06:58:33,586 [tserver.TabletServer] DEBUG: MultiScanSess 127.0.0.1:36422 17 entries in 0.01 secs (lookup_time:0.01 secs tablets:1 ranges:1) 
      

      Attachments

        Issue Links

          Activity

            People

              shutchis Shana Hutchison
              shutchis Shana Hutchison
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0h
                  0h
                  Logged:
                  Time Spent - 10m
                  10m