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 > > >
