<jupyter_start><jupyter_text>JVMQuake GCLog Analyzer=======================This notebook displayes the GC debt algorithm that `jvmquake` uses and will parse the file `gclog` assuming it is a standard Java GC file from a JVM running with `-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps  -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime` that contains lines that look like:```2019-03-05T02:41:44.826+0000: 7.395: Total time for which application threads were stopped: 0.0001693 seconds, Stopping threads took: 0.0000766 seconds2019-03-05T02:41:44.935+0000: 7.504: Application time: 0.1087838 seconds        2019-03-05T02:41:44.935+0000: 7.504: Total time for which application threads were stopped: 0.0002082 seconds, Stopping threads took: 0.0000504 seconds2019-03-05T02:41:45.058+0000: 7.627: Application time: 0.1229325 seconds        2019-03-05T02:41:45.058+0000: 7.627: Total time for which application threads were stopped: 0.0002039 seconds, Stopping threads took: 0.0000656 seconds2019-03-05T02:41:45.400+0000: 7.969: Application time: 0.3417643 seconds        2019-03-05T02:41:45.400+0000: 7.969: Total time for which application threads were stopped: 0.0002733 seconds, Stopping threads took: 0.0000479 seconds2019-03-05T02:41:46.400+0000: 8.969: Application time: 1.0001321 seconds        2019-03-05T02:41:46.671+0000: 9.240: Total time for which application threads were stopped: 0.2710559 seconds, Stopping threads took: 0.2709677 seconds2019-03-05T02:41:46.691+0000: 9.260: Application time: 0.0201782 seconds        2019-03-05T02:41:46.692+0000: 9.261: Total time for which application threads were stopped: 0.0002705 seconds, Stopping threads took: 0.0000955 seconds```Based on this data it will show when `jvmquake` would step in and detect a spiral of death.<jupyter_code>import re
import datetime

runtimes = []
pauses = []
safepoints = []

float_regex = "[-+]?(\d+(\.\d*)?|\.\d+)([eE][-+]?\d+)?"
runtime_match = re.compile("Application time: {0} seconds".format(float_regex))
pause_match = re.compile("Total time for which application threads were stopped: {0} seconds, "
                         "Stopping threads took: {0} seconds".format(float_regex))
timestamp_match = re.compile("(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}.\d{3})\+\d{4}")

# NOTE: If you want a different gclog, either symlink to gclog or change this file
with open('gclog') as gclog:
    for line in gclog:
        timestamp = timestamp_match.search(line)
        if timestamp is None:
            continue
        dt = datetime.datetime.strptime(timestamp.groups(0)[0], '%Y-%m-%dT%H:%M:%S.%f')
        runtime = runtime_match.search(line)
        pause_time = pause_match.search(line)
        if runtime:
            runtimes.append((dt, float(runtime.groups(0)[0])))
        elif pause_time:
            pauses.append((dt, float(pause_time.groups(0)[0])))
            safepoints.append((dt, float(pause_time.groups(0)[3])))
            
print("Found {} runtimes and {} pauses".format(len(runtimes), len(pauses)))
# A proper GC log should have roughly equal runtimes to pauses
assert abs(len(runtimes) - len(pauses)) < 2
# A proper GC log should have equal numbers of safepoint datapoints and gc latencies
assert len(safepoints) == len(pauses)
# The bucket for keeping track of relative running and paused time
token_bucket = 0
# The amount of weight to give running seconds over GCing seconds. This defines
# our expected application throughput
runtime_weight = 4
# The amount of time that we must exceed the expected throughput by before
# triggering the signal and death actions
gc_threshold = 30
    
adj_runtimes = []
token_bucket_values = []
kill_pos = []
kill_times = []

for i in range(min(len(runtimes), len(pauses))):
    dt, runtime = runtimes[i]
    if (token_bucket - (runtime * runtime_weight)) < 0:
        adj_runtimes.append((dt, token_bucket))
    else:
        adj_runtimes.append((dt, runtime))
        
    token_bucket = max(0, token_bucket - (runtime * runtime_weight))
    token_bucket_values.append((dt, token_bucket))
    
    dt, pause_time = pauses[i]
    token_bucket += pause_time
    if token_bucket > gc_threshold - 1:
        print('WARNING: Would have killed process at {0} with debt {1}'.format(dt, token_bucket))
        kill_times.append(dt)
        kill_pos.append(i)
    token_bucket_values.append((dt, token_bucket))
