From 4112b5a72eb0f85270ccc984f1744e8515c331b5 Mon Sep 17 00:00:00 2001 From: Michel Albert Date: Sun, 28 Jul 2013 15:04:51 +0200 Subject: [PATCH] Using a dedicated logger inside overviewer_core. --- overviewer_core/assetmanager.py | 8 +++- overviewer_core/aux_files/genPOI.py | 21 +++++---- overviewer_core/cache.py | 1 - overviewer_core/configParser.py | 19 ++++---- overviewer_core/files.py | 4 +- overviewer_core/logger.py | 12 ++++- overviewer_core/observer.py | 10 ++-- overviewer_core/textures.py | 37 ++++++++------- overviewer_core/tileset.py | 72 +++++++++++++++-------------- overviewer_core/world.py | 40 ++++++++-------- 10 files changed, 127 insertions(+), 97 deletions(-) diff --git a/overviewer_core/assetmanager.py b/overviewer_core/assetmanager.py index be3b083..24e895b 100644 --- a/overviewer_core/assetmanager.py +++ b/overviewer_core/assetmanager.py @@ -27,6 +27,10 @@ import world import util from files import FileReplacer, mirror_dir + +LOG = logging.getLogger(__name__) + + class AssetManager(object): """\ These objects provide an interface to metadata and persistent data, and at the @@ -51,8 +55,8 @@ directory. self.overviewerConfig = json.loads(overviewerConfig_str) except Exception, e: if os.path.exists(os.path.join(self.outputdir, "overviewerConfig.js")): - logging.warning("A previous overviewerConfig.js was found, but I couldn't read it for some reason. Continuing with a blank config") - logging.debug(traceback.format_exc()) + LOG.warning("A previous overviewerConfig.js was found, but I couldn't read it for some reason. Continuing with a blank config") + LOG.debug(traceback.format_exc()) self.overviewerConfig = dict(tilesets=dict()) def get_tileset_config(self, name): diff --git a/overviewer_core/aux_files/genPOI.py b/overviewer_core/aux_files/genPOI.py index 45e36ff..a11ac35 100755 --- a/overviewer_core/aux_files/genPOI.py +++ b/overviewer_core/aux_files/genPOI.py @@ -24,6 +24,9 @@ from overviewer_core import logger from overviewer_core import nbt from overviewer_core import configParser, world +LOG = logging.getLogger(__name__) + + def replaceBads(s): "Replaces bad characters with good characters!" bads = [" ", "(", ")"] @@ -38,7 +41,7 @@ def handleEntities(rset, outputdir, render, rname): if hasattr(rset, "_pois"): return - logging.info("Looking for entities in %r", rset) + LOG.info("Looking for entities in %r", rset) filters = render['markers'] rset._pois = dict(TileEntities=[], Entities=[]) @@ -48,7 +51,7 @@ def handleEntities(rset, outputdir, render, rname): rset._pois['TileEntities'] += data['TileEntities'] rset._pois['Entities'] += data['Entities'] - logging.info("Done.") + LOG.info("Done.") def handlePlayers(rset, render, worldpath): if not hasattr(rset, "_pois"): @@ -77,7 +80,7 @@ def handlePlayers(rset, render, worldpath): if isSinglePlayer: data = data['Data']['Player'] except IOError: - logging.warning("Skipping bad player dat file %r", playerfile) + LOG.warning("Skipping bad player dat file %r", playerfile) continue playername = playerfile.split(".")[0] if isSinglePlayer: @@ -138,7 +141,7 @@ def main(): try: config = mw_parser.get_validated_config() except Exception: - logging.exception("An error was encountered with your configuration. See the info below.") + LOG.exception("An error was encountered with your configuration. See the info below.") return 1 destdir = config['outputdir'] @@ -152,7 +155,7 @@ def main(): try: worldpath = config['worlds'][render['world']] except KeyError: - logging.error("Render %s's world is '%s', but I could not find a corresponding entry in the worlds dictionary.", + LOG.error("Render %s's world is '%s', but I could not find a corresponding entry in the worlds dictionary.", rname, render['world']) return 1 render['worldname_orig'] = render['world'] @@ -167,7 +170,7 @@ def main(): rset = w.get_regionset(render['dimension'][1]) if rset == None: # indicates no such dimension was found: - logging.error("Sorry, you requested dimension '%s' for %s, but I couldn't find it", render['dimension'][0], render_name) + LOG.error("Sorry, you requested dimension '%s' for %s, but I couldn't find it", render['dimension'][0], render_name) return 1 for f in render['markers']: @@ -190,8 +193,8 @@ def main(): handlePlayers(rset, render, worldpath) handleManual(rset, render['manualpois']) - logging.info("Done handling POIs") - logging.info("Writing out javascript files") + LOG.info("Done handling POIs") + LOG.info("Writing out javascript files") markerSetDict = dict() for (flter, rset) in markersets: # generate a unique name for this markerset. it will not be user visible @@ -310,7 +313,7 @@ def main(): output.write("overviewer.util.injectMarkerScript('markersDB.js');\n") output.write("overviewer.util.injectMarkerScript('markers.js');\n") output.write("overviewer.collections.haveSigns=true;\n") - logging.info("Done") + LOG.info("Done") if __name__ == "__main__": main() diff --git a/overviewer_core/cache.py b/overviewer_core/cache.py index d21dbc5..6877e2b 100644 --- a/overviewer_core/cache.py +++ b/overviewer_core/cache.py @@ -21,7 +21,6 @@ attribute. """ import functools -import logging import cPickle class LRUCache(object): diff --git a/overviewer_core/configParser.py b/overviewer_core/configParser.py index cad7c75..2d88475 100644 --- a/overviewer_core/configParser.py +++ b/overviewer_core/configParser.py @@ -7,6 +7,9 @@ import traceback import settingsDefinition import settingsValidators +LOG = logging.getLogger(__name__) + + class MissingConfigException(Exception): "To be thrown when the config file can't be found" pass @@ -83,14 +86,14 @@ class MultiWorldParser(object): except Exception, ex: if isinstance(ex, SyntaxError): - logging.error("Syntax error parsing %s" % settings_file) - logging.error("The traceback below will tell you which line triggered the syntax error\n") + LOG.error("Syntax error parsing %s" % settings_file) + LOG.error("The traceback below will tell you which line triggered the syntax error\n") elif isinstance(ex, NameError): - logging.error("NameError parsing %s" % settings_file) - logging.error("The traceback below will tell you which line referenced the non-existent variable\n") + LOG.error("NameError parsing %s" % settings_file) + LOG.error("The traceback below will tell you which line referenced the non-existent variable\n") else: - logging.error("Error parsing %s" % settings_file) - logging.error("The traceback below will tell you which line triggered the error\n") + LOG.error("Error parsing %s" % settings_file) + LOG.error("The traceback below will tell you which line triggered the error\n") # skip the execfile part of the traceback exc_type, exc_value, exc_traceback = sys.exc_info() @@ -102,8 +105,8 @@ class MultiWorldParser(object): else: if "execfile" in l: print_rest = True # on windows, our traceback as no 'execfile'. in this case, print everything - if print_rest: logging.error("Partial traceback:\n" + "\n".join(lines)) - else: logging.error("Partial traceback:\n" + "\n".join(formatted_lines)) + if print_rest: LOG.error("Partial traceback:\n" + "\n".join(lines)) + else: LOG.error("Partial traceback:\n" + "\n".join(formatted_lines)) sys.exit(1) # At this point, make a pass through the file to possibly set global diff --git a/overviewer_core/files.py b/overviewer_core/files.py index dc680bb..51de642 100644 --- a/overviewer_core/files.py +++ b/overviewer_core/files.py @@ -20,6 +20,8 @@ import shutil import logging import stat +LOG = logging.getLogger(__name__) + ## useful recursive copy, that ignores common OS cruft def mirror_dir(src, dst, entities=None): '''copies all of the entities from src to dst''' @@ -104,7 +106,7 @@ if renameworks: try: os.remove(self.tmpname) except Exception, e: - logging.warning("An error was raised, so I was doing " + LOG.warning("An error was raised, so I was doing " "some cleanup first, but I couldn't remove " "'%s'!", self.tmpname) else: diff --git a/overviewer_core/logger.py b/overviewer_core/logger.py index 4ecbab2..f592986 100644 --- a/overviewer_core/logger.py +++ b/overviewer_core/logger.py @@ -20,8 +20,8 @@ import platform import ctypes from cStringIO import StringIO -# Some cool code for colored logging: -# For background, add 40. For foreground, add 30 +# Some cool code for colored logging: For background, add 40. For foreground, +# add 30 BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE = range(8) RESET_SEQ = "\033[0m" @@ -277,6 +277,12 @@ def configure(loglevel=logging.INFO, verbose=False, simple=False): logger = logging.getLogger('overviewer') logger.setLevel(loglevel) + # because overviewer_core does not live in the same namespace as + # overviewer.py, we need a second logger. This allows us to use the + # standard ``logger.getLogger(__name__)`` where needed. + core_logger = logging.getLogger('overviewer_core') + core_logger.setLevel(loglevel) + if not logger.handlers: # No handlers have been configure yet... (probably the first call of # logger.configure) @@ -304,3 +310,5 @@ def configure(loglevel=logging.INFO, verbose=False, simple=False): err_handler.setFormatter(errformatter) logger.addHandler(out_handler) logger.addHandler(err_handler) + core_logger.addHandler(out_handler) + core_logger.addHandler(err_handler) diff --git a/overviewer_core/observer.py b/overviewer_core/observer.py index 48e2632..b64cc39 100644 --- a/overviewer_core/observer.py +++ b/overviewer_core/observer.py @@ -20,6 +20,8 @@ import sys import os import json +LOG = logging.getLogger(__name__) + class Observer(object): """Base class that defines the observer interface. """ @@ -93,14 +95,14 @@ class LoggingObserver(Observer): self.last_update = -101 def finish(self): - logging.info("Rendered %d of %d. %d%% complete", self.get_max_value(), + LOG.info("Rendered %d of %d. %d%% complete", self.get_max_value(), self.get_max_value(), 100.0) super(LoggingObserver, self).finish() def update(self, current_value): super(LoggingObserver, self).update(current_value) if self._need_update(): - logging.info("Rendered %d of %d. %d%% complete", + LOG.info("Rendered %d of %d. %d%% complete", self.get_current_value(), self.get_max_value(), self.get_percentage()) self.last_update = current_value @@ -137,7 +139,7 @@ class ProgressBarObserver(progressbar.ProgressBar, Observer): def start(self, max_value): self._set_max_value(max_value) - logging.info("Rendering %d total tiles." % max_value) + LOG.info("Rendering %d total tiles." % max_value) super(ProgressBarObserver, self).start() def is_started(self): @@ -147,7 +149,7 @@ class ProgressBarObserver(progressbar.ProgressBar, Observer): self._end_time = time.time() super(ProgressBarObserver, self).finish() self.fd.write('\n') - logging.info("Rendering complete!") + LOG.info("Rendering complete!") def update(self, current_value): if super(ProgressBarObserver, self).update(current_value): diff --git a/overviewer_core/textures.py b/overviewer_core/textures.py index 93e18f2..beaa9ac 100644 --- a/overviewer_core/textures.py +++ b/overviewer_core/textures.py @@ -29,6 +29,9 @@ import functools import util from c_overviewer import alpha_over +LOG = logging.getLogger(__name__) + + class TextureException(Exception): "To be thrown when a texture is not found." pass @@ -141,7 +144,7 @@ class Textures(object): 'environment/'. """ - if verbose: logging.info("Starting search for {0}".format(filename)) + if verbose: LOG.info("Starting search for {0}".format(filename)) # a list of subdirectories to search for a given file, # after the obvious '.' @@ -160,7 +163,7 @@ class Textures(object): if os.path.isdir(self.find_file_local_path): path = search_dir(self.find_file_local_path) if path: - if verbose: logging.info("Found %s in '%s'", filename, path) + if verbose: LOG.info("Found %s in '%s'", filename, path) return open(path, mode) elif os.path.isfile(self.find_file_local_path): # Must be a resource pack. Look for the requested file within @@ -172,7 +175,7 @@ class Textures(object): # pack.getinfo() will raise KeyError if the file is # not found. pack.getinfo(packfilename) - if verbose: logging.info("Found %s in '%s'", packfilename, self.find_file_local_path) + if verbose: LOG.info("Found %s in '%s'", packfilename, self.find_file_local_path) return pack.open(packfilename) except (KeyError, IOError): pass @@ -181,24 +184,24 @@ class Textures(object): # If we haven't returned at this point, then the requested file was NOT # found in the user-specified texture path or resource pack. - if verbose: logging.info("Did not find the file in specified texture path") + if verbose: LOG.info("Did not find the file in specified texture path") # Look in the location of the overviewer executable for the given path programdir = util.get_program_path() path = search_dir(programdir) if path: - if verbose: logging.info("Found %s in '%s'", filename, path) + if verbose: LOG.info("Found %s in '%s'", filename, path) return open(path, mode) if sys.platform.startswith("darwin"): path = search_dir("/Applications/Minecraft") if path: - if verbose: logging.info("Found %s in '%s'", filename, path) + if verbose: LOG.info("Found %s in '%s'", filename, path) return open(path, mode) - if verbose: logging.info("Did not find the file in overviewer executable directory") - if verbose: logging.info("Looking for installed minecraft jar files...") + if verbose: LOG.info("Did not find the file in overviewer executable directory") + if verbose: LOG.info("Looking for installed minecraft jar files...") # Find an installed minecraft client jar and look in it for the texture # file we need. @@ -215,7 +218,7 @@ class Textures(object): try: versions = os.listdir(versiondir) - if verbose: logging.info("Found these versions: {0}".format(versions)) + if verbose: LOG.info("Found these versions: {0}".format(versions)) except OSError: # Directory doesn't exist? Ignore it. It will find no versions and # fall through the checks below to the error at the bottom of the @@ -244,7 +247,7 @@ class Textures(object): most_recent_version = versionparts if most_recent_version != [0,0,0]: - if verbose: logging.info("Most recent version >=1.6.0: {0}. Searching it for the file...".format(most_recent_version)) + if verbose: LOG.info("Most recent version >=1.6.0: {0}. Searching it for the file...".format(most_recent_version)) jarname = ".".join(str(x) for x in most_recent_version) jarpath = os.path.join(versiondir, jarname, jarname + ".jar") @@ -254,14 +257,14 @@ class Textures(object): for jarfilename in search_zip_paths: try: jar.getinfo(jarfilename) - if verbose: logging.info("Found %s in '%s'", jarfilename, jarpath) + if verbose: LOG.info("Found %s in '%s'", jarfilename, jarpath) return jar.open(jarfilename) except (KeyError, IOError), e: pass - if verbose: logging.info("Did not find file {0} in jar {1}".format(filename, jarpath)) + if verbose: LOG.info("Did not find file {0} in jar {1}".format(filename, jarpath)) else: - if verbose: logging.info("Did not find any non-snapshot minecraft jars >=1.6.0") + if verbose: LOG.info("Did not find any non-snapshot minecraft jars >=1.6.0") # Last ditch effort: look for the file is stored in with the overviewer # installation. We include a few files that aren't included with Minecraft @@ -269,16 +272,16 @@ class Textures(object): # they were generated by the game and not stored as images. Nowdays I # believe that's not true, but we still have a few files distributed # with overviewer. - if verbose: logging.info("Looking for texture in overviewer_core/data/textures") + if verbose: LOG.info("Looking for texture in overviewer_core/data/textures") path = search_dir(os.path.join(programdir, "overviewer_core", "data", "textures")) if path: - if verbose: logging.info("Found %s in '%s'", filename, path) + if verbose: LOG.info("Found %s in '%s'", filename, path) return open(path, mode) elif hasattr(sys, "frozen") or imp.is_frozen("__main__"): # windows special case, when the package dir doesn't exist path = search_dir(os.path.join(programdir, "textures")) if path: - if verbose: logging.info("Found %s in '%s'", filename, path) + if verbose: LOG.info("Found %s in '%s'", filename, path) return open(path, mode) raise TextureException("Could not find the textures while searching for '{0}'. Try specifying the 'texturepath' option in your config file.\nSet it to the path to a Minecraft Resource pack.\nAlternately, install the Minecraft client (which includes textures)\nAlso see \n(Remember, this version of Overviewer requires a 1.6-compatible resource pack)\n(Also note that I won't automatically use snapshots; you'll have to use the texturepath option to use a snapshot jar)".format(filename)) @@ -383,7 +386,7 @@ class Textures(object): try: lightcolor = list(self.load_image("light_normal.png").getdata()) except Exception: - logging.warning("Light color image could not be found.") + LOG.warning("Light color image could not be found.") lightcolor = None self.lightcolor = lightcolor return lightcolor diff --git a/overviewer_core/tileset.py b/overviewer_core/tileset.py index a36ef55..bdacbb6 100644 --- a/overviewer_core/tileset.py +++ b/overviewer_core/tileset.py @@ -37,6 +37,10 @@ import rendermodes import c_overviewer from c_overviewer import resize_half + +LOG = logging.getLogger(__name__) + + """ tileset.py contains the TileSet class, and in general, routines that manage a @@ -293,24 +297,24 @@ class TileSet(object): if os.path.exists(self.outputdir): # Somehow there's no config but the output dir DOES exist. # That's strange! - logging.warning( + LOG.warning( "For render '%s' I couldn't find any persistent config, " "but I did find my tile directory already exists. This " "shouldn't normally happen, something may be up, but I " "think I can continue...", self.options['name']) - logging.info("Switching to --check-tiles mode") + LOG.info("Switching to --check-tiles mode") self.options['renderchecks'] = 1 else: # This is the typical code path for an initial render, make # this a "forcerender" self.options['renderchecks'] = 2 - logging.debug("This is the first time rendering %s. Doing" + + LOG.debug("This is the first time rendering %s. Doing" + " a full-render", self.options['name']) elif not os.path.exists(self.outputdir): # Somehow the outputdir got erased but the metadata file is # still there. That's strange! - logging.warning( + LOG.warning( "This is strange. There is metadata for render '%s' but " "the output directory is missing. This shouldn't " "normally happen. I guess we have no choice but to do a " @@ -319,18 +323,18 @@ class TileSet(object): elif config.get("render_in_progress", False): # The last render must have been interrupted. The default should be # a check-tiles render then - logging.warning( + LOG.warning( "The last render for '%s' didn't finish. I'll be " + "scanning all the tiles to make sure everything's up "+ "to date.", self.options['name'], ) - logging.warning("The total tile count will be (possibly "+ + LOG.warning("The total tile count will be (possibly "+ "wildly) inaccurate, because I don't know how many "+ "tiles need rendering. I'll be checking them as I go") self.options['renderchecks'] = 1 else: - logging.debug("No rendercheck mode specified for %s. "+ + LOG.debug("No rendercheck mode specified for %s. "+ "Rendering tile whose chunks have changed since %s", self.options['name'], time.strftime("%x %X", time.localtime(self.last_rendertime)), @@ -339,7 +343,7 @@ class TileSet(object): if not os.path.exists(self.outputdir): if self.options['renderchecks'] != 2: - logging.warning( + LOG.warning( "The tile directory didn't exist, but you have specified " "explicitly not to do a --fullrender (which is the default for " "this situation). I'm overriding your decision and setting " @@ -377,7 +381,7 @@ class TileSet(object): # This warning goes here so it's only shown once if self.treedepth >= 15: - logging.warning("Just letting you know, your map requries %s zoom levels. This is REALLY big!", + LOG.warning("Just letting you know, your map requries %s zoom levels. This is REALLY big!", self.treedepth) # Do any tile re-arranging if necessary. Skip if there was no config @@ -418,7 +422,7 @@ class TileSet(object): # The following block of code implementes the changelist functionality. fd = self.options.get("changelist", None) if fd: - logging.debug("Changelist activated for %s (fileno %s)", self, fd) + LOG.debug("Changelist activated for %s (fileno %s)", self, fd) # This re-implements some of the logic from do_work() def write_out(tilepath): if len(tilepath) == self.treedepth: @@ -610,20 +614,20 @@ class TileSet(object): # Skip a depth 1 tree. A depth 1 tree pretty much can't happen, so # when we detect this it usually means the tree is actually empty return - logging.debug("Current tree depth for %s is reportedly %s. Target tree depth is %s", + LOG.debug("Current tree depth for %s is reportedly %s. Target tree depth is %s", self.options['name'], curdepth, self.treedepth) if self.treedepth != curdepth: if self.treedepth > curdepth: - logging.warning("Your map seems to have expanded beyond its previous bounds.") - logging.warning( "Doing some tile re-arrangements... just a sec...") + LOG.warning("Your map seems to have expanded beyond its previous bounds.") + LOG.warning( "Doing some tile re-arrangements... just a sec...") for _ in xrange(self.treedepth-curdepth): self._increase_depth() elif self.treedepth < curdepth: - logging.warning("Your map seems to have shrunk. Did you delete some chunks? No problem. Re-arranging tiles, just a sec...") + LOG.warning("Your map seems to have shrunk. Did you delete some chunks? No problem. Re-arranging tiles, just a sec...") for _ in xrange(curdepth - self.treedepth): self._decrease_depth() - logging.info( + LOG.info( "There done. I'm switching to --check-tiles mode for " "this one render. This will make sure any old tiles that " "should no longer exist are deleted.") @@ -793,7 +797,7 @@ class TileSet(object): dirty.add(tile.path) t = int(time.time()-stime) - logging.debug("Finished chunk scan for %s. %s chunks scanned in %s second%s", + LOG.debug("Finished chunk scan for %s. %s chunks scanned in %s second%s", self.options['name'], chunkcount, t, "s" if t != 1 else "") @@ -856,10 +860,10 @@ class TileSet(object): # Ignore errors if it's "file doesn't exist" if e.errno != errno.ENOENT: raise - logging.warning("Tile %s was requested for render, but no children were found! This is probably a bug", imgpath) + LOG.warning("Tile %s was requested for render, but no children were found! This is probably a bug", imgpath) return - #logging.debug("writing out compositetile {0}".format(imgpath)) + #LOG.debug("writing out compositetile {0}".format(imgpath)) # Create the actual image now img = Image.new("RGBA", (384, 384), self.options['bgcolor']) @@ -876,12 +880,12 @@ class TileSet(object): resize_half(quad, src) img.paste(quad, path[0]) except Exception, e: - logging.warning("Couldn't open %s. It may be corrupt. Error was '%s'", path[1], e) - logging.warning("I'm going to try and delete it. You will need to run the render again and with --check-tiles") + LOG.warning("Couldn't open %s. It may be corrupt. Error was '%s'", path[1], e) + LOG.warning("I'm going to try and delete it. You will need to run the render again and with --check-tiles") try: os.unlink(path[1]) except Exception, e: - logging.error("While attempting to delete corrupt image %s, an error was encountered. You will need to delete it yourself. Error was '%s'", path[1], e) + LOG.error("While attempting to delete corrupt image %s, an error was encountered. You will need to delete it yourself. Error was '%s'", path[1], e) # Save it with FileReplacer(imgpath) as tmppath: @@ -917,7 +921,7 @@ class TileSet(object): if not chunks: # No chunks were found in this tile - logging.warning("%s was requested for render, but no chunks found! This may be a bug", tile) + LOG.warning("%s was requested for render, but no chunks found! This may be a bug", tile) try: os.unlink(imgpath) except OSError, e: @@ -925,7 +929,7 @@ class TileSet(object): if e.errno != errno.ENOENT: raise else: - logging.debug("%s deleted", tile) + LOG.debug("%s deleted", tile) return # Create the directory if not exists @@ -940,7 +944,7 @@ class TileSet(object): if e.errno != errno.EEXIST: raise - #logging.debug("writing out worldtile {0}".format(imgpath)) + #LOG.debug("writing out worldtile {0}".format(imgpath)) # Compile this image tileimg = Image.new("RGBA", (384, 384), self.options['bgcolor']) @@ -965,10 +969,10 @@ class TileSet(object): except nbt.CorruptionError: # A warning and traceback was already printed by world.py's # get_chunk() - logging.debug("Skipping the render of corrupt chunk at %s,%s and moving on.", chunkx, chunkz) + LOG.debug("Skipping the render of corrupt chunk at %s,%s and moving on.", chunkx, chunkz) except Exception, e: - logging.error("Could not render chunk %s,%s for some reason. This is likely a render primitive option error.", chunkx, chunkz) - logging.error("Full error was:", exc_info=1) + LOG.error("Could not render chunk %s,%s for some reason. This is likely a render primitive option error.", chunkx, chunkz) + LOG.error("Full error was:", exc_info=1) sys.exit(1) ## Semi-handy routine for debugging the drawing routine @@ -1044,14 +1048,14 @@ class TileSet(object): max_chunk_mtime = max(c[5] for c in get_chunks_by_tile(tileobj, self.regionset)) except ValueError: # max got an empty sequence! something went horribly wrong - logging.warning("tile %s expected contains no chunks! this may be a bug", path) + LOG.warning("tile %s expected contains no chunks! this may be a bug", path) max_chunk_mtime = 0 if tile_mtime > 120 + max_chunk_mtime: # If a tile has been modified more recently than any of its # chunks, then this could indicate a potential issue with # this or future renders. - logging.warning( + LOG.warning( "I found a tile with a more recent modification time " "than any of its chunks. This can happen when a tile has " "been modified with an outside program, or by a copy " @@ -1061,7 +1065,7 @@ class TileSet(object): "preserve the mtimes Overviewer sets. Please see our FAQ " "page on docs.overviewer.org or ask us in IRC for more " "information") - logging.warning("Tile was: %s", imgpath) + LOG.warning("Tile was: %s", imgpath) if max_chunk_mtime > tile_mtime: # chunks have a more recent mtime than the tile. Render the tile @@ -1114,7 +1118,7 @@ class TileSet(object): # Check this tile's mtime imgpath = os.path.join(self.outputdir, *(str(x) for x in path)) imgpath += "." + self.imgextension - logging.debug("Testing mtime for composite-tile %s", imgpath) + LOG.debug("Testing mtime for composite-tile %s", imgpath) try: tile_mtime = os.stat(imgpath)[stat.ST_MTIME] except OSError, e: @@ -1142,17 +1146,17 @@ class TileSet(object): if os.path.exists(imgpath): # No need to catch ENOENT since this is only called from the # master process - logging.debug("Found an image that shouldn't exist. Deleting it: %s", imgpath) + LOG.debug("Found an image that shouldn't exist. Deleting it: %s", imgpath) os.remove(imgpath) else: # path referrs to a composite tile, and by extension a directory dirpath = os.path.join(self.outputdir, *(str(x) for x in path)) imgpath = dirpath + "." + self.imgextension if os.path.exists(imgpath): - logging.debug("Found an image that shouldn't exist. Deleting it: %s", imgpath) + LOG.debug("Found an image that shouldn't exist. Deleting it: %s", imgpath) os.remove(imgpath) if os.path.exists(dirpath): - logging.debug("Found a subtree that shouldn't exist. Deleting it: %s", dirpath) + LOG.debug("Found a subtree that shouldn't exist. Deleting it: %s", dirpath) shutil.rmtree(dirpath) ## diff --git a/overviewer_core/world.py b/overviewer_core/world.py index ecf5f22..5b0f994 100644 --- a/overviewer_core/world.py +++ b/overviewer_core/world.py @@ -27,6 +27,8 @@ import numpy from . import nbt from . import cache +LOG = logging.getLogger(__name__) + """ This module has routines for extracting information about available worlds @@ -49,7 +51,7 @@ def log_other_exceptions(func): except ChunkDoesntExist: raise except Exception, e: - logging.exception("%s raised this exception", func.func_name) + LOG.exception("%s raised this exception", func.func_name) raise return newfunc @@ -104,7 +106,7 @@ class World(object): # Hard-code this to only work with format version 19133, "Anvil" if not ('version' in data and data['version'] == 19133): - logging.critical("Sorry, This version of Minecraft-Overviewer only works with the 'Anvil' chunk format") + LOG.critical("Sorry, This version of Minecraft-Overviewer only works with the 'Anvil' chunk format") raise ValueError("World at %s is not compatible with Overviewer" % self.worlddir) # This isn't much data, around 15 keys and values for vanilla worlds. @@ -153,7 +155,7 @@ class World(object): return self.regionsets[index] else: # assume a get_type() value candids = [x for x in self.regionsets if x.get_type() == index] - logging.debug("You asked for %r, and I found the following candids: %r", index, candids) + LOG.debug("You asked for %r, and I found the following candids: %r", index, candids) if len(candids) > 0: return candids[0] else: @@ -249,8 +251,8 @@ class RegionSet(object): """ self.regiondir = os.path.normpath(regiondir) self.rel = os.path.normpath(rel) - logging.debug("regiondir is %r" % self.regiondir) - logging.debug("rel is %r" % self.rel) + LOG.debug("regiondir is %r" % self.regiondir) + LOG.debug("rel is %r" % self.rel) # we want to get rid of /regions, if it exists if self.rel.endswith(os.path.normpath("/region")): @@ -259,10 +261,10 @@ class RegionSet(object): # this is the main world self.type = None else: - logging.warning("Unkown region type in %r", regiondir) + LOG.warning("Unkown region type in %r", regiondir) self.type = "__unknown" - logging.debug("Scanning regions. Type is %r" % self.type) + LOG.debug("Scanning regions. Type is %r" % self.type) # This is populated below. It is a mapping from (x,y) region coords to filename self.regionfiles = {} @@ -275,7 +277,7 @@ class RegionSet(object): self.regionfiles[(x,y)] = regionfile self.empty_chunk = [None,None] - logging.debug("Done scanning regions") + LOG.debug("Done scanning regions") # Re-initialize upon unpickling def __getstate__(self): @@ -349,22 +351,22 @@ class RegionSet(object): if tries > 0: # Flush the region cache to possibly read a new region file # header - logging.debug("Encountered a corrupt chunk at %s,%s. Flushing cache and retrying", x, z) - #logging.debug("Error was:", exc_info=1) + LOG.debug("Encountered a corrupt chunk at %s,%s. Flushing cache and retrying", x, z) + #LOG.debug("Error was:", exc_info=1) del self.regioncache[regionfile] time.sleep(0.5) continue else: if isinstance(e, nbt.CorruptRegionError): - logging.warning("Tried several times to read chunk %d,%d. Its region (%d,%d) may be corrupt. Giving up.", + LOG.warning("Tried several times to read chunk %d,%d. Its region (%d,%d) may be corrupt. Giving up.", x, z,x//32,z//32) elif isinstance(e, nbt.CorruptChunkError): - logging.warning("Tried several times to read chunk %d,%d. It may be corrupt. Giving up.", + LOG.warning("Tried several times to read chunk %d,%d. It may be corrupt. Giving up.", x, z) else: - logging.warning("Tried several times to read chunk %d,%d. Unknown error. Giving up.", + LOG.warning("Tried several times to read chunk %d,%d. Unknown error. Giving up.", x, z) - logging.debug("Full traceback:", exc_info=1) + LOG.debug("Full traceback:", exc_info=1) # Let this exception propagate out through the C code into # tileset.py, where it is caught and gracefully continues # with the next chunk @@ -454,7 +456,7 @@ class RegionSet(object): try: mcr = self._get_regionobj(regionfile) except nbt.CorruptRegionError: - logging.warning("Found a corrupt region file at %s,%s. Skipping it.", regionx, regiony) + LOG.warning("Found a corrupt region file at %s,%s. Skipping it.", regionx, regiony) continue for chunkx, chunky in mcr.get_chunks(): yield chunkx+32*regionx, chunky+32*regiony, mcr.get_chunk_timestamp(chunkx, chunky) @@ -472,7 +474,7 @@ class RegionSet(object): try: data = self._get_regionobj(regionfile) except nbt.CorruptRegionError: - logging.warning("Ignoring request for chunk %s,%s; region %s,%s seems to be corrupt", + LOG.warning("Ignoring request for chunk %s,%s; region %s,%s seems to be corrupt", x,z, x//32,z//32) return None if data.chunk_exists(x,z): @@ -493,7 +495,7 @@ class RegionSet(object): Returns (regionx, regiony, filename)""" - logging.debug("regiondir is %s, has type %r", self.regiondir, self.type) + LOG.debug("regiondir is %s, has type %r", self.regiondir, self.type) for f in os.listdir(self.regiondir): if re.match(r"^r\.-?\d+\.-?\d+\.mca$", f): @@ -501,7 +503,7 @@ class RegionSet(object): x = int(p[1]) y = int(p[2]) if abs(x) > 500000 or abs(y) > 500000: - logging.warning("Holy shit what is up with region file %s !?" % f) + LOG.warning("Holy shit what is up with region file %s !?" % f) yield (x, y, os.path.join(self.regiondir, f)) class RegionSetWrapper(object): @@ -674,7 +676,7 @@ class CachedRegionSet(RegionSetWrapper): except AttributeError: s += repr(obj) - logging.debug("Initializing a cache with key '%s'", s) + LOG.debug("Initializing a cache with key '%s'", s) s = hashlib.md5(s).hexdigest()