def __print_gc(self, data):
""" print data to the user, expecting datetime keys and list(int) values """
print(". <300ms + 301-500ms ! >500ms")
print('-'*30)
busiest = None
for time, pauses in data:
total = sum(pauses)
if not busiest:
busiest = (time, total)
elif total > busiest[1]:
busiest = (time, total)
print(time.strftime("%Y-%m-%d %H:%M:%S"), end=' ')
print(len(pauses), end=' ')
for pause in pauses:
c = '.'
if pause > 300:
c = '+'
if pause > 500:
c = '!'
print(c, end='')
print('')
print('')
print('busiest period: %s (%sms)' % (busiest[0].strftime("%Y-%m-%d %H:%M:%S"), busiest[1]))
print('')
percentiles = [[]]
percentiles.append(get_percentile_headers("GC pauses"))
header = [""]
header.extend(["---" for i in range(6)])
percentiles.append(header)
percentiles.append(get_percentiles("ms", list(itertools.chain.from_iterable(
pauses for time, pauses in data)), strformat="%i"))
pad_table(percentiles, min_width=11, extra_pad=2)
for line in percentiles:
print("".join(line))
print()
def print_report(self):
"prints a report for the file this class was initialized with, analyzing if necessary"
if not self.analyzed:
self.analyze()
print("sysbottle version %s" % VERSION)
print()
print()
print("* total records: %s" % self.count)
if self.count:
def report_percentage(a):
return (float(a) / float(self.count)) * 100.0
print(
"* total bottleneck time: %.2f%% (cpu bound, io bound, or both)"
% report_percentage(self.iowait_exceeded + self.cpu_exceeded))
print("* cpu+system+nice+steal time > %.2f%%: %.2f%%" %
(self.conf["cpu_threshold"],
report_percentage(self.cpu_exceeded)))
print("* iowait time > %.2f%%: %.2f%%" % (
self.conf["iowait_threshold"],
report_percentage(self.iowait_exceeded),
))
print("* start %s" % self.start)
print("* end %s" % self.end)
log_time_seconds = (self.end - self.start).total_seconds() + 1
print("* log time: %ss" % log_time_seconds)
print("* interval: %ss" % report_percentage(log_time_seconds))
for device in self.devices.keys():
print("* %s time at queue depth >= %.2f: %.2f%%" % (
device,
self.conf["queue_threshold"],
report_percentage(self.queuedepth[device]),
))
print()
lines = []
lines.append(get_percentile_headers())
lines.append(["", "---", "---", "---", "---", "---", "---"])
lines.append(get_percentiles("cpu", self.cpu_stats["total"]))
lines.append(get_percentiles("iowait", self.cpu_stats["%iowait"]))
lines.append([])
lines.append(get_percentile_headers())
lines.append(["", "---", "---", "---", "---", "---", "---"])
for device in self.devices:
lines.append([device, "", "", "", "", "", ""])
for iotype in self.devices[device].keys():
if "qu" in iotype or "wait" in iotype:
lines.append(
get_percentiles("- " + iotype + ":",
self.devices[device][iotype]))
lines.append([])
humanize.pad_table(lines, 8, 2)
for line in lines:
print("".join(line))
self.print_recommendations()
def test_pad_table(self):
"""padding defaults"""
data = [["1", "2", "3"]]
data.append(["2", "2222", "33333"])
humanize.pad_table(data)
# first column
self.assertEqual(data[0][0], "1")
self.assertEqual(data[1][0], "2")
# second column
self.assertEqual(data[0][1], "2 ")
self.assertEqual(data[1][1], "2222")
# last column does not pad
self.assertEqual(data[0][2], "3")
self.assertEqual(data[1][2], "33333")
def test_pad_table_with_min_width_and_padding(self):
"""tests table padding with various paddings and min width"""
data = [["1", "2", "3"]]
data.append(["2", "2222", "33333"])
humanize.pad_table(data, min_width=2, extra_pad=1)
# first column
self.assertEqual(data[0][0], "1 ")
self.assertEqual(data[1][0], "2 ")
# second column
self.assertEqual(data[0][1], "2 ")
self.assertEqual(data[1][1], "2222 ")
# last column does not pad
self.assertEqual(data[0][2], "3")
self.assertEqual(data[1][2], "33333")
def test_pad_table_should_always_trim_last_col(self):
"""verifies when the last col is missing in a row the next column is padded down"""
data = [["1", "2", ""]]
data.append(["2", "2222", "33333"])
humanize.pad_table(data, min_width=2, extra_pad=1)
# first column
self.assertEqual(data[0][0], "1 ")
self.assertEqual(data[1][0], "2 ")
# second column
self.assertEqual(data[0][1], "2")
self.assertEqual(data[1][1], "2222 ")
# last column does not pad
self.assertEqual(data[0][2], "")
self.assertEqual(data[1][2], "33333")
def test_pad_table_headers():
"""demonstrates the use of irrelagular data added to table that is ignored"""
data = [["my header"]]
data.append(["1", "2", "3"])
data.append(["2", "2222", "33333"])
humanize.pad_table(data, min_width=2, extra_pad=1)
#header
assert data[0][0] == "my header"
#column are unbroken
assert data[1][0] == "1 "
assert data[2][0] == "2 "
assert data[1][1] == "2 "
assert data[2][1] == "2222 "
assert data[1][2] == "3 "
assert data[2][2] == "33333 "
def test_pad_table():
"""padding defaults"""
data = [["1", "2", "3"]]
data.append(["2", "2222", "33333"])
humanize.pad_table(data)
#first column
assert data[0][0] == "1"
assert data[1][0] == "2"
#second column
assert data[0][1] == "2 "
assert data[1][1] == "2222"
#third column
assert data[0][2] == "3 "
assert data[1][2] == "33333"
def test_pad_table_with_min_width_and_padding():
"""tests table padding with various paddings and min width"""
data = [["1", "2", "3"]]
data.append(["2", "2222", "33333"])
humanize.pad_table(data, min_width=2, extra_pad=1)
#first column
assert data[0][0] == "1 "
assert data[1][0] == "2 "
#second column
assert data[0][1] == "2 "
assert data[1][1] == "2222 "
#third column
assert data[0][2] == "3 "
assert data[1][2] == "33333 "
def test_pad_table_headers(self):
"""demonstrates the use of irrelagular data added to table that is ignored"""
data = [["my header"]]
data.append(["1", "2", "3"])
data.append(["2", "2222", "33333"])
humanize.pad_table(data, min_width=2, extra_pad=1)
# header
self.assertEqual(data[0][0], "my header")
# column are unbroken
self.assertEqual(data[1][0], "1 ")
self.assertEqual(data[2][0], "2 ")
self.assertEqual(data[1][1], "2 ")
self.assertEqual(data[2][1], "2222 ")
# as always last column does not pad
self.assertEqual(data[1][2], "3")
self.assertEqual(data[2][2], "33333")
def generate_report(parsed):
"""generates a report from the result of parsing a
tarball or series of files"""
calculated = calculate_report(parsed)
report = []
report.append("")
report.append("NOTE: as of version 0.3.13 all evictions with duration of 0 ms " + \
"are deducted from the item eviction count and are not part of the " + \
"eviction freq or duration calculations")
report.append("")
if not calculated.get('start_log'):
report.append("start log: 'None'")
else:
report.append("start log: '%s'" % \
calculated.get('start_log').strftime(dates.CASSANDRA_LOG_FORMAT))
if not calculated.get('last_log'):
report.append("end log: 'None'")
else:
report.append("end log: '%s'" % \
calculated.get('last_log').strftime(dates.CASSANDRA_LOG_FORMAT))
report.append("")
node_info = calculated.get('node_info', [])
generate_recommendations(report, node_info)
if not node_info:
return "\nNo Logs Found For Processing\n"
table = []
table.append(["node", "Avg time between evictions", "Avg eviction duration", \
"Times (byte/item) limit reached", "Most recent limit (byte/item)", "Log duration"])
table.append(["----", "--------------------------", "---------------------", \
"-------------------------------", "-----------------------------", "------------"])
for node in node_info:
table.append([node.name, humanize.format_millis(node.avg_evict_freq), \
humanize.format_millis(node.avg_evict_duration), \
"%i/%i" % \
(node.byte_limit, node.item_limit), \
"%s/%i" % \
(humanize.format_bytes(node.last_byte_limit), node.last_item_limit), \
humanize.format_millis(node.log_duration)])
humanize.pad_table(table)
for row in table:
report.append(" ".join(row))
report.append("") #provides empty line after last line
return "\n".join(report)
def print_summary(self):
""" prints a summary report """
self.analyze()
summary = Summary(self.nodes)
print("%s version: %s" % (self.command_name, VERSION))
print('')
print("Summary (%s lines)" % format_num(summary.lines))
print("Summary (%s skipped lines)" % format_num(summary.skipped_lines))
print('')
print("dse versions: %s" % (set(summary.versions) or 'unknown'))
print("cassandra versions: %s" %
(set(summary.cassandra_versions) or 'unknown'))
print("first log time: %s" % summary.start)
print("last log time: %s" % summary.end)
if not self.dumps_analyzed:
print("Nothing found!")
return
print("duration: %s" %
format_seconds(int(summary.duration.total_seconds())))
print("total stages analyzed: %s" % self.dumps_analyzed)
print("total nodes analyzed: %s" % len(summary.nodes))
pauses = summary.get_pauses()
if pauses:
print('')
percentiles = []
percentiles.append(get_percentile_headers("GC pauses"))
percentiles.append(["", "---", "---", "---", "---", "---", "---"])
percentiles.append(get_percentiles("ms", pauses, strformat="%i"))
pad_table(percentiles, min_width=11, extra_pad=2)
for line in percentiles:
print("".join(line))
print("total GC events: %s" % len(pauses))
print('')
ops = summary.get_busiest_tables('ops')[:5]
if ops:
print("busiest tables by ops across all nodes")
print('-' * 30)
for onode, (oname, num) in ops:
print("* %s: %s: %s" % (onode, oname, num))
print('')
print("busiest table by data across all nodes")
print('-' * 30)
for dnode, (dname, data) in summary.get_busiest_tables('data')[:5]:
print("* %s: %s: %s" % (dnode, dname, data))
print('')
print("busiest stages across all nodes")
print('-' * 30)
data = []
for (name, status, stage, value) in summary.get_busiest_stages():
data.append(
["* %s %s:" % (stage, status),
str(value),
"(%s)" % name])
pad_table(data, extra_pad=2)
for line in data:
print("".join(line))
pending = summary.get_stages_in('pending')
data = []
if pending:
data.append([])
self.__print_stages('pending', pending, data)
delayed = summary.get_stages_in('local backpressure')
if delayed:
data.append([])
self.__print_backpressure(delayed, data)
data.append([])
pad_table(data, extra_pad=2)
for line in data:
print("".join(line))
self.__print_recs()
def print_histogram(self):
""" print histogram report, analyzing if necessary """
self.analyze()
print("%s version: %s" % (self.command_name, VERSION))
print('')
print("Histogram")
print('')
if not self.nodes:
print("Nothing found!")
return
for name, node in self.nodes.items():
print(name)
print('-' * 60)
print("%s lines" % format_num(node.lines))
print("%s skipped lines" % format_num(node.skipped_lines))
print("dse version: %s" % (node.version or 'unknown'))
print("cassandra version: %s" %
(node.cassandra_version or 'unknown'))
print("log start time: %s" % node.start)
print("log end time: %s" % node.end)
if not node.dumps_analyzed:
print("Nothing found!")
continue
print("duration: %s" %
format_seconds(int(node.duration().total_seconds())))
print("stages analyzed: %s" % node.dumps_analyzed)
if node.pauses:
percentiles = [[]]
percentiles.append(get_percentile_headers("GC pauses"))
header = [""]
header.extend(["---" for i in range(6)])
percentiles.append(header)
percentiles.append(
get_percentiles("ms", node.pauses, strformat="%i"))
pad_table(percentiles, min_width=11, extra_pad=2)
for line in percentiles:
print("".join(line))
print("total GC events: %s" % len(node.pauses))
print('')
ops = node.get_busiest_tables('ops')[:5]
if ops:
print("busiest tables (ops)")
print('-' * 30)
nlen = max(len(o[0]) for o in ops)
for n, t in ops:
print(n.ljust(nlen), t)
data = node.get_busiest_tables('data')[:5]
print("busiest tables (data)")
print('-' * 30)
nlen = max(len(d[0]) for d in data)
for n, t in data:
print(n.ljust(nlen), t)
print('')
if node.stages:
percentiles = []
percentiles.append(get_percentile_headers('stages'))
percentiles.append([])
for status, stage in node.stages.items():
header = [status.upper()]
header.extend("" for i in range(6))
percentiles.append(header)
for tpname, vals in sorted(stage.items(),
key=lambda tpool: max(tpool[1]),
reverse=True):
percentiles.append(
get_percentiles(tpname, vals, strformat="%i"))
percentiles.append([])
pad_table(percentiles, extra_pad=2)
for line in percentiles:
print("".join(line))
print('')
self.__print_recs()
def print_report(self,
top=None,
alloc=False,
collate=True,
start=None,
end=None):
""" analyze and report on ttop files """
parser = TTopParser(start=start, end=end)
print("ttop version %s" % VERSION)
print()
table = []
for file in self.files:
with diag.FileWithProgress(file) as log:
table.append([])
if env.DEBUG:
print("parsing", file)
for total, threads in parser.parse(log):
if alloc:
table.append([
total["date"].strftime("%Y-%m-%d %H:%M:%S"),
"Threads",
"Alloc/s",
"Total: " + format_bytes(total["heap_rate"]),
])
else:
table.append([
total["date"].strftime("%Y-%m-%d %H:%M:%S"),
"Threads",
"CPU%",
"Total: " + str(total["app_cpu"]) + "%",
])
header = "=" * 80
table.append([header])
combined = threads
if collate:
combined = self.collate_threads(threads)
ordered = []
if alloc:
ordered = sorted(
combined.items(),
key=lambda k: k[1]["heap_rate"],
reverse=True,
)
else:
ordered = sorted(
combined.items(),
key=lambda k: k[1]["total_cpu"],
reverse=True,
)
if top:
ordered = ordered[0:top]
for name, value in ordered:
count = 1
if collate:
count = int(value["thread_count"])
if alloc:
table.append([
name,
str(count),
format_bytes(value["heap_rate"]),
textbar(total["heap_rate"],
value["heap_rate"]),
])
else:
table.append([
name,
str(count),
"{:.2f}".format(value["total_cpu"]),
textbar(total["app_cpu"], value["total_cpu"]),
])
table.append([])
pad_table(table, extra_pad=1)
for row in table:
print("".join(row))
print()
def generate_report(parsed, recommendations):
"""generates report from calculated data"""
calculated = parsed.get("summary")
# allows nodes to be tabbed out for a block look
table = []
table.append(["nodes", simple_format(calculated.get("nodes"))])
table.append([
"dse version(s) (startup logs)",
format_list(calculated.get("versions", []))
])
table.append([
"cassandra version(s) (startup logs)",
format_list(calculated.get("cassandra_versions", [])),
])
table.append([
"solr version(s) (startup logs)",
format_list(calculated.get("solr_versions", [])),
])
table.append([
"spark version(s) (startup logs)",
format_list(calculated.get("spark_versions", [])),
])
table.append(["worst gc pause (system logs)", format_gc(calculated)])
table.append([
"worst read latency (cfstats)",
format_table_stat_float(calculated.get("worst_read_latency"),
val_suffix="ms"),
])
table.append([
"worst write latency (cfstats)",
format_table_stat_float(calculated.get("worst_write_latency"),
val_suffix="ms"),
])
table.append([
"worst tombstones query (cfstats)",
format_table_stat(calculated.get("worst_tombstone")),
])
table.append([
"worst live cells query (cfstats)",
format_table_stat(calculated.get("worst_live_cells")),
])
table.append(["largest table (cfstats)", format_largest_table(calculated)])
table.append([
"busiest table reads (cfstats)",
format_busiest_table(calculated.get("busiest_table_reads"), "reads"),
])
table.append([
"busiest table writes (cfstats)",
format_busiest_table(calculated.get("busiest_table_writes"), "writes"),
])
table.append([
"largest partition (cfstats)",
format_partition_bytes(calculated.get("worst_part_size"), 2) + " " +
format_table_loc(calculated.get("worst_part_size")),
])
humanize.pad_table(table)
report = [""]
for row in table:
report.append(" ".join(row))
report.append("")
report.append("errors parsing")
report.append("--------------")
if parsed.get("warnings"):
for warning in parsed.get("warnings"):
report.append("* %s" % warning)
else:
report.append("No parsing errors")
# "* random error is here"
report.append("")
report.append("recommendations")
report.append("---------------")
# recs here
if recommendations:
for rec in recommendations:
rec_str = "* %s." % rec.get("issue")
if rec.get("rec"):
rec_str = rec_str + " %s." % rec.get("rec")
report.append(rec_str)
if rec.get("nodes"):
# allows nodes to be tabbed out for a block look
nodes_fmtd = humanize.format_list(rec.get("nodes"),
newline="\n" + " " * 18)
report.append(" nodes affected: %s" % nodes_fmtd)
report.append(" --")
else:
report.append("No recommendations")
return "\n".join(report)
