import sys
import time
import argparse
+import matplotlib
+matplotlib.use('GTK3Cairo')
import matplotlib.pyplot as plt
parser = argparse.ArgumentParser()
parser.add_argument('log_file')
parser.add_argument('-q', '--queue', help='plot queue size', action='store_true')
-parser.add_argument('-e', '--encoder-threads', help='plot encoder thread activity', action='store_true')
+parser.add_argument('--encoder-threads', help='plot encoder thread activity', action='store_true')
parser.add_argument('-f', '--plot-first-encoder', help='plot more detailed activity of the first encoder thread', action='store_true')
parser.add_argument('-s', '--fps-stats', help='frames-per-second stats', action='store_true')
parser.add_argument('--encoder-stats', help='encoder thread activity stats', action='store_true')
-parser.add_argument('--dump-first-encoder', help='dump activity of the first encoder thread', action='store_true')
+parser.add_argument('--encoder-dump', help='dump activity of the specified encoder', action='store_true')
+parser.add_argument('-e', '--encoder', help='encoder index (from 0)')
parser.add_argument('--from', help='time in seconds to start at', type=int, dest='from_time')
parser.add_argument('--to', help='time in seconds to stop at', type=int, dest='to_time')
+parser.add_argument('--max-encoder-threads', help='maximum number of encoder threads to plot with --encoder-threads', type=int, default=None)
args = parser.parse_args()
def find_nth(haystack, needle, n):
# Representation of time in seconds and microseconds
class Time:
- def __init__(self, s = 0, m = 0):
+ def __init__(self, s=0, m=0):
self.seconds = s
self.microseconds = m
else:
return Time(self.seconds - x.seconds, m)
+class EncoderThread:
+ def __init__(self, id):
+ self.id = id
+ self.events = []
+ self.server = None
+
+ def add_event(self, time, message, values):
+ self.events.append((time, message, values))
+
queue_size = []
general_events = []
encoder_threads = []
-encoder_thread_events = dict()
-def add_encoder_thread_event(thread, time, event):
+def find_encoder_thread(id):
global encoder_threads
- global encoder_thread_events
- if not thread in encoder_threads:
+ thread = None
+ for t in encoder_threads:
+ if t.id == id:
+ thread = t
+
+ if thread is None:
+ thread = EncoderThread(id)
encoder_threads.append(thread)
- encoder_thread_events[thread] = [(time, event)]
- else:
- encoder_thread_events[thread].append((time, event))
+
+ return thread
def add_general_event(time, event):
global general_events
values = {}
for i in range(2, len(p)):
x = p[i].split('=')
- values[x[0]] = x[1]
+ if len(x) == 2:
+ values[x[0]] = x[1]
else:
# Date/time timestamp: other LOG_*
s = find_nth(l, ':', 3)
- T = Time(time.mktime(time.strptime(l[:s])))
+ try:
+ T = Time(time.mktime(time.strptime(l[:s])))
+ except:
+ try:
+ T = Time(time.mktime(time.strptime(l[:s], "%d.%m.%Y %H:%M:%S")))
+ except:
+ try:
+ T = Time(time.mktime(time.strptime(l[:s], "%d/%m/%Y %H:%M:%S")))
+ except:
+ x = l[:s]
+ if not x.endswith('M'):
+ x += 'M'
+ T = Time(time.mktime(time.strptime(x, "%d/%m/%Y %H:%M:%S %p")))
message = l[s+2:]
# T is elapsed time since the first log message
if message == 'add-frame-to-queue':
queue_size.append((T, values['queue']))
elif message in ['encoder-sleep', 'encoder-wake', 'start-local-encode', 'finish-local-encode', 'start-remote-send', 'start-remote-encode', 'start-remote-receive', 'finish-remote-receive']:
- add_encoder_thread_event(values['thread'], T, message)
+ find_encoder_thread(values['thread']).add_event(T, message, values)
# Human-readable log message (other LOG_*)
elif message.startswith('Finished locally-encoded'):
add_general_event(T, 'end_local_encode')
# y=0 thread is sleeping
# y=1 thread is awake
# y=2 thread is encoding
+ # y=3 thread is awaiting a remote encode
+
+ if args.max_encoder_threads is not None:
+ encoder_threads = encoder_threads[0:min(args.max_encoder_threads, len(encoder_threads))]
+
plt.figure()
- N = len(encoder_thread_events)
+ N = len(encoder_threads)
n = 1
- for thread, events in encoder_thread_events.iteritems():
+ for thread in encoder_threads:
plt.subplot(N, 1, n)
+ plt.ylim([-0.5, 2.5])
x = []
y = []
previous = 0
- for e in events:
+ for e in thread.events:
if args.from_time is not None and e[0].float_seconds() <= args.from_time:
continue
if args.to_time is not None and e[0].float_seconds() >= args.to_time:
continue
+ if e[1] == 'start-remote-send' or e[1] == 'finish-remote-send' or e[1] == 'start-remote-receive' or e[1] == 'finish-remote-receive':
+ continue
x.append(e[0].float_seconds())
x.append(e[0].float_seconds())
y.append(previous)
- if e[1] == 'sleep':
+ if e[1] == 'encoder-sleep':
y.append(0)
- elif e[1] == 'wake':
+ elif e[1] == 'encoder-wake':
y.append(1)
- elif e[1] == 'begin_encode':
+ elif e[1] == 'start-local-encode':
y.append(2)
- elif e[1] == 'end_encode':
+ elif e[1] == 'finish-local-encode':
+ y.append(1)
+ elif e[1] == 'start-remote-encode':
+ y.append(3)
+ elif e[1] == 'finish-remote-encode':
y.append(1)
+ else:
+ print('unknown event %s' % e[1], file=sys.stderr)
+ sys.exit(1)
previous = y[-1]
elif args.plot_first_encoder:
plt.figure()
- N = len(encoder_thread_events)
+ N = len(encoder_threads)
n = 1
- events = encoder_thread_events.itervalues().next()
+ events = encoder_threads[0].events
N = 6
n = 1
- for t in ['sleep', 'wake', 'begin_encode', 'end_encode']:
+ for t in ['encoder-sleep', 'encoder-wake', 'start-local-encode', 'finish-local-encode']:
plt.subplot(N, 1, n)
x = []
y = []
plt.show()
-elif args.dump_first_encoder:
- events = encoder_thread_events.itervalues().next()
- last = 0
- for e in events:
- print e[0].float_seconds(), (e[0].float_seconds() - last), e[1]
- last = e[0].float_seconds()
+elif args.encoder_dump:
+ for t in encoder_threads[int(args.encoder)]:
+ last = 0
+ for e in t.events:
+ print((e[0].float_seconds() - last), e[1])
+ last = e[0].float_seconds()
elif args.fps_stats:
local = 0
remote += 1
if end == None:
- print 'Job did not appear to end'
+ print('Job did not appear to end')
sys.exit(1)
duration = end - start
- print 'Job ran for %fs' % duration.float_seconds()
- print '%d local and %d remote' % (local, remote)
- print '%.2f fps local and %.2f fps remote' % (local / duration.float_seconds(), remote / duration.float_seconds())
+ print('Job ran for %fs' % duration.float_seconds())
+ print('%d local and %d remote' % (local, remote))
+ print('%.2f fps local and %.2f fps remote' % (local / duration.float_seconds(), remote / duration.float_seconds()))
elif args.encoder_stats:
# Broad stats on what encoder threads spent their time doing
remote_encoding = Time()
receiving = Time()
wakes = 0
- for e in encoder_thread_events[t]:
- if e[1] not in ['encoder-sleep', 'encoder-wake', 'start-remote-send', 'start-remote-encode', 'start-remote-receive', 'finish-remote-receive']:
- continue
-
+ for e in t.events:
if last is not None:
if last[1] == 'encoder-sleep':
asleep += e[0] - last[0]
elif last[1] == 'encoder-wake':
wakes += 1
+ elif last[1] == 'start-local-encode':
local_encoding += e[0] - last[0]
elif last[1] == 'start-remote-send':
sending += e[0] - last[0]
remote_encoding += e[0] - last[0]
elif last[1] == 'start-remote-receive':
receiving += e[0] - last[0]
+ elif last[1] == 'start-encoder-thread':
+ find_encoder_thread(last[2]['thread']).server = last[2]['server']
last = e
- print '-- Encoder thread %s' % t
- print '\tAwoken %d times' % wakes
+ print('-- Encoder thread %s (%s)' % (t.server, t.id))
+ print('\tAwoken %d times' % wakes)
+
total = asleep.float_seconds() + local_encoding.float_seconds() + sending.float_seconds() + remote_encoding.float_seconds() + receiving.float_seconds()
if total == 0:
continue
- print '\tAsleep: %s (%.2f%%)' % (asleep, asleep.float_seconds() * 100 / total)
- if local_encoding.float_seconds() > 0:
- print '\tLocal encoding: %s (%.2f%%)' % (local_encoding, local_encoding.float_seconds() * 100 / total)
+
+ print('\t%s: %2.f%% %fs' % ('Asleep'.ljust(16), asleep.float_seconds() * 100 / total, asleep.float_seconds()))
+
+ def print_with_fps(v, name, total, frames):
+ if v.float_seconds() > 1:
+ print('\t%s: %2.f%% %f %.2ffps' % (name.ljust(16), v.float_seconds() * 100 / total, v.float_seconds(), frames / v.float_seconds()))
+
+ print_with_fps(local_encoding, 'Local encoding', total, wakes)
if sending.float_seconds() > 0:
- print '\tSending: %s (%.2f%%)' % (sending, sending.float_seconds() * 100 / total)
- if remote_encoding.float_seconds() > 0:
- print '\tRemote encoding: %s (%.2f%%)' % (remote_encoding, remote_encoding.float_seconds() * 100 / total)
+ print('\t%s: %2.f%%' % ('Sending'.ljust(16), sending.float_seconds() * 100 / total))
+ print_with_fps(remote_encoding, 'Remote encoding', total, wakes)
if receiving.float_seconds() > 0:
- print '\tReceiving: %s (%.2f%%)' % (receiving, receiving.float_seconds() * 100 / total)
- print ''
+ print('\t%s: %2.f%%' % ('Receiving'.ljust(16), receiving.float_seconds() * 100 / total))
+ print('')
projects / dcpomatic.git / blobdiff