diff --git a/SWESimulators/Common.py b/SWESimulators/Common.py index fddd958..d50ef0b 100644 --- a/SWESimulators/Common.py +++ b/SWESimulators/Common.py @@ -27,6 +27,7 @@ import time import re import io import hashlib +import logging import pycuda.compiler as cuda_compiler import pycuda.gpuarray @@ -38,9 +39,9 @@ import pycuda.driver as cuda Class which keeps track of time spent for a section of code """ class Timer(object): - def __init__(self, tag, verbose=True): - self.verbose = verbose + def __init__(self, tag): self.tag = tag + self.logger = logging.getLogger(__name__) def __enter__(self): self.start = time.time() @@ -50,8 +51,7 @@ class Timer(object): self.end = time.time() self.secs = self.end - self.start self.msecs = self.secs * 1000 # millisecs - if self.verbose: - print("=> " + self.tag + ' %f ms' % self.msecs) + self.logger.info("%s: %f ms", self.tag, self.msecs) @@ -66,7 +66,8 @@ class CudaContext(object): self.verbose = verbose self.blocking = blocking self.use_cache = use_cache - self.modules = {} + self.logger = logging.getLogger(__name__) + self.kernels = {} self.module_path = os.path.dirname(os.path.realpath(__file__)) @@ -74,63 +75,53 @@ class CudaContext(object): cuda.init(flags=0) #Print some info about CUDA - if (self.verbose): - print("CUDA version " + str(cuda.get_version())) - print("Driver version " + str(cuda.get_driver_version())) + self.logger.info("CUDA version %s", str(cuda.get_version())) + self.logger.info("Driver version %s", str(cuda.get_driver_version())) self.cuda_device = cuda.Device(0) if (self.verbose): - print("Using " + self.cuda_device.name()) - print(" => compute capability: " + str(self.cuda_device.compute_capability())) - print(" => memory: " + str(self.cuda_device.total_memory() / (1024*1024)) + " MB") + self.logger.info("Using '%s' GPU", self.cuda_device.name()) + self.logger.debug(" => compute capability: %s", str(self.cuda_device.compute_capability())) + self.logger.debug(" => memory: %d MB", self.cuda_device.total_memory() / (1024*1024)) # Create the CUDA context if (self.blocking): self.cuda_context = self.cuda_device.make_context(flags=cuda.ctx_flags.SCHED_BLOCKING_SYNC) - if (self.verbose): - print("=== WARNING ===") - print("Using blocking context") - print("=== WARNING ===") + self.logger.warning("Using blocking context") else: self.cuda_context = self.cuda_device.make_context(flags=cuda.ctx_flags.SCHED_AUTO) - if (self.verbose): - print("Created context <" + str(self.cuda_context.handle) + ">") + self.logger.info("Created context handle <%s>", str(self.cuda_context.handle)) #Create cache dir for cubin files if (self.use_cache): self.cache_path = os.path.join(self.module_path, "cuda_cache") if not os.path.isdir(self.cache_path): os.mkdir(self.cache_path) - if (verbose): - print("Using CUDA cache dir " + self.cache_path) + self.logger.debug("Using CUDA cache dir %s", self.cache_path) def __del__(self, *args): - if self.verbose: - print("Cleaning up CUDA context <" + str(self.cuda_context.handle) + ">") + self.logger.info("Cleaning up CUDA context handle <%s>", str(self.cuda_context.handle)) # Loop over all contexts in stack, and remove "this" other_contexts = [] while (cuda.Context.get_current() != None): context = cuda.Context.get_current() - if (self.verbose): - if (context.handle != self.cuda_context.handle): - print(" `-> <" + str(self.cuda_context.handle) + "> Popping context <" + str(context.handle) + "> which we do not own") - other_contexts = [context] + other_contexts - cuda.Context.pop() - else: - print(" `-> <" + str(self.cuda_context.handle) + "> Popping context <" + str(context.handle) + "> (ourselves)") - cuda.Context.pop() + if (context.handle != self.cuda_context.handle): + self.logger.debug("<%s> Popping <%s> (*not* ours)", str(self.cuda_context.handle), str(context.handle)) + other_contexts = [context] + other_contexts + cuda.Context.pop() + else: + self.logger.debug("<%s> Popping <%s> (ours)", str(self.cuda_context.handle), str(context.handle)) + cuda.Context.pop() # Add all the contexts we popped that were not our own for context in other_contexts: - if (self.verbose): - print(" `-> <" + str(self.cuda_context.handle) + "> Pushing <" + str(context.handle) + ">") + self.logger.debug("<%s> Pushing <%s>", str(self.cuda_context.handle), str(context.handle)) cuda.Context.push(context) - if (self.verbose): - print(" `-> <" + str(self.cuda_context.handle) + "> Detaching context") + self.logger.debug("<%s> Detaching", str(self.cuda_context.handle)) self.cuda_context.detach() @@ -143,49 +134,45 @@ class CudaContext(object): num_includes = 0 max_includes = 100 kernel_hasher = hashlib.md5() + logger = logging.getLogger(__name__) - with Timer("compiler", verbose=False) as timer: - # Loop over file and includes, and check if something has changed - files = [kernel_filename] - while len(files): + # Loop over file and includes, and check if something has changed + files = [kernel_filename] + while len(files): + + if (num_includes > max_includes): + raise("Maximum number of includes reached - circular include in {:}?".format(kernel_filename)) + + filename = files.pop() - if (num_includes > max_includes): - raise("Maximum number of includes reached - circular include in {:}?".format(kernel_filename)) + logger.debug("Hashing %s", filename) + + modified = os.path.getmtime(filename) + + # Open the file + with io.open(filename, "r") as file: - filename = files.pop() + # Search for #inclue and also hash the file + file_str = file.read() + kernel_hasher.update(file_str.encode('utf-8')) + kernel_hasher.update(str(modified).encode('utf-8')) - if (verbose): - print("`-> Hashing " + filename) - - modified = os.path.getmtime(filename) - - # Open the file - with io.open(filename, "r") as file: + #Find all includes + includes = re.findall('^\W*#include\W+(.+?)\W*$', file_str, re.M) - # Search for #inclue and also hash the file - file_str = file.read() - kernel_hasher.update(file_str.encode('utf-8')) - kernel_hasher.update(str(modified).encode('utf-8')) - - #Find all includes - includes = re.findall('^\W*#include\W+(.+?)\W*$', file_str, re.M) - - # Loop over everything that looks like an include - for include_file in includes: - - #Search through include directories for the file - file_path = os.path.dirname(filename) - for include_path in [file_path] + include_dirs: - - # If we find it, add it to list of files to check - temp_path = os.path.join(include_path, include_file) - if (os.path.isfile(temp_path)): - files = files + [temp_path] - num_includes = num_includes + 1 #For circular includes... - break + # Loop over everything that looks like an include + for include_file in includes: - if (verbose): - print("`-> Hashed in " + str(timer.secs) + " seconds") + #Search through include directories for the file + file_path = os.path.dirname(filename) + for include_path in [file_path] + include_dirs: + + # If we find it, add it to list of files to check + temp_path = os.path.join(include_path, include_file) + if (os.path.isfile(temp_path)): + files = files + [temp_path] + num_includes = num_includes + 1 #For circular includes... + break return kernel_hasher.hexdigest() @@ -200,82 +187,80 @@ class CudaContext(object): Helper function to print compilation output """ def cuda_compile_message_handler(compile_success_bool, info_str, error_str): - if (verbose): - print("`-> Compilation returned " + str(compile_success_bool)) - if info_str: - print("`-> Info: " + info_str) - if error_str: - print("`-> Error: " + error_str) + self.logger.debug("Compilation returned %s", str(compile_success_bool)) + if info_str: + self.logger.debug("Info: %s", info_str) + if error_str: + self.logger.debug("Error: %s", error_str) - if (verbose): - print("Getting " + kernel_filename) + self.logger.debug("Getting %s", kernel_filename) # Create a hash of the kernel (and its includes) + kwargs_hasher = hashlib.md5() + kwargs_hasher.update(str(kwargs).encode('utf-8')); + kwargs_hash = kwargs_hasher.hexdigest() + kwargs_hasher = None root, ext = os.path.splitext(kernel_filename) kernel_hash = root \ + "_" + CudaContext.hash_kernel( \ os.path.join(self.module_path, kernel_filename), \ include_dirs=[self.module_path] + include_dirs, \ verbose=verbose) \ - + "_" + str(hash(str(kwargs))) \ + + "_" + kwargs_hash \ + ext cached_kernel_filename = os.path.join(self.cache_path, kernel_hash) # If we have the kernel in our hashmap, return it - if (kernel_hash in self.modules.keys()): - if (verbose): - print("`-> Found kernel " + kernel_hash + " cached in hashmap") - return self.modules[kernel_hash].get_function(kernel_function_name) + if (kernel_hash in self.kernels.keys()): + self.logger.debug("Found kernel %s cached in hashmap (%s)", kernel_filename, kernel_hash) + return self.kernels[kernel_hash] # If we have it on disk, return it elif (self.use_cache and os.path.isfile(cached_kernel_filename)): - if (verbose): - print("`-> Found kernel " + kernel_hash + " cached on disk") + self.logger.debug("Found kernel %s cached on disk (%s)", kernel_filename, kernel_hash) with io.open(cached_kernel_filename, "rb") as file: file_str = file.read() module = cuda.module_from_buffer(file_str, message_handler=cuda_compile_message_handler) - self.modules[kernel_hash] = module - kernel = self.modules[kernel_hash].get_function(kernel_function_name) + kernel = module.get_function(kernel_function_name) kernel.prepare(prepared_call_args) + self.kernels[kernel_hash] = kernel return kernel # Otherwise, compile it from source else: - if (verbose): - print("`-> Compiling " + kernel_filename) + self.logger.debug("Compiling %s (%s)", kernel_filename, kernel_hash) #Create kernel string kernel_string = "" for key, value in kwargs.items(): kernel_string += "#define {:s} {:s}\n".format(str(key), str(value)) - kernel_string += '#include "' + os.path.join(self.module_path, kernel_filename) + '"' + kernel_string += '#include "{:s}"'.format(os.path.join(self.module_path, kernel_filename)) if (self.use_cache): with io.open(cached_kernel_filename + ".txt", "w") as file: file.write(kernel_string) - with Timer("compiler", verbose=False) as timer: + with Timer("compiler") as timer: cubin = cuda_compiler.compile(kernel_string, include_dirs=include_dirs, no_extern_c=no_extern_c, cache_dir=False) module = cuda.module_from_buffer(cubin, message_handler=cuda_compile_message_handler) - self.modules[kernel_hash] = module if (self.use_cache): with io.open(cached_kernel_filename, "wb") as file: file.write(cubin) - if (verbose): - print("`-> Compiled in " + str(timer.secs) + " seconds") - - kernel = self.modules[kernel_hash].get_function(kernel_function_name) + kernel = module.get_function(kernel_function_name) kernel.prepare(prepared_call_args) + self.kernels[kernel_hash] = kernel + + return kernel """ Clears the kernel cache (useful for debugging & development) """ def clear_kernel_cache(self): - self.modules = {} + self.kernels = {} diff --git a/SWESimulators/IPythonMagic.py b/SWESimulators/IPythonMagic.py index ad01bbe..84d2f91 100644 --- a/SWESimulators/IPythonMagic.py +++ b/SWESimulators/IPythonMagic.py @@ -19,6 +19,8 @@ You should have received a copy of the GNU General Public License along with this program. If not, see . """ +import logging + from IPython.core.magic import line_magic, Magics, magics_class import pycuda.driver as cuda @@ -28,29 +30,31 @@ import pycuda.driver as cuda class CudaContextHandler(Magics): @line_magic def cuda_context_handler(self, context_name): - print("Registering " + context_name + " as a global context") + self.logger = logging.getLogger(__name__) + + self.logger.debug("Registering %s as a global context", context_name) if context_name in self.shell.user_ns.keys(): - print("`-> Context already registered! Ignoring") + self.logger.debug("Context already registered! Ignoring") return else: - print("`-> Creating context") + self.logger.debug("Creating context") self.shell.ex(context_name + " = Common.CudaContext(verbose=True, blocking=False)") # this function will be called on exceptions in any cell def custom_exc(shell, etype, evalue, tb, tb_offset=None): - print("Exception caught: Resetting to CUDA context " + context_name) + self.logger.exception("Exception caught: Resetting to CUDA context %s", context_name) while (cuda.Context.get_current() != None): context = cuda.Context.get_current() - print("`-> popping " + str(context.handle)) + self.logger.info("Popping <%s>", str(context.handle)) cuda.Context.pop() if context_name in self.shell.user_ns.keys(): - print("`-> pushing " + str(self.shell.user_ns[context_name].cuda_context.handle)) + self.logger.info("Pushing <%s>", str(self.shell.user_ns[context_name].cuda_context.handle)) self.shell.ex(context_name + ".cuda_context.push()") else: - print("No CUDA context called " + context_name + " found (something is wrong)!") - print("CUDA will not work now") + self.logger.error("No CUDA context called %s found (something is wrong)", context_name) + self.logger.error("CUDA will not work now") # still show the error within the notebook, don't just swallow it shell.showtraceback((etype, evalue, tb), tb_offset=tb_offset) @@ -62,14 +66,15 @@ class CudaContextHandler(Magics): # Handle CUDA context when exiting python import atexit def exitfunc(): - print("Exitfunc: Resetting CUDA context stack") + self.logger.info("Exitfunc: Resetting CUDA context stack") while (cuda.Context.get_current() != None): context = cuda.Context.get_current() - print("`-> popping " + str(context.handle)) + self.logger.info("`-> Popping <%s>", str(context.handle)) cuda.Context.pop() atexit.register(exitfunc) -print("Registering automatic CUDA context handling") -print("(use %cuda_context_handler my_context to create a context called my_context") +logger = logging.getLogger(__name__) +logger.info("Registering automatic CUDA context handling") +logger.debug("(use %cuda_context_handler my_context to create a context called my_context") ip = get_ipython() ip.register_magics(CudaContextHandler) diff --git a/SWESimulators/PlotHelper.py b/SWESimulators/PlotHelper.py deleted file mode 100644 index aa6ce43..0000000 --- a/SWESimulators/PlotHelper.py +++ /dev/null @@ -1,165 +0,0 @@ -# -*- coding: utf-8 -*- - -""" -This python class aids in plotting results from the numerical -simulations - -Copyright (C) 2016 SINTEF ICT - -This program is free software: you can redistribute it and/or modify -it under the terms of the GNU General Public License as published by -the Free Software Foundation, either version 3 of the License, or -(at your option) any later version. - -This program is distributed in the hope that it will be useful, -but WITHOUT ANY WARRANTY; without even the implied warranty of -MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the -GNU General Public License for more details. - -You should have received a copy of the GNU General Public License -along with this program. If not, see . -""" - - -from matplotlib import pyplot as plt -import matplotlib.gridspec as gridspec -import numpy as np -import time - -""" -Class that makes plotting faster by caching the plots instead of recreating them -""" -class PlotHelper: - - def __init__(self, fig, x_coords, y_coords, radius, eta1, u1, v1, eta2=None, u2=None, v2=None, interpolation_type='spline36'): - self.ny, self.nx = eta1.shape - self.fig = fig; - - fig.set_figheight(15) - fig.set_figwidth(15) - - min_x = np.min(x_coords[:,0]); - min_y = np.min(y_coords[0,:]); - - max_x = np.max(x_coords[0,:]); - max_y = np.max(y_coords[:,0]); - - domain_extent = [ x_coords[0, 0], x_coords[0, -1], y_coords[0, 0], y_coords[-1, 0] ] - - if (eta2 is not None): - assert(u2 is not None) - assert(v2 is not None) - self.gs = gridspec.GridSpec(3, 3) - else: - self.gs = gridspec.GridSpec(2, 3) - - ax = self.fig.add_subplot(self.gs[0, 0]) - self.sp_eta = plt.imshow(eta1, interpolation=interpolation_type, origin='bottom', vmin=-0.05, vmax=0.05, extent=domain_extent) - plt.axis('tight') - ax.set_aspect('equal') - plt.title('Eta') - plt.colorbar() - - ax = self.fig.add_subplot(self.gs[0, 1]) - self.sp_u = plt.imshow(u1, interpolation=interpolation_type, origin='bottom', vmin=-1.5, vmax=1.5, extent=domain_extent) - plt.axis('tight') - ax.set_aspect('equal') - plt.title('U') - plt.colorbar() - - ax = self.fig.add_subplot(self.gs[0, 2]) - self.sp_v = plt.imshow(v1, interpolation=interpolation_type, origin='bottom', vmin=-1.5, vmax=1.5, extent=domain_extent) - plt.axis('tight') - ax.set_aspect('equal') - plt.title('V') - plt.colorbar() - - ax = self.fig.add_subplot(self.gs[1, 0]) - self.sp_radial1, = plt.plot(radius.ravel(), eta1.ravel(), '.') - plt.axis([0, min(max_x, max_y), -1.5, 1]) - plt.title('Eta Radial plot') - - ax = self.fig.add_subplot(self.gs[1, 1]) - self.sp_x_axis1, = plt.plot(x_coords[self.ny/2,:], eta1[self.ny/2,:], 'k+--', label='x-axis') - self.sp_y_axis1, = plt.plot(y_coords[:,self.nx/2], eta1[:,self.nx/2], 'kx:', label='y-axis') - plt.axis([max(min_x, min_y), min(max_x, max_y), -1.5, 1]) - plt.title('Eta along axis') - plt.legend() - - ax = self.fig.add_subplot(self.gs[1, 2]) - self.sp_x_diag1, = plt.plot(1.41*np.diagonal(x_coords, offset=-abs(self.nx-self.ny)/2), \ - np.diagonal(eta1, offset=-abs(self.nx-self.ny)/2), \ - 'k+--', label='x = -y') - self.sp_y_diag1, = plt.plot(1.41*np.diagonal(y_coords.T, offset=abs(self.nx-self.ny)/2), \ - np.diagonal(eta1.T, offset=abs(self.nx-self.ny)/2), \ - 'kx:', label='x = y') - plt.axis([max(min_x, min_y), min(max_x, max_y), -1.5, 1]) - plt.title('Eta along diagonal') - plt.legend() - - - if (eta2 is not None): - ax = self.fig.add_subplot(self.gs[2, 0]) - self.sp_radial2, = plt.plot(radius.ravel(), eta2.ravel(), '.') - plt.axis([0, min(max_x, max_y), -1.5, 1]) - plt.title('Eta2 Radial plot') - - ax = self.fig.add_subplot(self.gs[2, 1]) - self.sp_x_axis2, = plt.plot(x_coords[self.ny/2,:], eta2[self.ny/2,:], 'k+--', label='x-axis') - self.sp_y_axis2, = plt.plot(y_coords[:,self.nx/2], eta2[:,self.nx/2], 'kx:', label='y-axis') - plt.axis([max(min_x, min_y), min(max_x, max_y), -1.5, 1]) - plt.title('Eta2 along axis') - plt.legend() - - ax = self.fig.add_subplot(self.gs[2, 2]) - self.sp_x_diag2, = plt.plot(1.41*np.diagonal(x_coords, offset=-abs(self.nx-self.ny)/2), \ - np.diagonal(eta2, offset=-abs(self.nx-self.ny)/2), \ - 'k+--', label='x = -y') - self.sp_y_diag2, = plt.plot(1.41*np.diagonal(y_coords.T, offset=abs(self.nx-self.ny)/2), \ - np.diagonal(eta2.T, offset=abs(self.nx-self.ny)/2), \ - 'kx:', label='x = y') - plt.axis([max(min_x, min_y), min(max_x, max_y), -1.5, 1]) - plt.title('Eta2 along diagonal') - plt.legend() - - - - - - def plot(self, eta1, u1, v1, eta2=None, u2=None, v2=None): - self.fig.add_subplot(self.gs[0, 0]) - self.sp_eta.set_data(eta1) - - self.fig.add_subplot(self.gs[0, 1]) - self.sp_u.set_data(u1) - - self.fig.add_subplot(self.gs[0, 2]) - self.sp_v.set_data(v1) - - self.fig.add_subplot(self.gs[1, 0]) - self.sp_radial1.set_ydata(eta1.ravel()); - - self.fig.add_subplot(self.gs[1, 1]) - self.sp_x_axis1.set_ydata(eta1[(self.ny+2)/2,:]) - self.sp_y_axis1.set_ydata(eta1[:,(self.nx+2)/2]) - - self.fig.add_subplot(self.gs[1, 2]) - self.sp_x_diag1.set_ydata(np.diagonal(eta1, offset=-abs(self.nx-self.ny)/2)) - self.sp_y_diag1.set_ydata(np.diagonal(eta1.T, offset=abs(self.nx-self.ny)/2)) - - if (eta2 is not None): - self.fig.add_subplot(self.gs[2, 0]) - self.sp_radial2.set_ydata(eta2.ravel()); - - self.fig.add_subplot(self.gs[2, 1]) - self.sp_x_axis2.set_ydata(eta2[(self.ny+2)/2,:]) - self.sp_y_axis2.set_ydata(eta2[:,(self.nx+2)/2]) - - self.fig.add_subplot(self.gs[2, 2]) - self.sp_x_diag2.set_ydata(np.diagonal(eta2, offset=-abs(self.nx-self.ny)/2)) - self.sp_y_diag2.set_ydata(np.diagonal(eta2.T, offset=abs(self.nx-self.ny)/2)) - - plt.draw() - time.sleep(0.001) - -