Sometimes this happens because the lock file is not cleared. Did you look for the .lock file?
Regards Sab On 15 Feb 2017 8:59 p.m., "Frank Lyaruu" <flya...@gmail.com> wrote: > No, it sure isn't... The log file doesn't seem to have been touched for > hours. The whole log file seems to be of the same millisecond, but hours > before the stack trace (The stack trace is from 15:25). It seems to have > barfed out of nowhere without logging anything. > > 2017/02/15-12:38:07.061758 7f1cf0101700 RocksDB version: 5.0.1 > 2017/02/15-12:38:07.061812 7f1cf0101700 Git sha rocksdb_build_git_sha: > 2017/02/15-12:38:07.061816 7f1cf0101700 Compile date Jan 7 2017 > 2017/02/15-12:38:07.061817 7f1cf0101700 DB SUMMARY > 2017/02/15-12:38:07.061918 7f1cf0101700 CURRENT file: CURRENT > 2017/02/15-12:38:07.061920 7f1cf0101700 IDENTITY file: IDENTITY > 2017/02/15-12:38:07.061927 7f1cf0101700 MANIFEST file: MANIFEST-000007 > size: 33335 Bytes > 2017/02/15-12:38:07.061930 7f1cf0101700 SST files in > /output/env.managed.repository-master/storage/KNVB-test-generation-175- > othermatchpersons/1_0/rocksdb/KNVB-test-generation-175- > personcore-PERSONCORE > dir, Total Num: 7, files: 000353.sst 000355.sst 000356.sst 000459.sst > 000489.sst 000498.sst 000499.sst > 2017/02/15-12:38:07.061932 7f1cf0101700 Write Ahead Log file in > /output/env.managed.repository-master/storage/KNVB-test-generation-175- > othermatchpersons/1_0/rocksdb/KNVB-test-generation-175- > personcore-PERSONCORE: > 000003.log size: 0 ; > 2017/02/15-12:38:07.061935 7f1cf0101700 > Options.error_if_exists: 0 > 2017/02/15-12:38:07.061936 7f1cf0101700 > Options.create_if_missing: 1 > 2017/02/15-12:38:07.061937 7f1cf0101700 > Options.paranoid_checks: 1 > 2017/02/15-12:38:07.061938 7f1cf0101700 > Options.env: 0x7f1cefbf8440 > 2017/02/15-12:38:07.061939 7f1cf0101700 > Options.info_log: 0x7f1cd8649b40 > 2017/02/15-12:38:07.061940 7f1cf0101700 > Options.max_open_files: -1 > 2017/02/15-12:38:07.061941 7f1cf0101700 > Options.max_file_opening_threads: 16 > 2017/02/15-12:38:07.061942 7f1cf0101700 > Options.disableDataSync: 0 > 2017/02/15-12:38:07.061943 7f1cf0101700 > Options.use_fsync: 0 > 2017/02/15-12:38:07.061944 7f1cf0101700 > Options.max_log_file_size: 0 > 2017/02/15-12:38:07.061945 7f1cf0101700 > Options.max_manifest_file_size: 18446744073709551615 > 2017/02/15-12:38:07.061946 7f1cf0101700 > Options.log_file_time_to_roll: 0 > 2017/02/15-12:38:07.061946 7f1cf0101700 > Options.keep_log_file_num: 1000 > 2017/02/15-12:38:07.061947 7f1cf0101700 > Options.recycle_log_file_num: 0 > 2017/02/15-12:38:07.061948 7f1cf0101700 > Options.allow_os_buffer: 1 > 2017/02/15-12:38:07.061949 7f1cf0101700 > Options.allow_mmap_reads: 0 > 2017/02/15-12:38:07.061950 7f1cf0101700 > Options.allow_fallocate: 1 > 2017/02/15-12:38:07.061951 7f1cf0101700 > Options.allow_mmap_writes: 0 > 2017/02/15-12:38:07.061952 7f1cf0101700 > Options.use_direct_reads: 0 > 2017/02/15-12:38:07.061953 7f1cf0101700 > Options.create_missing_column_families: 0 > 2017/02/15-12:38:07.061954 7f1cf0101700 > Options.db_log_dir: > 2017/02/15-12:38:07.061955 7f1cf0101700 > Options.wal_dir: > /output/env.managed.repository-master/storage/KNVB-test-generation-175- > othermatchpersons/1_0/rocksdb/KNVB-test-generation-175- > personcore-PERSONCORE > 2017/02/15-12:38:07.061956 7f1cf0101700 > Options.table_cache_numshardbits: 6 > 2017/02/15-12:38:07.061957 7f1cf0101700 > Options.delete_obsolete_files_period_micros: 21600000000 > 2017/02/15-12:38:07.061958 7f1cf0101700 > Options.max_subcompactions: 1 > 2017/02/15-12:38:07.061958 7f1cf0101700 > Options.max_background_flushes: 1 > 2017/02/15-12:38:07.061959 7f1cf0101700 > Options.WAL_ttl_seconds: 0 > 2017/02/15-12:38:07.061960 7f1cf0101700 > Options.WAL_size_limit_MB: 0 > 2017/02/15-12:38:07.061961 7f1cf0101700 > Options.manifest_preallocation_size: 4194304 > 2017/02/15-12:38:07.061962 7f1cf0101700 > Options.allow_os_buffer: 1 > 2017/02/15-12:38:07.061963 7f1cf0101700 > Options.allow_mmap_reads: 0 > 2017/02/15-12:38:07.061964 7f1cf0101700 > Options.allow_mmap_writes: 0 > 2017/02/15-12:38:07.061965 7f1cf0101700 > Options.is_fd_close_on_exec: 1 > 2017/02/15-12:38:07.061992 7f1cf0101700 > Options.stats_dump_period_sec: 600 > 2017/02/15-12:38:07.061994 7f1cf0101700 > Options.advise_random_on_open: 1 > 2017/02/15-12:38:07.061995 7f1cf0101700 > Options.db_write_buffer_size: 0 > 2017/02/15-12:38:07.061996 7f1cf0101700 > Options.access_hint_on_compaction_start: 1 > 2017/02/15-12:38:07.061997 7f1cf0101700 > Options.new_table_reader_for_compaction_inputs: 0 > 2017/02/15-12:38:07.061998 7f1cf0101700 > Options.compaction_readahead_size: 0 > 2017/02/15-12:38:07.061999 7f1cf0101700 > Options.random_access_max_buffer_size: 1048576 > 2017/02/15-12:38:07.062000 7f1cf0101700 > Options.writable_file_max_buffer_size: 1048576 > 2017/02/15-12:38:07.062000 7f1cf0101700 > Options.use_adaptive_mutex: 0 > 2017/02/15-12:38:07.062001 7f1cf0101700 > Options.rate_limiter: (nil) > 2017/02/15-12:38:07.062003 7f1cf0101700 > Options.sst_file_manager.rate_bytes_per_sec: 0 > 2017/02/15-12:38:07.062004 7f1cf0101700 > Options.bytes_per_sync: 0 > 2017/02/15-12:38:07.062004 7f1cf0101700 > Options.wal_bytes_per_sync: 0 > 2017/02/15-12:38:07.062005 7f1cf0101700 > Options.wal_recovery_mode: 2 > 2017/02/15-12:38:07.062006 7f1cf0101700 > Options.enable_thread_tracking: 0 > 2017/02/15-12:38:07.062007 7f1cf0101700 > Options.allow_concurrent_memtable_write: 1 > 2017/02/15-12:38:07.062008 7f1cf0101700 > Options.enable_write_thread_adaptive_yield: 1 > 2017/02/15-12:38:07.062009 7f1cf0101700 > Options.write_thread_max_yield_usec: 100 > 2017/02/15-12:38:07.062010 7f1cf0101700 > Options.write_thread_slow_yield_usec: 3 > 2017/02/15-12:38:07.062011 7f1cf0101700 > Options.row_cache: None > 2017/02/15-12:38:07.062012 7f1cf0101700 > Options.wal_filter: None > 2017/02/15-12:38:07.062013 7f1cf0101700 > Options.avoid_flush_during_recovery: 0 > 2017/02/15-12:38:07.062014 7f1cf0101700 > Options.base_background_compactions: 1 > 2017/02/15-12:38:07.062015 7f1cf0101700 > Options.max_background_compactions: 1 > 2017/02/15-12:38:07.062016 7f1cf0101700 > Options.avoid_flush_during_shutdown: 0 > 2017/02/15-12:38:07.062017 7f1cf0101700 > Options.delayed_write_rate : 2097152 > 2017/02/15-12:38:07.062018 7f1cf0101700 > Options.max_total_wal_size: 0 > 2017/02/15-12:38:07.062018 7f1cf0101700 Compression algorithms supported: > 2017/02/15-12:38:07.062020 7f1cf0101700 Snappy supported: 1 > 2017/02/15-12:38:07.062021 7f1cf0101700 Zlib supported: 1 > 2017/02/15-12:38:07.062021 7f1cf0101700 Bzip supported: 1 > 2017/02/15-12:38:07.062022 7f1cf0101700 LZ4 supported: 1 > 2017/02/15-12:38:07.062023 7f1cf0101700 ZSTD supported: 0 > 2017/02/15-12:38:07.062024 7f1cf0101700 Fast CRC32 supported: 0 > 2017/02/15-12:38:07.062512 7f1cf0101700 Options.comparator: > leveldb.BytewiseComparator > 2017/02/15-12:38:07.062516 7f1cf0101700 Options.merge_operator: > None > 2017/02/15-12:38:07.062518 7f1cf0101700 Options.compaction_filter: > None > 2017/02/15-12:38:07.062519 7f1cf0101700 > Options.compaction_filter_factory: None > 2017/02/15-12:38:07.062520 7f1cf0101700 Options.memtable_factory: > SkipListFactory > 2017/02/15-12:38:07.062521 7f1cf0101700 Options.table_factory: > BlockBasedTable > 2017/02/15-12:38:07.062532 7f1cf0101700 table_factory options: > flush_block_policy_factory: FlushBlockBySizePolicyFactory (0x7f1d18fe03d0) > cache_index_and_filter_blocks: 0 > pin_l0_filter_and_index_blocks_in_cache: 0 > index_type: 0 > hash_index_allow_collision: 1 > checksum: 1 > no_block_cache: 0 > block_cache: 0x7f1cc4c8bbd8 > block_cache_size: 1048576 > block_cache_compressed: (nil) > block_size: 4096 > block_size_deviation: 10 > block_restart_interval: 16 > index_block_restart_interval: 1 > filter_policy: nullptr > whole_key_filtering: 1 > skip_table_builder_flush: 0 > format_version: 0 > 2017/02/15-12:38:07.062555 7f1cf0101700 Options.write_buffer_size: > 3145728 > 2017/02/15-12:38:07.062557 7f1cf0101700 Options.max_write_buffer_number: > 3 > 2017/02/15-12:38:07.062559 7f1cf0101700 Options.compression: LZ4 > 2017/02/15-12:38:07.062560 7f1cf0101700 > Options.bottommost_compression: Disabled > 2017/02/15-12:38:07.062561 7f1cf0101700 Options.prefix_extractor: > nullptr > 2017/02/15-12:38:07.062562 7f1cf0101700 > Options.memtable_insert_with_hint_prefix_extractor: nullptr > 2017/02/15-12:38:07.062563 7f1cf0101700 Options.num_levels: 7 > 2017/02/15-12:38:07.062564 7f1cf0101700 > Options.min_write_buffer_number_to_merge: 1 > 2017/02/15-12:38:07.062565 7f1cf0101700 > Options.max_write_buffer_number_to_maintain: 0 > 2017/02/15-12:38:07.062566 7f1cf0101700 > Options.compression_opts.window_bits: -14 > 2017/02/15-12:38:07.062567 7f1cf0101700 > Options.compression_opts.level: -1 > 2017/02/15-12:38:07.062568 7f1cf0101700 > Options.compression_opts.strategy: 0 > 2017/02/15-12:38:07.062569 7f1cf0101700 > Options.compression_opts.max_dict_bytes: 0 > 2017/02/15-12:38:07.062570 7f1cf0101700 > Options.level0_file_num_compaction_trigger: 4 > 2017/02/15-12:38:07.062571 7f1cf0101700 > Options.level0_slowdown_writes_trigger: 20 > 2017/02/15-12:38:07.062572 7f1cf0101700 > Options.level0_stop_writes_trigger: 32 > 2017/02/15-12:38:07.062572 7f1cf0101700 > Options.target_file_size_base: 67108864 > 2017/02/15-12:38:07.062573 7f1cf0101700 > Options.target_file_size_multiplier: 1 > 2017/02/15-12:38:07.062574 7f1cf0101700 > Options.max_bytes_for_level_base: 30000000 > 2017/02/15-12:38:07.062575 7f1cf0101700 > Options.level_compaction_dynamic_level_bytes: 0 > 2017/02/15-12:38:07.062576 7f1cf0101700 > Options.max_bytes_for_level_multiplier: 3.000000 > 2017/02/15-12:38:07.062581 7f1cf0101700 > Options.max_bytes_for_level_multiplier_addtl[0]: 1 > 2017/02/15-12:38:07.062582 7f1cf0101700 > Options.max_bytes_for_level_multiplier_addtl[1]: 1 > 2017/02/15-12:38:07.062583 7f1cf0101700 > Options.max_bytes_for_level_multiplier_addtl[2]: 1 > 2017/02/15-12:38:07.062584 7f1cf0101700 > Options.max_bytes_for_level_multiplier_addtl[3]: 1 > 2017/02/15-12:38:07.062585 7f1cf0101700 > Options.max_bytes_for_level_multiplier_addtl[4]: 1 > 2017/02/15-12:38:07.062585 7f1cf0101700 > Options.max_bytes_for_level_multiplier_addtl[5]: 1 > 2017/02/15-12:38:07.062586 7f1cf0101700 > Options.max_bytes_for_level_multiplier_addtl[6]: 1 > 2017/02/15-12:38:07.062587 7f1cf0101700 > Options.max_sequential_skip_in_iterations: 8 > 2017/02/15-12:38:07.062588 7f1cf0101700 > Options.max_compaction_bytes: 1677721600 > 2017/02/15-12:38:07.062589 7f1cf0101700 > Options.arena_block_size: 393216 > 2017/02/15-12:38:07.062590 7f1cf0101700 > Options.soft_pending_compaction_bytes_limit: 68719476736 > 2017/02/15-12:38:07.062591 7f1cf0101700 > Options.hard_pending_compaction_bytes_limit: 274877906944 > 2017/02/15-12:38:07.062592 7f1cf0101700 > Options.rate_limit_delay_max_milliseconds: 1000 > 2017/02/15-12:38:07.062593 7f1cf0101700 > Options.disable_auto_compactions: 0 > 2017/02/15-12:38:07.062594 7f1cf0101700 > Options.verify_checksums_in_compaction: 1 > 2017/02/15-12:38:07.062595 7f1cf0101700 > Options.compaction_style: 1 > 2017/02/15-12:38:07.062596 7f1cf0101700 > Options.compaction_pri: 0 > 2017/02/15-12:38:07.062597 7f1cf0101700 > Options.compaction_options_universal.size_ratio: 1 > 2017/02/15-12:38:07.062598 7f1cf0101700 > Options.compaction_options_universal.min_merge_width: 2 > 2017/02/15-12:38:07.062599 7f1cf0101700 > Options.compaction_options_universal.max_merge_width: 4294967295 > 2017/02/15-12:38:07.062600 7f1cf0101700 > Options.compaction_options_universal.max_size_amplification_percent: 200 > 2017/02/15-12:38:07.062601 7f1cf0101700 > Options.compaction_options_universal.compression_size_percent: -1 > 2017/02/15-12:38:07.062602 7f1cf0101700 > Options.compaction_options_fifo.max_table_files_size: 1073741824 > 2017/02/15-12:38:07.062602 7f1cf0101700 > Options.table_properties_collectors: > 2017/02/15-12:38:07.062615 7f1cf0101700 > Options.inplace_update_support: 0 > 2017/02/15-12:38:07.062616 7f1cf0101700 > Options.inplace_update_num_locks: 10000 > 2017/02/15-12:38:07.062617 7f1cf0101700 > Options.min_partial_merge_operands: 2 > 2017/02/15-12:38:07.062618 7f1cf0101700 > Options.memtable_prefix_bloom_size_ratio: 0.000000 > 2017/02/15-12:38:07.062620 7f1cf0101700 Options.memtable_huge_page_size: > 0 > 2017/02/15-12:38:07.062621 7f1cf0101700 > Options.bloom_locality: 0 > 2017/02/15-12:38:07.062622 7f1cf0101700 > Options.max_successive_merges: 0 > 2017/02/15-12:38:07.062623 7f1cf0101700 > Options.optimize_filters_for_hits: 0 > 2017/02/15-12:38:07.062624 7f1cf0101700 > Options.paranoid_file_checks: 0 > 2017/02/15-12:38:07.062625 7f1cf0101700 > Options.force_consistency_checks: 0 > 2017/02/15-12:38:07.062625 7f1cf0101700 > Options.report_bg_io_stats: 0 > > On Wed, Feb 15, 2017 at 3:56 PM, Damian Guy <damian....@gmail.com> wrote: > > > Hi Frank, > > > > Very hard to say from the stack trace. The exception isn't the most > > informative! > > Is there anything obvious in the RocksDB LOG? > > > > Thanks, > > Damian > > > > > > On Wed, 15 Feb 2017 at 06:38 Frank Lyaruu <flya...@gmail.com> wrote: > > > > > Hi Kafka crew, > > > > > > I'm rolling out a Kafka Streams application on a pretty large dataset, > > and > > > I see some exceptions that worry me, which I haven't seen with smaller > > data > > > sets > > > (Using Kafka streams trunk of a few days ago) > > > > > > 2017-02-15 15:25:14,431 | INFO | StreamThread-42 | StreamTask > > > | 86 - com.dexels.kafka.streams - 0.0.53.201702141103 | task > > > [9_4] Initializing state stores > > > 2017-02-15 15:25:14,433 | ERROR | StreamThread-42 | > ConsumerCoordinator > > > | 86 - com.dexels.kafka.streams - 0.0.53.201702141103 | User > > > provided listener > > > org.apache.kafka.streams.processor.internals.StreamThread$1 for group > > > KNVB-test-generation-175-person failed on partition assignment > > > org.apache.kafka.streams.errors.ProcessorStateException: Error opening > > > store KNVB-test-generation-175-person-sportlinkkernel- > > PERSONCOMMUNICATION > > > at location > > > > > > /output/env.managed.repository-master/storage/ > KNVB-test-generation-175- > > person/9_4/rocksdb/KNVB-test-generation-175-person-sportlinkkernel- > > PERSONCOMMUNICATION > > > at > > > > > > org.apache.kafka.streams.state.internals.RocksDBStore. > > openDB(RocksDBStore.java:175) > > > at > > > > > > org.apache.kafka.streams.state.internals.RocksDBStore. > > openDB(RocksDBStore.java:145) > > > at > > > > > > org.apache.kafka.streams.state.internals.RocksDBStore. > > init(RocksDBStore.java:150) > > > at > > > > > > org.apache.kafka.streams.state.internals.MeteredKeyValueStore$7.run( > > MeteredKeyValueStore.java:100) > > > at > > > > > > org.apache.kafka.streams.processor.internals.StreamsMetricsImpl. > > measureLatencyNs(StreamsMetricsImpl.java:188) > > > at > > > > > > org.apache.kafka.streams.state.internals.MeteredKeyValueStore.init( > > MeteredKeyValueStore.java:131) > > > at > > > > > > org.apache.kafka.streams.state.internals.CachingKeyValueStore.init( > > CachingKeyValueStore.java:62) > > > at > > > > > > org.apache.kafka.streams.processor.internals.AbstractTask. > > initializeStateStores(AbstractTask.java:85) > > > at > > > > > > org.apache.kafka.streams.processor.internals. > > StreamTask.<init>(StreamTask.java:143) > > > at > > > > > > org.apache.kafka.streams.processor.internals. > > StreamThread.createStreamTask(StreamThread.java:834) > > > at > > > > > > org.apache.kafka.streams.processor.internals.StreamThread$TaskCreator. > > createTask(StreamThread.java:1207) > > > at > > > > > > org.apache.kafka.streams.processor.internals.StreamThread$ > > AbstractTaskCreator.retryWithBackoff(StreamThread.java:1180) > > > at > > > > > > org.apache.kafka.streams.processor.internals. > > StreamThread.addStreamTasks(StreamThread.java:937) > > > at > > > > > > org.apache.kafka.streams.processor.internals.StreamThread.access$500( > > StreamThread.java:69) > > > at > > > > > > org.apache.kafka.streams.processor.internals.StreamThread$1. > > onPartitionsAssigned(StreamThread.java:236) > > > at > > > > > > org.apache.kafka.clients.consumer.internals.ConsumerCoordinator. > > onJoinComplete(ConsumerCoordinator.java:255) > > > at > > > > > > org.apache.kafka.clients.consumer.internals.AbstractCoordinator. > > joinGroupIfNeeded(AbstractCoordinator.java:339) > > > at > > > > > > org.apache.kafka.clients.consumer.internals.AbstractCoordinator. > > ensureActiveGroup(AbstractCoordinator.java:303) > > > at > > > > > > org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.poll( > > ConsumerCoordinator.java:286) > > > at > > > > > > org.apache.kafka.clients.consumer.KafkaConsumer. > > pollOnce(KafkaConsumer.java:1030) > > > at > > > > > > org.apache.kafka.clients.consumer.KafkaConsumer.poll( > > KafkaConsumer.java:995) > > > at > > > > > > org.apache.kafka.streams.processor.internals.StreamThread.runLoop( > > StreamThread.java:582) > > > at > > > > > > org.apache.kafka.streams.processor.internals. > > StreamThread.run(StreamThread.java:368) > > > Caused by: org.rocksdb.RocksDBException: > > > at org.rocksdb.RocksDB.open(Native Method) > > > at org.rocksdb.RocksDB.open(RocksDB.java:231) > > > at > > > > > > org.apache.kafka.streams.state.internals.RocksDBStore. > > openDB(RocksDBStore.java:168) > > > ... 22 more > > > > > > I've checked the folder it points to: > > > > > > [root@842376-demeter1 KNVB-test-generation-175-personcore-PERSONCORE]# > > ls > > > -l > > > total 223348 > > > -rw-r--r--. 1 431 433 68153335 Feb 15 11:09 000353.sst > > > -rw-r--r--. 1 431 433 68207125 Feb 15 11:09 000355.sst > > > -rw-r--r--. 1 431 433 7241027 Feb 15 11:09 000356.sst > > > -rw-r--r--. 1 431 433 59070938 Feb 15 11:12 000459.sst > > > -rw-r--r--. 1 431 433 18783280 Feb 15 11:13 000489.sst > > > -rw-r--r--. 1 431 433 0 Feb 15 11:38 000502.log > > > -rw-r--r--. 1 431 433 7183476 Feb 15 11:38 000505.sst > > > -rw-r--r--. 1 431 433 16 Feb 15 11:38 CURRENT > > > -rw-r--r--. 1 431 433 37 Feb 15 10:57 IDENTITY > > > -rw-r--r--. 1 431 433 0 Feb 15 10:57 LOCK > > > -rw-r--r--. 1 431 433 13446 Feb 15 11:38 LOG > > > -rw-r--r--. 1 431 433 13130 Feb 15 10:57 LOG.old.1487158687061100 > > > -rw-r--r--. 1 431 433 456 Feb 15 11:38 MANIFEST-000501 > > > -rw-r--r--. 1 431 433 4275 Feb 15 10:57 OPTIONS-000005 > > > -rw-r--r--. 1 431 433 4275 Feb 15 11:38 OPTIONS-000504 > > > [root@842376-demeter1 KNVB-test-generation-175-personcore-PERSONCORE]# > > > > > > What strikes me as odd is that none of the files have been touched in > the > > > last few hours (the stacktrace is from 15:25), so there doesn't appear > to > > > have been any logging of that error (on the rocksdb side) > > > > > > Any ideas? Or should I post this to RocksDb? > > > > > > regards, Frank > > > > > >