import matplotlib
import matplotlib.pyplot as plt
import matplotlib.style as style
import numpy as np

style.use('tableau-colorblind10')
matplotlib.rcParams.update({'font.size': 16})
sample_x = [i for i in range(min(len(adj_runtimes), len(pauses)))]
pause_y = [i[1] for i in pauses]
safepoint_y = [i[1] for i in safepoints]
runtime_y = [-1 * float(i[1]) for i in adj_runtimes]

fig1, ax = plt.subplots(figsize=(12,8))
plt.stem(sample_x, pause_y, linefmt='C0-', markerfmt='C0^', basefmt=' ', label='Pause debt')
plt.stem(sample_x, safepoint_y, linefmt='C7-', markerfmt='C7^', basefmt=' ', label='Safepoint debt')
plt.stem(sample_x, runtime_y, linefmt='C1-', markerfmt='C1v', basefmt=' ', label='Runtime credit')

if kill_pos:
    plt.axvline(x=kill_pos[0], linestyle='--', color='k', label='jvmquake trigger')
    
plt.hlines(gc_threshold, sample_x[0], sample_x[-1], label='Pause threshold')    
    
plt.yscale('symlog', linthreshy=2, subsy=[2,3,4,5,6,7,8,9])
plt.title('Simulated jvmquake debt')
plt.xlabel('Pause/Runtime Events')
plt.ylabel('Seconds of Debt')
plt.ylim(-10, 40)
plt.minorticks_on()

plt.grid(which='major', linestyle=':', linewidth='0.4', color='black')
plt.grid(which='minor', linestyle=':', linewidth='0.4', color='black')
plt.legend(loc='upper right', bbox_to_anchor=(0.4, 0.9),
           facecolor='C6')
plt.show()
xmin = min([min(i[0] for i in runtimes), min(i[0] for i in pauses)])
xmax = max([max(i[0] for i in runtimes), max(i[0] for i in pauses)])

pause_x = [i[0] for i in pauses]
safepoint_x = [i[0] for i in safepoints]
runtime_x = [i[0] for i in adj_runtimes]

fig1, ax = plt.subplots(figsize=(12,8))
plt.stem(pause_x, pause_y, linefmt='C0-', markerfmt='C0^', basefmt=' ', label='Pause debt')
plt.stem(safepoint_x, safepoint_y, linefmt='C7-', markerfmt='C7^', basefmt=' ', label='Safepoint debt')
plt.stem(runtime_x, runtime_y, linefmt='C1-', markerfmt='C1v', basefmt=' ', label='Runtime credit')

if kill_times:
    plt.axvline(x=kill_times[0], linestyle='--', color='k', label='jvmquake trigger')
    
plt.hlines(gc_threshold, xmin, xmax, label='Pause threshold')    
    
plt.yscale('symlog', linthreshy=2, subsy=[2,3,4,5,6,7,8,9])
plt.title('Simulated jvmquake debt')
plt.xlabel('Time')
plt.ylabel('Seconds of Debt')
plt.ylim(-10, 40)
plt.minorticks_on()

plt.grid(which='major', linestyle=':', linewidth='0.4', color='black')
plt.grid(which='minor', linestyle=':', linewidth='0.4', color='black')
plt.legend(loc='lower right', facecolor='C6')
plt.show()<jupyter_output><empty_output>
{'fraction_non_alphanumeric': 0.1508832898928468, 'fraction_numerical': 0.07515204170286707, 'mean_word_length': 4.755833333333333, 'pattern_counts': {'":': 0, '<': 7, '<?xml version=': 0, '>': 6, 'https://': 0, 'lorem ipsum': 0, 'www.': 0, 'xml': 0}, 'pii_count': 0, 'substrings_counts': 0, 'word_list_counts': {'cursed_substrings.json': 0, 'profanity_word_list.json': 0, 'sexual_word_list.json': 0, 'zh_pornsignals.json': 0}}
{'chain_length': '1', 'dir': 'jupyter-structured-clean-dedup', 'id': '254974', 'license': 'Apache-2.0', 'n_tokens_mistral': 2760, 'n_tokens_neox': 2402, 'n_words': 614, 'path': 'notebooks/debt_visualizer.ipynb', 'repo_name': 'jolynch/jvm-watchdog', 'size': '6906'}