def trace_memory_info(event=''):
if not MEM:
return
last_tick = MEM['tick']
tick_len = MEM['tick_len'] or float('inf')
t = time.time()
if (t - last_tick < tick_len) and not event:
return
vmi = psutil.virtual_memory()
if last_tick == 0:
with config.open_log_file(MEM['file_name'], 'w') as log_file:
print("time,rss,used,available,percent,event", file=log_file)
MEM['tick'] = t
current_process = psutil.Process()
rss = current_process.memory_info().rss
for child in current_process.children(recursive=True):
try:
rss += child.memory_info().rss
except (psutil.NoSuchProcess, psutil.AccessDenied) as e:
pass
timestamp = datetime.datetime.now().strftime("%d/%m/%Y %H:%M:%S")
trace_hwm('rss', GB(rss), timestamp, event)
trace_hwm('used', GB(vmi.used), timestamp, event)
# logger.debug("memory_info: rss: %s available: %s percent: %s"
# % (GB(mi.rss), GB(vmi.available), GB(vmi.percent)))
with config.open_log_file(MEM['file_name'], 'a') as output_file:
print("%s, %.2f, %.2f, %.2f, %s%%, %s" %
(timestamp,
GB(rss),
GB(vmi.used),
GB(vmi.available),
vmi.percent,
event), file=output_file)
def trace_memory_info(event=''):
if not MEM:
return
last_tick = MEM['tick']
tick_len = MEM['tick_len'] or float('inf')
t = time.time()
if (t - last_tick < tick_len) and not event:
return
vmi = psutil.virtual_memory()
if last_tick == 0:
with config.open_log_file(MEM['file_name'], 'w') as log_file:
print("time,rss,used,available,percent,event", file=log_file)
MEM['tick'] = t
current_process = psutil.Process()
rss = current_process.memory_info().rss
for child in current_process.children(recursive=True):
try:
rss += child.memory_info().rss
except (psutil.NoSuchProcess, psutil.AccessDenied) as e:
pass
timestamp = datetime.datetime.now().strftime("%d/%m/%Y %H:%M:%S")
trace_hwm('rss', GB(rss), timestamp, event)
trace_hwm('used', GB(vmi.used), timestamp, event)
# logger.debug("memory_info: rss: %s available: %s percent: %s"
# % (GB(mi.rss), GB(vmi.available), GB(vmi.percent)))
with config.open_log_file(MEM['file_name'], 'a') as output_file:
print("%s, %.2f, %.2f, %.2f, %s%%, %s" %
(timestamp, GB(rss), GB(vmi.used), GB(
vmi.available), vmi.percent, event),
file=output_file)
def log_hwm():
for tag in HWM:
hwm = HWM[tag]
logger.info("high water mark %s: %.2f timestamp: %s label: %s" %
(tag, hwm['mark'], hwm['timestamp'], hwm['label']))
with config.open_log_file(MEM['file_name'], 'a') as log_file:
for tag in HWM:
hwm = HWM[tag]
print("high water mark %s: %.2f timestamp: %s label: %s" %
(tag, hwm['mark'], hwm['timestamp'], hwm['label']), file=log_file)
def log_hwm():
for tag in HWM:
hwm = HWM[tag]
logger.info("high water mark %s: %.2f timestamp: %s label: %s" %
(tag, hwm['mark'], hwm['timestamp'], hwm['label']))
with config.open_log_file(MEM['file_name'], 'a') as log_file:
for tag in HWM:
hwm = HWM[tag]
print("high water mark %s: %.2f timestamp: %s label: %s" %
(tag, hwm['mark'], hwm['timestamp'], hwm['label']),
file=log_file)
def init_trace(tick_len=None, file_name="mem.csv", write_header=False):
MEM['tick'] = 0
if file_name is not None:
MEM['file_name'] = file_name
if tick_len is None:
MEM['tick_len'] = DEFAULT_TICK_LEN
else:
MEM['tick_len'] = tick_len
logger.info("init_trace file_name %s" % file_name)
# - check for optional process name prefix
MEM['prefix'] = inject.get_injectable('log_file_prefix', 'main')
if write_header:
with config.open_log_file(file_name, 'w') as log_file:
print("process,time,rss,used,available,percent,event",
file=log_file)
def trace_memory_info(event=''):
if not MEM:
return
last_tick = MEM['tick']
tick_len = MEM['tick_len'] or float('inf')
t = time.time()
if (t - last_tick < tick_len) and not event:
return
force_garbage_collect()
vmi = psutil.virtual_memory()
MEM['tick'] = t
current_process = psutil.Process()
rss = current_process.memory_info().rss
for child in current_process.children(recursive=True):
try:
rss += child.memory_info().rss
except (psutil.NoSuchProcess, psutil.AccessDenied) as e:
pass
timestamp = datetime.datetime.now().strftime("%d/%m/%Y %H:%M:%S")
trace_hwm('rss', GB(rss), timestamp, event)
trace_hwm('used', GB(vmi.used), timestamp, event)
if event:
logger.info(
f"trace_memory_info {event} rss: {GB(rss)}GB used: {GB(vmi.used)} GB percent: {vmi.percent}%"
)
with config.open_log_file(MEM['file_name'], 'a') as output_file:
print("%s, %s, %.2f, %.2f, %.2f, %s%%, %s" %
(MEM['prefix'], timestamp, GB(rss), GB(
vmi.used), GB(vmi.available), vmi.percent, event),
file=output_file)
def trace_memory_info(event, trace_ticks=0):
global MEM_TICK
tick = time.time()
if trace_ticks and (tick - MEM_TICK < trace_ticks):
return
MEM_TICK = tick
process_name = multiprocessing.current_process().name
pid = os.getpid()
current_process = psutil.Process()
if USS:
info = current_process.memory_full_info()
uss = info.uss
else:
info = current_process.memory_info()
uss = 0
full_rss = rss = info.rss
num_children = 0
for child in current_process.children(recursive=True):
try:
child_info = child.memory_info()
full_rss += child_info.rss
num_children += 1
except (psutil.NoSuchProcess, psutil.AccessDenied) as e:
pass
noteworthy = True # any reason not to always log this if we are filtering idle ticks?
noteworthy = (num_children > 0) or noteworthy
noteworthy = check_global_hwm('rss', full_rss or rss, event) or noteworthy
noteworthy = check_global_hwm('uss', uss, event) or noteworthy
if noteworthy:
# logger.debug(f"trace_memory_info {event} "
# f"rss: {GB(full_rss) if num_children else GB(rss)} "
# f"uss: {GB(rss)} ")
timestamp = datetime.datetime.now().strftime(
"%Y/%m/%d %H:%M:%S.%f") # sortable
with mem_log_lock:
MEM_LOG_HEADER = "process,pid,rss,full_rss,uss,event,children,time"
with config.open_log_file(MEM_LOG_FILE_NAME,
'a',
header=MEM_LOG_HEADER,
prefix=True) as log_file:
print(
f"{process_name},"
f"{pid},"
f"{util.INT(rss)}," # want these as ints so we can plot them...
f"{util.INT(full_rss)},"
f"{util.INT(uss)},"
f"{event},"
f"{num_children},"
f"{timestamp}",
file=log_file)
# return rss and uss for optional use by interested callers
return full_rss or rss, uss