def PrepareData(self):
simulation_time_begin_year = SimTime.SimulationTimeBegin().strftime(
"%y")
self.row = []
for h, i in sorted(_header_idx.iteritems()):
if h.startswith("dsk/xvd") \
or h.startswith("io/xvd") \
or h.startswith("total_cpu_usage:"):
self.row.append(float(self.raw_row[i]))
elif h.startswith("system:time"):
# It doesn't have year. Use simulation_time_begin_year.
# 27-12 15:34:18
# 01234567890123
simulation_time = datetime.datetime.strptime(
(simulation_time_begin_year + self.raw_row[i]),
"%y%d-%m %H:%M:%S")
self.row.append(
SimTime.ToSimulatedTime(simulation_time).strftime(
"%m%d-%H%M%S"))
elif h.startswith("memory_usage:") \
or h.startswith("net/total:") \
or h.startswith("system:"):
self.row.append(float(self.raw_row[i]) / 1024.0)
else:
self.row.append(self.raw_row[i])
def GetSstAccFreqAtSpecificTime(at_simulated_time):
fn = "%s/sst-accfreq-%s-at-%.04f" % (Conf.Get("dn_result"),
Conf.Get("simulation_time_begin"),
at_simulated_time)
if os.path.isfile(fn):
return fn
# t0: a specific time when we take the snapshot
t0 = SimTime.SimulatedTimeAt(at_simulated_time)
Cons.P("t0 (time of snapshot): %s" % t0)
sst_lives = GetSstLives()
with open(fn, "w") as fo:
fmt = "%4d %13s %13s %7.3f %1d %5.2f"
fo.write("# t0 (time of snapshot): %s\n" % t0)
fo.write("%s\n" % Util.BuildHeader(
fmt,
"sst_id ts_before ts_after reads_per_64MB_per_sec level age_in_day"
))
for sst_id, sl in sst_lives.iteritems():
if t0 < SimTime.ToSimulatedTime(sl.ts_created):
continue
if (sl.ts_deleted is not None) and (SimTime.ToSimulatedTime(
sl.ts_deleted) < t0):
continue
ts_prev = None
for ts, v in sorted(sl.ts_acccnt.iteritems()):
ts_simulated = SimTime.ToSimulatedTime(ts)
if ts_simulated < t0:
ts_prev = ts_simulated
continue
#Cons.P("ts_simulated: %s" % ts_simulated)
if ts_prev is not None:
#cnt = v[0]
cnt_per_64MB_per_sec = v[1]
#temp = v[2]
fo.write(
(fmt + "\n") %
(sst_id, ts_prev.strftime("%y%d%m-%H%M%S"),
ts_simulated.strftime("%y%d%m-%H%M%S"),
cnt_per_64MB_per_sec, sl.Level(),
((t0 - SimTime.ToSimulatedTime(
sl.TsCreated())).total_seconds() / 3600.0 / 24)))
break
Cons.P("Created %s %d" % (fn, os.path.getsize(fn)))
return fn
def GenDataFileForGnuplot(dt):
SimTime.Init(dt)
dn = "%s/%s" % (Conf.GetDir("output_dir"), dt)
Util.MkDirs(dn)
fn = "%s/dstat-data" % dn
if os.path.isfile(fn):
return fn
with Cons.MT("Generating data file for plot ..."):
global _header_idx
global _body_rows
_header_idx = None
_body_rows = None
_Parse(dt)
fmt = "%9.0f %9.0f %9.0f %9.0f %9.0f %9.0f %9.0f %9.0f" \
" %6.1f %6.1f %6.1f %6.1f %6.1f %6.1f %6.1f %6.1f" \
" %8.0f %8.0f %8.0f %8.0f" \
" %3.0f %3.0f" \
" %3.0f %3.0f %11s" \
" %3.1f %6.2f %3.1f %6.2f %6.2f %6.3f"
header = Util.BuildHeader(
fmt, " ".join(k for k, v in sorted(_header_idx.iteritems())))
with open(fn, "w") as fo:
i = 0
for r in _body_rows:
if i % 50 == 0:
fo.write("%s\n" % header)
i += 1
#Cons.P(fmt % tuple(r.Prepared()))
fo.write((fmt + "\n") % tuple(r.Prepared()))
Cons.P("Created %s %d" % (fn, os.path.getsize(fn)))
return fn
def PlotSstAccfreqByAgeIndividual():
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()
sst_lives = RocksDbLogReader.GetSstAccFreqByAgeDataFiles()
for sl in sst_lives:
env["IN_FN"] = "%s/%s/sst-age-accfreq-data/%d" \
% (Conf.Get("dn_result"), Conf.Get("simulation_time_begin"), sl.Id())
env["LEVEL"] = str(sl.Level())
if sl.TsDeleted() is None:
raise RuntimeError("Unexpected")
env["AGE_DELETED"] = str(
SimTime.ToSimulatedTimeDur(
(sl.TsDeleted() - sl.TsCreated()).total_seconds()))
out_fn = "%s/L%d-%d.pdf" % (dn_out, sl.Level(), sl.Id())
env["OUT_FN"] = out_fn
start_time = time.time()
Util.RunSubp("gnuplot %s/sst-accfreq-by-age-individual.gnuplot" %
os.path.dirname(__file__),
env=env,
print_cmd=False)
dur = time.time() - start_time
Cons.P("Created %s %d in %.0f ms" %
(out_fn, os.path.getsize(out_fn), dur * 1000.0))
def main(argv):
Conf.ParseArgs()
dn_out = Conf.Get("dn_result")
Util.MkDirs(dn_out)
SimTime.Init(Conf.Get("simulation_time_begin"))
Plot.Plot()
def main(argv):
Conf.ParseArgs()
SimTime.Init(Conf.Get("simulation_time_begin"))
Util.MkDirs(Conf.dn_result)
Plot.Plot()
def main(argv): Conf.ParseArgs() # Get the simulation/simulated time begin/end by parsing a client log file # with the the same simulation time begin SimTime.Init() Plot.Plot()
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)
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)
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 _CalcAgeAccfreq(self):
if self.age_accfreq is not None:
return
# Temperature drops by 0.99 each time unit.
# When the time unit is sec, temperature 1 drops to 0.001 in 687.31586483
# seconds, 11 min 27 secs. Seems a reasonable number.
# 0.99 ^ n = 0.001
# n = 687.31586483
#temp_drop_alpha = 0.99
#age_end_simulated_time_prev = None
#temp = None
self.age_accfreq = []
age_end_prev = None
cnt_per_size_first_5_min = 0.0
for ts, v in sorted(self.ts_acccnt.iteritems()):
age_end = (ts - self.ts_created).total_seconds()
age_begin = age_end - 1.0
if age_begin < 0.0:
age_begin = 0.0
if (age_end_prev is not None) and (age_begin < age_end_prev):
age_begin = age_end_prev
# Simulated time
age_begin_simulated_time = SimTime.ToSimulatedTimeDur(age_begin)
age_end_simulated_time = SimTime.ToSimulatedTimeDur(age_end)
# Dur in seconds
age_dur_simulated_time = age_end_simulated_time - age_begin_simulated_time
# You don't need to calculate temperature here. It is already calculated by RocksDB-Mutant.
self.age_accfreq.append((
age_begin,
age_end,
age_begin_simulated_time,
age_end_simulated_time,
v[1] # cnt_per_64MB_per_sec
,
v[2] # temp
))
age_end_prev = age_end
def __init__(self, simulation_time_begin):
self.simulation_time_begin = simulation_time_begin
self.sim_time = SimTime.SimTime(simulation_time_begin)
# {sst_id: SstLife()}
self.sst_lives = None
self._BuildSstLives()
self._CalcStorageCost()
def PrepareData(self):
simulation_time_begin_year = SimTime.SimulationTimeBegin().strftime(
"%y")
self.row = []
for h, i in sorted(_header_idx.iteritems()):
if h.startswith("dsk/xvd") \
or h.startswith("io/xvd") \
or h.startswith("total_cpu_usage:"):
self.row.append(float(self.raw_row[i]))
elif h.startswith("system:time"):
# It doesn't have year. Use simulation_time_begin_year.
# 27-12 15:34:18
# 01234567890123
simulation_time = datetime.datetime.strptime(
(simulation_time_begin_year + self.raw_row[i]),
"%y%d-%m %H:%M:%S")
# Convert to relative time
rel = SimTime.ToSimulationTimeRelative(simulation_time)
totalSeconds = rel.seconds
# Exclude the first one that is too big.
if totalSeconds > 12 * 3600:
r1 = "00:00:00"
else:
hours, remainder = divmod(totalSeconds, 3600)
minutes, seconds = divmod(remainder, 60)
r1 = "%s:%s:%s" % (hours, minutes, seconds)
self.row.append(r1)
elif h.startswith("memory_usage:") \
or h.startswith("net/total:") \
or h.startswith("system:"):
self.row.append(float(self.raw_row[i]) / 1024.0)
else:
self.row.append(self.raw_row[i])
def Plot(param):
job_id = param[0]
exp_dt = param[1]
dn_log_job = "%s/work/mutant/log/quizup/sla-admin/%s" % (
os.path.expanduser("~"), job_id)
fn_log_quizup = "%s/quizup/%s" % (dn_log_job, exp_dt)
fn_log_rocksdb = "%s/rocksdb/%s" % (dn_log_job, exp_dt)
fn_log_dstat = "%s/dstat/%s.csv" % (dn_log_job, exp_dt)
log_q = QuizupLog(fn_log_quizup)
SimTime.Init(log_q.SimTime("simulated_time_begin"),
log_q.SimTime("simulated_time_end"),
log_q.SimTime("simulation_time_begin"),
log_q.SimTime("simulation_time_end"))
qz_std_max = _QzSimTimeDur(
log_q.quizup_options["simulation_time_dur_in_sec"])
qz_opt_str = _QuizupOptionsFormattedStr(log_q.quizup_options)
error_adj_ranges = log_q.quizup_options["error_adj_ranges"].replace(
",", " ")
(fn_rocksdb_sla_admin_log, pid_params,
num_sla_adj) = RocksdbLog.ParseLog(fn_log_rocksdb, exp_dt)
fn_dstat = DstatLog.GenDataFileForGnuplot(fn_log_dstat, exp_dt)
fn_out = "%s/sla-admin-by-time-%s.pdf" % (Conf.GetDir("output_dir"),
exp_dt)
with Cons.MT("Plotting ..."):
env = os.environ.copy()
env["STD_MAX"] = qz_std_max
env["ERROR_ADJ_RANGES"] = error_adj_ranges
env["IN_FN_QZ"] = fn_log_quizup
env["IN_FN_SLA_ADMIN"] = "" if num_sla_adj == 0 else fn_rocksdb_sla_admin_log
env["QUIZUP_OPTIONS"] = qz_opt_str
env["PID_PARAMS"] = "%s %s %s %s" % (pid_params["target_value"],
pid_params["p"], pid_params["i"],
pid_params["d"])
env["WORKLOAD_EVENTS"] = " ".join(
str(t) for t in log_q.simulation_time_events)
env["IN_FN_DS"] = fn_dstat
env["OUT_FN"] = fn_out
Util.RunSubp("gnuplot %s/sla-admin-by-time.gnuplot" %
os.path.dirname(__file__),
env=env)
Cons.P("Created %s %d" % (fn_out, os.path.getsize(fn_out)))
def __init__(self, simulation_time_begin, from_95p=False):
with Cons.MT("Parsing RocksDB log %s ..." % simulation_time_begin):
self.simulation_time_begin = simulation_time_begin
self.sim_time = SimTime.SimTime(simulation_time_begin)
self.from_95p = from_95p
if self.from_95p:
self.simulated_time_95 = self.sim_time.SimulatedTimeBegin() \
+ datetime.timedelta(seconds = (self.sim_time.SimulatedTimeEnd() - self.sim_time.SimulatedTimeBegin()).total_seconds() * 0.5)
#Cons.P(self.simulated_time_95)
# 2016-07-26 17:17:24.123500
else:
self.simulated_time_95 = None
# {sst_id: SstLife()}
self.sst_lives = None
self._BuildSstLives()
self._CalcNumSSTablesSizeAtEachLevelOverTime()
def _ParseSstAccCnt(line):
if line is None:
raise RuntimeError("Unexpected")
mo = re.match(r"(?P<ts>(\d|\/|-|:|\.)+) .+EVENT_LOG_v1 (?P<json>.+)", line)
ts = datetime.datetime.strptime(mo.group("ts"), "%Y/%m/%d-%H:%M:%S.%f")
ts_rel = ts - SimTime.SimulationTimeBegin()
Cons.P("line ts: %s" % str(ts_rel)[:11])
j = json.loads(mo.group("json"))
#Cons.P(j["mutant_table_acc_cnt"]["sst"])
# 2816:2:1:1.046:0.199 2869:2:1:1.046:0.264 2903:3:2:3.705:0.174 3385:3:2:2.092:1.087 3389:3:3:3.138:1.646 ...
tokens = j["mutant_table_acc_cnt"]["sst"].split(" ")
sst_acc_infos = []
for t in tokens:
sst_acc_infos.append(SstAccInfo(t))
sst_acc_infos.sort(key=lambda x: x.temp)
for ai in sst_acc_infos:
Cons.P(ai)
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 main(argv):
Conf.ParseArgs()
SimTime.Init(Conf.Get("simulation_time_begin"))
RocksDbLogReader.CalcStorageCost()
def _ParseLog(fn, exp_dt):
if not os.path.exists(fn):
fn_zipped = "%s.7z" % fn
if not os.path.exists(fn_zipped):
raise RuntimeError("Unexpected: %s" % fn)
Util.RunSubp("cd %s && 7z e %s > /dev/null" %
(os.path.dirname(fn_zipped), os.path.basename(fn_zipped)))
if not os.path.exists(fn):
raise RuntimeError("Unexpected")
fn_out = "%s/rocksdb-sla-admin-%s" % (Conf.GetDir("output_dir"), exp_dt)
pid_params = None
num_sla_adj = 0
last_lines_mutant_table_acc_cnt = Queue.Queue()
with open(fn) as fo, open(fn_out, "w") as fo_out:
# {u'num_ssts_should_be_in_slow_dev': 0, u'sst_ott': 0.005, u'num_ssts_in_slow_dev': 0, u'num_ssts_in_fast_dev': 0,
# u'num_ssts_should_be_in_fast_dev': 0, u'cur_lat': 5.8963, u'adj_type': u'no_sstable', u'sst_status': u''}
fmt = "%12s %7.2f %7.2f %7.2f %7.2f %1d" \
" %6.1f %6.1f" \
" %8.2f" \
" %3d %3d %3d %3d" \
" %28s %10.7f %10.7f"
header = Util.BuildHeader(fmt, "ts cur_latency lat_ra_all_0 lat_ra_all_1 lat_ra_filtered make_adjustment" \
" slow_dev_r_iops slow_dev_w_iops" \
" new_sst_ott" \
" num_ssts_in_fast_dev num_ssts_in_slow_dev num_ssts_should_be_in_fast_dev num_ssts_should_be_in_slow_dev" \
" adj_type pid_adj pid_adj1" \
)
# Running average including all
# Running average excluding background SSTable compactions and migrations
lat_q_all_0 = collections.deque()
lat_q_all_1 = collections.deque()
lat_q_filtered = collections.deque()
i = 0
for line in fo:
try:
line = line.strip()
if "mutant_sla_admin_init" in line:
#Cons.P(line)
# 2017/09/04-14:38:46.191160 7f084ccf9700 EVENT_LOG_v1 {"time_micros": 1504535926190841, "mutant_sla_admin_init": {"target_value":
# 19, "p": 1, "i": 0, "d": 0}}
mo = re.match(
r"(?P<ts>(\d|\/|-|:|\.)+) .+EVENT_LOG_v1 (?P<json>.+)",
line)
j = json.loads(mo.group("json"))
j1 = j["mutant_sla_admin_init"]
pid_params = j1
fo_out.write("# target_latency: %s\n" % j1["target_value"])
fo_out.write("# k_p: %s\n" % j1["p"])
fo_out.write("# k_i: %s\n" % j1["i"])
fo_out.write("# k_d: %s\n" % j1["d"])
fo_out.write("#\n")
elif "mutant_sla_admin_adjust" in line:
#Cons.P(line)
# 2017/09/04-14:38:46.363976 7f07f8450700 EVENT_LOG_v1 {"time_micros": 1504535926363296, "mutant_sla_admin_adjust": {"cur_lat":
# 21.535, "dt": 0, "p": -2.53497, "i": 0, "d": 0, "adj": -2.53497, "sst_ott": 7.46503, "sst_status": "1209:2:17.113:0:0
# 1316:2:66.572:0:0 ...", "num_ssts_in_fast_dev": 126, "num_ssts_in_slow_dev": 6, "num_ssts_should_be_in_fast_dev": 132,
# "num_ssts_should_be_in_slow_dev": 0}}
mo = re.match(
r"(?P<ts>(\d|\/|-|:|\.)+) .+EVENT_LOG_v1 (?P<json>.+)",
line)
try:
j = json.loads(mo.group("json"))
except ValueError as e:
# This happens when the log file is not finialized.
Cons.P("Exception: %s" % e)
Cons.P(" fn: %s" % fn)
Cons.P(" time_micros: %s" % j["time_micros"])
Cons.P(" Ignoring ...")
continue
num_sla_adj += 1
# time_micros is in local time. ts seems to be in UTC. Quizup ts is in UTC.
#ts = datetime.datetime.fromtimestamp(int(j["time_micros"]) / 1000000.0)
ts = datetime.datetime.strptime(mo.group("ts"),
"%Y/%m/%d-%H:%M:%S.%f")
ts_rel = ts - SimTime.SimulationTimeBegin()
j1 = j["mutant_sla_admin_adjust"]
if i % 40 == 0:
fo_out.write(header + "\n")
i += 1
make_adjustment = j1["make_adjustment"]
cur_lat = float(j1["cur_lat"])
# append() appends to the right. coupled with popleft(), it implements a queue.
lat_q_all_0.append(cur_lat)
lat_q_all_1.append(cur_lat)
if make_adjustment == 1:
lat_q_filtered.append(cur_lat)
# Calc the averages of the last n observations
while 10 < len(lat_q_all_0):
lat_q_all_0.popleft()
while 400 < len(lat_q_all_1):
lat_q_all_1.popleft()
while 10 < len(lat_q_filtered):
lat_q_filtered.popleft()
lat_ra_all_0 = -1
lat_ra_all_1 = -1
lat_ra_filtered = -1
if 0 < len(lat_q_all_0):
lat_ra_all_0 = sum(lat_q_all_0) / len(lat_q_all_0)
if 0 < len(lat_q_all_1):
lat_ra_all_1 = sum(lat_q_all_1) / len(lat_q_all_1)
if 0 < len(lat_q_filtered):
lat_ra_filtered = sum(lat_q_filtered) / len(
lat_q_filtered)
# {u'num_ssts_should_be_in_slow_dev': 12, u'make_adjustment': 0, u'slow_dev_r_iops': -1, u'num_ssts_in_slow_dev': 0,
# u'num_ssts_in_fast_dev': 216, u'num_ssts_should_be_in_fast_dev': 204, u'cur_lat': 424.31, u'sst_ott': 0, u'slow_dev_w_iops':
# -1, u'sst_status': u'2083:2:1.797:0:0 2257:2:3.057:0:0 2386:3:2.446:0:0 2425:2:2.345:0:0 2455:2:3.060:0:0 2529:2:1.581:0:0
# ...
# 3843:1:-1.000:0:1'}
fo_out.write(
(fmt + "\n") %
(str(ts_rel)[:11], cur_lat, lat_ra_all_0, lat_ra_all_1,
lat_ra_filtered, j1["make_adjustment"],
j1["slow_dev_r_iops"], j1["slow_dev_w_iops"],
j1["sst_ott"], j1["num_ssts_in_fast_dev"],
j1["num_ssts_in_slow_dev"],
j1["num_ssts_should_be_in_fast_dev"],
j1["num_ssts_should_be_in_slow_dev"], j1["adj_type"]
if "adj_type" in j1 else "-", j1["adj"] if "adj" in j1
else 0, j1["adj1"] if "adj1" in j1 else 0))
elif "mutant_table_acc_cnt" in line:
if 500 <= last_lines_mutant_table_acc_cnt.qsize():
last_lines_mutant_table_acc_cnt.get_nowait()
last_lines_mutant_table_acc_cnt.put(line)
except KeyError as e:
Cons.P("KeyError: %s fn=%s line=%s" % (e, fn, line))
sys.exit(1)
# Checked to see what their access count distribution is like
if False:
line = None
try:
line = last_lines_mutant_table_acc_cnt.get_nowait()
except Queue.Empty as e:
# This happens
pass
if line is not None:
_ParseSstAccCnt(line)
Cons.P("Created %s %d" % (fn_out, os.path.getsize(fn_out)))
return (fn_out, pid_params, num_sla_adj)
def _CalcAgeAccfreq(self):
if self.age_accfreq is not None:
return
# Temperature drops by 0.99 each time unit.
# When the time unit is sec, temperature 1 drops to 0.001 in 687.31586483
# seconds, 11 min 27 secs. Seems a reasonable number.
# 0.99 ^ n = 0.001
# n = 687.31586483
#temp_drop_alpha = 0.99
#age_end_simulated_time_prev = None
#temp = None
self.age_accfreq = []
age_end_prev = None
cnt_per_size_first_5_min = 0.0
for ts, v in sorted(self.ts_acccnt.iteritems()):
age_end = (ts - self.ts_created).total_seconds()
age_begin = age_end - 1.0
if age_begin < 0.0:
age_begin = 0.0
if (age_end_prev is not None) and (age_begin < age_end_prev):
age_begin = age_end_prev
# Simulated time
age_begin_simulated_time = SimTime.ToSimulatedTimeDur(age_begin)
age_end_simulated_time = SimTime.ToSimulatedTimeDur(age_end)
# Dur in seconds
age_dur_simulated_time = age_end_simulated_time - age_begin_simulated_time
# You don't need this calculation. This was already calculated by
# RocksDB-Mutant.
#
# Unit is num / 64 MB / sec
# Calculation is as if the accesses are all happened at the time ts
#cnt_per_size = v[0] / (self.size / (64.0 * 1024 * 1024))
#acc_freq = cnt_per_size / age_dur_simulated_time
#
# Calculate temperature
# - Defined using simulated time. Let's assume that RocksDB knows the
# simulated time. In practice, it's the wall clock time.
# - Initial temperature: If the first age_begin is less than 10 sec,
# consider it as an initial temperature. The 10 sec threshold is in
# simulation time, since the reporting granularity, 1 sec, is in
# simulation time.
#
# Update every 5 minutes or 10. Wait until you actually need it. It's
# just about plotting. Mutant calculates it in that interval.
#
#if age_end_simulated_time < 5*60:
# cnt_per_size_first_5_min += cnt_per_size
# temp = None
#else:
# if temp is None:
# cnt_per_size_first_5_min += cnt_per_size
# temp = cnt_per_size_first_5_min / age_end_simulated_time
# else:
# temp = temp * math.pow(temp_drop_alpha, age_end_simulated_time - age_end_simulated_time_prev) \
# + cnt_per_size * (1.0 - temp_drop_alpha)
#age_end_simulated_time_prev = age_end_simulated_time
self.age_accfreq.append((age_begin, age_end
, age_begin_simulated_time, age_end_simulated_time
, v[1] # cnt_per_64MB_per_sec
, v[2] # temp
))
age_end_prev = age_end
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 main(argv):
Conf.ParseArgs()
SimTime.Init(Conf.Get("simulation_time_begin"))
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 _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)