def _HourlyStat(cur):
with Cons.MT("Hourly stat ..."):
Cons.P("# Left set of columns are for RocksDB, right one is for Mutant")
Cons.P("# J: all jobs")
Cons.P("# JR: recovery jobs")
Cons.P("# JF: flush jobs")
Cons.P("# JC: compaction jobs")
Cons.P("# JCL: compaction jobs. leveled organization triggered")
Cons.P("# SCL: sstables created. leveled organization triggered")
Cons.P("# SPJCL: sstables created / job. leveled organization triggered")
Cons.P("# SSCL: sum of the sstable sizes created. leveled organization triggered. In GB.")
Cons.P("# SCLR: sstables created. leveled organization triggered. regular compactions")
Cons.P("# SCLCM: sstables created. leveled organization triggered. compaction-migrations")
Cons.P("# JCT: compaction jobs. temperature-triggered single-sstable migration")
Cons.P("# SSCT: sum of the sstable sizes created. temperature-triggered single-sstable migration. In GB.")
Cons.P("#")
fmt = "%1d" \
" %2d %1d %1d %2d %2d" \
" %3d %5.3f %4.0f %3d %3d %2d %4.0f" \
" %6d %1d %1d %3d %3d" \
" %3d %5.3f %4.0f %3d %3d %3d %4.0f"
Cons.P(Util.BuildHeader(fmt, "hour" \
" J JR JF JC JCL" \
" SCL SPJCL SSCL SCLR SCLCM JCT SSCT" \
" J JR JF JC JCL" \
" SCL SPJCL SSCL SCLR SCLCM JCT SSCT"
))
for hour in range(10):
j = {}
j_r = {}
j_f = {}
j_c = {}
j_c_l = {}
s_c_l = {}
spj_c_l = {}
ss_c_l = {}
s_c_l_r = {}
s_c_l_cm = {}
j_c_t = {}
ss_c_t = {}
for db_type in ["R", "M"]:
db_type_str = "RocksDB" if db_type == "R" else "Mutant"
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info WHERE hour=%d and db_type='%s'" % (hour, db_type_str))
j[db_type] = cur.fetchone()["cnt"]
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info WHERE hour=%d and db_type='%s' and creation_reason='R'" % (hour, db_type_str))
j_r[db_type] = cur.fetchone()["cnt"]
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info WHERE hour=%d and db_type='%s' and creation_reason='F'" % (hour, db_type_str))
j_f[db_type] = cur.fetchone()["cnt"]
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info WHERE hour=%d and db_type='%s' and creation_reason='C'" % (hour, db_type_str))
j_c[db_type] = cur.fetchone()["cnt"]
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info" \
" WHERE hour=%d and db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0"
% (hour, db_type_str))
j_c_l[db_type] = cur.fetchone()["cnt"]
cur.execute("SELECT count(sst_id) as cnt FROM sst_creation_info" \
" WHERE hour=%d and db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0"
% (hour, db_type_str))
s_c_l[db_type] = cur.fetchone()["cnt"]
spj_c_l[db_type] = 0 if j_c_l[db_type] == 0 else (float(s_c_l[db_type]) / j_c_l[db_type])
cur.execute("SELECT sum(sst_size) as v FROM sst_creation_info" \
" WHERE hour=%d and db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0"
% (hour, db_type_str))
ss_c_l[db_type] = cur.fetchone()["v"]
if ss_c_l[db_type] is None:
ss_c_l[db_type] = 0
ss_c_l[db_type] = float(ss_c_l[db_type]) / 1024 / 1024 / 1024
cur.execute("SELECT count(sst_id) as cnt FROM sst_creation_info" \
" WHERE hour=%d and db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0 and migr_dirc IN ('-', 'N')"
% (hour, db_type_str))
s_c_l_r[db_type] = cur.fetchone()["cnt"]
cur.execute("SELECT count(sst_id) as cnt FROM sst_creation_info" \
" WHERE hour=%d and db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0 and migr_dirc IN ('S', 'F')"
% (hour, db_type_str))
s_c_l_cm[db_type] = cur.fetchone()["cnt"]
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info" \
" WHERE hour=%d and db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=1"
% (hour, db_type_str))
j_c_t[db_type] = cur.fetchone()["cnt"]
cur.execute("SELECT sum(sst_size) as v FROM sst_creation_info" \
" WHERE hour=%d and db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=1"
% (hour, db_type_str))
ss_c_t[db_type] = cur.fetchone()["v"]
if ss_c_t[db_type] is None:
ss_c_t[db_type] = 0
ss_c_t[db_type] = float(ss_c_t[db_type]) / 1024 / 1024 / 1024
Cons.P(fmt % (hour
, j["R"], j_r["R"], j_f["R"], j_c["R"], j_c_l["R"]
, s_c_l["R"], spj_c_l["R"], ss_c_l["R"], s_c_l_r["R"], s_c_l_cm["R"], j_c_t["R"], ss_c_t["R"]
, j["M"], j_r["M"], j_f["M"], j_c["M"], j_c_l["M"]
, s_c_l["M"], spj_c_l["M"], ss_c_l["M"], s_c_l_r["M"], s_c_l_cm["M"], j_c_t["M"], ss_c_t["M"]
))
def __init__(self, p):
self.fn_out = "%s/ycsb-by-time-%s" % (Conf.GetOutDir(), p.exp_dt)
if os.path.isfile(self.fn_out):
return
fn_in = "%s/%s/ycsb/%s-%s" % (p.dn_base, p.job_id, p.exp_dt, p.workload)
#Cons.P(fn_in)
with Cons.MT("Generating ycsb time-vs-metrics file for plot ..."):
# Unzip when the file is not there
if not os.path.exists(fn_in):
fn_zipped = "%s.bz2" % fn_in
if not os.path.exists(fn_zipped):
raise RuntimeError("Unexpected: %s" % fn_in)
Util.RunSubp("cd %s && bzip2 -dk %s > /dev/null" % (os.path.dirname(fn_zipped), os.path.basename(fn_zipped)))
if not os.path.exists(fn_in):
raise RuntimeError("Unexpected")
#Cons.P(fn_in)
mo_list = []
line_params = None
line_run = None
with open(fn_in) as fo:
for line in fo:
#Cons.P(line)
# 2017-10-13 20:41:01:258 2 sec: 34 operations; 34 current ops/sec; est completion in 68 days 1 hours [READ: Count=28, Max=46943, Min=33,
# Avg=32239.54, 90=45343, 99=46943, 99.9=46943, 99.99=46943] [INSERT: Count=8, Max=9343, Min=221, Avg=4660.88, 90=8695, 99=9343, 99.9=9343,
# 99.99=9343]
mo = re.match(r"\d\d\d\d-\d\d-\d\d \d\d:\d\d:\d\d:\d\d\d (?P<rel_time>\d+) sec: \d+ operations; " \
"(?P<db_iops>(\d|\.)+) current ops\/sec; .*" \
"\[READ: Count=(?P<r_cnt>\d+), Max=(?P<r_max>\d+), Min=(?P<r_min>\d+), Avg=(?P<r_avg>(\d|\.)+)," \
" 90=(?P<r_90>\d+), 99=(?P<r_99>\d+), 99.9=(?P<r_999>\d+), 99.99=(?P<r_9999>\d+)\] " \
"\[INSERT: Count=(?P<w_cnt>\d+), Max=(?P<w_max>\d+), Min=(?P<w_min>\d+), Avg=(?P<w_avg>(\d|\.)+)," \
" 90=(?P<w_90>\d+), 99=(?P<w_99>\d+), 99.9=(?P<w_999>\d+), 99.99=(?P<w_9999>\d+)\] " \
, line)
if mo is not None:
total_seconds = int(mo.group("rel_time"))
s = total_seconds % 60
total_seconds -= s
total_mins = total_seconds / 60
m = total_mins % 60
total_mins -= m
h = total_mins / 60
rel_time = "%02d:%02d:%02d" % (h, m, s)
mo_list.append((rel_time, mo))
continue
if line.startswith("params = {"):
line_params = line
continue
if line.startswith("run = {"):
line_run = line
continue
if len(mo_list) == 0:
raise RuntimeError("Unexpected. Check file [%s]" % fn_in)
cnt = 0
db_iops = []
r_cnt = 0
r_avg = 0.0
r_min = 0
r_max = 0
r_90 = 0
r_99 = 0
r_999 = 0
r_9999 = 0
w_cnt = 0
w_avg = 0.0
w_min = 0
w_max = 0
w_90 = 0
w_99 = 0
w_999 = 0
w_9999 = 0
for e in mo_list:
rel_time = e[0]
mo = e[1]
db_iops.append(float(mo.group("db_iops")))
r_cnt += int(mo.group("r_cnt"))
r_avg += float(mo.group("r_avg"))
r_min += int(mo.group("r_min"))
r_max += int(mo.group("r_max"))
r_90 += int(mo.group("r_90"))
r_99 += int(mo.group("r_99"))
r_999 += int(mo.group("r_999"))
r_9999 += int(mo.group("r_9999"))
w_cnt += int(mo.group("w_cnt"))
w_avg += float(mo.group("w_avg"))
w_min += int(mo.group("w_min"))
w_max += int(mo.group("w_max"))
w_90 += int(mo.group("w_90"))
w_99 += int(mo.group("w_99"))
w_999 += int(mo.group("w_999"))
w_9999 += int(mo.group("w_9999"))
cnt += 1
db_iops_stat = Stat.Gen(db_iops)
with open(self.fn_out, "w") as fo_out:
fo_out.write("# %s" % line_params)
fo_out.write("# %s" % line_run)
fo_out.write("\n")
fo_out.write("# db_iops.avg= %14f\n" % db_iops_stat.avg)
fo_out.write("# db_iops.min= %14f\n" % db_iops_stat.min)
fo_out.write("# db_iops.max= %14f\n" % db_iops_stat.max)
fo_out.write("# db_iops._25= %14f\n" % db_iops_stat._25)
fo_out.write("# db_iops._50= %14f\n" % db_iops_stat._50)
fo_out.write("# db_iops._75= %14f\n" % db_iops_stat._75)
fo_out.write("# r_cnt = %14f\n" % (float(r_cnt ) / cnt))
fo_out.write("# r_avg = %14f\n" % (float(r_avg ) / cnt))
fo_out.write("# r_min = %14f\n" % (float(r_min ) / cnt))
fo_out.write("# r_max = %14f\n" % (float(r_max ) / cnt))
fo_out.write("# r_90 = %14f\n" % (float(r_90 ) / cnt))
fo_out.write("# r_99 = %14f\n" % (float(r_99 ) / cnt))
fo_out.write("# r_999 = %14f\n" % (float(r_999 ) / cnt))
fo_out.write("# r_9999 = %14f\n" % (float(r_9999) / cnt))
fo_out.write("# w_cnt = %14f\n" % (float(w_cnt ) / cnt))
fo_out.write("# w_avg = %14f\n" % (float(w_avg ) / cnt))
fo_out.write("# w_min = %14f\n" % (float(w_min ) / cnt))
fo_out.write("# w_max = %14f\n" % (float(w_max ) / cnt))
fo_out.write("# w_90 = %14f\n" % (float(w_90 ) / cnt))
fo_out.write("# w_99 = %14f\n" % (float(w_99 ) / cnt))
fo_out.write("# w_999 = %14f\n" % (float(w_999 ) / cnt))
fo_out.write("# w_9999 = %14f\n" % (float(w_9999) / cnt))
fo_out.write("\n")
fmt = "%8s" \
" %9.2f" \
" %6d %8.2f %3d %6d" \
" %6d %6d %6d %6d" \
" %6d %8.2f %3d %6d" \
" %6d %6d %6d %6d"
header = Util.BuildHeader(fmt, "rel_time" \
" db_iops" \
" read_cnt read_lat_avg read_lat_min read_lat_max" \
" read_lat_90p read_lat_99p read_lat_99.9p read_lat_99.99p" \
" write_cnt write_lat_avg write_lat_min write_lat_max" \
" write_lat_90p write_lat_99p write_lat_99.9p write_lat_99.99p" \
)
i = 0
for e in mo_list:
rel_time = e[0]
mo = e[1]
if i % 40 == 0:
fo_out.write(header + "\n")
fo_out.write((fmt + "\n") % (
rel_time
, float(mo.group("db_iops"))
, int(mo.group("r_cnt")) , float(mo.group("r_avg")) , int(mo.group("r_min")) , int(mo.group("r_max"))
, int(mo.group("r_90")) , int(mo.group("r_99")) , int(mo.group("r_999")) , int(mo.group("r_9999"))
, int(mo.group("w_cnt")) , float(mo.group("w_avg")) , int(mo.group("w_min")) , int(mo.group("w_max"))
, int(mo.group("w_90")) , int(mo.group("w_99")) , int(mo.group("w_999")) , int(mo.group("w_9999"))
))
i += 1
Cons.P("Created %s %d" % (self.fn_out, os.path.getsize(self.fn_out)))
def __init__(self, dn_log_job, exp_dt):
self.fn_out = "%s/rocksdb-by-time-%s" % (Conf.GetOutDir(), exp_dt)
if os.path.isfile(self.fn_out):
return
# These classes rely on the global data structures, thus not thread-safe. Fine for now.
SstEvents.Init(exp_dt)
HowCreated.Init()
CompInfo.Init()
with Cons.MT("Generating rocksdb time-vs-metrics file for plot ..."):
fn_log_rocksdb = "%s/rocksdb/%s" % (dn_log_job, exp_dt)
if not os.path.exists(fn_log_rocksdb):
fn_zipped = "%s.bz2" % fn_log_rocksdb
if not os.path.exists(fn_zipped):
raise RuntimeError("Unexpected: %s" % fn_log_rocksdb)
Util.RunSubp(
"cd %s && bzip2 -dk %s > /dev/null" %
(os.path.dirname(fn_zipped), os.path.basename(fn_zipped)))
if not os.path.exists(fn_log_rocksdb):
raise RuntimeError("Unexpected")
Cons.P(fn_log_rocksdb)
with open(fn_log_rocksdb) as fo:
for line in fo:
#Cons.P(line)
# 2018/01/05-08:10:30.085011 7f40083d8700 migrate_sstables: 0
if " migrate_sstables: " in line:
mo = re.match(
r"(?P<ts>(\d|\/|-|:|\.)+) .* migrate_sstables: (?P<v>\d).*",
line)
if mo is None:
raise RuntimeError("Unexpected: [%s]" % line)
self.migrate_sstables = (mo.group("v") == "1")
SstEvents.migrate_sstables = self.migrate_sstables
HowCreated.migrate_sstables = self.migrate_sstables
# 2017/10/13-20:41:54.872056 7f604a7e4700 EVENT_LOG_v1 {"time_micros": 1507927314871238, "cf_name": "usertable", "job": 3, "event":
# "table_file_creation", "file_number": 706, "file_size": 258459599, "path_id": 0, "table_properties": {"data_size": 256772973, "index_size": 1685779,
# "filter_size": 0, "raw_key_size": 6767934, "raw_average_key_size": 30, "raw_value_size": 249858360, "raw_average_value_size": 1140,
# "num_data_blocks": 54794, "num_entries": 219174, "filter_policy_name": "", "reason": kFlush, "kDeletedKeys": "0", "kMergeOperands": "0"}}
elif "\"event\": \"table_file_creation\"" in line:
SstEvents.Created(line)
# 2018/01/01-05:33:49.183505 7f97d0ff1700 EVENT_LOG_v1 {"time_micros": 1514784829183496, "job": 6, "event": "table_file_deletion", "file_number": 21}
elif "\"event\": \"table_file_deletion\"" in line:
SstEvents.Deleted(line)
# 2018/01/23-00:13:13.593310 7fa321da9700 EVENT_LOG_v1 {"time_micros": 1516666393593302, "mutant_calc_out_sst_path_id": {"in_sst": "(sst_id=16
# temp=57.189 level=0 path_id=0 size=258425431 age=30)", "in_sst_temp": "57.188590", "sst_ott": 3176.66, "out_sst_path_id": 1,
# "temp_triggered_single_sst_compaction": 1}}
elif "\"mutant_calc_out_sst_path_id\"" in line:
CompInfo.SetTempTriggeredSingleSstMigr(line)
# Figure out how an SSTable is created
# (a) start building CompInfo
# 2018/01/05-08:40:21.078219 7fd13ffff700 EVENT_LOG_v1 {"time_micros": 1515141621078214, "mutant_sst_compaction_migration": {"in_sst": "(sst_id=16
# temp=57.345 level=0 path_id=0 size=258423184 age=30) (sst_id=13 temp=3738.166 level=0 path_id=1 size=118885 age=440)", "out_sst_path_id": 1,
# "temp_triggered_single_sst_compaction": 1}}
#
# Some SSTables are created without this log, meaning not going through _CalcOutputPathId(). Use the other one.
#elif "mutant_sst_compaction_migration" in line:
# if not self.migrate_sstables:
# continue
# CompInfo.Add(line)
# Build CompInfo
# We manually parse this just because there are multiple keys with "files_L0" and json would probably not be able to parse it
# 2018/01/05-08:40:21.078303 7fd13ffff700 EVENT_LOG_v1 {"time_micros": 1515141621078294, "job": 5, "event": "compaction_started", "files_L0": [16,
# 13], "files_L0": [16, 13], "score": 0, "input_data_size": 517084138}
elif "compaction_started" in line:
CompInfo.SetCompStarted(line)
# (c) Assign out_sst_info to CompInfo using job_id. It is done when parsing table_file_creation above.
CompInfo.CalcMigrDirections()
SstEvents.Write(self.fn_out)
def GetData():
fn_hm = "%s/sst-heatmap-by-time-%s" % (Conf.dn_result, Conf.Get("simulation_time_begin"))
fn_vl = "%s/sst-heatmap-by-time-vertical-lines-%s" % (Conf.dn_result, Conf.Get("simulation_time_begin"))
if os.path.isfile(fn_hm) and os.path.isfile(fn_vl):
return (fn_hm, fn_vl, _MaxHeatFromHeatmapByTimeData(fn_hm))
# {sst_id, SstLife()}
sst_lives = RocksdbLogReader.GetSstLives()
with Cons.MT("Generating Sst heatmap by time ..."):
# Gather temperature info at n different times
num_times = Conf.heatmap_by_time_num_times
# Set start and end times
# Start time is when the first Sstable is created, not the simulation_time_begin, when no SSTable exists yet.
# Exp start time: 160927-143257.395
# First Sstable open time: 160927-143411.273
min_sst_opened = None
for sst_gen, sl in sorted(sst_lives.iteritems()):
min_sst_opened = sl.TsCreated() if min_sst_opened is None else min(min_sst_opened, sl.TsCreated())
st = min_sst_opened
et = SimTime.SimulationTimeEnd()
dur = (et - st).total_seconds()
# { t0: {HeatBoxes} }
time_heatboxes = {}
max_temperature = None
for i in range(0, num_times):
t0 = st + datetime.timedelta(seconds=(float(dur) * i / num_times + time_offset_in_sec))
t1 = st + datetime.timedelta(seconds=(float(dur) * (i+1) / num_times + time_offset_in_sec))
# Sort boxes by their temperature. Heights are proportional to their sizes.
boxes = []
for sst_gen, sl in sorted(sst_lives.iteritems()):
temp = sl.TempAtTime(t0)
if max_temperature is None:
max_temperature = temp
else:
max_temperature = max(max_temperature, temp)
if temp is None:
continue
boxes.append(_Box(sl, t0, t1, temp))
boxes.sort(key=lambda b: b.temp, reverse=True)
time_heatboxes[t0] = boxes
Cons.ClearLine()
Cons.Pnnl("%4d/%4d" % (i + 1, num_times))
print ""
for t, boxes in sorted(time_heatboxes.iteritems()):
for b in boxes:
b.SetTempColor(max_temperature)
# Set y-coordinate of each box
for t, boxes in sorted(time_heatboxes.iteritems()):
total_size = 0
for b in boxes:
total_size += b.sl.Size()
s = 0
for b in boxes:
b.y0 = float(s) / total_size
s += b.sl.Size()
b.y1 = float(s) / total_size
# Convert to simulated time
# { t0: {HeatBoxes} }
time_heatboxes1 = {}
for t, boxes in sorted(time_heatboxes.iteritems()):
t1 = SimTime.ToSimulatedTime(t)
for b in boxes:
b.t0 = SimTime.ToSimulatedTime(b.t0)
b.t1 = SimTime.ToSimulatedTime(b.t1)
time_heatboxes1[t1] = boxes
# Make leftmost time to 0.
t_first = None
#t_base = datetime.datetime(2000, 1, 1)
vertical_lines = []
for t, boxes in sorted(time_heatboxes1.iteritems()):
if t_first is None:
t_first = t
vl = None
for b in boxes:
#b.t0 = t_base + (b.t0 - t_first)
#b.t1 = t_base + (b.t1 - t_first)
b.t0 = (b.t0 - t_first).total_seconds()
b.t1 = (b.t1 - t_first).total_seconds()
vl = b.t1
vertical_lines.append(vl)
del vertical_lines[-1]
fmt = "%4d %1d" \
" %8d %8d" \
" %6.4f %6.4f" \
" %8.3f %11.6f %8d %6s"
with open(fn_hm, "w") as fo:
fo.write("# max_temperature=%f\n" % max_temperature)
# y0 is smaller than y1 (y0 is placed higher in the plot than y1).
fo.write("%s\n" % Util.BuildHeader(fmt, \
"sst_gen level t0 t1 y0 y1" \
" temp temp_relative temp_color heat_color_hex"))
for t, boxes in sorted(time_heatboxes1.iteritems()):
for b in boxes:
fo.write((fmt + "\n") % ( \
b.sl.Id(), b.sl.Level()
#, b.t0.strftime("%y%m%d-%H%M%S.%f")[:-3], b.t1.strftime("%y%m%d-%H%M%S.%f")[:-3]
, b.t0, b.t1
, b.y0, b.y1
, b.temp, (float(b.temp) / max_temperature)
, b.temp_color, ("%0.6X" % b.temp_color)
))
fo.write("\n")
Cons.P("Created %s %d" % (fn_hm, os.path.getsize(fn_hm)))
with open(fn_vl, "w") as fo:
for vl in vertical_lines:
#fo.write("%s\n" % vl.strftime("%y%m%d-%H%M%S.%f")[:-3])
fo.write("%8d\n" % vl)
Cons.P("Created %s %d" % (fn_vl, os.path.getsize(fn_vl)))
return (fn_hm, fn_vl, max_temperature)
def main():
parser = optparse.OptionParser(usage="usage: %prog [options]",
version="%prog 0.1")
parser.add_option("--encoded_params", help="Encoded parameters")
(options, args) = parser.parse_args()
if len(args) != 0:
parser.error("wrong number of arguments")
#Cons.P(pprint.pformat(options))
signal.signal(signal.SIGINT, sigint_handler)
params = json.loads(
zlib.decompress(base64.b64decode(options.encoded_params)))
# Cons.P(pprint.pformat(params))
#
# {u'cache_filter_index_at_all_levels': u'false',
# u'db_path': u'/mnt/local-ssd1/rocksdb-data/quizup',
# u'db_stg_devs': [[u'/mnt/local-ssd0/rocksdb-data/ycsb/t0', 0.528],
# [u'/mnt/ebs-st1/rocksdb-data-t1', 0.045]],
# u'evict_cached_data': u'true',
# u'exp_desc': u'Mutant_QuizUp',
# u'memory_limit_in_mb': 5120.0,
# u'migrate_sstables': u'true',
# u'migration_resistance': 0.05,
# u'monitor_temp': u'true',
# u'record_size': 5000,
# u'simulation_time_dur_in_sec': 600,
# u'target_cost': 0.4,
# u'use_90p_loaded_db': u'false',
# u'workload_time_range': [0.0, 0.9]}
with Cons.MT("Building ..."):
Util.RunSubp("make -j16")
if ("use_90p_loaded_db"
in params) and (params["use_90p_loaded_db"].lower() == "true"):
raise RuntimeError("Implement!")
# cmd = "aws s3 sync --delete s3://rocksdb-data/%s %s" % (r["load"]["use_90p_loaded_db"][0], params["db_path"])
# # aws s3 sync fails sometimes when pounded with requests and it seems that it doesn't tell you whether it succeeded or not.
# # Repeat many times. It fixed the issue.
# # A better approach would be running a checksum. Oh well.
# for i in range(5):
# Util.RunSubp(cmd, measure_time=True, shell=True, gen_exception=False)
# if 2 <= len(r["load"]["use_90p_loaded_db"]):
# cmd = "aws s3 sync --delete s3://rocksdb-data/%s %s" % (r["load"]["use_90p_loaded_db"][1], params["db_stg_devs"][1][0])
# for i in range(5):
# Util.RunSubp(cmd, measure_time=True, shell=True, gen_exception=False)
# Util.RunSubp("sync", measure_time=True, shell=True, gen_exception=False)
# # Re-create the directories when a preloaded DB is not specified.
# paths = params["db_stg_devs"]
# for i in range(len(r["load"]["use_90p_loaded_db"]), len(paths)):
# Util.RunSubp("rm -rf %s || true" % paths[i][0])
# Util.MkDirs(paths[i][0])
# Load the database from the scratch
else:
# Delete existing data
Util.RunSubp("sudo rm -rf %s || true" % params["db_path"])
for p in params["db_stg_devs"]:
Util.RunSubp("rm -rf %s || true" % p[0])
Util.MkDirs(p[0])
# One experiment per machine instance. We don't do multiple experiments, since it's bad for the EBS rate limiting.
if False:
# The ycsb log directory contains 2 files when the load phase is included. 1, otherwise.
cur_datetime = datetime.datetime.now().strftime(
"%y%m%d-%H%M%S.%f")[:-3]
fn_ycsb_log = "%s/%s-%s" % (_dn_log_root_ycsb, cur_datetime,
params["workload_type"])
cmd = "cd %s && bin/ycsb load rocksdb %s -m %s > %s 2>&1" % (
_dn_ycsb, ycsb_params, mutant_options, fn_ycsb_log)
Util.RunSubp(cmd,
measure_time=True,
shell=True,
gen_exception=False)
Cons.P("Created %s %d" %
(fn_ycsb_log, os.path.getsize(fn_ycsb_log)))
# No need to upload these to S3
#Util.RunSubp("pbzip2 -k %s" % fn_ycsb_log)
#UploadToS3("%s.bz2" % fn_ycsb_log)
# Archive rocksdb log
fn1 = "%s/%s" % (_dn_log_rocksdb, cur_datetime)
cmd = "cp %s/LOG %s" % (params["db_path"], fn1)
Util.RunSubp(cmd,
measure_time=True,
shell=True,
gen_exception=False)
#Util.RunSubp("pbzip2 -k %s" % fn1)
#UploadToS3("%s.bz2" % fn1)
CheckRocksDBLog(fn1)
if params["evict_cached_data"].lower() == "true":
_EvictCache()
Dstat.Restart()
cmd = "stdbuf -i0 -o0 -e0 ./quizup --encoded_params=%s" % options.encoded_params
if params["memory_limit_in_mb"] == 0:
Util.RunSubp("LD_LIBRARY_PATH=%s/work/mutant/rocksdb %s" \
% (os.path.expanduser("~"), cmd), shell=True, gen_exception=False)
else:
fn_cgconfig = "%s/cgconfig.conf" % os.path.dirname(__file__)
Util.RunSubp("sed -i 's/" \
"^ memory\.limit_in_bytes = .*" \
"/ memory\.limit_in_bytes = %d;" \
"/g' %s" % (int(float(params["memory_limit_in_mb"]) * 1024 * 1024), fn_cgconfig))
Util.RunSubp("sudo cgconfigparser -l %s" % fn_cgconfig)
Util.RunSubp("LD_LIBRARY_PATH=%s/work/mutant/rocksdb cgexec -g memory:small_mem %s" \
% (os.path.expanduser("~"), cmd), shell=True, gen_exception=False)
Dstat.Stop()
# Draw attention if there is any WARN or ERROR in the RocksDB log
CheckRocksDBLog()
if ("upload_result_to_s3"
in params) and (params["upload_result_to_s3"].lower() == "true"):
AppendAllOptionsToClientLogFileAndZip(params)
UploadToS3(params["job_id"])
def DeleteQ(q):
with Cons.MT("Deleting queue ..."):
response = _bc.delete_queue(QueueUrl=q._url)
Cons.P(pprint.pformat(response, indent=2))
def SetEc2Tags(v):
global _ec2_tags
_ec2_tags = json.loads(v)
Cons.P("_ec2_tags: %s" % pprint.pformat(_ec2_tags))
def _BuildSstLives(self):
with Cons.MT("Building sst lives ..."):
self.sst_lives = {}
dn = "%s/work/mutant/misc/rocksdb/log/rocksdb" % os.path.expanduser(
"~")
fn = "%s/%s" % (dn, self.simulation_time_begin)
if not os.path.isfile(fn):
fn_7z = "%s.7z" % fn
if not os.path.isfile(fn_7z):
raise RuntimeError("Unexpected")
Util.RunSubp("cd %s && 7z e %s" % (dn, fn_7z))
if not os.path.isfile(fn):
raise RuntimeError("Unexpected")
# For setting SSTable levels
#{ job_id: dest_level }
self.jobid_destlevel = {}
line_no = 0
with open(fn) as fo:
for line in fo:
line_no += 1
# 2016/12/21-01:27:40.840324 7f702dffb700 EVENT_LOG_v1 {"time_micros":
# 1482301660840289, "cf_name": "default", "job": 4, "event":
# "table_file_creation", "file_number": 15, "file_size": 67569420,
# "path_id": 0, "table_properties": {"data_size": 67110556, "index_size": 458020,
# "filter_size": 0, "raw_key_size": 1752468, "raw_average_key_size": 25,
# "raw_value_size": 65132550, "raw_average_value_size": 966,
# "num_data_blocks": 16857, "num_entries": 67425, "filter_policy_name":
# "", "reason": kCompaction, "kDeletedKeys": "0", "kMergeOperands": "0"}}
mo = re.match(r"(?P<ts>\d\d\d\d/\d\d/\d\d-\d\d:\d\d:\d\d\.\d\d\d\d\d\d)" \
".+ EVENT_LOG_v1 {\"time_micros\": (?P<time_micros>\d+)" \
", \"cf_name\": \"default\"" \
", \"job\": (?P<job>\d+)" \
", \"event\": \"table_file_creation\"" \
", \"file_number\": (?P<file_number>\d+)" \
", \"file_size\": (?P<file_size>\d+)" \
", \"path_id\": (?P<path_id>\d+)" \
".+" \
", \"reason\": (?P<reason>\w+)" \
".*"
, line)
if mo is not None:
self._SetTabletCreated(mo)
continue
# 2016/12/21-02:15:58.341853 7f702dffb700 EVENT_LOG_v1 {"time_micros":
# 1482304558341847, "job": 227, "event": "table_file_deletion",
# "file_number": 1058}
mo = re.match(r"(?P<ts>\d\d\d\d/\d\d/\d\d-\d\d:\d\d:\d\d\.\d\d\d\d\d\d)" \
".+ EVENT_LOG_v1 {\"time_micros\": (?P<time_micros>\d+)" \
", \"job\": \d+" \
", \"event\": \"table_file_deletion\"" \
", \"file_number\": (?P<file_number>\d+)" \
"}" \
".*"
, line)
if mo is not None:
self._SetTabletDeleted(mo)
continue
# 2017/01/20-23:03:00.960592 7fc8037fe700 EVENT_LOG_v1 {"time_micros":
# 1484971380960590, "mutant_trivial_move": {"in_sst": "sst_id=145
# level=1 path_id=0 temp=20.721", "out_sst_path_id": 0}}
mo = re.match(r"(?P<ts>\d\d\d\d/\d\d/\d\d-\d\d:\d\d:\d\d\.\d\d\d\d\d\d)" \
".+ EVENT_LOG_v1 {\"time_micros\": (?P<time_micros>\d+)" \
", \"mutant_trivial_move\": {" \
"\"in_sst\": \"" \
"sst_id=(?P<in_sst_id>\d+)" \
" level=(?P<in_level>\d+)" \
" path_id=(?P<in_path_id>\d+)" \
" temp=(?P<in_temp>(\d|\.)+)" \
"\", \"out_sst_path_id\": (?P<out_path_id>\d+)}}" \
".*"
, line)
if mo is not None:
self._SetTrivialMove(mo)
continue
# These two are to get SSTable levels. From compactions or trivial
# moves.
#
# 2017/02/10-01:05:17.199656 7fa0f17fa700 [default] [JOB 225]
# Compacting 1@1 + 3@2 files to L2, score 1.01
mo = re.match(r"(?P<ts>\d\d\d\d/\d\d/\d\d-\d\d:\d\d:\d\d\.\d\d\d\d\d\d)" \
".+ \[(\w|\d)+\] \[JOB (?P<job_id>\d+)\]" \
" Compacting \d+@\d+( \+ \d+@\d+)* files" \
" to L(?P<dest_level>\d), score (\d|\.)+" \
".*"
, line)
if mo is not None:
self._SetCompacting(mo)
continue
# 2017/02/09-20:07:08.521173 7fa0f37fe700 (Original Log Time
# 2017/02/09-20:07:08.519960) [default] Moving #56 to level-2
# 67579565 bytes
mo = re.match(r"(?P<ts>\d\d\d\d/\d\d/\d\d-\d\d:\d\d:\d\d\.\d\d\d\d\d\d)" \
".+ \[(\w|\d)+\] Moving #(?P<sst_id>\d+) to level-(?P<level>\d) \d+ bytes" \
".*"
, line)
if mo is not None:
self._SetMoving(mo)
continue
Cons.P("Processed %d lines" % line_no)
deleted = 0
not_deleted = 0
for sst_id, sl in self.sst_lives.iteritems():
if sl.TsDeleted() is None:
not_deleted += 1
else:
deleted += 1
Cons.P("Created %d SstLives. %d not-deleted, %d deleted" %
(len(self.sst_lives), not_deleted, deleted))
def YcsbLoad(params, r):
with Cons.MT("Loading the YCSB workload ..."):
global _dn_log_root
_dn_log_root = "%s/ycsb/%s" % (Conf.GetDir("log_archive_dn"),
Ec2Util.JobId())
global _dn_log_root_ycsb
_dn_log_root_ycsb = "%s/ycsb" % _dn_log_root
Util.MkDirs(_dn_log_root_ycsb)
global _dn_log_rocksdb
_dn_log_rocksdb = "%s/rocksdb" % _dn_log_root
Util.MkDirs(_dn_log_rocksdb)
if ("use_preloaded_db" in r["load"]) and (r["load"]["use_preloaded_db"]
is not None):
cmd = "aws s3 sync --delete s3://rocksdb-data/%s %s" % (
r["load"]["use_preloaded_db"][0], params["db_path"])
# aws s3 sync fails sometimes when pounded with requests and it seems that it doesn't tell you whether it succeeded or not.
# Repeat many times. It fixed the issue.
# A better approach would be running a checksum. Oh well.
for i in range(5):
Util.RunSubp(cmd,
measure_time=True,
shell=True,
gen_exception=False)
if 2 <= len(r["load"]["use_preloaded_db"]):
cmd = "aws s3 sync --delete s3://rocksdb-data/%s %s" % (
r["load"]["use_preloaded_db"][1],
params["db_stg_devs"][1][0])
for i in range(5):
Util.RunSubp(cmd,
measure_time=True,
shell=True,
gen_exception=False)
Util.RunSubp("sync",
measure_time=True,
shell=True,
gen_exception=False)
# Re-create the directories when a preloaded DB is not specified.
paths = params["db_stg_devs"]
for i in range(len(r["load"]["use_preloaded_db"]), len(paths)):
Util.RunSubp("rm -rf %s || true" % paths[i][0])
Util.MkDirs(paths[i][0])
else:
# Delete existing data
Util.RunSubp("sudo rm -rf %s || true" % params["db_path"])
for p in params["db_stg_devs"]:
Util.RunSubp("rm -rf %s || true" % p[0])
Util.MkDirs(p[0])
ycsb_params = \
" -s" \
" -P workloads/workload%s" \
" -p rocksdb.dir=%s" \
" -threads 100" \
" -p status.interval=1" \
" -p fieldcount=10" \
" -p fieldlength=100" \
" %s" \
% (params["workload_type"], params["db_path"], r["load"]["ycsb_params"])
# -P file Specify workload file
# -cp path Additional Java classpath entries
# -jvm-args args Additional arguments to the JVM
# -p key=value Override workload property
# -s Print status to stderr
# -target n Target ops/sec (default: unthrottled)
# -threads n Number of client threads (default: 1)
mutant_options = base64.b64encode(
zlib.compress(json.dumps(r["mutant_options"])))
# The ycsb log directory contains 2 files when the load phase is included. 1, otherwise.
cur_datetime = datetime.datetime.now().strftime(
"%y%m%d-%H%M%S.%f")[:-3]
fn_ycsb_log = "%s/%s-%s" % (_dn_log_root_ycsb, cur_datetime,
params["workload_type"])
cmd = "cd %s && bin/ycsb load rocksdb %s -m %s > %s 2>&1" % (
_dn_ycsb, ycsb_params, mutant_options, fn_ycsb_log)
Util.RunSubp(cmd,
measure_time=True,
shell=True,
gen_exception=False)
Cons.P("Created %s %d" %
(fn_ycsb_log, os.path.getsize(fn_ycsb_log)))
# No need to upload these to S3
#Util.RunSubp("pbzip2 -k %s" % fn_ycsb_log)
#UploadToS3("%s.bz2" % fn_ycsb_log)
# Archive rocksdb log
fn1 = "%s/%s" % (_dn_log_rocksdb, cur_datetime)
cmd = "cp %s/LOG %s" % (params["db_path"], fn1)
Util.RunSubp(cmd,
measure_time=True,
shell=True,
gen_exception=False)
#Util.RunSubp("pbzip2 -k %s" % fn1)
#UploadToS3("%s.bz2" % fn1)
CheckRocksDBLog(fn1)
# Stop after loading the DB. Useful for taking a snapshot.
if ("stop_after_load" in r["load"]) and (r["load"]["stop_after_load"]
== "true"):
sys.exit(1)
def _Log(msg):
Cons.P("%s: %s" % (time.strftime("%y%m%d-%H%M%S"), msg))
def _CalcNumSSTablesSizeAtEachLevelOverTime(self):
if self.sst_lives is None:
raise RuntimeError("Unexpected")
# Sort them by ts_cd and, to break ties, by sst_id
# {ts_created_or_deleted: sst_id}
class TscdSstid:
def __init__(self, sim_time, ts, event, sst_id):
self.ts = ts
if ts is not None:
self.ts = sim_time.ToSimulatedTime(self.ts)
# "C"reated or "D"eleted
self.event = event
self.sst_id = sst_id
if self.ts is not None:
if sim_time.SimulatedTimeEnd() < self.ts:
# This happens. Tolerate ts no bigger than sim_time.SimulatedTimeEnd()
# by 5 minutes, which is small compared with the 14 day time
# interval.
if (self.ts - sim_time.SimulatedTimeEnd()
).total_seconds() > 300:
raise RuntimeError(
"Unexpected: sim_time.SimulatedTimeEnd()=%s self.ts=%s"
% (sim_time.SimulatedTimeEnd(), self.ts))
if self.event == "D" and self.ts is None:
self.ts = sim_time.SimulatedTimeEnd()
if self.ts is None:
raise RuntimeError("Unexpected")
def __str__(self):
return "(%s %s %d)" % (self.ts, self.event, self.sst_id)
def __repr__(self):
return self.__str__()
@staticmethod
def Cmp(a, b):
if a.ts < b.ts:
return -1
elif a.ts > b.ts:
return 1
else:
# Breaking tie. The order is not important.
return (a.sst_id - b.sst_id)
tscd_sstid = []
for sst_id, sl in self.sst_lives.iteritems():
tscd_sstid.append(
TscdSstid(self.sim_time, sl.TsCreated(), "C", sst_id))
tscd_sstid.append(
TscdSstid(self.sim_time, sl.TsDeleted(), "D", sst_id))
#Cons.P(pprint.pformat(tscd_sstid))
tscd_sstid = sorted(tscd_sstid, cmp=TscdSstid.Cmp)
#Cons.P(pprint.pformat(tscd_sstid))
# Calculate the number of SSTables and size at each level
cur_num_ssts_by_level = [0, 0, 0]
cur_size_by_level = [0.0, 0.0, 0.0]
# Size*time in byte*sec up to now
cumulative_numssts_time_by_level = [0.0, 0.0, 0.0]
cumulative_size_time_by_level = [0.0, 0.0, 0.0]
cur_num_ssts_by_pathid = [0, 0, 0, 0]
cur_size_by_pathid = [0.0, 0.0, 0.0, 0.0]
cumulative_numssts_time_by_pathid = [0.0, 0.0, 0.0, 0.0]
cumulative_size_time_by_pathid = [0.0, 0.0, 0.0, 0.0]
# Init to simulated_time_begin
ts_prev = self.sim_time.SimulatedTimeBegin()
dn = "%s/.output" % os.path.dirname(__file__)
fn = "%s/num-sstables-size-at-each-level-over-time-%s" % (
dn, self.simulation_time_begin)
with open(fn, "w") as fo:
# 160727-122652.458
# 12345678901234567
fmt = "%17s %17s %5d" \
" %2d %2d %2d" \
" %2d %2d %2d" \
" %8.3f %8.3f %8.3f" \
" %8.3f %8.3f %8.3f"
header = Util.BuildHeader(fmt \
, "ts0 ts1 ts_dur" \
" prev_num_ssts_L0 prev_num_ssts_L1 prev_num_ssts_L2" \
" cur_num_ssts_L0 cur_num_ssts_L1 cur_num_ssts_L2" \
\
" prev_size_L0_in_MB prev_size_L1_in_MB prev_size_L2_in_MB" \
" cur_size_L0_in_MB cur_size_L1_in_MB cur_size_L2_in_MB" \
)
i = 0
for e in tscd_sstid:
if i % 30 == 0:
fo.write("%s\n" % header)
i += 1
if self.simulated_time_95 is None:
if e.ts < self.sim_time.SimulatedTimeBegin():
Cons.P("e.ts %s < self.sim_time.SimulatedTimeBegin() %s. Adjusting to the latter. This happens." \
% (e.ts, self.sim_time.SimulatedTimeBegin()))
e.ts = self.sim_time.SimulatedTimeBegin()
else:
if e.ts < self.simulated_time_95:
e.ts = self.simulated_time_95
prev_num_ssts_by_level = cur_num_ssts_by_level[:]
prev_size_by_level = cur_size_by_level[:]
prev_num_ssts_by_pathid = cur_num_ssts_by_pathid[:]
prev_size_by_pathid = cur_size_by_pathid[:]
for j in range(3):
cumulative_numssts_time_by_level[j] += (
cur_num_ssts_by_level[j] *
(e.ts - ts_prev).total_seconds())
cumulative_size_time_by_level[j] += (
cur_size_by_level[j] *
(e.ts - ts_prev).total_seconds())
for j in range(4):
cumulative_numssts_time_by_pathid[j] += (
cur_num_ssts_by_pathid[j] *
(e.ts - ts_prev).total_seconds())
cumulative_size_time_by_pathid[j] += (
cur_size_by_pathid[j] *
(e.ts - ts_prev).total_seconds())
level = self.sst_lives[e.sst_id].Level()
if level is None:
# Ignore those in the beginning
if self.simulated_time_95 is None:
if (e.ts - self.sim_time.SimulatedTimeBegin()
).total_seconds() < 1.0:
ts_prev = e.ts
continue
else:
if e.ts <= self.simulated_time_95:
ts_prev = e.ts
continue
raise RuntimeError("Unexpected: sst_id=%d level is not defined yet. ts_prev=%s ts=%s ts_dur=%d" \
% (e.sst_id, ts_prev, e.ts, (e.ts - ts_prev).total_seconds()))
pathid = self.sst_lives[e.sst_id].PathId()
size = self.sst_lives[e.sst_id].Size()
if e.event == "C":
cur_num_ssts_by_level[level] += 1
cur_size_by_level[level] += size
cur_num_ssts_by_pathid[pathid] += 1
cur_size_by_pathid[pathid] += size
elif e.event == "D":
cur_num_ssts_by_level[level] -= 1
cur_size_by_level[level] -= size
cur_num_ssts_by_pathid[pathid] -= 1
cur_size_by_pathid[pathid] -= size
else:
raise RuntimeError("Unexpected")
# We'll see if you need by_pathid stat here
fo.write((fmt + "\n") %
(ts_prev.strftime("%y%m%d-%H%M%S.%f")[:-3],
e.ts.strftime("%y%m%d-%H%M%S.%f")[:-3],
(e.ts - ts_prev).total_seconds(),
prev_num_ssts_by_level[0], prev_num_ssts_by_level[1],
prev_num_ssts_by_level[2], cur_num_ssts_by_level[0],
cur_num_ssts_by_level[1], cur_num_ssts_by_level[2],
(prev_size_by_level[0] / (1024.0 * 1024)),
(prev_size_by_level[1] / (1024.0 * 1024)),
(prev_size_by_level[2] / (1024.0 * 1024)),
(cur_size_by_level[0] / (1024.0 * 1024)),
(cur_size_by_level[1] / (1024.0 * 1024)),
(cur_size_by_level[2] / (1024.0 * 1024))))
ts_prev = e.ts
# Don't bother with printing the last row. Quite a lot of the last rows
# have the same timestamps.
self.avg_numssts_by_level = {}
for j in range(3):
self.avg_numssts_by_level[
j] = cumulative_numssts_time_by_level[
j] / self.sim_time.SimulatedTimeDur().total_seconds()
self.avg_sizetime_by_level = {}
for j in range(3):
self.avg_sizetime_by_level[j] = cumulative_size_time_by_level[
j] / (1024.0 * 1024 * 1024) / (3600.0 * 24 * 365.25 / 12)
self.avg_numssts_by_pathid = {}
for j in range(4):
self.avg_numssts_by_pathid[
j] = cumulative_numssts_time_by_pathid[
j] / self.sim_time.SimulatedTimeDur().total_seconds()
self.avg_sizetime_by_pathid = {}
for j in range(4):
self.avg_sizetime_by_pathid[
j] = cumulative_size_time_by_pathid[j] / (
1024.0 * 1024 * 1024) / (3600.0 * 24 * 365.25 / 12)
stat_str = []
stat_str.append("Average number of SSTables:")
for j in range(3):
stat_str.append(" L%d: %9.6f" %
(j, self.avg_numssts_by_level[j]))
stat_str.append("SSTable size-time (GB*Month):")
for j in range(3):
stat_str.append(" L%d: %f" %
(j, self.avg_sizetime_by_level[j]))
for s in stat_str:
fo.write("# %s\n" % s)
Cons.P("Created %s %d" % (fn, os.path.getsize(fn)))
def PlotSstAccfreqAtSpecificTime(at_simulated_time):
in_fn = RocksDbLogReader.GetSstAccFreqAtSpecificTime(at_simulated_time)
out_fn = "%s.pdf" % in_fn
out_fn2 = "%s-2.pdf" % in_fn
with Cons.MT("Plotting SSTable access frequencies at specific time ..."):
env = os.environ.copy()
env["IN_FN"] = in_fn
env["OUT_FN"] = out_fn
env["OUT_FN2"] = out_fn2
Util.RunSubp("gnuplot %s/sst-accfreq-at-specific-time.gnuplot" %
os.path.dirname(__file__),
env=env)
Cons.P("Created %s %d" % (out_fn, os.path.getsize(out_fn)))
Cons.P("Created %s %d" % (out_fn2, os.path.getsize(out_fn2)))
# TODO: plot by rank, sst, age, level and (sst or age) and explain why none of them works perfectly.
# this motivates the needs for direct sstable access monitoring
# - also, good for guaranteeing latency SLOs, since we are directly working on the access frequencies, rather than indiret metrics.
return
with Cons.MT("Plotting SSTable access frequencies at specific time ..."):
# Plot for all levels. Stop when there is no sstable at a level.
level = 0
while True:
env["LEVEL"] = str(level)
sst_lives = RocksDbLogReader.GetSstAccFreqByAgeDataFiles(level)
if len(sst_lives) == 0:
break
env["SST_IDS"] = " ".join(str(sl.Id()) for sl in sst_lives)
env["SST_SIZES"] = " ".join(str(sl.Size()) for sl in sst_lives)
age_deleted = []
for sl in sst_lives:
age_deleted.append(
SimTime.ToSimulatedTimeDur(
(sl.TsDeleted() - sl.TsCreated()).total_seconds()))
env["AGE_DELETED"] = " ".join(str(i) for i in age_deleted)
# Age deleted max. Round up with an hour granularity.
age_deleted_max = max(age_deleted)
age_deleted_max = math.ceil(age_deleted_max / 3600.0) * 3600
env["AGE_DELETED_MAX"] = str(age_deleted_max)
accfreq_max_all_sst_in_level = 0.0
temp_max_all_sst_in_level = 0.0
accfreq_max_list = []
temp_max_list = []
for sl in sst_lives:
accfreq_max = 0.0
temp_max = 0.0
for accfreq in sl.AgeAccfreq():
accfreq_max_all_sst_in_level = max(
accfreq_max_all_sst_in_level, accfreq[4])
temp_max_all_sst_in_level = max(temp_max_all_sst_in_level,
accfreq[5])
accfreq_max = max(accfreq_max, accfreq[4])
temp_max = max(temp_max, accfreq[5])
accfreq_max_list.append(accfreq_max)
temp_max_list.append(temp_max)
Cons.P("Level : %d" % level)
Cons.P("Max acc freq : %f" % max(accfreq_max_list))
Cons.P("Max temperature: %f" % max(temp_max_list))
env["ACCFREQ_MAX_ALL_SST_IN LEVEL"] = str(
accfreq_max_all_sst_in_level)
env["TEMP_MAX_ALL_SST_IN_LEVEL"] = str(temp_max_all_sst_in_level)
env["ACCFREQ_MAX"] = " ".join(str(e) for e in accfreq_max_list)
env["TEMP_MAX"] = " ".join(str(e) for e in temp_max_list)
out_fn = "%s/L%d.pdf" % (dn_out, level)
env["OUT_FN"] = out_fn
with Cons.MT("Plotting level %d ..." % level):
Util.RunSubp(
"gnuplot %s/sst-accfreq-by-age-multiplot-by-level.gnuplot"
% os.path.dirname(__file__),
env=env,
print_cmd=False)
Cons.P("Created %s %d" % (out_fn, os.path.getsize(out_fn)))
level += 1
def PlotSstAccfreqByAgeIndividualMultiplot():
with Cons.MT(
"Plotting individual SSTable access frequencies by their ages ..."
):
dn_out = "%s/%s/sst-age-accfreq-plot" % (
Conf.Get("dn_result"), Conf.Get("simulation_time_begin"))
Util.MkDirs(dn_out)
env = os.environ.copy()
dn = "%s/%s/sst-age-accfreq-data" % (Conf.Get("dn_result"),
Conf.Get("simulation_time_begin"))
env["IN_DN"] = dn
# Plot for all levels. Stop when there is no sstable at a level.
level = 0
while True:
env["LEVEL"] = str(level)
sst_lives = RocksDbLogReader.GetSstAccFreqByAgeDataFiles(level)
if len(sst_lives) == 0:
break
env["SST_IDS"] = " ".join(str(sl.Id()) for sl in sst_lives)
env["SST_SIZES"] = " ".join(str(sl.Size()) for sl in sst_lives)
age_deleted = []
for sl in sst_lives:
age_deleted.append(
SimTime.ToSimulatedTimeDur(
(sl.TsDeleted() - sl.TsCreated()).total_seconds()))
env["AGE_DELETED"] = " ".join(str(i) for i in age_deleted)
# Age deleted max. Round up with an hour granularity.
age_deleted_max = max(age_deleted)
age_deleted_max = math.ceil(age_deleted_max / 3600.0) * 3600
env["AGE_DELETED_MAX"] = str(age_deleted_max)
accfreq_max_all_sst_in_level = 0.0
temp_max_all_sst_in_level = 0.0
accfreq_max_list = []
temp_max_list = []
for sl in sst_lives:
accfreq_max = 0.0
temp_max = 0.0
for accfreq in sl.AgeAccfreq():
accfreq_max_all_sst_in_level = max(
accfreq_max_all_sst_in_level, accfreq[4])
temp_max_all_sst_in_level = max(temp_max_all_sst_in_level,
accfreq[5])
accfreq_max = max(accfreq_max, accfreq[4])
temp_max = max(temp_max, accfreq[5])
accfreq_max_list.append(accfreq_max)
temp_max_list.append(temp_max)
Cons.P("Level : %d" % level)
Cons.P("Max acc freq : %f" % max(accfreq_max_list))
Cons.P("Max temperature: %f" % max(temp_max_list))
env["ACCFREQ_MAX_ALL_SST_IN LEVEL"] = str(
accfreq_max_all_sst_in_level)
env["TEMP_MAX_ALL_SST_IN_LEVEL"] = str(temp_max_all_sst_in_level)
env["ACCFREQ_MAX"] = " ".join(str(e) for e in accfreq_max_list)
env["TEMP_MAX"] = " ".join(str(e) for e in temp_max_list)
out_fn = "%s/L%d.pdf" % (dn_out, level)
env["OUT_FN"] = out_fn
with Cons.MT("Plotting level %d ..." % level):
Util.RunSubp(
"gnuplot %s/sst-accfreq-by-age-multiplot-by-level.gnuplot"
% os.path.dirname(__file__),
env=env,
print_cmd=False)
Cons.P("Created %s %d" % (out_fn, os.path.getsize(out_fn)))
level += 1
def _OverallStat(cur, fn0, fn1):
with Cons.MT("Overall stat ..."):
for db_type in ["RocksDB", "Mutant"]:
fn = fn0 if db_type == "RocksDB" else fn1
Cons.P("# %s" % db_type)
Cons.P("# fn=%s" % fn)
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info WHERE db_type='%s'" % db_type)
r = cur.fetchone()
Cons.P("# num_jobs=%d" % r["cnt"])
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info WHERE db_type='%s' and creation_reason='R'" % db_type)
Cons.P("# num_jobs_recovery=%d" % cur.fetchone()["cnt"])
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info WHERE db_type='%s' and creation_reason='F'" % db_type)
Cons.P("# num_jobs_flush=%d" % cur.fetchone()["cnt"])
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info WHERE db_type='%s' and creation_reason='C'" % db_type)
num_comp_jobs_all = cur.fetchone()["cnt"]
Cons.P("# num_jobs_comp_all=%d" % num_comp_jobs_all)
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0"
% db_type)
num_jobs_comp_level_triggered = cur.fetchone()["cnt"]
Cons.P("# num_jobs_comp_level_triggered=%d" % num_jobs_comp_level_triggered)
cur.execute("SELECT count(distinct(sst_id)) as cnt FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0"
% db_type)
num_outssts_comp_level_triggered = cur.fetchone()["cnt"]
Cons.P("# num_outssts_comp_level_triggered=%d" % num_outssts_comp_level_triggered)
Cons.P("# num_outssts_comp_level_triggered_per_job=%f" % (float(num_outssts_comp_level_triggered) / num_jobs_comp_level_triggered))
# Distribution of the number of output SSTables per job
cur.execute("SELECT job_id, count(distinct(sst_id)) as num_ssts FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0" \
" GROUP BY job_id ORDER BY job_id"
% db_type)
numssts_cnt = {}
for r in cur.fetchall():
c = r["num_ssts"]
if c not in numssts_cnt:
numssts_cnt[c] = 1
else:
numssts_cnt[c] += 1
Cons.P("# %s" % numssts_cnt)
cur.execute("SELECT count(distinct(sst_id)) as cnt FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0 and migr_dirc IN ('-', 'N')"
% db_type)
Cons.P("# num_outssts_comp_level_triggered_regular_compaction=%d" % cur.fetchone()["cnt"])
cur.execute("SELECT count(distinct(sst_id)) as cnt FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0 and migr_dirc IN ('S', 'F')"
% db_type)
Cons.P("# num_outssts_comp_level_triggered_compaction_migration=%d" % cur.fetchone()["cnt"])
if True:
# From the SSTables created from compaction-migrations
# There are more SSTables that get migrated to the slow storage than to the fast storage. Makes sense, since they get old in general.
cur.execute("SELECT count(distinct(sst_id)) as cnt FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0 and migr_dirc IN ('S')"
% db_type)
Cons.P("# num_outssts_comp_level_triggered_compaction_migration_to_slow_storage=%d" % cur.fetchone()["cnt"])
if False:
cur.execute("SELECT job_id, count(distinct(sst_id)) as num_ssts FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0 and migr_dirc IN ('S')" \
" GROUP BY job_id ORDER BY job_id"
% db_type)
for r in cur.fetchall():
Cons.P("# job_id=%d num_ssts=%d" % (r["job_id"], r["num_ssts"]))
cur.execute("SELECT count(distinct(sst_id)) as cnt FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0 and migr_dirc IN ('F')"
% db_type)
Cons.P("# num_outssts_comp_level_triggered_compaction_migration_to_fast_storage=%d" % cur.fetchone()["cnt"])
if False:
cur.execute("SELECT job_id, count(distinct(sst_id)) as num_ssts FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=0 and migr_dirc IN ('F')" \
" GROUP BY job_id ORDER BY job_id"
% db_type)
for r in cur.fetchall():
Cons.P("# job_id=%d num_ssts=%d" % (r["job_id"], r["num_ssts"]))
cur.execute("SELECT count(distinct(job_id)) as cnt FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=1"
% db_type)
Cons.P("# num_jobs_comp_temp_triggered_migr=%d" % cur.fetchone()["cnt"])
if False:
# With a temperature-triggered single-sstable migration, there is always a single input sstable, but there can be multiple output sstables.
# Interesting.
# All of those happened with a 256MB L0 SSTable in the fast storage becoming cold and being migrated to the slow storage,
# making 4 64MB L0 SSTables in the slow storage.
# I don't think there is any harm there. It's just the output file is splitted into 4 small ones.
# Count each of them as a single migration.
cur.execute("SELECT count(distinct(sst_id)) as cnt FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=1"
% db_type)
Cons.P("# num_outssts_comp_temp_triggered_migr=%d" % cur.fetchone()["cnt"])
cur.execute("SELECT job_id, count(distinct(sst_id)) as num_ssts FROM sst_creation_info" \
" WHERE db_type='%s' and creation_reason='C' and temp_triggered_single_sst_migr=1" \
" GROUP BY job_id ORDER BY job_id"
% db_type)
for r in cur.fetchall():
if 1 < r["num_ssts"]:
Cons.P("# job_id=%d num_ssts=%d" % (r["job_id"], r["num_ssts"]))
def GetMutantCostLatencyDataFile():
dn = "%s/.output" % os.path.dirname(__file__)
fn = "%s/mutant-cost-latency" % dn
if os.path.exists(fn):
return fn
stg_sizetime_cost_by_sst_mig_temp_thresholds = StgSizeCost.StgSizetimeCostMutant(
)
#Cons.P(stg_sizetime_cost_by_sst_mig_temp_thresholds)
exps_root = Conf.Manifest.Get(
"2-level Mutant latencies by SSTable migration temperature thresholds")
# { metadata_caching: { sst_mig_temp_threshold: Latency() } }
mdcaching_smtt_latexps = {}
for md_caching, exps in {True: exps_root["Mutant"]["MetadataCachingOn"] \
, False: exps_root["Mutant"]["MetadataCachingOff"]}.iteritems():
#Cons.P("%s %s" % (md_caching, exps))
for sst_mig_temp_threshold, v in exps.iteritems():
sst_mig_temp_threshold = float(sst_mig_temp_threshold)
for simulation_time_begin in v:
if md_caching not in mdcaching_smtt_latexps:
mdcaching_smtt_latexps[md_caching] = {}
if sst_mig_temp_threshold not in mdcaching_smtt_latexps[
md_caching]:
mdcaching_smtt_latexps[md_caching][
sst_mig_temp_threshold] = Latency()
mdcaching_smtt_latexps[md_caching][sst_mig_temp_threshold].Add(
ClientLogReader.ClientLogReader(simulation_time_begin))
with open(fn, "w") as fo:
fmt = "%1s %17s" \
" %8.5f" \
" %10.3f %10.3f %10.3f" \
" %10.3f %10.3f %10.3f"
fo.write("%s\n" % Util.BuildHeader(fmt, \
"md_caching sst_mig_temp_threshold" \
" cost_$" \
" lat_put_avg_avg_in_ms lat_put_avg_min_in_ms lat_put_avg_max_in_ms" \
" lat_get_avg_avg_in_ms lat_get_avg_min_in_ms lat_get_avg_max_in_ms"
))
for md_caching, v in mdcaching_smtt_latexps.iteritems():
for sst_mig_temp_threshold, lat in sorted(v.iteritems()):
fo.write((fmt + "\n") % (
("T" if md_caching else "F"),
sst_mig_temp_threshold
# Average cost
,
stg_sizetime_cost_by_sst_mig_temp_thresholds[
sst_mig_temp_threshold].Cost("Sum")[0],
lat.PutAvgAvg(),
lat.PutAvgMin(),
lat.PutAvgMax(),
lat.GetAvgAvg(),
lat.GetAvgMin(),
lat.GetAvgMax()))
Cons.P("Created %s %d" % (fn, os.path.getsize(fn)))
# Mutant latency individual. Useful for filtering out outliers
# TODO: work on this
# TODO: do the same thing with unmodified RocksDB
# fn_lat_individual = "%s/mutant-latency-individual" % fn
#
# with open(fn_lat_individual, "w") as fo:
# fmt = "%17s" \
# " %28s %1s %17s" \
# " %10.3f %10.3f"
#
# #" %9.6f %9.6f %9.6f" \
#
# fo.write("%s\n" % Util.BuildHeader(fmt, \
# "simulation_time_begin" \
# " system metadata_caching SSTable_migration_temperature_threshold"
# " Lat_put_in_ms Lat_get_in_ms"
# ))
#
# for stg_dev, exps in sorted(rocks_dev_exps.iteritems(), reverse=True):
# for e in exps.Exps():
# fo.write((fmt + "\n") % (
# e[0].simulation_time_begin
# , ("UnmodifiedRocksDB_%s" % stg_dev)
# , "-"
# , "-"
# , e[0].put_avg
# , e[0].get_avg
# ))
#
# for md_caching, v in sorted(mu_mdcaching_smtt_exps.iteritems()):
# for sst_mig_temp_threshold, mu_exps in sorted(v.iteritems()):
# for e in mu_exps.Exps():
# fo.write((fmt + "\n") % (
# e[0].simulation_time_begin
# , "Mutant"
# , ("T" if md_caching else "F")
# , sst_mig_temp_threshold
# , e[1].avg_numssts_by_level[0]
# , e[1].avg_numssts_by_level[1]
# , e[1].avg_numssts_by_level[2]
#
# #, e[1].avg_sizetime_by_level[0]
# #, e[1].avg_sizetime_by_level[1]
# #, e[1].avg_sizetime_by_level[2]
#
# , e[1].avg_numssts_by_pathid[0]
# , e[1].avg_numssts_by_pathid[1]
# , e[1].avg_numssts_by_pathid[2]
# , e[1].avg_numssts_by_pathid[3]
#
# , e[0].put_avg
# , e[0].get_avg
# ))
# Cons.P("Created %s %d" % (fn_lat_individual, os.path.getsize(fn_lat_individual)))
return fn
def MayPrintNewlines(self):
with self.msg_lock:
if self.lines_printed > 0:
Cons.P("\n")
self.lines_printed = 0
self.msg = ""
def GetPlotDataMutant(workload_type, dev_type, dn):
fn_out = "%s/ycsb-%s-%s" % (_dn_output, workload_type, dev_type)
fn_out_ind = "%s/ycsb-%s-%s-individual" % (_dn_output, workload_type,
dev_type)
if os.path.isfile(fn_out) and os.path.isfile(fn_out_ind):
return (fn_out, fn_out_ind)
with Cons.MT("Generating plot data for %s ..." % dev_type):
dn = dn.replace("~", os.path.expanduser("~"))
fn_manifest = "%s/manifest.yaml" % dn
sstott_targetiops_exps = None
with open(fn_manifest) as fo:
sstott_targetiops_exps = yaml.load(fo)
#Cons.P(pprint.pformat(sstott_targetiops_exps, width=230))
exp_ycsblog = {}
with Cons.MT("Parsing YCSB log files ..."):
for sst_ott, v in sstott_targetiops_exps.iteritems():
for ti, exps in v.iteritems():
for e in exps:
fn = "%s/%s" % (dn, e)
#Cons.P(fn)
if not os.path.exists(fn):
Util.RunSubp("pbzip2 -k -d %s.bz2" % fn)
ycsb_log = YcsbLog(fn)
exp_ycsblog[e] = ycsb_log
#Cons.P(ycsb_log)
with Cons.MT("Gen individual/avg stat by target IOPSes ..."):
# Gen individual stat
fmt = "%9.4f %6d %17s %5.0f" \
" %5.0f %2.0f %8.0f %2.0f %2.0f %2.0f %4.0f %6.0f %6.0f %7.0f %8.0f" \
" %5.0f %3.0f %8.0f %2.0f %2.0f %3.0f %5.0f %6.0f %6.0f %7.0f %7.0f"
header = Util.BuildHeader(fmt, "sst_ott target_iops exp_dt iops" \
" r_avg r_min r_max r_1 r_5 r_50 r_90 r_95 r_99 r_99.9 r_99.99" \
" w_avg w_min w_max w_1 w_5 w_50 w_90 w_95 w_99 w_99.9 w_99.99")
with open(fn_out_ind, "w") as fo:
fo.write("# Latency in us\n")
i = 0
for sst_ott, v in sorted(sstott_targetiops_exps.iteritems()):
for ti, exps in sorted(v.iteritems()):
for e in exps:
if i % 40 == 0:
fo.write(header + "\n")
y = exp_ycsblog[e]
#Cons.P(e)
fo.write((fmt + "\n") %
(sst_ott, ti, y.exp_dt, y.op_sec, y.r_avg,
y.r_min, y.r_max, y.r_1, y.r_5, y.r_50,
y.r_90, y.r_95, y.r_99, y.r_999,
y.r_9999, y.w_avg, y.w_min, y.w_max,
y.w_1, y.w_5, y.w_50, y.w_90, y.w_95,
y.w_99, y.w_999, y.w_9999))
i += 1
Cons.P("Created %s %d" % (fn_out_ind, os.path.getsize(fn_out_ind)))
# Gen average stat
with open(fn_out, "w") as fo:
fmt = "%9.4f %6d %6.0f" \
" %5.0f %2d %8d %2d %2d %2d %4d %5d %6d %7d %7d" \
" %4.0f %2d %8d %2d %2d %3d %4d %5d %5d %7d %7d" \
" %1d"
header = Util.BuildHeader(fmt, "sst_ott target_iops iops" \
" r_avg r_min r_max r_1p r_5p r_50p r_90p r_95p r_99p r_99.9p r_99.99p" \
" w_avg w_min w_max w_1p w_5p w_50p w_90p w_95p w_99p w_99.9p w_99.99p" \
" num_exps" \
)
fo.write("# Latency in us\n")
fo.write("#\n")
i = 0
for sst_ott, v in sorted(sstott_targetiops_exps.iteritems()):
for ti, exps in sorted(v.iteritems()):
if i % 40 == 0:
fo.write(header + "\n")
yas = YcsbAvgStat()
for e in exps:
yas.Add(exp_ycsblog[e])
yas.Calc()
#Cons.P(yas)
fo.write(
(fmt + "\n") %
(sst_ott, ti, yas.op_sec, yas.r_avg, yas.r_min,
yas.r_max, yas.r_1, yas.r_5, yas.r_50, yas.r_90,
yas.r_95, yas.r_99, yas.r_999, yas.r_9999,
yas.w_avg, yas.w_min, yas.w_max, yas.w_1, yas.w_5,
yas.w_50, yas.w_90, yas.w_95, yas.w_99, yas.w_999,
yas.w_9999, len(yas.logs)))
i += 1
fo.write("\n")
Cons.P("Created %s %d" % (fn_out, os.path.getsize(fn_out)))
return (fn_out, fn_out_ind)
def YcsbRun(params, r):
global _ycsb_run_dt
_ycsb_run_dt = datetime.datetime.now().strftime("%y%m%d-%H%M%S.%f")[:-3]
fn_ycsb_log = "%s/%s-%s" % (_dn_log_root_ycsb, _ycsb_run_dt,
params["workload_type"])
ycsb_params = \
" -s" \
" -P workloads/workload%s" \
" -p rocksdb.dir=%s" \
" -threads 100" \
" -p status.interval=1" \
" -p fieldcount=10" \
" -p fieldlength=100" \
" -p readproportion=0.95" \
" -p insertproportion=0.05" \
" %s" \
% (params["workload_type"], params["db_path"], r["run"]["ycsb_params"])
# YCSB raw output shouldn't go to the root file system, which is heavily rate limited.
# -p measurement.raw.output_file=/tmp/ycsb-lat-raw
#
# Disabled for now. It takes up too much memory. Causing the file system cache size to shrink.
# " -p measurementtype=raw" \
# " -p measurement.raw.output_file=/mnt/local-ssd0/ycsb-lat-raw" \
mutant_options = base64.b64encode(
zlib.compress(json.dumps(r["mutant_options"])))
cmd0 = "cd %s && bin/ycsb run rocksdb %s -m %s > %s 2>&1" % (
_dn_ycsb, ycsb_params, mutant_options, fn_ycsb_log)
cmd1 = "bin/ycsb run rocksdb %s -m %s > %s 2>&1" % (
ycsb_params, mutant_options, fn_ycsb_log)
if ("memory_limit_in_mb"
in r["run"]) and (r["run"]["memory_limit_in_mb"] != 0):
# Just setting memory limit with cgroup seems to be worknig fine. I was wondering if I needed to set the same with JVM.
fn_cgconfig = "%s/cgconfig.conf" % os.path.dirname(__file__)
Util.RunSubp("sed -i 's/" \
"^ memory\.limit_in_bytes = .*" \
"/ memory\.limit_in_bytes = %d;" \
"/g' %s" % (int(float(r["run"]["memory_limit_in_mb"]) * 1024 * 1024), fn_cgconfig))
Util.RunSubp("sudo cgconfigparser -l %s" % fn_cgconfig)
Util.RunSubp("cd %s && cgexec -g memory:small_mem %s" %
(_dn_ycsb, cmd1),
measure_time=True,
shell=True,
gen_exception=False)
else:
Util.RunSubp(cmd0, measure_time=True, shell=True, gen_exception=False)
# Append parameters. Useful for post processing.
with open(fn_ycsb_log, "a") as fo:
fo.write("params = %s\n" % params)
fo.write("run = %s\n" % r)
Cons.P("Created %s %d" % (fn_ycsb_log, os.path.getsize(fn_ycsb_log)))
Util.RunSubp("pbzip2 -k %s" % fn_ycsb_log)
UploadToS3("%s.bz2" % fn_ycsb_log)
# Archive rocksdb log
fn1 = "%s/%s" % (_dn_log_rocksdb, _ycsb_run_dt)
cmd = "cp %s/LOG %s" % (params["db_path"], fn1)
Util.RunSubp(cmd, measure_time=True, shell=True, gen_exception=False)
Util.RunSubp("pbzip2 -k %s" % fn1)
UploadToS3("%s.bz2" % fn1)
CheckRocksDBLog(fn1)
def GenDataThrpVsLat():
fn_out = "%s/mutant-ycsb-thrp-vs-lat-by-costslos" % Conf.GetOutDir()
if os.path.exists(fn_out):
return fn_out
# {clst_slo: {target_iops: YcsbLogReader}}
costslo_tio_ylr = {}
with Cons.MT("Generating thrp vs lat data file ..."):
conf_root = Conf.Get("mutant")
dn_base = conf_root["dn_base"].replace("~", os.path.expanduser("~"))
for k, v in sorted(conf_root["by_cost_slos"].iteritems()):
# k: "0.1, 0.1":
mo = re.match(
r"(?P<cost_slo>(\d|.)+), ?(?P<cost_slo_epsilon>(\d|.)+)", k)
cost_slo = float(mo.group("cost_slo"))
# This is not used for now
cost_slo_epsilon = float(mo.group("cost_slo_epsilon"))
if cost_slo not in costslo_tio_ylr:
costslo_tio_ylr[cost_slo] = {}
#Cons.P("%f %f" % (cost_slo, cost_slo_epsilon))
for target_iops, v1 in sorted(v.iteritems()):
fn = "%s/%s" % (dn_base, v1["fn"])
# 01:30:00-04:00:00
t = v1["time"].split("-")
time_begin = t[0]
time_end = t[1]
# Not sure if you want to parallelize this. This whole thing takes only about 6 secs.
costslo_tio_ylr[cost_slo][target_iops] = YcsbLogReader(
fn, time_begin, time_end)
conf_root = Conf.Get("rocksdb")
dn_base = conf_root["dn_base"].replace("~", os.path.expanduser("~"))
cost_ebsst1 = 0.045
cost_localssd = 0.528
cost_slo = cost_localssd
costslo_tio_ylr[cost_slo] = {}
for target_iops, v1 in sorted(conf_root["local-ssd"].iteritems()):
fn = "%s/%s" % (dn_base, v1["fn"])
t = v1["time"].split("-")
time_begin = t[0]
time_end = t[1]
costslo_tio_ylr[cost_slo][target_iops] = YcsbLogReader(
fn, time_begin, time_end)
cost_slo = cost_ebsst1
costslo_tio_ylr[cost_slo] = {}
for target_iops, v1 in sorted(conf_root["ebs-st1"].iteritems()):
fn = "%s/%s" % (dn_base, v1["fn"])
t = v1["time"].split("-")
time_begin = t[0]
time_end = t[1]
costslo_tio_ylr[cost_slo][target_iops] = YcsbLogReader(
fn, time_begin, time_end)
with open(fn_out, "w") as fo:
fmt = "%6.3f %7s %6.0f %6.0f" \
" %8.2f %8.2f %9.2f %10.2f %10.2f" \
" %8.2f %8.2f %8.2f %9.2f %9.2f"
fo.write("%s\n" % Util.BuildHeader(fmt, "cost_slo cost_slo_label target_iops iops" \
" r_avg r_90 r_99 r_99.9 r_99.99" \
" w_avg w_90 w_99 w_99.9 w_99.99"
))
for cost_slo, v in sorted(costslo_tio_ylr.iteritems()):
last_tio = sorted(v.keys())[-1]
for tio, ylr in sorted(v.iteritems()):
# Too much info
#cost_slo_label = ("\"%s $%s\"" % ("R" if cost_slo in [cost_localssd, cost_ebsst1] else "M", ("%f" % cost_slo).rstrip("0").rstrip("."))) \
# if tio == last_tio \
# else "\"\""
cost_slo_label = ("\"%s\"" % ("%f" % cost_slo).rstrip("0").rstrip(".")) \
if tio == last_tio \
else "\"\""
fo.write(
(fmt + "\n") %
(cost_slo, cost_slo_label, tio, ylr.db_iops_stat.avg,
ylr.r_avg, ylr.r_90, ylr.r_99, ylr.r_999, ylr.r_9999,
ylr.w_avg, ylr.w_90, ylr.w_99, ylr.w_999, ylr.w_9999))
fo.write("\n")
Cons.P("Created %s %d" % (fn_out, os.path.getsize(fn_out)))
return fn_out
def PrepareBlockDevs():
with Cons.MT("Preparing block storage devices ..."):
# Make sure we are using the known machine types
inst_type = Util.RunSubp(
"curl -s http://169.254.169.254/latest/meta-data/instance-type",
print_cmd=False,
print_output=False)
# {dev_name: directory_name}
# ext4 label is the same as the directory_name
blk_devs = {"xvdb": "local-ssd0"}
# All c3 types have 2 SSDs
if inst_type.startswith("c3."):
blk_devs["xvdc"] = "local-ssd1"
elif inst_type in [
"r3.large", "r3.xlarge", "r3.2xlarge", "r3.4xlarge",
"i2.xlarge"
]:
pass
else:
raise RuntimeError("Unexpected instance type %s" % inst_type)
if os.path.exists("/dev/xvdd"):
blk_devs["xvdd"] = "ebs-gp2"
if os.path.exists("/dev/xvde"):
blk_devs["xvde"] = "ebs-st1"
if os.path.exists("/dev/xvdf"):
blk_devs["xvdf"] = "ebs-sc1"
# Init local SSDs
# - https://docs.aws.amazon.com/AWSEC2/latest/UserGuide/disk-performance.html
if inst_type.startswith("c3."):
Util.RunSubp("sudo umount /dev/xvdb || true")
Util.RunSubp("sudo umount /dev/xvdc || true")
if Ec2InitUtil.GetParam(["erase_local_ssd"]) == "true":
# tee has a problem of not stopping. For now, you can give up on ssd1.
# - https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=89224
#
# "count" one less than what it says below: 81909 - 1
#
# 81908+0 records in
# 81908+0 records out
# 85886763008 bytes (86 GB) copied, 1631.16 s, 52.7 MB/s
# 1683187 ms = 28 mins
# temporary comment for fast debuging
Util.RunSubp(
"sudo sh -c \"dd if=/dev/zero bs=1M count=81908 | tee /dev/xvdb > /dev/xvdc\"",
measure_time=True)
#
# sudo dd if=/dev/zero bs=1M of=/dev/xvdb || true
# dd: error writing '/dev/xvdb': No space left on device
# 81910+0 records in
# 81909+0 records out
# 85887811584 bytes (86 GB) copied, 1394.5 s, 61.6 MB/s
# 1394510 ms = 23 mins
#Util.RunSubp("sudo dd if=/dev/zero bs=1M of=/dev/xvdb || true", measure_time=True)
# Test with virtual block devices
# $ sudo dd if=/dev/zero of=/run/dev0-backstore bs=1M count=100
# $ sudo dd if=/dev/zero of=/run/dev1-backstore bs=1M count=100
# $ grep loop /proc/devices
# 7 loop
# $ sudo mknod /dev/fake-dev0 b 7 200
# $ sudo losetup /dev/fake-dev0 /run/dev0-backstore
# $ sudo mknod /dev/fake-dev1 b 7 201
# $ sudo losetup /dev/fake-dev1 /run/dev1-backstore
# $ lsblk
# - http://askubuntu.com/questions/546921/how-to-create-virtual-block-devices
# - You can use /dev/full too, which is easier.
#Util.RunSubp("sudo umount /dev/loop200 || true")
#Util.RunSubp("sudo umount /dev/loop201 || true")
#
#Util.RunSubpStopOn("sudo sh -c \"dd if=/dev/zero bs=1M | tee /dev/loop200 > /dev/loop201\"", measure_time=True)
#Util.RunSubp("sudo dd if=/dev/zero bs=1M of=/dev/loop201 || true", measure_time=True)
Util.RunSubp("sudo umount /mnt || true")
for dev_name, dir_name in blk_devs.iteritems():
Cons.P("Setting up %s ..." % dev_name)
Util.RunSubp("sudo umount /dev/%s || true" % dev_name)
Util.RunSubp("sudo mkdir -p /mnt/%s" % dir_name)
# Prevent lazy Initialization
# - "When creating an Ext4 file system, the existing regions of the inode
# tables must be cleaned (overwritten with nulls, or "zeroed"). The
# "lazyinit" feature should significantly accelerate the creation of a
# file system, because it does not immediately initialize all inode
# tables, initializing them gradually instead during the initial mounting
# process in background (from Kernel version 2.6.37)."
# - https://www.thomas-krenn.com/en/wiki/Ext4_Filesystem
# - Default values are 1s, which do lazy init.
# - man mkfs.ext4
#
# nodiscard is in the documentation
# - https://docs.aws.amazon.com/AWSEC2/latest/UserGuide/ssd-instance-store.html
# - Without nodiscard, it takes about 80 secs for a 800GB SSD.
#
# Could be parallelized
# local-ssd0 9,799 ms
# ebs-gp2 11,728 ms
# ebs-st1 68,082 ms
# ebs-sc1 207,481 ms
Util.RunSubp(
"sudo mkfs.ext4 -m 0 -E nodiscard,lazy_itable_init=0,lazy_journal_init=0 -L %s /dev/%s"
% (dir_name, dev_name),
measure_time=True)
# Some are already mounted. I suspect /etc/fstab does the magic when the
# file system is created. Give it some time and umount
time.sleep(1)
Util.RunSubp("sudo umount /dev/%s || true" % dev_name)
# -o discard for TRIM
Util.RunSubp("sudo mount -t ext4 -o discard /dev/%s /mnt/%s" %
(dev_name, dir_name))
Util.RunSubp("sudo chown -R ubuntu /mnt/%s" % dir_name)
def GenPlotData():
with Cons.MT("Generating plot data ..."):
Util.MkDirs(_dn_stat)
global _fn_stat
_fn_stat = "%s/%s" % (_dn_stat, _log_id)
if os.path.isfile(_fn_stat):
Cons.P("%s already exists" % _fn_stat)
return
fn_log = "%s/%s" % (_dn_ycsb_log, _log_id)
sps = []
with open(fn_log) as fo:
# h0: header 0
# h1: header 1
# body : body
loc = "h0"
for line in fo.readlines():
if loc == "h0":
#Cons.P("%s" % line)
if line.startswith("+ bin/ycsb run"):
loc = "h1"
continue
elif loc == "h1":
if line.startswith(
"DBWrapper: report latency for each error is false and specific error codes to track for latency are:"
):
loc = "body"
continue
elif loc == "body":
if line.startswith("[OVERALL]"):
loc = "tail"
break
sps.append(StatPerSec(line))
timerange = sps[-1].timestamp - sps[0].timestamp
# Reduce the output file size by skipping points that would overwrite on
# existing points. For those points, the values are set to -1.
#
# Points within 1/400 of x-axis are considered to be too close.
TIME_GRANULARITY_IN_SEC = int(timerange / 400)
# We don't need separate IOPSes for read and write.
#
#IOPS_GRANULARITY_IN_LOG_E = 0.01
#for i in range(len(sps)):
# if (i < TIME_GRANULARITY_IN_SEC):
# continue
# if sps[i].read_iops > 0:
# cur_read_iops = math.log(sps[i].read_iops, 10)
# for j in range(1, TIME_GRANULARITY_IN_SEC):
# if sps[i - j].read_iops > 0:
# if math.fabs(cur_read_iops - math.log(sps[i - j].read_iops, 10)) < IOPS_GRANULARITY_IN_LOG_E:
# sps[i].read_iops = -1
# break
# if sps[i].ins_iops > 0:
# cur_ins_iops = math.log(sps[i].ins_iops, 10)
# for j in range(1, TIME_GRANULARITY_IN_SEC):
# if sps[i - j].ins_iops > 0:
# if math.fabs(cur_ins_iops - math.log(sps[i - j].ins_iops, 10)) < IOPS_GRANULARITY_IN_LOG_E:
# sps[i].ins_iops = -1
# break
iops_max = 0
for s in sps:
iops_max = max(iops_max, s.iops)
IOPS_GRANULARITY = int(iops_max / 200)
for i in range(len(sps)):
if (i < TIME_GRANULARITY_IN_SEC):
continue
if sps[i].iops > 0:
for j in range(1, TIME_GRANULARITY_IN_SEC):
if sps[i - j].iops > 0:
if math.fabs(sps[i].iops -
sps[i - j].iops) < IOPS_GRANULARITY:
sps[i].iops = -1
break
# Reduce overlapped points - latency
#
# Calculate max latency manually. There were 3 outliers as big as 350 ms.
#lat_max = 0
#for s in sps:
# lat_max = max(lat_max, s.read_lat_avg, s.ins_lat_avg)
lat_max = 70000
LAT_GRANULARITY = int(lat_max / 100)
for i in range(len(sps)):
if (i < TIME_GRANULARITY_IN_SEC):
continue
if sps[i].read_lat_avg > 0:
for j in range(1, TIME_GRANULARITY_IN_SEC):
if sps[i - j].read_lat_avg > 0:
if math.fabs(sps[i].read_lat_avg -
sps[i -
j].read_lat_avg) < LAT_GRANULARITY:
sps[i].read_lat_avg = -1
break
if sps[i].ins_lat_avg > 0:
for j in range(1, TIME_GRANULARITY_IN_SEC):
if sps[i - j].ins_lat_avg > 0:
if math.fabs(sps[i].ins_lat_avg -
sps[i - j].ins_lat_avg) < LAT_GRANULARITY:
sps[i].ins_lat_avg = -1
break
with open(_fn_stat, "w") as fo:
StatPerSec.WriteHeader(fo)
for s in sps:
fo.write("%s\n" % s)
Cons.P("Created %s %d" % (_fn_stat, os.path.getsize(_fn_stat)))
def Write(fn):
fmt = "%12s %12s %7.3f %4d %4d %7.3f %7.3f" \
" %4s %9s %4s %1s %1s %1s"
header = Util.BuildHeader(fmt, "rel_ts_HHMMSS_begin" \
" rel_ts_HHMMSS_end" \
" ts_dur" \
" num_sstables_begin" \
" num_sstables_end" \
" sstable_size_sum_in_gb_begin" \
" sstable_size_sum_in_gb_end" \
\
" end_sst_id" \
" end_sst_size" \
" end_sst_creation_jobid" \
" end_sst_creation_reason" \
" end_sst_temp_triggered_single_migr" \
" end_sst_migration_direction")
i = 0
with open(fn, "w") as fo:
if i % 40 == 0:
fo.write(header + "\n")
i += 1
ts_prev = datetime.timedelta(0)
ts_str_prev = "00:00:00.000"
num_ssts_prev = 0
total_sst_size_prev = 0
for ts, num_ssts in sorted(SstEvents.ts_numssts.iteritems()):
ts_str = _ToStr(ts)
total_sst_size = SstEvents.ts_sstsize[ts]
sst_id = "-"
sst_size = "-"
job_id = "-"
creation_reason = "-"
# Temperature-triggered single-sstable migration
temp_triggered_migr = "-"
migr_dirc = "-"
if ts in SstEvents.createts_sstid:
sst_id = SstEvents.createts_sstid[ts]
sst_size = SstEvents.sstid_size[sst_id]
hc = HowCreated.Get(sst_id)
job_id = hc.JobId()
creation_reason = hc.Reason()
temp_triggered_migr = "T" if CompInfo.TempTriggeredSingleSstMigr(
job_id) else "-"
if SstEvents.migrate_sstables:
if creation_reason == "C":
migr_dirc = CompInfo.MigrDirc(job_id, sst_id)
fo.write((fmt + "\n") %
(ts_str_prev, ts_str,
(ts.total_seconds() - ts_prev.total_seconds()),
num_ssts_prev, num_ssts,
(float(total_sst_size_prev) / 1024 / 1024 / 1024),
(float(total_sst_size) / 1024 / 1024 / 1024), sst_id,
sst_size, job_id, creation_reason,
temp_triggered_migr, migr_dirc))
ts_str_prev = ts_str
ts_prev = ts
num_ssts_prev = num_ssts
total_sst_size_prev = total_sst_size
Cons.P("Created %s %d" % (fn, os.path.getsize(fn)))
def Boxes(n, m):
# TODO: clean up
#if Conf.Get("simulation_time_begin") is None:
# #MutantLogReader.Get()
# RocksdbLogReader.Get()
dn = "%s/sst-by-level-by-ks-range-with-temperature" % Conf.dn_result
fn_boxes = "%s/%s-boxes-%d" % (dn, Conf.Get("simulation_time_begin"), n)
fn_level_info = "%s/%s-level-info-%d" % (dn, Conf.Get("simulation_time_begin"), n)
if os.path.isfile(fn_boxes) and os.path.isfile(fn_level_info):
_UpdateMaxPlotHeight(fn_boxes)
return (fn_boxes, fn_level_info)
# {sst_id, SstLife()}
sst_lives = RocksdbLogReader.GetSstLives()
with Cons.MT("Generating SSTables by level by ks range with temperature at specific time n=%d m=%s ..." % (n, m)):
Util.MkDirs(dn)
t0 = sst_lives[n].TsCreated() + datetime.timedelta(seconds=m)
# May or may not want to use the rectangle height proportional to the
# SSTable size. We'll see. Log-scale height might be better.
#
# Boxes representing SSTables
boxes = []
for sst_gen, sl in sorted(sst_lives.iteritems()):
temp = sl.TempAtTime(t0)
if temp is None:
continue
boxes.append(_Box(sl, temp))
# Sort boxes by level acendening, sst_gen decending. At the same level, the
# younger SSTables (with bigger sst_gen number) tend to be hotter.
boxes.sort(key=lambda b: b.sst_life.Id(), reverse=True)
boxes.sort(key=lambda b: b.sst_life.Level())
level_labels_y = [box_height / 2.0]
level_separators_y = []
# Set y0 of each box
cur_y0_max = - (box_height + y_spacing)
prev_level = None
for b in boxes:
if b.sst_life.level == 0:
b.y0 = cur_y0_max + box_height + y_spacing
cur_y0_max = b.y0
else:
if b.sst_life.level == prev_level:
b.y0 = cur_y0_max
else:
b.y0 = cur_y0_max + box_height + 2*y_spacing
sep = cur_y0_max + box_height + y_spacing
level_separators_y.append(sep)
level_labels_y.append(sep + y_spacing + box_height / 2.0)
cur_y0_max = b.y0
prev_level = b.sst_life.level
global max_plot_height
max_plot_height = cur_y0_max + box_height + y_spacing if max_plot_height is None \
else max(max_plot_height, cur_y0_max + box_height + y_spacing)
fn_boxes = "%s/%s-boxes-%d" % (dn, Conf.Get("simulation_time_begin"), n)
with open(fn_boxes, "w") as fo:
fmt = "%3d %1d %9d %6.2f %8d %6s %20d %20d %5.1f"
fo.write("%s\n" % Util.BuildHeader(fmt, "sst_gen level size temperature(reads_per_sec_per_mb)" \
" temperature_color temperature_color_hex" \
" ks_first ks_last box_y0"))
for b in boxes:
fo.write((fmt + "\n") % (b.sst_life.Id()
, b.sst_life.Level()
, b.sst_life.Size()
, b.temp
, b.color, "%0.6X" % b.color
# This is the problem. RocksDB log doesn't have SSTable keyrange. Oh
# well. Let's use the Cassandra log and come back.
, b.sst_life.key_range[0]
, b.sst_life.key_range[1]
, b.y0
))
Cons.P("Created %s %d" % (fn_boxes, os.path.getsize(fn_boxes)))
with open(fn_level_info, "w") as fo:
fmt = "%5s %5s"
fo.write("%s\n" % Util.BuildHeader(fmt, "level_label_y level_separator_y"))
for i in range(max(len(level_labels_y), len(level_separators_y))):
l = "-"
if i < len(level_labels_y):
l = "%5.1f" % level_labels_y[i]
s = "-"
if i < len(level_separators_y):
s = "%5.1f" % level_separators_y[i]
fo.write((fmt + "\n") % (l, s))
Cons.P("Created %s %d" % (fn_level_info, os.path.getsize(fn_level_info)))
return (fn_boxes, fn_level_info)
def GetFnCostSloEpsilonVsMetrics():
fn_out = "%s/cost-slo-epsilon-vs-metrics" % Conf.GetOutDir()
if os.path.isfile(fn_out):
return (fn_out, _GetLinearRegErrorBoundParams(fn_out))
dn_base = Conf.GetDir("dn_base")
# {cost_slo_epsilon: fn}
cse_fn = {}
for cost_slo_epsilon, fn0 in Conf.Get("by_cost_slo_epsilons").iteritems():
fn = "%s/%s" % (dn_base, fn0)
cse_fn[cost_slo_epsilon] = fn
#Cons.P(pprint.pformat(cse_fn))
params = []
for cost_slo_epsilon, fn_ycsb_log in sorted(cse_fn.iteritems()):
params.append(fn_ycsb_log)
parallel_processing = True
if parallel_processing:
with terminating(Pool()) as pool:
result = pool.map(GetFnTimeVsMetrics, params)
else:
result = []
for p in params:
result.append(GetFnTimeVsMetrics(p))
#Cons.P(result)
cse_outfn = {}
i = 0
for cost_slo_epsilon, fn_ycsb_log in sorted(cse_fn.iteritems()):
cse_outfn[cost_slo_epsilon] = result[i]
i += 1
with open(fn_out, "w") as fo:
fo.write(
"# Linear regression coefficients of CSE vs storage cost = [%s]\n"
% " ".join(str(i) for i in _CalcUpperBound(cse_outfn)))
fo.write("\n")
fo.write("# CSE: Storge cost SLO epsilon\n")
fo.write("# JR: jobs_recovery\n")
fo.write("# JF: jobs_flush\n")
fo.write("# JC: jobs_compaction\n")
fo.write("# JCL: jobs_comp_leveled_organization_triggered\n")
fo.write("# SSCL: total_sst_size_comp_level_triggered_in_gb\n")
fo.write(
"# SSCLCM: total_sst_size_comp_level_triggered_comp_migrs_in_gb\n"
)
fo.write(
"# SSCLCMS: total_sst_size_comp_level_triggered_comp_migrs_to_slow_in_gb\n"
)
fo.write(
"# SSCLCMF: total_sst_size_comp_level_triggered_comp_migrs_to_fast_in_gb\n"
)
fo.write("# JCT: jobs_comp_temp_triggered_migr\n")
fo.write("# SSCT: total_sst_size_comp_temp_triggered_migr_in_gb\n")
fo.write("# SSCTS: To slow storage\n")
fo.write("# SSCTF: To fast storage\n")
fo.write("\n")
fmt = "%4.2f %8.6f %8.6f %8.6f %8.6f %1d %2d %4d" \
" %4d %7.3f %7.3f %7.3f %7.3f" \
" %4d %7.3f %7.3f %7.3f"
header = Util.BuildHeader(fmt, "CSE" \
" stg_unit_cost_$_gb_month" \
" stg_cost_$" \
" fast_stg_cost_$" \
" slow_stg_cost_$" \
" JR" \
" JF" \
" JC" \
" JCL" \
" SSCL" \
" SSCLCM" \
" SSCLCMS" \
" SSCLCMF" \
" JCT" \
" SSCT" \
" SSCTS" \
" SSCTF" \
)
fo.write(header + "\n")
for cost_slo_epsilon, fn1 in sorted(cse_outfn.iteritems()):
kvs = [
["total_stg_unit_cost", None], ["total_stg_cost", None],
["fast_stg_cost", None], ["slow_stg_cost", None],
["num_jobs_recovery", None], ["num_jobs_flush", None],
["num_jobs_comp_all", None],
["num_jobs_comp_level_triggered", None],
["total_sst_size_comp_level_triggered_in_gb", None],
["total_sst_size_comp_level_triggered_comp_migrs_in_gb", None],
[
"total_sst_size_comp_level_triggered_comp_migrs_to_slow_in_gb",
None
],
[
"total_sst_size_comp_level_triggered_comp_migrs_to_fast_in_gb",
None
], ["num_jobs_comp_temp_triggered_migr", None],
["total_sst_size_comp_temp_triggered_migr", None],
["total_sst_size_comp_temp_triggered_migr_to_slow", None],
["total_sst_size_comp_temp_triggered_migr_to_fast", None]
]
with open(fn1) as fo1:
for line in fo1:
if not line.startswith("#"):
continue
for kv in kvs:
k = kv[0]
mo = re.match(r".+%s=(?P<v>(\d|\.)+)" % k, line)
if mo:
kv[1] = float(mo.group("v"))
continue
try:
fo.write(
(fmt + "\n") %
(cost_slo_epsilon, kvs[0][1], kvs[1][1], kvs[2][1],
kvs[3][1], kvs[4][1], kvs[5][1], kvs[6][1], kvs[7][1],
kvs[8][1], kvs[9][1], kvs[10][1], kvs[11][1], kvs[12][1],
kvs[13][1], kvs[14][1], kvs[15][1]))
except TypeError as e:
Cons.P(fn1)
raise e
Cons.P("Created %s %d" % (fn_out, os.path.getsize(fn_out)))
return (fn_out, _GetLinearRegErrorBoundParams(fn_out))
def __init__(self, dn_log_job, exp_dt):
self.fn_out = "%s/rocksdb-by-time-%s" % (Conf.GetOutDir(), exp_dt)
if os.path.isfile(self.fn_out):
return
self.exp_begin_dt = datetime.datetime.strptime(exp_dt,
"%y%m%d-%H%M%S.%f")
#Cons.P(self.exp_begin_dt)
with Cons.MT("Generating rocksdb time-vs-metrics file for plot ..."):
fn_log_rocksdb = "%s/rocksdb/%s" % (dn_log_job, exp_dt)
if not os.path.exists(fn_log_rocksdb):
fn_zipped = "%s.bz2" % fn_log_rocksdb
if not os.path.exists(fn_zipped):
raise RuntimeError("Unexpected: %s" % fn_log_rocksdb)
Util.RunSubp(
"cd %s && bzip2 -dk %s > /dev/null" %
(os.path.dirname(fn_zipped), os.path.basename(fn_zipped)))
if not os.path.exists(fn_log_rocksdb):
raise RuntimeError("Unexpected")
# Histogram with 1 second binning
# {rel_ts: [file_size]}
ts_size = {}
with open(fn_log_rocksdb) as fo:
for line in fo:
if "\"event\": \"table_file_creation\"" in line:
#Cons.P(line)
# 2017/10/13-20:41:54.872056 7f604a7e4700 EVENT_LOG_v1 {"time_micros": 1507927314871238, "cf_name": "usertable", "job": 3, "event": "table_file_creation", "file_number": 706, "file_size": 258459599, "path_id": 0, "table_properties": {"data_size": 256772973, "index_size": 1685779, "filter_size": 0, "raw_key_size": 6767934, "raw_average_key_size": 30, "raw_value_size": 249858360, "raw_average_value_size": 1140, "num_data_blocks": 54794, "num_entries": 219174, "filter_policy_name": "", "reason": kFlush, "kDeletedKeys": "0", "kMergeOperands": "0"}}
mo = re.match(
r"(?P<ts>(\d|\/|-|:|\.)+) .+EVENT_LOG_v1 (?P<json>.+)",
line)
if mo is None:
raise RuntimeError("Unexpected: [%s]" % line)
ts = datetime.datetime.strptime(
mo.group("ts"), "%Y/%m/%d-%H:%M:%S.%f")
ts_rel = ts - self.exp_begin_dt
# Fix the illegal json format
j = mo.group("json").replace("kFlush",
"\"kFlush\"").replace(
"kCompaction",
"\"kCompaction\"")
try:
j1 = json.loads(j)
except ValueError as e:
Cons.P("%s [%s]" % (e, line))
sys.exit(1)
# You may be able to use path_id later
sst_size = int(j1["file_size"])
#Cons.P("%s %d" % (ts_rel, sst_size))
total_s = ts_rel.total_seconds()
s = total_s % 60
total_s -= s
total_m = total_s / 60
m = total_m % 60
total_m -= m
h = total_m / 60
ts1 = "%02d:%02d:%02d" % (h, m, s)
if ts1 not in ts_size:
ts_size[ts1] = []
ts_size[ts1].append(sst_size)
fmt = "%8s %2d %9d"
with open(self.fn_out, "w") as fo:
fo.write(
Util.BuildHeader(
fmt, "rel_ts_HHMMSS num_sstables sum_sst_sizes") +
"\n")
for ts, sizes in sorted(ts_size.iteritems()):
fo.write((fmt + "\n") % (ts, len(sizes), sum(sizes)))
Cons.P("Created %s %d" %
(self.fn_out, os.path.getsize(self.fn_out)))
def _BuildMemtSstLives():
with Cons.MT("Building memt and sst lives ..."):
#global _memt_lives
global _sst_lives
#_memt_lives = {}
_sst_lives = {}
dn = "%s/work/mutant/misc/rocksdb/log/rocksdb" % os.path.expanduser(
"~")
fn = "%s/%s" % (dn, Conf.Get("simulation_time_begin"))
if not os.path.isfile(fn):
fn_7z = "%s.7z" % fn
if not os.path.isfile(fn_7z):
raise RuntimeError("Unexpected")
Util.RunSubp("cd %s && 7z e %s" % (dn, fn_7z))
if not os.path.isfile(fn):
raise RuntimeError("Unexpected")
line_no = 0
with open(fn) as fo:
for line in fo:
line_no += 1
# It's fast enough and often times excuted in parallel. No need to show the progress.
if False:
if line_no % 100 == 0:
Cons.ClearLine()
Cons.Pnnl("Processing line %d" % line_no)
# Not needed for storage cost calculation
#
# 2016/12/21-02:17:14.329266 7f702d7fa700 EVENT_LOG_v1 {"time_micros":
# 1482304634329023, "mutant_table_acc_cnt": {"memt":
# "0x7f69fc00c350:51723 0x7f6bec011200:26942", "sst": "1069:0:30.123:20.123
# 1059:980:30.123:20.123"}
#mo = re.match(r".+ EVENT_LOG_v1 {\"time_micros\": (?P<time_micros>\d+)" \
# ", \"mutant_table_acc_cnt\": {(\"memt\": \"(?P<memt_acc_cnt>(\w|\d|:| )+)\")?" \
# "(, )?" \
# "(\"sst\": \"(?P<sst_acc_cnt>(\w|\d|:|-|\.| )+)\")?" \
# "}" \
# ".*"
# , line)
#if mo is not None:
# _SetTabletAccess(mo)
# continue
# 2016/12/21-01:27:40.840324 7f702dffb700 EVENT_LOG_v1 {"time_micros":
# 1482301660840289, "cf_name": "default", "job": 4, "event":
# "table_file_creation", "file_number": 15, "file_size": 67569420,
# "path_id": 0, "table_properties": {"data_size": 67110556, "index_size": 458020,
# "filter_size": 0, "raw_key_size": 1752468, "raw_average_key_size": 25,
# "raw_value_size": 65132550, "raw_average_value_size": 966,
# "num_data_blocks": 16857, "num_entries": 67425, "filter_policy_name":
# "", "reason": kCompaction, "kDeletedKeys": "0", "kMergeOperands": "0"}}
mo = re.match(r"(?P<ts>\d\d\d\d/\d\d/\d\d-\d\d:\d\d:\d\d\.\d\d\d\d\d\d)" \
".+ EVENT_LOG_v1 {\"time_micros\": (?P<time_micros>\d+)" \
", \"cf_name\": \"default\"" \
", \"job\": (?P<job>\d+)" \
", \"event\": \"table_file_creation\"" \
", \"file_number\": (?P<file_number>\d+)" \
", \"file_size\": (?P<file_size>\d+)" \
", \"path_id\": (?P<path_id>\d+)" \
".+" \
", \"reason\": (?P<reason>\w+)" \
".*"
, line)
if mo is not None:
_SetTabletCreated(mo)
continue
# 2016/12/21-02:15:58.341853 7f702dffb700 EVENT_LOG_v1 {"time_micros":
# 1482304558341847, "job": 227, "event": "table_file_deletion",
# "file_number": 1058}
mo = re.match(r"(?P<ts>\d\d\d\d/\d\d/\d\d-\d\d:\d\d:\d\d\.\d\d\d\d\d\d)" \
".+ EVENT_LOG_v1 {\"time_micros\": (?P<time_micros>\d+)" \
", \"job\": \d+" \
", \"event\": \"table_file_deletion\"" \
", \"file_number\": (?P<file_number>\d+)" \
"}" \
".*"
, line)
if mo is not None:
_SetTabletDeleted(mo)
continue
# 2017/01/20-23:03:00.960592 7fc8037fe700 EVENT_LOG_v1 {"time_micros":
# 1484971380960590, "mutant_trivial_move": {"in_sst": "sst_id=145
# level=1 path_id=0 temp=20.721", "out_sst_path_id": 0}}
mo = re.match(r"(?P<ts>\d\d\d\d/\d\d/\d\d-\d\d:\d\d:\d\d\.\d\d\d\d\d\d)" \
".+ EVENT_LOG_v1 {\"time_micros\": (?P<time_micros>\d+)" \
", \"mutant_trivial_move\": {" \
"\"in_sst\": \"" \
"sst_id=(?P<in_sst_id>\d+)" \
" level=(?P<in_level>\d+)" \
" path_id=(?P<in_path_id>\d+)" \
" temp=(?P<in_temp>(\d|\.)+)" \
"\", \"out_sst_path_id\": (?P<out_path_id>\d+)}}" \
".*"
, line)
if mo is not None:
_SetTrivialMove(mo)
continue
# You can check out the other events here. All useful ones were covered above.
#Cons.P(line)
Cons.ClearLine()
Cons.P("Processed %d lines" % line_no)
deleted = 0
not_deleted = 0
for sst_id, sl in _sst_lives.iteritems():
if sl.TsDeleted() is None:
not_deleted += 1
else:
deleted += 1
Cons.P("Created %d SstLives. %d not-deleted, %d deleted" %
(len(_sst_lives), not_deleted, deleted))
def __init__(self, dn_log_job, exp_dt):
self.fn_out = "%s/rocksdb-by-time-%s" % (Conf.GetOutDir(), exp_dt)
if os.path.isfile(self.fn_out):
return
self.sst_events = SstEvents(self, exp_dt)
self.sst_info = SstInfo()
self.comp_info = CompInfo(self)
self.stg_cost = StgCost.StgCost(exp_dt)
with Cons.MT("Generating rocksdb time-vs-metrics file for plot ..."):
fn_log_rocksdb = "%s/rocksdb/%s" % (dn_log_job, exp_dt)
if not os.path.exists(fn_log_rocksdb):
fn_zipped = "%s.bz2" % fn_log_rocksdb
if not os.path.exists(fn_zipped):
raise RuntimeError("Unexpected: %s" % fn_log_rocksdb)
Util.RunSubp(
"cd %s && bzip2 -dk %s > /dev/null" %
(os.path.dirname(fn_zipped), os.path.basename(fn_zipped)))
if not os.path.exists(fn_log_rocksdb):
raise RuntimeError("Unexpected")
Cons.P(fn_log_rocksdb)
with open(fn_log_rocksdb) as fo:
for line in fo:
#Cons.P(line)
# 2018/01/05-08:10:30.085011 7f40083d8700 migrate_sstables: 0
if " migrate_sstables: " in line:
mo = re.match(
r"(?P<ts>(\d|\/|-|:|\.)+) .* migrate_sstables: (?P<v>\d).*",
line)
if mo is None:
raise RuntimeError("Unexpected: [%s]" % line)
self.migrate_sstables = (mo.group("v") == "1")
# Storage pricing. Fast and slow.
# We parse the 2 storage configuration for now.
# You don't need this for the baseline, unmodified DB, since the unit cost is always the same.
# 2018/01/23-22:53:48.875126 7f3300cd8700 stg_cost_list: 0.528000 0.045000
elif " stg_cost_list: " in line:
self.stg_cost.SetStgPricing(line)
# 2018/01/23-22:53:48.875128 7f3300cd8700 stg_cost_slo: 0.300000
elif " stg_cost_slo: " in line:
self.stg_cost.SetTargetCost(line)
# 2018/01/23-22:53:48.875130 7f3300cd8700 stg_cost_slo_epsilon: 0.020000
elif " stg_cost_slo_epsilon: " in line:
self.stg_cost.SetMigrationResistance(line)
# 2018/02/27-17:27:33.745680 7fcbc1536700 EVENT_LOG_v1 {"time_micros": 1519752453745660, "Set target_cost to ": 0.2}
elif "Set target_cost to" in line:
self.stg_cost.SetCostChange(line)
# 2018/02/27-16:49:17.959334 7ff0ed2b2700 EVENT_LOG_v1 {"time_micros": 1519750157959324, "mutant_sst_opened": {"file_number": 2274, "file_size":
# 10950641, "path_id": 0, "level": 1}}
elif "\"mutant_sst_opened\": " in line:
self.sst_events.Created1(line)
# 2017/10/13-20:41:54.872056 7f604a7e4700 EVENT_LOG_v1 {"time_micros": 1507927314871238, "cf_name": "usertable", "job": 3, "event":
# "table_file_creation", "file_number": 706, "file_size": 258459599, "path_id": 0, "table_properties": {"data_size": 256772973, "index_size": 1685779,
# "filter_size": 0, "raw_key_size": 6767934, "raw_average_key_size": 30, "raw_value_size": 249858360, "raw_average_value_size": 1140,
# "num_data_blocks": 54794, "num_entries": 219174, "filter_policy_name": "", "reason": kFlush, "kDeletedKeys": "0", "kMergeOperands": "0"}}
elif "\"event\": \"table_file_creation\"" in line:
self.sst_events.Created2(line)
# 2018/01/01-05:33:49.183505 7f97d0ff1700 EVENT_LOG_v1 {"time_micros": 1514784829183496, "job": 6, "event": "table_file_deletion", "file_number": 21}
elif "\"event\": \"table_file_deletion\"" in line:
self.sst_events.Deleted(line)
# 2018/01/23-00:13:13.593310 7fa321da9700 EVENT_LOG_v1 {"time_micros": 1516666393593302, "mutant_calc_out_sst_path_id": {"in_sst": "(sst_id=16
# temp=57.189 level=0 path_id=0 size=258425431 age=30)", "in_sst_temp": "57.188590", "sst_ott": 3176.66, "out_sst_path_id": 1,
# "temp_triggered_single_sst_compaction": 1}}
elif "\"mutant_calc_out_sst_path_id\"" in line:
self.comp_info.SetTempTriggeredSingleSstMigr(line)
# Figure out how an SSTable is created
# (a) start building CompInfo
# 2018/01/05-08:40:21.078219 7fd13ffff700 EVENT_LOG_v1 {"time_micros": 1515141621078214, "mutant_sst_compaction_migration": {"in_sst": "(sst_id=16
# temp=57.345 level=0 path_id=0 size=258423184 age=30) (sst_id=13 temp=3738.166 level=0 path_id=1 size=118885 age=440)", "out_sst_path_id": 1,
# "temp_triggered_single_sst_compaction": 1}}
#
# Some SSTables are created without this log, meaning not going through _CalcOutputPathId(). Use the other one.
#elif "mutant_sst_compaction_migration" in line:
# if not self.migrate_sstables:
# continue
# self.comp_info.Add(line)
# Build CompInfo
# We manually parse this just because there are multiple keys with "files_L0" and json would probably not be able to parse it
# 2018/01/05-08:40:21.078303 7fd13ffff700 EVENT_LOG_v1 {"time_micros": 1515141621078294, "job": 5, "event": "compaction_started", "files_L0": [16,
# 13], "files_L0": [16, 13], "score": 0, "input_data_size": 517084138}
elif "compaction_started" in line:
self.comp_info.SetCompStarted(line)
# (c) Assign out_sst_info to CompInfo using job_id. It is done when parsing table_file_creation above.
self.comp_info.CalcMigrDirections()
self.sst_events.Write(self.fn_out)
self.stg_cost.AddStatToFile(self.fn_out)
def _CalcStorageCost():
global _sst_lives
if _sst_lives is None:
raise RuntimeError("Unexpected")
# Sort them by ts_cd and, to break ties, by sst_id
# {ts_created_or_deleted: sst_id}
class TscdSstid:
def __init__(self, ts, event, sst_id):
self.ts = ts
if ts is not None:
self.ts = SimTime.ToSimulatedTime(self.ts)
# "C"reated or "D"eleted
self.event = event
self.sst_id = sst_id
if self.ts is not None:
if SimTime.SimulatedTimeEnd() < self.ts:
# This happens. Tolerate ts no bigger than SimTime.SimulatedTimeEnd()
# by 5 minutes, which is small compared with the 14 day time
# interval.
if SimTime.SimulatedTimeEnd() < self.ts:
Cons.P("SimTime.SimulatedTimeEnd() %s < self.ts %s. event=%s. It's okay. Adjust to the former" \
% (SimTime.SimulatedTimeEnd(), self.ts, event))
self.ts = SimTime.SimulatedTimeEnd()
if self.event == "D" and self.ts is None:
self.ts = SimTime.SimulatedTimeEnd()
if self.ts is None:
raise RuntimeError("Unexpected")
def __str__(self):
return "(%s %s %d)" % (self.ts, self.event, self.sst_id)
def __repr__(self):
return self.__str__()
@staticmethod
def Cmp(a, b):
if a.ts < b.ts:
return -1
elif a.ts > b.ts:
return 1
else:
# Breaking tie. The order is not important.
return (a.sst_id - b.sst_id)
tscd_sstid = []
for sst_id, sl in _sst_lives.iteritems():
tscd_sstid.append(TscdSstid(sl.TsCreated(), "C", sst_id))
tscd_sstid.append(TscdSstid(sl.TsDeleted(), "D", sst_id))
#Cons.P(pprint.pformat(tscd_sstid))
tscd_sstid = sorted(tscd_sstid, cmp=TscdSstid.Cmp)
#Cons.P(pprint.pformat(tscd_sstid))
# Make output dn
dn = "%s/%s" % (Conf.GetDir("dn_result"),
Conf.Get("simulation_time_begin"))
Util.MkDirs(dn)
# Calculate current storage size by scanning them from the oldest to the
# newest. We have 4 storage devices.
cur_size = [0.0, 0.0, 0.0, 0.0]
cur_num_ssts = [0, 0, 0, 0]
# Size * time in byte * sec up to now
cumulative_size_time = [0.0, 0.0, 0.0, 0.0]
# Init to simulated_time_begin
ts_prev = SimTime.SimulatedTimeBegin()
stat = []
# Store to a file to that you can plot time vs storage size plot.
fn = "%s/data-size-by-stg-devs-by-time" % dn
with open(fn, "w") as fo:
# 160727-122652.458
# 12345678901234567
fmt = "%17s %17s %5d" \
" %2d %2d %2d %2d" \
" %2d %2d %2d %2d" \
" %8.3f %8.3f %8.3f %8.3f %8.3f" \
" %8.3f %8.3f %8.3f %8.3f %8.3f" \
" %6.3f %6.3f %6.3f %6.3f %6.3f"
header = Util.BuildHeader(fmt
, "ts0 ts1 ts_dur" \
" prev_num_ssts_0 prev_num_ssts_1 prev_num_ssts_2 prev_num_ssts_3" \
" cur_num_ssts_0 cur_num_ssts_1 cur_num_ssts_2 cur_num_ssts_3" \
\
" prev_size_0_in_MB" \
" prev_size_1_in_MB" \
" prev_size_2_in_MB" \
" prev_size_3_in_MB" \
" prev_size_sum_in_MB" \
\
" cur_size_0_in_MB" \
" cur_size_1_in_MB" \
" cur_size_2_in_MB" \
" cur_size_3_in_MB" \
" cur_size_sum_in_MB" \
\
" cumulative_size_time_0_in_GB*month" \
" cumulative_size_time_1_in_GB*month" \
" cumulative_size_time_2_in_GB*month" \
" cumulative_size_time_3_in_GB*month" \
" cumulative_size_time_sum_in_GB*month"
)
i = 0
for e in tscd_sstid:
if i % 40 == 0:
fo.write("%s\n" % header)
i += 1
if e.ts < SimTime.SimulatedTimeBegin():
Cons.P("e.ts %s < SimTime.SimulatedTimeBegin() %s. Adjusting to the latter. This happens." \
% (e.ts, SimTime.SimulatedTimeBegin()))
e.ts = SimTime.SimulatedTimeBegin()
prev_size = cur_size[:]
prev_num_ssts = cur_num_ssts[:]
for j in range(4):
cumulative_size_time[j] += (cur_size[j] *
(e.ts - ts_prev).total_seconds())
path_id = _sst_lives[e.sst_id].PathId()
size = _sst_lives[e.sst_id].Size()
if e.event == "C":
cur_size[path_id] += size
cur_num_ssts[path_id] += 1
elif e.event == "D":
cur_size[path_id] -= size
cur_num_ssts[path_id] -= 1
else:
raise RuntimeError("Unexpected")
fo.write(
(fmt + "\n") %
(ts_prev.strftime("%y%m%d-%H%M%S.%f")[:-3],
e.ts.strftime("%y%m%d-%H%M%S.%f")[:-3],
(e.ts - ts_prev).total_seconds(), prev_num_ssts[0],
prev_num_ssts[1], prev_num_ssts[2], prev_num_ssts[3],
cur_num_ssts[0], cur_num_ssts[1], cur_num_ssts[2],
cur_num_ssts[3], (prev_size[0] / (1024.0 * 1024)),
(prev_size[1] / (1024.0 * 1024)),
(prev_size[2] / (1024.0 * 1024)), (prev_size[3] /
(1024.0 * 1024)),
(sum(prev_size) / (1024.0 * 1024)), (cur_size[0] /
(1024.0 * 1024)),
(cur_size[1] / (1024.0 * 1024)), (cur_size[2] /
(1024.0 * 1024)),
(cur_size[3] / (1024.0 * 1024)), (sum(cur_size) /
(1024.0 * 1024)),
(cumulative_size_time[0] / (1024.0 * 1024 * 1024) /
(3600.0 * 24 * 365.25 / 12)),
(cumulative_size_time[1] / (1024.0 * 1024 * 1024) /
(3600.0 * 24 * 365.25 / 12)), (cumulative_size_time[2] /
(1024.0 * 1024 * 1024) /
(3600.0 * 24 * 365.25 / 12)),
(cumulative_size_time[3] / (1024.0 * 1024 * 1024) /
(3600.0 * 24 * 365.25 / 12)), (sum(cumulative_size_time) /
(1024.0 * 1024 * 1024) /
(3600.0 * 24 * 365.25 / 12))))
ts_prev = e.ts
# Don't bother with printing the last row. Quite a lot of the last rows
# have the same timestamps.
stat.append("Data size-time (GB*Month):")
stat.append(" Local SSD : %f" %
(cumulative_size_time[0] / (1024.0 * 1024 * 1024) /
(3600.0 * 24 * 365.25 / 12)))
stat.append(" EBS SSD : %f" %
(cumulative_size_time[1] / (1024.0 * 1024 * 1024) /
(3600.0 * 24 * 365.25 / 12)))
stat.append(" EBS Mag : %f" %
(cumulative_size_time[2] / (1024.0 * 1024 * 1024) /
(3600.0 * 24 * 365.25 / 12)))
stat.append(" EBS Mag Cold: %f" %
(cumulative_size_time[3] / (1024.0 * 1024 * 1024) /
(3600.0 * 24 * 365.25 / 12)))
stat.append(" Sum : %f" %
(sum(cumulative_size_time) / (1024.0 * 1024 * 1024) /
(3600.0 * 24 * 365.25 / 12)))
stat.append("Storage cost ($):")
stat.append(" Local SSD : %f" %
(_storage_cost[0] * cumulative_size_time[0] /
(1024.0 * 1024 * 1024) / (3600.0 * 24 * 365.25 / 12)))
stat.append(" EBS SSD : %f" %
(_storage_cost[1] * cumulative_size_time[1] /
(1024.0 * 1024 * 1024) / (3600.0 * 24 * 365.25 / 12)))
stat.append(" EBS Mag : %f" %
(_storage_cost[2] * cumulative_size_time[2] /
(1024.0 * 1024 * 1024) / (3600.0 * 24 * 365.25 / 12)))
stat.append(" EBS Mag Cold: %f" %
(_storage_cost[3] * cumulative_size_time[3] /
(1024.0 * 1024 * 1024) / (3600.0 * 24 * 365.25 / 12)))
stat.append(" Sum : %f" %
((_storage_cost[0] * cumulative_size_time[0] +
_storage_cost[1] * cumulative_size_time[1] +
_storage_cost[2] * cumulative_size_time[2] +
_storage_cost[3] * cumulative_size_time[3]) /
(1024.0 * 1024 * 1024) / (3600.0 * 24 * 365.25 / 12)))
for l in stat:
fo.write("# %s\n" % l)
Cons.P("Created %s %d" % (fn, os.path.getsize(fn)))
for l in stat:
Cons.P(l)
def Init(simulation_time_begin):
with Cons.MT("Init Conf ...", print_time=False):
global _simulation_time_begin
global _simulation_time_end
global _simulated_time_begin
global _simulated_time_end
_simulation_time_begin = None
_simulation_time_end = None
_simulated_time_begin = None
_simulated_time_end = None
dn = "%s/client" % Conf.GetDir("log_dir")
fn = "%s/%s" % (dn, simulation_time_begin)
if not os.path.isfile(fn):
fn_7z = "%s.7z" % fn
if not os.path.isfile(fn_7z):
raise RuntimeError("File not found: %s" % fn_7z)
Util.RunSubp("cd %s && 7z e %s" % (dn, fn_7z))
if not os.path.isfile(fn):
raise RuntimeError("Unexpected")
with Cons.MT("Parsing simulated/simulation time from %s ..." % fn,
print_time=False):
with open(fn) as fo:
for line in fo:
#Cons.P(line)
# simulation_time_end : 161227-162418.288
mo = re.match(
r"# simulation_time_begin: (?P<dt>\d\d\d\d\d\d-\d\d\d\d\d\d\.\d\d\d)",
line)
if mo is not None:
_simulation_time_begin = mo.group("dt")
if _simulation_time_begin != simulation_time_begin:
raise RuntimeError("Unexpected")
_simulation_time_begin = datetime.datetime.strptime(
_simulation_time_begin, "%y%m%d-%H%M%S.%f")
continue
mo = re.match(
r"# simulation_time_end : (?P<dt>\d\d\d\d\d\d-\d\d\d\d\d\d\.\d\d\d)",
line)
if mo is not None:
_simulation_time_end = mo.group("dt")
_simulation_time_end = datetime.datetime.strptime(
_simulation_time_end, "%y%m%d-%H%M%S.%f")
continue
mo = re.match(
r"# simulated_time_begin : (?P<dt>\d\d\d\d\d\d-\d\d\d\d\d\d\.\d\d\d)",
line)
if mo is not None:
_simulated_time_begin = mo.group("dt")
_simulated_time_begin = datetime.datetime.strptime(
_simulated_time_begin, "%y%m%d-%H%M%S.%f")
continue
mo = re.match(
r"# simulated_time_end : (?P<dt>\d\d\d\d\d\d-\d\d\d\d\d\d\.\d\d\d)",
line)
if mo is not None:
_simulated_time_end = mo.group("dt")
_simulated_time_end = datetime.datetime.strptime(
_simulated_time_end, "%y%m%d-%H%M%S.%f")
# Got all you needed. break to save time
break
Cons.P("simulation_time_begin: %s" % _simulation_time_begin)
Cons.P("simulation_time_end : %s" % _simulation_time_end)
Cons.P("simulated_time_begin : %s" % _simulated_time_begin)
Cons.P("simulated_time_end : %s" % _simulated_time_end)
def Heatmap():
# Set Conf.ExpStartTime(), if not already set.
if Conf.ExpStartTime() is None:
MutantLogReader.Get()
fn_hm = "%s/sst-heatmap-by-time-%s" % (Conf.dn_result, Conf.ExpStartTime())
fn_vl = "%s/sst-heatmap-by-time-vertical-lines-%s" % (Conf.dn_result,
Conf.ExpStartTime())
if os.path.isfile(fn_hm) and os.path.isfile(fn_vl):
return (fn_hm, fn_vl, _MaxHeatFromHeatmapByTimeData(fn_hm))
sst_lives = MemtSstLife.GetSstLives()
with Cons.MT("Generating Sst heatmap by time ..."):
# Gather heat info at n different times
num_times = Conf.heatmap_by_time_num_times
if Conf.ExpFinishTime() is None:
MemtSstLife.SetExpEndTimeFromSstLives()
min_sst_opened = None
for sst_gen, sl in sorted(sst_lives.iteritems()):
min_sst_opened = sl.Opened() if min_sst_opened is None else min(
min_sst_opened, sl.Opened())
# Start time is when the first Sstable is opened, not the experiment start
# time, when no SSTable exists yet.
# Exp start time: 160927-143257.395
# First Sstable open time: 160927-143411.273
#st = datetime.datetime.strptime(Conf.ExpStartTime(), "%y%m%d-%H%M%S.%f")
st = datetime.datetime.strptime(min_sst_opened, "%y%m%d-%H%M%S.%f")
et = datetime.datetime.strptime(Conf.ExpFinishTime(),
"%y%m%d-%H%M%S.%f")
dur = (et - st).total_seconds()
# { t0: {HeatBoxes} }
time_heatboxes = {}
vertical_lines = []
for i in range(0, num_times):
t0 = st + datetime.timedelta(seconds=(float(dur) * i / num_times +
time_offset_in_sec))
t1 = st + datetime.timedelta(seconds=(float(dur) *
(i + 1) / num_times +
time_offset_in_sec))
vertical_lines.append(t1)
# Heat boxes are sorted by their heat and plotted with the heights
# proportional to the size.
boxes = []
for sst_gen, sl in sorted(sst_lives.iteritems()):
h = sl.HeatAtTime(t0)
if h is None:
continue
boxes.append(_Box(sl, t0, t1, h))
boxes.sort(key=lambda b: b.heat, reverse=True)
time_heatboxes[t0] = boxes
Cons.ClearLine()
Cons.Pnnl("%4d/%4d" % (i + 1, num_times))
print ""
del vertical_lines[-1]
# Set y-coordinate of each box
for t, boxes in sorted(time_heatboxes.iteritems()):
total_size = 0
for b in boxes:
total_size += b.sl.Size()
s = 0
for b in boxes:
b.y0 = float(s) / total_size
s += b.sl.Size()
b.y1 = float(s) / total_size
# Make leftmost time to 0.
t_first = None
t_base = datetime.datetime(2000, 1, 1)
for t, boxes in sorted(time_heatboxes.iteritems()):
if t_first is None:
t_first = t
for b in boxes:
b.t0 = t_base + (b.t0 - t_first)
b.t1 = t_base + (b.t1 - t_first)
for i in range(len(vertical_lines)):
vertical_lines[i] = t_base + (vertical_lines[i] - t_first)
fmt = "%4d %1d %17s %17s %6.4f %6.4f" \
" %8.3f %8d %6s"
with open(fn_hm, "w") as fo:
fo.write("# heat_max=%f\n" % MemtSstLife.SstLife.max_heat)
# y0 is smaller than y1 (y0 is placed higher in the plot than y1).
fo.write("%s\n" % Util.BuildHeader(fmt, \
"sst_gen level t0 t1 y0 y1" \
" heat heat_color heat_color_hex"))
for t, boxes in sorted(time_heatboxes.iteritems()):
for b in boxes:
fo.write((fmt + "\n") % ( \
b.sl.sst_gen, b.sl.level
, b.t0.strftime("%y%m%d-%H%M%S.%f")[:-3], b.t1.strftime("%y%m%d-%H%M%S.%f")[:-3]
, b.y0, b.y1
, b.heat, b.heat_color, ("%0.6X" % b.heat_color)
))
fo.write("\n")
Cons.P("Created %s %d" % (fn_hm, os.path.getsize(fn_hm)))
with open(fn_vl, "w") as fo:
for vl in vertical_lines:
fo.write("%s\n" % vl.strftime("%y%m%d-%H%M%S.%f")[:-3])
Cons.P("Created %s %d" % (fn_vl, os.path.getsize(fn_vl)))
return (fn_hm, fn_vl, MemtSstLife.SstLife.max_heat)
