andreacavalli/rocksdb
0
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Adding advisor Rules and parser scripts with unit tests. (#3934)

Browse Source 
Summary:
This adds some rules in the tools/advisor/advisor/rules.ini (refer this for more information) file and corresponding python parser scripts for parsing the rules file and the rocksdb LOG and OPTIONS files. This is WIP for adding rules depending on ODS. The starting point of the script is the rocksdb/tools/advisor/advisor/rule_parser.py file.
Closes https://github.com/facebook/rocksdb/pull/3934

Reviewed By: maysamyabandeh

Differential Revision: D8304059

Pulled By: poojam23

fbshipit-source-id: 47f2a50f04d46d40e225dd1cbf58ba490f79e239
This commit is contained in:
Pooja Malik 2018-06-06 14:28:51 -07:00 committed by Facebook Github Bot
parent 4420df4b0e
commit 5504a056f8
16 changed files with 1206 additions and 0 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

0
tools/advisor/advisor/__init__.py Normal file
View File

96
tools/advisor/advisor/db_log_parser.py Normal file
View File

@ -0,0 +1,96 @@
# Copyright (c) 2011-present, Facebook, Inc. All rights reserved.
# This source code is licensed under both the GPLv2 (found in the
# COPYING file in the root directory) and Apache 2.0 License
# (found in the LICENSE.Apache file in the root directory).
from abc import ABC, abstractmethod
import glob
import re
from enum import Enum
class DataSource(ABC):
class Type(Enum):
LOG = 1
DB_OPTIONS = 2
STATS = 3
PERF_CONTEXT = 4
ODS = 5
def __init__(self, type):
self.type = type
@abstractmethod
def check_and_trigger_conditions(self, conditions):
pass
class Log:
@staticmethod
def is_new_log(log_line):
# The assumption is that a new log will start with a date printed in
# the below regex format.
date_regex = '\d{4}/\d{2}/\d{2}-\d{2}:\d{2}:\d{2}\.\d{6}'
return re.match(date_regex, log_line)
def __init__(self, log_line):
token_list = log_line.strip().split()
self.time = token_list[0]
self.context = token_list[1]
self.message = " ".join(token_list[2:])
def get_time(self):
return self.time
def get_context(self):
return self.context
def get_message(self):
return self.message
def append_message(self, remaining_log):
self.message = self.message + remaining_log
def __repr__(self):
return 'time: ' + self.time + ', context: ' + self.context +\
', message: ' + self.message
class DatabaseLogs(DataSource):
def __init__(self, logs_path_prefix):
super().__init__(DataSource.Type.LOG)
self.logs_path_prefix = logs_path_prefix
def trigger_appropriate_conditions(self, conditions, log):
conditions_to_be_removed = []
for cond in conditions:
if re.search(cond.regex, log.get_message(), re.IGNORECASE):
cond.set_trigger(log)
conditions_to_be_removed.append(cond)
for remove_cond in conditions_to_be_removed:
conditions.remove(remove_cond)
return conditions
def check_and_trigger_conditions(self, conditions):
for file_name in glob.glob(self.logs_path_prefix + '*'):
with open(file_name, 'r') as db_logs:
new_log = None
for line in db_logs:
if not conditions:
break
if Log.is_new_log(line):
if new_log:
conditions = self.trigger_appropriate_conditions(
conditions,
new_log
)
new_log = Log(line)
else:
# To account for logs split into multiple lines
new_log.append_message(line)
# Check for the last log in the file.
if new_log and conditions:
conditions = self.trigger_appropriate_conditions(
conditions,
new_log
)

107
tools/advisor/advisor/db_options_parser.py Normal file
View File

@ -0,0 +1,107 @@
# Copyright (c) 2011-present, Facebook, Inc. All rights reserved.
# This source code is licensed under both the GPLv2 (found in the
# COPYING file in the root directory) and Apache 2.0 License
# (found in the LICENSE.Apache file in the root directory).
from advisor.db_log_parser import DataSource
from advisor.ini_parser import IniParser
class OptionsSpecParser(IniParser):
@staticmethod
def is_new_option(line):
return '=' in line
@staticmethod
def get_section_type(line):
'''
Example section header: [TableOptions/BlockBasedTable "default"]
Here section_type returned would be 'TableOptions.BlockBasedTable'
'''
section_path = line.strip()[1:-1].split()[0]
section_type = '.'.join(section_path.split('/'))
return section_type
@staticmethod
def get_section_name(line):
token_list = line.strip()[1:-1].split('"')
if len(token_list) < 3:
return None
return token_list[1]
class DatabaseOptions(DataSource):
def __init__(self, rocksdb_options):
super().__init__(DataSource.Type.DB_OPTIONS)
self.options_path = rocksdb_options
# Load the options from the given file to a dictionary.
self.load_from_source()
self.options_dict = None
self.column_families = None
def load_from_source(self):
self.options_dict = {}
with open(self.options_path, 'r') as db_options:
for line in db_options:
line = OptionsSpecParser.remove_trailing_comment(line)
if not line:
continue
if OptionsSpecParser.is_section_header(line):
curr_sec_type = OptionsSpecParser.get_section_type(line)
curr_sec_name = OptionsSpecParser.get_section_name(line)
if curr_sec_name:
option_prefix = curr_sec_name + '.' + curr_sec_type
if curr_sec_type == 'CFOptions':
if not self.column_families:
self.column_families = []
self.column_families.append(curr_sec_name)
else:
option_prefix = curr_sec_type
elif OptionsSpecParser.is_new_option(line):
key, value = OptionsSpecParser.get_key_value_pair(line)
if not self.options_dict:
self.options_dict = {}
self.options_dict[option_prefix + '.' + key] = value
else:
error = 'Not able to parse line in Options file.'
OptionsSpecParser.exit_with_parse_error(line, error)
def check_and_trigger_conditions(self, conditions):
'''
For every condition, if the fields are not present set_trigger will
not be called for it. Or if all the fields are present, then the
trigger will be set to whatever the expression evaluates to.
'''
for cond in conditions:
# This contains the indices of options to whose name the column
# family name needs to be prepended in order to create the full
# option name as parsed from the options file.
incomplete_option_ix = []
ix = 0
options = []
for option in cond.options:
if option in self.options_dict.keys():
options.append(self.options_dict[option])
else:
incomplete_option_ix.append(ix)
options.append(0)
ix += 1
# if all the options were present as is:
if not incomplete_option_ix:
if not eval(cond.eval_expr):
cond.set_trigger(cond.eval_expr)
continue
# for all the options that were not present as is, we prepend them
# their names with every column family found in options file.
for col_fam in self.column_families:
present = True
for ix in incomplete_option_ix:
full_option = col_fam + '.' + cond.options[ix]
if full_option not in self.options_dict.keys():
present = False
break
options[ix] = self.options_dict[full_option]
if present and not eval(cond.eval_expr):
cond.set_trigger(cond.eval_expr)

76
tools/advisor/advisor/ini_parser.py Normal file
View File

@ -0,0 +1,76 @@
# Copyright (c) 2011-present, Facebook, Inc. All rights reserved.
# This source code is licensed under both the GPLv2 (found in the
# COPYING file in the root directory) and Apache 2.0 License
# (found in the LICENSE.Apache file in the root directory).
from enum import Enum
class IniParser:
class Element(Enum):
rule = 1
cond = 2
sugg = 3
key_val = 4
comment = 5
@staticmethod
def remove_trailing_comment(line):
line = line.strip()
comment_start = line.find('#')
if comment_start > -1:
return line[:comment_start]
return line
@staticmethod
def is_section_header(line):
# A section header looks like: [Rule "my-new-rule"]. Essentially,
# a line that is in square-brackets.
line = line.strip()
if line.startswith('[') and line.endswith(']'):
return True
return False
@staticmethod
def get_section_name(line):
# For a section header: [Rule "my-new-rule"], this method will return
# "my-new-rule".
token_list = line.strip()[1:-1].split('"')
if len(token_list) < 3:
error = 'needed section header: [<section_type> "<section_name>"]'
raise ValueError('Parsing error: ' + error + '\n' + line)
return token_list[1]
@staticmethod
def get_element(line):
line = IniParser.remove_trailing_comment(line)
if not line:
return IniParser.Element.comment
if IniParser.is_section_header(line):
if line.strip()[1:-1].startswith('Suggestion'):
return IniParser.Element.sugg
if line.strip()[1:-1].startswith('Rule'):
return IniParser.Element.rule
if line.strip()[1:-1].startswith('Condition'):
return IniParser.Element.cond
if '=' in line:
return IniParser.Element.key_val
error = 'not a recognizable RulesSpec element'
raise ValueError('Parsing error: ' + error + '\n' + line)
@staticmethod
def get_key_value_pair(line):
line = line.strip()
key = line.split('=')[0].strip()
value = line.split('=')[1].strip()
if not value:
return (key, None)
values = IniParser.get_list_from_value(value)
if len(values) == 1:
return (key, value)
return (key, values)
@staticmethod
def get_list_from_value(value):
values = value.strip().split(':')
return values

365
tools/advisor/advisor/rule_parser.py Normal file
View File

@ -0,0 +1,365 @@
# Copyright (c) 2011-present, Facebook, Inc. All rights reserved.
# This source code is licensed under both the GPLv2 (found in the
# COPYING file in the root directory) and Apache 2.0 License
# (found in the LICENSE.Apache file in the root directory).
from abc import ABC, abstractmethod
import argparse
from advisor.db_log_parser import DatabaseLogs, DataSource
from advisor.db_options_parser import DatabaseOptions
from enum import Enum
from advisor.ini_parser import IniParser
class Section(ABC):
def __init__(self, name):
self.name = name
@abstractmethod
def set_parameter(self, key, value):
pass
@abstractmethod
def perform_checks(self):
pass
class Rule(Section):
def __init__(self, name):
super().__init__(name)
self.conditions = None
self.suggestions = None
def set_parameter(self, key, value):
# If the Rule is associated with a single suggestion/condition, then
# value will be a string and not a list. Hence, convert it to a single
# element list before storing it in self.suggestions or
# self.conditions.
if key == 'conditions':
if isinstance(value, str):
self.conditions = [value]
else:
self.conditions = value
elif key == 'suggestions':
if isinstance(value, str):
self.suggestions = [value]
else:
self.suggestions = value
def get_suggestions(self):
return self.suggestions
def perform_checks(self):
if not self.conditions or len(self.conditions) < 1:
raise ValueError(
self.name + ': rule must have at least one condition'
)
if not self.suggestions or len(self.suggestions) < 1:
raise ValueError(
self.name + ': rule must have at least one suggestion'
)
def is_triggered(self, conditions_dict):
condition_triggers = []
for cond in self.conditions:
condition_triggers.append(conditions_dict[cond].is_triggered())
return all(condition_triggers)
def __repr__(self):
# Append conditions
rule_string = "Rule: " + self.name + " has conditions:: "
is_first = True
for cond in self.conditions:
if is_first:
rule_string += cond
is_first = False
else:
rule_string += (" AND " + cond)
# Append suggestions
rule_string += "\nsuggestions:: "
is_first = True
for sugg in self.suggestions:
if is_first:
rule_string += sugg
is_first = False
else:
rule_string += (", " + sugg)
# Return constructed string
return rule_string
class Suggestion(Section):
class Action(Enum):
set = 1
increase = 2
decrease = 3
def __init__(self, name):
super().__init__(name)
self.option = None
self.action = None
self.suggested_value = None
self.description = None
def set_parameter(self, key, value):
if key == 'option':
self.option = value
elif key == 'action':
if self.option and not value:
raise ValueError(self.name + ': provide action for option')
self.action = self.Action[value]
elif key == 'suggested_value':
self.suggested_value = value
elif key == 'description':
self.description = value
def perform_checks(self):
if not self.description:
if not self.option:
raise ValueError(self.name + ': provide option or description')
if not self.action:
raise ValueError(self.name + ': provide action for option')
if self.action is self.Action.set and not self.suggested_value:
raise ValueError(
self.name + ': provide suggested value for option'
)
def __repr__(self):
if self.description:
return self.description
sugg_string = ""
if self.action is self.Action.set:
sugg_string = (
self.name + ' suggests setting ' + self.option +
' to ' + self.suggested_value
)
else:
sugg_string = self.name + ' suggests ' + self.action.name + ' in '
sugg_string += (self.option + '.')
if self.suggested_value:
sugg_string += (
' The suggested value is ' + self.suggested_value
)
return sugg_string
class Condition(Section):
def __init__(self, name):
# a rule is identified by its name, so there should be no duplicates
super().__init__(name)
self.data_source = None
self.trigger = None
def perform_checks(self):
if not self.data_source:
raise ValueError(self.name + ': condition not tied to data source')
def set_data_source(self, data_source):
self.data_source = data_source
def get_data_source(self):
return self.data_source
def reset_trigger(self):
self.trigger = None
def set_trigger(self, condition_trigger):
self.trigger = condition_trigger
def is_triggered(self):
if self.trigger:
return True
return False
def set_parameter(self, key, value):
# must be defined by the subclass
raise ValueError(self.name + ': provide source for condition')
class LogCondition(Condition):
@classmethod
def create(cls, base_condition):
base_condition.set_data_source(DataSource.Type['LOG'])
base_condition.__class__ = cls
return base_condition
class Scope(Enum):
database = 1
column_family = 2
def set_parameter(self, key, value):
if key == 'regex':
self.regex = value
elif key == 'scope':
self.scope = self.Scope[value]
def perform_checks(self):
super().perform_checks()
if not self.regex:
raise ValueError(self.name + ': provide regex for log condition')
def __repr__(self):
log_cond_str = (
self.name + ' checks if the regex ' + self.regex + ' is found ' +
' in the LOG file in the scope of ' + self.scope.name
)
return log_cond_str
class OptionCondition(Condition):
@classmethod
def create(cls, base_condition):
base_condition.set_data_source(DataSource.Type['DB_OPTIONS'])
base_condition.__class__ = cls
return base_condition
def set_parameter(self, key, value):
if key == 'options':
self.options = value
if key == 'evaluate':
self.eval_expr = value
def perform_checks(self):
super().perform_checks()
if not self.options:
raise ValueError(self.name + ': options missing in condition')
if not self.eval_expr:
raise ValueError(self.name + ': expression missing in condition')
def __repr__(self):
log_cond_str = (
self.name + ' checks if the given expression evaluates to true'
)
return log_cond_str
class RulesSpec:
def __init__(self, rules_path):
self.file_path = rules_path
self.rules_dict = {}
self.conditions_dict = {}
self.suggestions_dict = {}
def perform_section_checks(self):
for rule in self.rules_dict.values():
rule.perform_checks()
for cond in self.conditions_dict.values():
cond.perform_checks()
for sugg in self.suggestions_dict.values():
sugg.perform_checks()
def load_rules_from_spec(self):
with open(self.file_path, 'r') as db_rules:
curr_section = None
for line in db_rules:
element = IniParser.get_element(line)
if element is IniParser.Element.comment:
continue
elif element is not IniParser.Element.key_val:
curr_section = element # it's a new IniParser header
section_name = IniParser.get_section_name(line)
if element is IniParser.Element.rule:
new_rule = Rule(section_name)
self.rules_dict[section_name] = new_rule
elif element is IniParser.Element.cond:
new_cond = Condition(section_name)
self.conditions_dict[section_name] = new_cond
elif element is IniParser.Element.sugg:
new_suggestion = Suggestion(section_name)
self.suggestions_dict[section_name] = new_suggestion
elif element is IniParser.Element.key_val:
key, value = IniParser.get_key_value_pair(line)
if curr_section is IniParser.Element.rule:
new_rule.set_parameter(key, value)
elif curr_section is IniParser.Element.cond:
if key == 'source':
if value == 'LOG':
new_cond = LogCondition.create(new_cond)
elif value == 'OPTIONS':
new_cond = OptionCondition.create(new_cond)
else:
new_cond.set_parameter(key, value)
elif curr_section is IniParser.Element.sugg:
new_suggestion.set_parameter(key, value)
def get_rules_dict(self):
return self.rules_dict
def get_conditions_dict(self):
return self.conditions_dict
def get_suggestions_dict(self):
return self.suggestions_dict
def trigger_conditions(data_sources, conditions_dict):
for source in data_sources:
cond_subset = [
cond
for cond in conditions_dict.values()
if cond.get_data_source() is source.type
]
if not cond_subset:
continue
source.check_and_trigger_conditions(cond_subset)
def get_triggered_rules(rules_dict, conditions_dict):
triggered_rules = []
for rule in rules_dict.values():
if rule.is_triggered(conditions_dict):
triggered_rules.append(rule)
return triggered_rules
def main(args):
# Load the rules with their conditions and suggestions.
db_rules = RulesSpec(args.rules_spec)
db_rules.load_rules_from_spec()
# Perform some basic sanity checks for each section.
db_rules.perform_section_checks()
rules_dict = db_rules.get_rules_dict()
conditions_dict = db_rules.get_conditions_dict()
suggestions_dict = db_rules.get_suggestions_dict()
print()
print('RULES')
for rule in rules_dict.values():
print(repr(rule))
print()
print('CONDITIONS')
for cond in conditions_dict.values():
print(repr(cond))
print()
print('SUGGESTIONS')
for sugg in suggestions_dict.values():
print(repr(sugg))
# Initialise the data sources.
data_sources = []
data_sources.append(DatabaseOptions(args.rocksdb_options))
data_sources.append(DatabaseLogs(args.rocksdb_log_prefix))
# Initialise the ConditionChecker with the provided data sources.
trigger_conditions(data_sources, conditions_dict)
# Check for the conditions read in from the Rules spec, if triggered.
print()
triggered_rules = get_triggered_rules(rules_dict, conditions_dict)
for rule in triggered_rules:
print('Rule: ' + rule.name + ' has been triggered and:')
rule_suggestions = rule.get_suggestions()
for sugg_name in rule_suggestions:
print(suggestions_dict[sugg_name])
if __name__ == "__main__":
parser = argparse.ArgumentParser(description='This script is used for\
gauging rocksdb performance using as input: Rocksdb LOG, OPTIONS,\
performance context, command-line statistics and statistics published\
on ODS and providing as output: suggestions to improve Rocksdb\
performance')
parser.add_argument('--rules_spec', required=True, type=str)
parser.add_argument('--rocksdb_options', required=True, type=str)
parser.add_argument('--rocksdb_log_prefix', required=True, type=str)
args = parser.parse_args()
main(args)

111
tools/advisor/advisor/rules.ini Normal file
View File

@ -0,0 +1,111 @@
# Copyright (c) 2011-present, Facebook, Inc. All rights reserved.
# This source code is licensed under both the GPLv2 (found in the
# COPYING file in the root directory) and Apache 2.0 License
# (found in the LICENSE.Apache file in the root directory).
#
# This ini file is very similar to the Rocksdb ini file in terms of syntax.
# (refer rocksdb/examples/rocksdb_option_file_example.ini)
# It is made up of multiple sections and each section is made up of multiple
# key-value pairs. Each section must have a name. The recognized sections are
# Rule, Suggestion, Condition followed by their name in "" that acts as an
# identifier. There should be at least one Rule section in the file.
#
# Each rule must be associated with at least one condition and one suggestion.
# If a Rule is associated with multiple Conditions, then all the conditions
# must be triggered in order for the Rule to be triggered.
# The suggestions don't have any ordering amongst them as of now.
#
# A Condition must be associated to a data source specified by the parameter
# 'source' and this must be the first parameter specified for the Condition.
#
# A suggestion is an advised change to a database or column_family option to
# improve the performance of the database in some way. Every suggestion is
# is associated with one or more Rules.
[Rule "stall-too-many-memtables"]
suggestions=inc-bg-flush:inc-write-buffer
conditions=stall-too-many-memtables
[Condition "stall-too-many-memtables"]
source=LOG
regex=Stopping writes because we have \d+ immutable memtables \(waiting for flush\), max_write_buffer_number is set to \d+
scope=column_family
[Rule "stall-too-many-L0"]
suggestions=inc-max-subcompactions:inc-max-bg-compactions:inc-write-buffer-size:dec-max-bytes-for-level-base:inc-l0-slowdown-writes-trigger
conditions=stall-too-many-L0
[Condition "stall-too-many-L0"]
source=LOG
regex=Stalling writes because we have \d+ level-0 files
scope=column_family
[Rule "stop-too-many-L0"]
suggestions=inc-max-bg-compactions:inc-write-buffer-size:inc-l0-stop-writes-trigger
conditions=stop-too-many-L0
[Condition "stop-too-many-L0"]
source=LOG
regex=Stopping writes because we have \d+ level-0 files
scope=column_family
[Rule "stall-too-many-compaction-bytes"]
suggestions=inc-max-bg-compactions:inc-write-buffer-size:inc-hard-pending-compaction-bytes-limit:inc-soft-pending-compaction-bytes-limit
conditions=stall-too-many-compaction-bytes
[Condition "stall-too-many-compaction-bytes"]
source=LOG
regex=Stalling writes because of estimated pending compaction bytes \d+
scope=column_family
[Suggestion "inc-bg-flush"]
option=DBOptions.max_background_flushes
action=increase
[Suggestion "inc-write-buffer"]
option=CFOptions.max_write_buffer_number
action=increase
[Suggestion "inc-max-subcompactions"]
option=DBOptions.max_subcompactions
action=increase
[Suggestion "inc-max-bg-compactions"]
option=DBOptions.max_background_compactions
action=increase
[Suggestion "inc-write-buffer-size"]
option=CFOptions.write_buffer_size
action=increase
[Suggestion "dec-max-bytes-for-level-base"]
option=CFOptions.max_bytes_for_level_base
action=decrease
[Suggestion "inc-l0-slowdown-writes-trigger"]
option=CFOptions.level0_slowdown_writes_trigger
action=increase
[Suggestion "inc-l0-stop-writes-trigger"]
option=CFOptions.level0_stop_writes_trigger
action=increase
[Suggestion "inc-hard-pending-compaction-bytes-limit"]
option=CFOptions.hard_pending_compaction_bytes_limit
action=increase
[Suggestion "inc-soft-pending-compaction-bytes-limit"]
option=CFOptions.soft_pending_compaction_bytes_limit
action=increase
[Rule "level0-level1-ratio"]
conditions=level0-level1-ratio
suggestions=l0-l1-ratio-health-check
[Condition "level0-level1-ratio"]
source=OPTIONS
options=CFOptions.level0_file_num_compaction_trigger:CFOptions.write_buffer_size:CFOptions.max_bytes_for_level_base
evaluate=int(options[0])*int(options[1])-int(options[2])<(-251659456) # should evaluate to a boolean
[Suggestion "l0-l1-ratio-health-check"]
description='modify options such that (level0_file_num_compaction_trigger * write_buffer_size - max_bytes_for_level_base < 5) is satisfied'

0
tools/advisor/test/__init__.py Normal file
View File

25
tools/advisor/test/input_files/LOG-0 Normal file
View File

@ -0,0 +1,25 @@
2018/05/25-14:30:05.601692 7f82bd676200 RocksDB version: 5.14.0
2018/05/25-14:30:07.626719 7f82ba72e700 (Original Log Time 2018/05/25-14:30:07.621966) [db/db_impl_compaction_flush.cc:1424] Calling FlushMemTableToOutputFile with column family [default], flush slots available 1, compaction slots available 1, flush slots scheduled 1, compaction slots scheduled 0
2018/05/25-14:30:07.626725 7f82ba72e700 [db/flush_job.cc:301] [default] [JOB 3] Flushing memtable with next log file: 8
2018/05/25-14:30:07.626738 7f82ba72e700 EVENT_LOG_v1 {"time_micros": 1527283807626732, "job": 3, "event": "flush_started", "num_memtables": 1, "num_entries": 28018, "num_deletes": 0, "memory_usage": 4065512, "flush_reason": "Write Buffer Full"}
2018/05/25-14:30:07.626740 7f82ba72e700 [db/flush_job.cc:331] [default] [JOB 3] Level-0 flush table #10: started
2018/05/25-14:30:07.764232 7f82b2f20700 [db/db_impl_write.cc:1373] [default] New memtable created with log file: #11. Immutable memtables: 1.
2018/05/25-14:30:07.764240 7f82b2f20700 [WARN] [db/column_family.cc:743] [default] Stopping writes because we have 2 immutable memtables (waiting for flush), max_write_buffer_number is set to 2
2018/05/23-11:53:12.800143 7f9f36b40700 [WARN] [db/column_family.cc:799] [default] Stalling writes because we have 4 level-0 files rate 39886
2018/05/23-11:53:12.800143 7f9f36b40700 [WARN] [db/column_family.cc:799] [default] Stopping writes because we have 4 level-0 files rate 39886
2018/05/25-14:30:09.398302 7f82ba72e700 EVENT_LOG_v1 {"time_micros": 1527283809398276, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 10, "file_size": 1890434, "table_properties": {"data_size": 1876749, "index_size": 23346, "filter_size": 0, "raw_key_size": 663120, "raw_average_key_size": 24, "raw_value_size": 2763000, "raw_average_value_size": 100, "num_data_blocks": 838, "num_entries": 27630, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}}
2018/05/25-14:30:09.398351 7f82ba72e700 [db/flush_job.cc:371] [default] [JOB 3] Level-0 flush table #10: 1890434 bytes OK
2018/05/25-14:30:25.491635 7f82ba72e700 [db/flush_job.cc:331] [default] [JOB 10] Level-0 flush table #23: started
2018/05/25-14:30:25.643618 7f82b2f20700 [db/db_impl_write.cc:1373] [default] New memtable created with log file: #24. Immutable memtables: 1.
2018/05/25-14:30:25.643633 7f82b2f20700 [WARN] [db/column_family.cc:743] [default] Stopping writes because we have 2 immutable memtables (waiting for flush), max_write_buffer_number is set to 2
2018/05/25-14:30:27.288181 7f82ba72e700 EVENT_LOG_v1 {"time_micros": 1527283827288158, "cf_name": "default", "job": 10, "event": "table_file_creation", "file_number": 23, "file_size": 1893200, "table_properties": {"data_size": 1879460, "index_size": 23340, "filter_size": 0, "raw_key_size": 663360, "raw_average_key_size": 24, "raw_value_size": 2764000, "raw_average_value_size": 100, "num_data_blocks": 838, "num_entries": 27640, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}}
2018/05/25-14:30:27.288210 7f82ba72e700 [db/flush_job.cc:371] [default] [JOB 10] Level-0 flush table #23: 1893200 bytes OK
2018/05/25-14:30:27.289353 7f82ba72e700 [WARN] [db/column_family.cc:764] [default] Stalling writes because of estimated pending compaction bytes 14410584
2018/05/25-14:30:27.289390 7f82ba72e700 (Original Log Time 2018/05/25-14:30:27.288829) [db/memtable_list.cc:377] [default] Level-0 commit table #23 started
2018/05/25-14:30:27.289393 7f82ba72e700 (Original Log Time 2018/05/25-14:30:27.289332) [db/memtable_list.cc:409] [default] Level-0 commit table #23: memtable #1 done
2018/05/25-14:34:21.047206 7f82ba72e700 EVENT_LOG_v1 {"time_micros": 1527284061047181, "cf_name": "default", "job": 44, "event": "table_file_creation", "file_number": 84, "file_size": 1890780, "table_properties": {"data_size": 1877100, "index_size": 23309, "filter_size": 0, "raw_key_size": 662808, "raw_average_key_size": 24, "raw_value_size": 2761700, "raw_average_value_size": 100, "num_data_blocks": 837, "num_entries": 27617, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}}
2018/05/25-14:34:21.047233 7f82ba72e700 [db/flush_job.cc:371] [default] [JOB 44] Level-0 flush table #84: 1890780 bytes OK
2018/05/25-14:34:21.048017 7f82ba72e700 (Original Log Time 2018/05/25-14:34:21.048005) EVENT_LOG_v1 {"time_micros": 1527284061047997, "job": 44, "event": "flush_finished", "output_compression": "Snappy", "lsm_state": [2, 1, 0, 0, 0, 0, 0], "immutable_memtables": 1}
2018/05/25-14:34:21.048592 7f82bd676200 [DEBUG] [db/db_impl_files.cc:261] [JOB 45] Delete /tmp/rocksdbtest-155919/dbbench/000084.sst type=2 #84 -- OK
2018/05/25-14:34:21.048603 7f82bd676200 EVENT_LOG_v1 {"time_micros": 1527284061048600, "job": 45, "event": "table_file_deletion", "file_number": 84}
2018/05/25-14:34:21.048981 7f82bd676200 [db/db_impl.cc:398] Shutdown complete

25
tools/advisor/test/input_files/LOG-1 Normal file
View File

@ -0,0 +1,25 @@
2018/05/25-14:30:05.601692 7f82bd676200 RocksDB version: 5.14.0
2018/05/25-14:30:07.626719 7f82ba72e700 (Original Log Time 2018/05/25-14:30:07.621966) [db/db_impl_compaction_flush.cc:1424] Calling FlushMemTableToOutputFile with column family [default], flush slots available 1, compaction slots available 1, flush slots scheduled 1, compaction slots scheduled 0
2018/05/25-14:30:07.626725 7f82ba72e700 [db/flush_job.cc:301] [default] [JOB 3] Flushing memtable with next log file: 8
2018/05/25-14:30:07.626738 7f82ba72e700 EVENT_LOG_v1 {"time_micros": 1527283807626732, "job": 3, "event": "flush_started", "num_memtables": 1, "num_entries": 28018, "num_deletes": 0, "memory_usage": 4065512, "flush_reason": "Write Buffer Full"}
2018/05/25-14:30:07.626740 7f82ba72e700 [db/flush_job.cc:331] [default] [JOB 3] Level-0 flush table #10: started
2018/05/25-14:30:07.764232 7f82b2f20700 [db/db_impl_write.cc:1373] [default] New memtable created with log file: #11. Immutable memtables: 1.
2018/05/25-14:30:07.764240 7f82b2f20700 [WARN] [db/column_family.cc:743] [default] Stopping writes because we have 2 immutable memtables (waiting for flush), max_write_buffer_number is set to 2
2018/05/23-11:53:12.800143 7f9f36b40700 [WARN] [db/column_family.cc:799] [default] Stalling writes because we have 4 level-0 files rate 39886
2018/05/23-11:53:12.800143 7f9f36b40700 [WARN] [db/column_family.cc:799] [default] Stopping writes because we have 4 level-0 files rate 39886
2018/05/25-14:30:09.398302 7f82ba72e700 EVENT_LOG_v1 {"time_micros": 1527283809398276, "cf_name": "default", "job": 3, "event": "table_file_creation", "file_number": 10, "file_size": 1890434, "table_properties": {"data_size": 1876749, "index_size": 23346, "filter_size": 0, "raw_key_size": 663120, "raw_average_key_size": 24, "raw_value_size": 2763000, "raw_average_value_size": 100, "num_data_blocks": 838, "num_entries": 27630, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}}
2018/05/25-14:30:09.398351 7f82ba72e700 [db/flush_job.cc:371] [default] [JOB 3] Level-0 flush table #10: 1890434 bytes OK
2018/05/25-14:30:25.491635 7f82ba72e700 [db/flush_job.cc:331] [default] [JOB 10] Level-0 flush table #23: started
2018/05/25-14:30:25.643618 7f82b2f20700 [db/db_impl_write.cc:1373] [default] New memtable created with log file: #24. Immutable memtables: 1.
2018/05/25-14:30:25.643633 7f82b2f20700 [WARN] [db/column_family.cc:743] [default] Stopping writes because we have 2 immutable memtables (waiting for flush), max_write_buffer_number is set to 2
2018/05/25-14:30:27.288181 7f82ba72e700 EVENT_LOG_v1 {"time_micros": 1527283827288158, "cf_name": "default", "job": 10, "event": "table_file_creation", "file_number": 23, "file_size": 1893200, "table_properties": {"data_size": 1879460, "index_size": 23340, "filter_size": 0, "raw_key_size": 663360, "raw_average_key_size": 24, "raw_value_size": 2764000, "raw_average_value_size": 100, "num_data_blocks": 838, "num_entries": 27640, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}}
2018/05/25-14:30:27.288210 7f82ba72e700 [db/flush_job.cc:371] [default] [JOB 10] Level-0 flush table #23: 1893200 bytes OK
2018/05/25-14:30:27.289353 7f82ba72e700 [WARN] [db/column_family.cc:764] [default] Stopping writes because of estimated pending compaction bytes 14410584
2018/05/25-14:30:27.289390 7f82ba72e700 (Original Log Time 2018/05/25-14:30:27.288829) [db/memtable_list.cc:377] [default] Level-0 commit table #23 started
2018/05/25-14:30:27.289393 7f82ba72e700 (Original Log Time 2018/05/25-14:30:27.289332) [db/memtable_list.cc:409] [default] Level-0 commit table #23: memtable #1 done
2018/05/25-14:34:21.047206 7f82ba72e700 EVENT_LOG_v1 {"time_micros": 1527284061047181, "cf_name": "default", "job": 44, "event": "table_file_creation", "file_number": 84, "file_size": 1890780, "table_properties": {"data_size": 1877100, "index_size": 23309, "filter_size": 0, "raw_key_size": 662808, "raw_average_key_size": 24, "raw_value_size": 2761700, "raw_average_value_size": 100, "num_data_blocks": 837, "num_entries": 27617, "filter_policy_name": "", "kDeletedKeys": "0", "kMergeOperands": "0"}}
2018/05/25-14:34:21.047233 7f82ba72e700 [db/flush_job.cc:371] [default] [JOB 44] Level-0 flush table #84: 1890780 bytes OK
2018/05/25-14:34:21.048017 7f82ba72e700 (Original Log Time 2018/05/25-14:34:21.048005) EVENT_LOG_v1 {"time_micros": 1527284061047997, "job": 44, "event": "flush_finished", "output_compression": "Snappy", "lsm_state": [2, 1, 0, 0, 0, 0, 0], "immutable_memtables": 1}
2018/05/25-14:34:21.048592 7f82bd676200 [DEBUG] [db/db_impl_files.cc:261] [JOB 45] Delete /tmp/rocksdbtest-155919/dbbench/000084.sst type=2 #84 -- OK
2018/05/25-14:34:21.048603 7f82bd676200 EVENT_LOG_v1 {"time_micros": 1527284061048600, "job": 45, "event": "table_file_deletion", "file_number": 84}
2018/05/25-14:34:21.048981 7f82bd676200 [db/db_impl.cc:398] Shutdown complete

31
tools/advisor/test/input_files/OPTIONS-000005 Normal file
View File

@ -0,0 +1,31 @@
# This is a RocksDB option file.
#
# For detailed file format spec, please refer to the example file
# in examples/rocksdb_option_file_example.ini
#
[Version]
rocksdb_version=5.14.0
options_file_version=1.1
[DBOptions]
manual_wal_flush=false
allow_ingest_behind=false
db_write_buffer_size=0
[CFOptions "default"]
ttl=0
max_bytes_for_level_base=268435456
max_bytes_for_level_multiplier=10.000000
level0_file_num_compaction_trigger=4
level0_stop_writes_trigger=36
write_buffer_size=4194000
min_write_buffer_number_to_merge=1
num_levels=7
compaction_filter_factory=nullptr
compaction_style=kCompactionStyleLevel
[TableOptions/BlockBasedTable "default"]
block_align=false
index_type=kBinarySearch

58
tools/advisor/test/input_files/rules_err1.ini Normal file
View File

@ -0,0 +1,58 @@
[Rule "missing-suggestions"]
suggestions=
conditions=missing-source
[Condition "normal-rule"]
source=LOG
regex=Stopping writes because we have \d+ immutable memtables \(waiting for flush\), max_write_buffer_number is set to \d+
scope=column_family
[Suggestion "inc-bg-flush"]
option=DBOptions.max_background_flushes
action=increase
[Suggestion "inc-write-buffer"]
option=CFOptions.max_write_buffer_number
action=increase
[Rule "missing-conditions"]
conditions=
suggestions=missing-description
[Condition "missing-options"]
source=OPTIONS
options=
evaluate=int(options[0])*int(options[1])-int(options[2])<(-251659456) # should evaluate to a boolean
[Rule "missing-expression"]
conditions=missing-expression
suggestions=missing-description
[Condition "missing-expression"]
source=OPTIONS
options=CFOptions.level0_file_num_compaction_trigger:CFOptions.write_buffer_size:CFOptions.max_bytes_for_level_base
evaluate=
[Suggestion "missing-description"]
description=
[Rule "stop-too-many-L0"]
suggestions=inc-max-bg-compactions:missing-action:inc-l0-stop-writes-trigger
conditions=missing-regex
[Condition "missing-regex"]
source=LOG
regex=
scope=column_family
[Suggestion "missing-option"]
option=
action=increase
[Suggestion "normal-suggestion"]
option=CFOptions.write_buffer_size
action=increase
[Suggestion "inc-l0-stop-writes-trigger"]
option=CFOptions.level0_stop_writes_trigger
action=increase

16
tools/advisor/test/input_files/rules_err2.ini Normal file
View File

@ -0,0 +1,16 @@
[Rule "normal-rule"]
suggestions=inc-bg-flush:inc-write-buffer
conditions=missing-source
[Condition "missing-source"]
source=
regex=Stopping writes because we have \d+ immutable memtables \(waiting for flush\), max_write_buffer_number is set to \d+
scope=column_family
[Suggestion "inc-bg-flush"]
option=DBOptions.max_background_flushes
action=increase
[Suggestion "inc-write-buffer"]
option=CFOptions.max_write_buffer_number
action=increase

16
tools/advisor/test/input_files/rules_err3.ini Normal file
View File

@ -0,0 +1,16 @@
[Rule "normal-rule"]
suggestions=missing-action:inc-write-buffer
conditions=missing-source
[Condition "normal-condition"]
source=LOG
regex=Stopping writes because we have \d+ immutable memtables \(waiting for flush\), max_write_buffer_number is set to \d+
scope=column_family
[Suggestion "missing-action"]
option=DBOptions.max_background_flushes
action=
[Suggestion "inc-write-buffer"]
option=CFOptions.max_write_buffer_number
action=increase

16
tools/advisor/test/input_files/rules_err4.ini Normal file
View File

@ -0,0 +1,16 @@
[Rule "normal-rule"]
suggestions=inc-bg-flush
conditions=missing-source
[Condition "normal-condition"]
source=LOG
regex=Stopping writes because we have \d+ immutable memtables \(waiting for flush\), max_write_buffer_number is set to \d+
scope=column_family
[Suggestion "inc-bg-flush"]
option=DBOptions.max_background_flushes
action=increase
[Suggestion] # missing section name
option=CFOptions.max_write_buffer_number
action=increase

51
tools/advisor/test/input_files/test_rules.ini Normal file
View File

@ -0,0 +1,51 @@
[Rule "single-condition-false"]
suggestions=inc-bg-flush:inc-write-buffer
conditions=log-4-false
[Rule "multiple-conds-true"]
suggestions=inc-write-buffer
conditions=log-1-true:log-2-true:log-3-true
[Rule "multiple-conds-one-false"]
suggestions=inc-bg-flush
conditions=log-1-true:log-4-false:log-3-true
[Rule "multiple-conds-all-false"]
suggestions=l0-l1-ratio-health-check
conditions=log-4-false:options-1-false
[Condition "log-1-true"]
source=LOG
regex=Stopping writes because we have \d+ immutable memtables \(waiting for flush\), max_write_buffer_number is set to \d+
scope=column_family
[Condition "log-2-true"]
source=LOG
regex=Stalling writes because we have \d+ level-0 files
scope=column_family
[Condition "log-3-true"]
source=LOG
regex=Stopping writes because we have \d+ level-0 files
scope=column_family
[Condition "log-4-false"]
source=LOG
regex=Stalling writes because of estimated pending compaction bytes \d+
scope=column_family
[Condition "options-1-false"]
source=OPTIONS
options=CFOptions.level0_file_num_compaction_trigger:CFOptions.write_buffer_size:random_access_max_buffer_size
evaluate=int(options[0])*int(options[1])-int(options[2])<0 # should evaluate to a boolean
[Suggestion "inc-bg-flush"]
option=DBOptions.max_background_flushes
action=increase
[Suggestion "inc-write-buffer"]
option=CFOptions.max_write_buffer_number
action=increase
[Suggestion "l0-l1-ratio-health-check"]
description='modify options such that (level0_file_num_compaction_trigger * write_buffer_size - max_bytes_for_level_base < 5) is satisfied'

213
tools/advisor/test/test_rule_parser.py Normal file
View File

@ -0,0 +1,213 @@
# Copyright (c) 2011-present, Facebook, Inc. All rights reserved.
# This source code is licensed under both the GPLv2 (found in the
# COPYING file in the root directory) and Apache 2.0 License
# (found in the LICENSE.Apache file in the root directory).
import os
import unittest
from advisor.rule_parser import RulesSpec, DatabaseLogs, DatabaseOptions
from advisor.rule_parser import get_triggered_rules, trigger_conditions
RuleToSuggestions = {
"stall-too-many-memtables": [
'inc-bg-flush',
'inc-write-buffer'
],
"stall-too-many-L0": [
'inc-max-subcompactions',
'inc-max-bg-compactions',
'inc-write-buffer-size',
'dec-max-bytes-for-level-base',
'inc-l0-slowdown-writes-trigger'
],
"stop-too-many-L0": [
'inc-max-bg-compactions',
'inc-write-buffer-size',
'inc-l0-stop-writes-trigger'
],
"stall-too-many-compaction-bytes": [
'inc-max-bg-compactions',
'inc-write-buffer-size',
'inc-hard-pending-compaction-bytes-limit',
'inc-soft-pending-compaction-bytes-limit'
],
"level0-level1-ratio": [
'l0-l1-ratio-health-check'
]
}
class TestAllRulesTriggered(unittest.TestCase):
def setUp(self):
# load the Rules
this_path = os.path.abspath(os.path.dirname(__file__))
ini_path = os.path.join(this_path, '../advisor/rules.ini')
self.db_rules = RulesSpec(ini_path)
self.db_rules.load_rules_from_spec()
self.db_rules.perform_section_checks()
# load the data sources: LOG and OPTIONS
log_path = os.path.join(this_path, 'input_files/LOG-0')
options_path = os.path.join(this_path, 'input_files/OPTIONS-000005')
self.data_sources = []
self.data_sources.append(DatabaseOptions(options_path))
self.data_sources.append(DatabaseLogs(log_path))
def test_triggered_conditions(self):
conditions_dict = self.db_rules.get_conditions_dict()
rules_dict = self.db_rules.get_rules_dict()
# Make sure none of the conditions is triggered beforehand
for cond in conditions_dict.values():
self.assertFalse(cond.is_triggered(), repr(cond))
for rule in rules_dict.values():
self.assertFalse(rule.is_triggered(conditions_dict), repr(rule))
# Trigger the conditions as per the data sources.
trigger_conditions(self.data_sources, conditions_dict)
# Make sure each condition and rule is triggered
for cond in conditions_dict.values():
self.assertTrue(cond.is_triggered(), repr(cond))
# Get the set of rules that have been triggered
triggered_rules = get_triggered_rules(rules_dict, conditions_dict)
for rule in rules_dict.values():
self.assertIn(rule, triggered_rules)
# Check the suggestions made by the triggered rules
for sugg in rule.get_suggestions():
self.assertIn(sugg, RuleToSuggestions[rule.name])
for rule in triggered_rules:
self.assertIn(rule, rules_dict.values())
for sugg in RuleToSuggestions[rule.name]:
self.assertIn(sugg, rule.get_suggestions())
class TestConditionsConjunctions(unittest.TestCase):
def setUp(self):
# load the Rules
this_path = os.path.abspath(os.path.dirname(__file__))
ini_path = os.path.join(this_path, 'input_files/test_rules.ini')
self.db_rules = RulesSpec(ini_path)
self.db_rules.load_rules_from_spec()
self.db_rules.perform_section_checks()
# load the data sources: LOG and OPTIONS
log_path = os.path.join(this_path, 'input_files/LOG-1')
options_path = os.path.join(this_path, 'input_files/OPTIONS-000005')
self.data_sources = []
self.data_sources.append(DatabaseOptions(options_path))
self.data_sources.append(DatabaseLogs(log_path))
def test_condition_conjunctions(self):
conditions_dict = self.db_rules.get_conditions_dict()
rules_dict = self.db_rules.get_rules_dict()
# Make sure none of the conditions is triggered beforehand
for cond in conditions_dict.values():
self.assertFalse(cond.is_triggered(), repr(cond))
for rule in rules_dict.values():
self.assertFalse(rule.is_triggered(conditions_dict), repr(rule))
# Trigger the conditions as per the data sources.
trigger_conditions(self.data_sources, conditions_dict)
# Check for the conditions
conds_triggered = ['log-1-true', 'log-2-true', 'log-3-true']
conds_not_triggered = ['log-4-false', 'options-1-false']
for cond in conds_triggered:
self.assertTrue(conditions_dict[cond].is_triggered(), repr(cond))
for cond in conds_not_triggered:
self.assertFalse(conditions_dict[cond].is_triggered(), repr(cond))
# Check for the rules
rules_triggered = ['multiple-conds-true']
rules_not_triggered = [
'single-condition-false',
'multiple-conds-one-false',
'multiple-conds-all-false'
]
for rule in rules_triggered:
self.assertTrue(
rules_dict[rule].is_triggered(conditions_dict),
repr(rule)
)
for rule in rules_not_triggered:
self.assertFalse(
rules_dict[rule].is_triggered(conditions_dict),
repr(rule)
)
class TestSanityChecker(unittest.TestCase):
def setUp(self):
this_path = os.path.abspath(os.path.dirname(__file__))
ini_path = os.path.join(this_path, 'input_files/rules_err1.ini')
db_rules = RulesSpec(ini_path)
db_rules.load_rules_from_spec()
self.rules_dict = db_rules.get_rules_dict()
self.conditions_dict = db_rules.get_conditions_dict()
self.suggestions_dict = db_rules.get_suggestions_dict()
def test_rule_missing_suggestions(self):
regex = '.*rule must have at least one suggestion.*'
with self.assertRaisesRegex(ValueError, regex):
self.rules_dict['missing-suggestions'].perform_checks()
def test_rule_missing_conditions(self):
regex = '.*rule must have at least one condition.*'
with self.assertRaisesRegex(ValueError, regex):
self.rules_dict['missing-conditions'].perform_checks()
def test_condition_missing_regex(self):
regex = '.*provide regex for log condition.*'
with self.assertRaisesRegex(ValueError, regex):
self.conditions_dict['missing-regex'].perform_checks()
def test_condition_missing_options(self):
regex = '.*options missing in condition.*'
with self.assertRaisesRegex(ValueError, regex):
self.conditions_dict['missing-options'].perform_checks()
def test_condition_missing_expression(self):
regex = '.*expression missing in condition.*'
with self.assertRaisesRegex(ValueError, regex):
self.conditions_dict['missing-expression'].perform_checks()
def test_suggestion_missing_option(self):
regex = '.*provide option or description.*'
with self.assertRaisesRegex(ValueError, regex):
self.suggestions_dict['missing-option'].perform_checks()
def test_suggestion_missing_description(self):
regex = '.*provide option or description.*'
with self.assertRaisesRegex(ValueError, regex):
self.suggestions_dict['missing-description'].perform_checks()
class TestParsingErrors(unittest.TestCase):
def setUp(self):
self.this_path = os.path.abspath(os.path.dirname(__file__))
def test_condition_missing_source(self):
ini_path = os.path.join(self.this_path, 'input_files/rules_err2.ini')
db_rules = RulesSpec(ini_path)
regex = '.*provide source for condition.*'
with self.assertRaisesRegex(ValueError, regex):
db_rules.load_rules_from_spec()
def test_suggestion_missing_action(self):
ini_path = os.path.join(self.this_path, 'input_files/rules_err3.ini')
db_rules = RulesSpec(ini_path)
regex = '.*provide action for option.*'
with self.assertRaisesRegex(ValueError, regex):
db_rules.load_rules_from_spec()
def test_section_no_name(self):
ini_path = os.path.join(self.this_path, 'input_files/rules_err4.ini')
db_rules = RulesSpec(ini_path)
regex = 'Parsing error: section header be like:.*'
with self.assertRaisesRegex(ValueError, regex):
db_rules.load_rules_from_spec()
if __name__ == '__main__':
unittest.main()