parallelvirtualcluster
/
pvc
1
0
Fork 0
Code Issues 11 Pull Requests Projects Releases 111 Wiki Activity

Use logger for debug output 

Using simple print statements was annoying (lack of timing info and
formatting), so move to using the debug logger for these instead with a
custom state ('d') with white text to differentiate them. Also indicate
which subthread of the keepalive each task is being executed in for
easier tracing of issues.
This commit is contained in:
Joshua Boniface 2020-08-17 12:46:52 -04:00
parent 15e78aa9f0
commit 553f96e7ef
2 changed files with 31 additions and 31 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

55
node-daemon/pvcnoded/Daemon.py
View File

@ -1052,7 +1052,7 @@ def collect_ceph_stats(queue):
# Primary-only functions # Primary-only functions
if this_node.router_state == 'primary': if this_node.router_state == 'primary':
if debug: if debug:
print("Set ceph health information in zookeeper (primary only)") logger.out("ceph-thread: Set ceph health information in zookeeper (primary only)", state='d')
command = { "prefix": "status", "format": "pretty" } command = { "prefix": "status", "format": "pretty" }
ceph_status = ceph_conn.mon_command(json.dumps(command), b'', timeout=1)[1].decode('ascii') ceph_status = ceph_conn.mon_command(json.dumps(command), b'', timeout=1)[1].decode('ascii')
@ -1065,7 +1065,7 @@ def collect_ceph_stats(queue):
return return
if debug: if debug:
print("Set ceph rados df information in zookeeper (primary only)") logger.out("ceph-thread: Set ceph rados df information in zookeeper (primary only)", state='d')
# Get rados df info # Get rados df info
command = { "prefix": "df", "format": "pretty" } command = { "prefix": "df", "format": "pretty" }
@ -1079,7 +1079,7 @@ def collect_ceph_stats(queue):
return return
if debug: if debug:
print("Set pool information in zookeeper (primary only)") logger.out("ceph-thread: Set pool information in zookeeper (primary only)", state='d')
# Get pool info # Get pool info
command = { "prefix": "df", "format": "json" } command = { "prefix": "df", "format": "json" }
@ -1098,7 +1098,7 @@ def collect_ceph_stats(queue):
pool_count = len(ceph_pool_df_raw) pool_count = len(ceph_pool_df_raw)
if debug: if debug:
print("Getting info for {} pools".format(pool_count)) logger.out("ceph-thread: Getting info for {} pools".format(pool_count), state='d')
for pool_idx in range(0, pool_count): for pool_idx in range(0, pool_count):
try: try:
# Combine all the data for this pool # Combine all the data for this pool
@ -1110,11 +1110,11 @@ def collect_ceph_stats(queue):
# Ignore any pools that aren't in our pool list # Ignore any pools that aren't in our pool list
if pool['name'] not in pool_list: if pool['name'] not in pool_list:
if debug: if debug:
print("Pool {} not in pool list {}".format(pool['name'], pool_list)) logger.out("ceph-thread: Pool {} not in pool list {}".format(pool['name'], pool_list), state='d')
continue continue
else: else:
if debug: if debug:
print("Parsing data for pool {}".format(pool['name'])) logger.out("ceph-thread: Parsing data for pool {}".format(pool['name']), state='d')
# Assemble a useful data structure # Assemble a useful data structure
pool_df = { pool_df = {
@ -1148,7 +1148,7 @@ def collect_ceph_stats(queue):
if len(osd_list) > 0: if len(osd_list) > 0:
# Get data from Ceph OSDs # Get data from Ceph OSDs
if debug: if debug:
print("Get data from Ceph OSDs") logger.out("ceph-thread: Get data from Ceph OSDs", state='d')
# Parse the dump data # Parse the dump data
osd_dump = dict() osd_dump = dict()
@ -1162,7 +1162,7 @@ def collect_ceph_stats(queue):
osd_dump_raw = [] osd_dump_raw = []
if debug: if debug:
print("Loop through OSD dump") logger.out("ceph-thread: Loop through OSD dump", state='d')
for osd in osd_dump_raw: for osd in osd_dump_raw:
osd_dump.update({ osd_dump.update({
str(osd['osd']): { str(osd['osd']): {
@ -1175,7 +1175,7 @@ def collect_ceph_stats(queue):
# Parse the df data # Parse the df data
if debug: if debug:
print("Parse the OSD df data") logger.out("ceph-thread: Parse the OSD df data", state='d')
osd_df = dict() osd_df = dict()
@ -1187,7 +1187,7 @@ def collect_ceph_stats(queue):
osd_df_raw = [] osd_df_raw = []
if debug: if debug:
print("Loop through OSD df") logger.out("ceph-thread: Loop through OSD df", state='d')
for osd in osd_df_raw: for osd in osd_df_raw:
osd_df.update({ osd_df.update({
str(osd['id']): { str(osd['id']): {
@ -1202,7 +1202,7 @@ def collect_ceph_stats(queue):
# Parse the status data # Parse the status data
if debug: if debug:
print("Parse the OSD status data") logger.out("ceph-thread: Parse the OSD status data", state='d')
osd_status = dict() osd_status = dict()
@ -1214,7 +1214,7 @@ def collect_ceph_stats(queue):
osd_status_raw = [] osd_status_raw = []
if debug: if debug:
print("Loop through OSD status data") logger.out("ceph-thread: Loop through OSD status data", state='d')
for line in osd_status_raw.split('\n'): for line in osd_status_raw.split('\n'):
# Strip off colour # Strip off colour
@ -1247,7 +1247,7 @@ def collect_ceph_stats(queue):
# Merge them together into a single meaningful dict # Merge them together into a single meaningful dict
if debug: if debug:
print("Merge OSD data together") logger.out("ceph-thread: Merge OSD data together", state='d')
osd_stats = dict() osd_stats = dict()
@ -1263,7 +1263,7 @@ def collect_ceph_stats(queue):
# Trigger updates for each OSD on this node # Trigger updates for each OSD on this node
if debug: if debug:
print("Trigger updates for each OSD on this node") logger.out("ceph-thread: Trigger updates for each OSD on this node", state='d')
for osd in osd_list: for osd in osd_list:
if d_osd[osd].node == myhostname: if d_osd[osd].node == myhostname:
@ -1297,12 +1297,9 @@ libvirt_vm_states = {
# VM stats update function # VM stats update function
def collect_vm_stats(queue): def collect_vm_stats(queue):
if debug:
print("Get VM statistics")
# Connect to libvirt # Connect to libvirt
if debug: if debug:
print("Connect to libvirt") logger.out("vm-thread: Connect to libvirt", state='d')
libvirt_name = "qemu:///system" libvirt_name = "qemu:///system"
lv_conn = libvirt.open(libvirt_name) lv_conn = libvirt.open(libvirt_name)
if lv_conn == None: if lv_conn == None:
@ -1313,7 +1310,7 @@ def collect_vm_stats(queue):
vcpualloc = 0 vcpualloc = 0
# Toggle state management of dead VMs to restart them # Toggle state management of dead VMs to restart them
if debug: if debug:
print("Toggle state management of dead VMs to restart them") logger.out("vm-thread: Toggle state management of dead VMs to restart them", state='d')
for domain, instance in this_node.d_domain.items(): for domain, instance in this_node.d_domain.items():
if domain in this_node.domain_list: if domain in this_node.domain_list:
# Add the allocated memory to our memalloc value # Add the allocated memory to our memalloc value
@ -1341,14 +1338,14 @@ def collect_vm_stats(queue):
# Get all the raw information about the VM # Get all the raw information about the VM
if debug: if debug:
print("Getting general statistics for VM {}".format(domain_name)) logger.out("vm-thread: Getting general statistics for VM {}".format(domain_name), state='d')
domain_state, domain_maxmem, domain_mem, domain_vcpus, domain_cputime = domain.info() domain_state, domain_maxmem, domain_mem, domain_vcpus, domain_cputime = domain.info()
domain_memory_stats = domain.memoryStats() domain_memory_stats = domain.memoryStats()
domain_cpu_stats = domain.getCPUStats(True)[0] domain_cpu_stats = domain.getCPUStats(True)[0]
except Exception as e: except Exception as e:
if debug: if debug:
try: try:
print("Failed getting VM information for {}: {}".format(domain.name(), e)) logger.out("vm-thread: Failed getting VM information for {}: {}".format(domain.name(), e), state='d')
except: except:
pass pass
continue continue
@ -1358,7 +1355,7 @@ def collect_vm_stats(queue):
this_node.domain_list.append(domain_uuid) this_node.domain_list.append(domain_uuid)
if debug: if debug:
print("Getting disk statistics for VM {}".format(domain_name)) logger.out("vm-thread: Getting disk statistics for VM {}".format(domain_name), state='d')
domain_disk_stats = [] domain_disk_stats = []
for disk in tree.findall('devices/disk'): for disk in tree.findall('devices/disk'):
disk_name = disk.find('source').get('name') disk_name = disk.find('source').get('name')
@ -1375,7 +1372,7 @@ def collect_vm_stats(queue):
}) })
if debug: if debug:
print("Getting network statistics for VM {}".format(domain_name)) logger.out("vm-thread: Getting network statistics for VM {}".format(domain_name), state='d')
domain_network_stats = [] domain_network_stats = []
for interface in tree.findall('devices/interface'): for interface in tree.findall('devices/interface'):
interface_name = interface.find('target').get('dev') interface_name = interface.find('target').get('dev')
@ -1408,7 +1405,7 @@ def collect_vm_stats(queue):
} }
if debug: if debug:
print("Writing statistics for VM {} to Zookeeper".format(domain_name)) logger.out("vm-thread: Writing statistics for VM {} to Zookeeper".format(domain_name), state='d')
try: try:
zkhandler.writedata(zk_conn, { zkhandler.writedata(zk_conn, {
@ -1416,7 +1413,7 @@ def collect_vm_stats(queue):
}) })
except Exception as e: except Exception as e:
if debug: if debug:
print(e) logger.out("vm-thread: {}".format(e), state='d')
# Close the Libvirt connection # Close the Libvirt connection
lv_conn.close() lv_conn.close()
@ -1438,7 +1435,7 @@ def node_keepalive():
# Get past state and update if needed # Get past state and update if needed
if debug: if debug:
print("Get past state and update if needed") logger.out("main-thread: Get past state and update if needed", state='d')
past_state = zkhandler.readdata(zk_conn, '/nodes/{}/daemonstate'.format(this_node.name)) past_state = zkhandler.readdata(zk_conn, '/nodes/{}/daemonstate'.format(this_node.name))
if past_state != 'run': if past_state != 'run':
this_node.daemon_state = 'run' this_node.daemon_state = 'run'
@ -1448,7 +1445,7 @@ def node_keepalive():
# Ensure the primary key is properly set # Ensure the primary key is properly set
if debug: if debug:
print("Ensure the primary key is properly set") logger.out("main-thread: Ensure the primary key is properly set", state='d')
if this_node.router_state == 'primary': if this_node.router_state == 'primary':
if zkhandler.readdata(zk_conn, '/primary_node') != this_node.name: if zkhandler.readdata(zk_conn, '/primary_node') != this_node.name:
zkhandler.writedata(zk_conn, {'/primary_node': this_node.name}) zkhandler.writedata(zk_conn, {'/primary_node': this_node.name})
@ -1507,7 +1504,7 @@ def node_keepalive():
# Set our information in zookeeper # Set our information in zookeeper
keepalive_time = int(time.time()) keepalive_time = int(time.time())
if debug: if debug:
print("Set our information in zookeeper") logger.out("main-thread: Set our information in zookeeper", state='d')
try: try:
zkhandler.writedata(zk_conn, { zkhandler.writedata(zk_conn, {
'/nodes/{}/memtotal'.format(this_node.name): str(this_node.memtotal), '/nodes/{}/memtotal'.format(this_node.name): str(this_node.memtotal),
@ -1584,7 +1581,7 @@ def node_keepalive():
# Look for dead nodes and fence them # Look for dead nodes and fence them
if not maintenance: if not maintenance:
if debug: if debug:
print("Look for dead nodes and fence them") logger.out("main-thread: Look for dead nodes and fence them", state='d')
if config['daemon_mode'] == 'coordinator': if config['daemon_mode'] == 'coordinator':
for node_name in d_node: for node_name in d_node:
try: try:

7
node-daemon/pvcnoded/log.py
View File

@ -29,11 +29,12 @@ class Logger(object):
# ANSII colours for output # ANSII colours for output
fmt_red = '\033[91m' fmt_red = '\033[91m'
fmt_blue = '\033[94m'
fmt_cyan = '\033[96m'
fmt_green = '\033[92m' fmt_green = '\033[92m'
fmt_yellow = '\033[93m' fmt_yellow = '\033[93m'
fmt_blue = '\033[94m'
fmt_purple = '\033[95m' fmt_purple = '\033[95m'
fmt_cyan = '\033[96m'
fmt_white = '\033[97m'
fmt_bold = '\033[1m' fmt_bold = '\033[1m'
fmt_end = '\033[0m' fmt_end = '\033[0m'
@ -49,6 +50,7 @@ class Logger(object):
't': { 'colour': fmt_purple, 'prompt': '>>> ' }, 't': { 'colour': fmt_purple, 'prompt': '>>> ' },
'i': { 'colour': fmt_blue, 'prompt': '>>> ' }, 'i': { 'colour': fmt_blue, 'prompt': '>>> ' },
's': { 'colour': fmt_cyan, 'prompt': '>>> ' }, 's': { 'colour': fmt_cyan, 'prompt': '>>> ' },
'd': { 'colour': fmt_white, 'prompt': '>>> ' },
'x': { 'colour': last_colour, 'prompt': last_prompt } 'x': { 'colour': last_colour, 'prompt': last_prompt }
} }
format_map_textual = { format_map_textual = {
@ -59,6 +61,7 @@ class Logger(object):
't': { 'colour': '', 'prompt': 'tick: ' }, 't': { 'colour': '', 'prompt': 'tick: ' },
'i': { 'colour': '', 'prompt': 'info: ' }, 'i': { 'colour': '', 'prompt': 'info: ' },
's': { 'colour': '', 'prompt': 'system: ' }, 's': { 'colour': '', 'prompt': 'system: ' },
'd': { 'colour': '', 'prompt': 'debug: ' },
'x': { 'colour': '', 'prompt': last_prompt } 'x': { 'colour': '', 'prompt': last_prompt }
} }