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

Mark Curtis edited comment on CASSANDRA-9862 at 8/3/15 9:18 AM:
----------------------------------------------------------------

Ok so we could add the following for more debugging would this level be ok or 
produce too much noise?

{code}
log4j.logger.org.apache.cassandra.db.compaction=DEBUG
{code}


was (Author: mark curtis):
Would there be a way of adding some more debugging to the compaction classes so 
we could get some more information in the logs perhaps when this problem occurs?

> Missing sstable files seen some time after the same file is logged as being 
> part of a compaction
> ------------------------------------------------------------------------------------------------
>
>                 Key: CASSANDRA-9862
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-9862
>             Project: Cassandra
>          Issue Type: Bug
>            Reporter: Mark Curtis
>            Assignee: Yuki Morishita
>
> The system will sometimes see a file not found exception in a given node’s 
> logs. This is seen after the same file appears in a compaction statement 
> either earlier on in the logs. I found the following events of potential 
> interest: 
> I pulled out the missing files using this command:
> {code}
> grep "Caused by: java.io.FileNotFoundException:" * | awk '{print $4}' | sort 
> -u > files-to-search
> {code}
> Using the following file as an example: 
> my_keyspace-my_table-jb-2085190-Data.db
> File is created from a flush
> system.log.10
> {code}
>    7549  INFO [FlushWriter:1] 2015-06-03 12:25:31,857 Memtable.java (line 
> 395) Completed flushing 
> /raid0/cassandra/data/my_keyspace/my_table/my_keyspace-my_table-jb-2085190-Data.d
>    7549 b (66804 bytes) for commitlog position 
> ReplayPosition(segmentId=1433333700832, position=2479196)
> {code}
> Next it appears in a compaction
> system.log.10
> {code}
>    8758  INFO [CompactionExecutor:5] 2015-06-03 12:25:37,209 
> CompactionTask.java (line 115) Compacting 
> [SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-data_viewer
>    
>   8758 _mapping-jb-2084993-Data.db'), 
> SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-my_table-jb-2085164-Data.db'),
>  SSTableReader(path='/raid0/cassand   
>   8758 
> ra/data/my_keyspace/my_table/my_keyspace-my_table-jb-2085190-Data.db'), 
> SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-data_viewer_m
> ...<truncated>...
> {code}
> The next time we see the file its in file not found exceptions
> {code}
> system.log.9
>   53811 java.lang.RuntimeException: java.io.FileNotFoundException: 
> /raid0/cassandra/data/my_keyspace/my_table/my_keyspace-my_table-jb-2085190-Data.db
>  (No such file or directory)
> {code}
> So going back to compaction executor 5 in system.log.10
> {code}
>    9102  INFO [CompactionExecutor:5] 2015-06-03 12:25:38,684 
> ColumnFamilyStore.java (line 794) Enqueuing flush of 
> Memtable-compactions_in_progress@1431151640(0/0 serialized/live bytes, 1 ops)
> ...
>    9107  INFO [CompactionExecutor:5] 2015-06-03 12:25:38,701 
> CompactionTask.java (line 287) Compacted 32 sstables to 
> [/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-data_viewer_mappi   
> 9107 ng-jb-2085196,].  1,970,986 bytes to 1,880,866 (~95% of original) in 
> 1,492ms = 1.202234MB/s.  13,576 total partitions merged to 11,243.  Partition 
> merge counts were {1:9379, 2:1474, 3:324, 4:54   9107 , 5:11, 6:1, }
>    9108  INFO [CompactionExecutor:5] 2015-06-03 12:25:38,702 
> ColumnFamilyStore.java (line 794) Enqueuing flush of 
> Memtable-compactions_in_progress@493376470(357/3570 serialized/live bytes, 16 
> ops)
> ...
>     9111  INFO [CompactionExecutor:5] 2015-06-03 12:25:38,717 
> CompactionTask.java (line 115) Compacting 
> [SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-data_viewer
>    
>     9111 _mapping-jb-2085182-Data.db'), 
> SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-my_table-jb-2085192-Data.db'),
>  SSTableReader(path='/raid0/cassand   
>     9111 
> ra/data/my_keyspace/my_table/my_keyspace-my_table-jb-2085175-Data.db'), 
> SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-data_viewer_m
>    
>     9111 apping-jb-2085196-Data.db'), 
> SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-my_table-jb-2085194-Data.db'),
>  SSTableReader(path='/raid0/cassandra   
>     9111 
> /data/my_keyspace/my_table/my_keyspace-my_table-jb-2085191-Data.db'), 
> SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-data_viewer_map
>    
>    9111 ping-jb-2085193-Data.db'), 
> SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-my_table-jb-2085195-Data.db'),
>  SSTableReader(path='/raid0/cassandra/d   
>    9111 ata/my_keyspace/my_table/my_keyspace-my_table-jb-2084985-Data.db'), 
> SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-data_viewer_mappi
>    
>    9111 ng-jb-2085114-Data.db'), 
> SSTableReader(path='/raid0/cassandra/data/my_keyspace/my_table/my_keyspace-my_table-jb-2084901-Data.db')]
>    9112 ERROR [CompactionExecutor:5] 2015-06-03 12:25:38,718 
> CassandraDaemon.java (line 199) Exception in thread 
> Thread[CompactionExecutor:5,1,main]
>    9113 java.lang.RuntimeException: java.io.FileNotFoundException: 
> /raid0/cassandra/data/my_keyspace/my_table/my_keyspace-my_table-jb-2084901-Data.db
>  (No such file or directory)
> {code}
> So could it be that because the thread "CompactionExecutor:5" hit an 
> exception in line 9113 that the compaction in 8758 didn't complete?



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to