PR#777: add debug timestamp log for logs

Merges #777
https://pagure.io/koji/pull-request/777

Fixes: #776
https://pagure.io/koji/issue/776
Add timestamps to logs
This commit is contained in:
Mike McLean 2018-05-03 14:52:30 -04:00
commit d9682472b3
2 changed files with 54 additions and 5 deletions

View file

@ -381,6 +381,7 @@ class BuildRoot(object):
uploadpath = self.getUploadPath()
logs = {}
ts_offsets = {}
finished = False
while not finished:
time.sleep(1)
@ -398,10 +399,36 @@ class BuildRoot(object):
if fname.endswith('.log') and fname not in logs:
fpath = os.path.join(resultdir, fname)
logs[fname] = (None, None, 0, fpath)
if self.options.log_timestamps and not fname.endswith('-ts.log'):
ts_name = '%s-ts.log' % fname
fpath = os.path.join(resultdir, ts_name)
if os.path.exists(fpath):
with open(fpath, 'rt') as ts_file:
lines = ts_file.readlines()
if lines:
last = int(lines[-1].split()[1])
ts_offsets[fname] = last
else:
with open(fpath, 'a') as ts_file:
ts_file.write('%.0f 0\n' % time.time())
logs[ts_name] = (None, None, 0, fpath)
if workdir and mocklog not in logs:
fpath = os.path.join(workdir, mocklog)
if os.path.exists(fpath):
logs[mocklog] = (None, None, 0, fpath)
if self.options.log_timestamps:
ts_name = '%s-ts.log' % mocklog
fpath = os.path.join(workdir, ts_name)
if os.path.exists(fpath):
with open(fpath, 'rt') as ts_file:
lines = ts_file.readlines()
if lines:
last = int(lines[-1].split()[1])
ts_offsets[mocklog] = last
else:
with open(fpath, 'a') as ts_file:
ts_file.write('%.0f 0\n' % time.time())
logs[ts_name] = (None, None, 0, fpath)
for (fname, (fd, inode, size, fpath)) in logs.items():
try:
@ -414,18 +441,34 @@ class BuildRoot(object):
self.logger.info('Rereading %s, inode: %s -> %s, size: %s -> %s' %
(fpath, inode, stat_info.st_ino, size, stat_info.st_size))
fd.close()
fd = file(fpath, 'r')
logs[fname] = (fd, stat_info.st_ino, stat_info.st_size, fpath)
fd = open(fpath, 'r')
logs[fname] = (fd, stat_info.st_ino, stat_info.st_size or size, fpath)
except:
self.logger.error("Error reading mock log: %s", fpath)
self.logger.error(''.join(traceback.format_exception(*sys.exc_info())))
continue
if self.options.log_timestamps and not fname.endswith('-ts.log'):
# race condition against incremental_upload's tell,
# but with enough precision for ts.log purposes
position = fd.tell()
ts_offsets.setdefault(fname, 0)
if ts_offsets[fname] < position:
fpath = os.path.join(resultdir, '%s-ts.log' % fname)
with open(fpath, 'a') as ts_file:
ts_file.write('%.0f %i\n' % (time.time(), position))
ts_offsets[fname] = position
incremental_upload(self.session, fname, fd, uploadpath, logger=self.logger)
#clean up and return exit status of command
for (fname, (fd, inode, size, fpath)) in logs.items():
if fd:
fd.close()
if not fd:
continue
if fname.endswith('-ts.log'):
# finish upload of ts.log as they could've been missed in
# last iteration
incremental_upload(self.session, fname, fd, uploadpath, logger=self.logger)
fd.close()
return status[1]
else:
@ -5667,6 +5710,7 @@ def get_options():
'offline_retry': True,
'offline_retry_interval': 120,
'keepalive' : True,
'log_timestamps': False,
'timeout' : None,
'no_ssl_verify' : False,
'use_fast_upload': True,
@ -5696,7 +5740,7 @@ def get_options():
elif name in ['offline_retry', 'use_createrepo_c', 'createrepo_skip_stat',
'createrepo_update', 'keepalive', 'use_fast_upload',
'support_rpm_source_layout', 'krb_rdns', 'krb_canon_host',
'build_arch_can_fail', 'no_ssl_verify']:
'build_arch_can_fail', 'no_ssl_verify', 'log_timestamps']:
defaults[name] = config.getboolean('kojid', name)
elif name in ['plugin', 'plugins']:
defaults['plugin'] = value.split()

View file

@ -92,3 +92,8 @@ from_addr=Koji Build System <buildsys@example.com>
;if set to True, failing subtask will not automatically cancel other siblings
;build_arch_can_fail = False
;if set to True additional logs with timestamps will get created and uploaded
;to hub. It could be useful for debugging purposes, but creates twice as many
;log files
;log_timestamps = False