diff --git a/overviewer.py b/overviewer.py index b33acfa..b005394 100755 --- a/overviewer.py +++ b/overviewer.py @@ -42,6 +42,8 @@ from overviewer_core import configParser, tileset, assetmanager, dispatcher from overviewer_core import cache from overviewer_core import observer +LOG = logging.getLogger('overviewer_core') + helptext = """ %prog [--rendermodes=...] [options] %prog --config= [options]""" @@ -159,14 +161,14 @@ def main(): from overviewer_core.textures import Textures tex = Textures() - logging.info("Looking for a few common texture files...") + LOG.info("Looking for a few common texture files...") try: f = tex.find_file("assets/minecraft/textures/blocks/sandstone_top.png", verbose=True) f = tex.find_file("assets/minecraft/textures/blocks/grass_top.png", verbose=True) f = tex.find_file("assets/minecraft/textures/blocks/diamond_ore.png", verbose=True) f = tex.find_file("assets/minecraft/textures/blocks/planks_acacia.png", verbose=True) except IOError: - logging.error("Could not find any texture files.") + LOG.error("Could not find any texture files.") return 1 return 0 @@ -186,7 +188,7 @@ def main(): else: # more helpful message for users who know what they're doing - logging.error("You must either specify --config or give me a world directory and output directory") + LOG.error("You must either specify --config or give me a world directory and output directory") parser.print_help() list_worlds() return 1 @@ -203,12 +205,12 @@ def main(): print("worlds['myworld'] = %r" % args[0]) print("outputdir = %r" % (args[1] if len(args) > 1 else "/path/to/output")) print() - logging.error("Cannot specify both --config AND a world + output directory on the command line.") + LOG.error("Cannot specify both --config AND a world + output directory on the command line.") parser.print_help() return 1 if not options.config and len(args) < 2: - logging.error("You must specify both the world directory and an output directory") + LOG.error("You must specify both the world directory and an output directory") parser.print_help() return 1 if not options.config and len(args) > 2: @@ -218,10 +220,10 @@ def main(): if not os.path.exists(args[start]): for end in range(start+1, len(args)+1): if os.path.exists(" ".join(args[start:end])): - logging.warning("It looks like you meant to specify \"%s\" as your world dir or your output\n\ + LOG.warning("It looks like you meant to specify \"%s\" as your world dir or your output\n\ dir but you forgot to put quotes around the directory, since it contains spaces." % " ".join(args[start:end])) return 1 - logging.error("Too many command line arguments") + LOG.error("Too many command line arguments") parser.print_help() return 1 @@ -233,8 +235,8 @@ dir but you forgot to put quotes around the directory, since it contains spaces. if not options.config: # No config file mode. worldpath, destdir = map(os.path.expanduser, args) - logging.debug("Using %r as the world directory", worldpath) - logging.debug("Using %r as the output directory", destdir) + LOG.debug("Using %r as the world directory", worldpath) + LOG.debug("Using %r as the output directory", destdir) mw_parser.set_config_item("worlds", {'world': worldpath}) mw_parser.set_config_item("outputdir", destdir) @@ -255,7 +257,7 @@ dir but you forgot to put quotes around the directory, since it contains spaces. else: if options.rendermodes: - logging.error("You cannot specify --rendermodes if you give a config file. Configure your rendermodes in the config file instead") + LOG.error("You cannot specify --rendermodes if you give a config file. Configure your rendermodes in the config file instead") parser.print_help() return 1 @@ -264,7 +266,7 @@ dir but you forgot to put quotes around the directory, since it contains spaces. mw_parser.parse(os.path.expanduser(options.config)) except configParser.MissingConfigException as e: # this isn't a "bug", so don't print scary traceback - logging.error(str(e)) + LOG.error(str(e)) util.nice_exit(1) # Add in the command options here, perhaps overriding values specified in @@ -277,16 +279,16 @@ dir but you forgot to put quotes around the directory, since it contains spaces. config = mw_parser.get_validated_config() except Exception as ex: if options.verbose: - 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.") else: # no need to print scary traceback! just - logging.error("An error was encountered with your configuration.") - logging.error(str(ex)) + LOG.error("An error was encountered with your configuration.") + LOG.error(str(ex)) return 1 if options.check_terrain: # we are already in the "if configfile" branch - logging.info("Looking for a few common texture files...") + LOG.info("Looking for a few common texture files...") for render_name, render in config['renders'].iteritems(): - logging.info("Looking at render %r", render_name) + LOG.info("Looking at render %r", render_name) # find or create the textures object texopts = util.dict_subset(render, ["texturepath"]) @@ -300,8 +302,8 @@ dir but you forgot to put quotes around the directory, since it contains spaces. ############################################################ # Final validation steps and creation of the destination directory - logging.info("Welcome to Minecraft Overviewer!") - logging.debug("Current log level: {0}".format(logging.getLogger().level)) + LOG.info("Welcome to Minecraft Overviewer!") + LOG.debug("Current log level: {0}".format(LOG.level)) # Override some render configdict options depending on one-time command line # modifiers @@ -310,26 +312,26 @@ dir but you forgot to put quotes around the directory, since it contains spaces. bool(options.checktiles) + bool(options.notilechecks) ) > 1: - logging.error("You cannot specify more than one of --forcerender, "+ + LOG.error("You cannot specify more than one of --forcerender, "+ "--check-tiles, and --no-tile-checks. These options conflict.") parser.print_help() return 1 if options.forcerender: - logging.info("Forcerender mode activated. ALL tiles will be rendered") + LOG.info("Forcerender mode activated. ALL tiles will be rendered") for render in config['renders'].itervalues(): render['renderchecks'] = 2 elif options.checktiles: - logging.info("Checking all tiles for updates manually.") + LOG.info("Checking all tiles for updates manually.") for render in config['renders'].itervalues(): render['renderchecks'] = 1 elif options.notilechecks: - logging.info("Disabling all tile mtime checks. Only rendering tiles "+ + LOG.info("Disabling all tile mtime checks. Only rendering tiles "+ "that need updating since last render") for render in config['renders'].itervalues(): render['renderchecks'] = 0 if not config['renders']: - logging.error("You must specify at least one render in your config file. See the docs if you're having trouble") + LOG.error("You must specify at least one render in your config file. See the docs if you're having trouble") return 1 ##################### @@ -340,7 +342,7 @@ dir but you forgot to put quotes around the directory, since it contains spaces. 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'] @@ -357,23 +359,23 @@ dir but you forgot to put quotes around the directory, since it contains spaces. try: renderLink = config['renders'][x] except KeyError: - logging.error("Render %s's overlay is '%s', but I could not find a corresponding entry in the renders dictionary.", + LOG.error("Render %s's overlay is '%s', but I could not find a corresponding entry in the renders dictionary.", rname, x) return 1 else: - logging.error("Render %s's overlay contains itself.", rname) + LOG.error("Render %s's overlay contains itself.", rname) return 1 destdir = config['outputdir'] if not destdir: - logging.error("You must specify the output directory in your config file.") - logging.error("e.g. outputdir = '/path/to/outputdir'") + LOG.error("You must specify the output directory in your config file.") + LOG.error("e.g. outputdir = '/path/to/outputdir'") return 1 if not os.path.exists(destdir): try: os.mkdir(destdir) except OSError: - logging.exception("Could not create the output directory.") + LOG.exception("Could not create the output directory.") return 1 ######################################################################## @@ -385,7 +387,7 @@ dir but you forgot to put quotes around the directory, since it contains spaces. # If we've been asked to update web assets, do that and then exit if options.update_web_assets: assetMrg.output_noconfig() - logging.info("Web assets have been updated") + LOG.info("Web assets have been updated") return 0 # The changelist support. @@ -395,7 +397,7 @@ dir but you forgot to put quotes around the directory, since it contains spaces. path = render['changelist'] if path not in changelists: out = open(path, "w") - logging.debug("Opening changelist %s (%s)", out, out.fileno()) + LOG.debug("Opening changelist %s (%s)", out, out.fileno()) changelists[path] = out else: out = changelists[path] @@ -417,7 +419,7 @@ dir but you forgot to put quotes around the directory, since it contains spaces. renders = config['renders'] for render_name, render in renders.iteritems(): - logging.debug("Found the following render thing: %r", render) + LOG.debug("Found the following render thing: %r", render) # find or create the world object try: @@ -439,13 +441,13 @@ dir but you forgot to put quotes around the directory, since it contains spaces. tex = texcache[texopts_key] try: - logging.debug("Asking for regionset %r" % render['dimension'][1]) + LOG.debug("Asking for regionset %r" % render['dimension'][1]) rset = w.get_regionset(render['dimension'][1]) except IndexError: - logging.error("Sorry, I can't find anything to render! Are you sure there are .mca files in the world directory?") + LOG.error("Sorry, I can't find anything to render! Are you sure there are .mca files in the world directory?") return 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 ################# @@ -465,7 +467,7 @@ dir but you forgot to put quotes around the directory, since it contains spaces. # object if (render['northdirection'] > 0): rset = world.RotatedRegionSet(rset, render['northdirection']) - logging.debug("Using RegionSet %r", rset) + LOG.debug("Using RegionSet %r", rset) ############################### # Do the final prep and create the TileSet object @@ -499,13 +501,13 @@ dir but you forgot to put quotes around the directory, since it contains spaces. assetMrg.finalize(tilesets) for out in changelists.itervalues(): - logging.debug("Closing %s (%s)", out, out.fileno()) + LOG.debug("Closing %s (%s)", out, out.fileno()) out.close() if config['processes'] == 1: - logging.debug("Final cache stats:") + LOG.debug("Final cache stats:") for c in caches: - logging.debug("\t%s: %s hits, %s misses", c.__class__.__name__, c.hits, c.misses) + LOG.debug("\t%s: %s hits, %s misses", c.__class__.__name__, c.hits, c.misses) if options.pid: os.remove(options.pid) @@ -550,10 +552,10 @@ if __name__ == "__main__": util.nice_exit(ret) except textures.TextureException as e: # this isn't a "bug", so don't print scary traceback - logging.error(str(e)) + LOG.error(str(e)) util.nice_exit(1) except Exception as e: - logging.exception("""An error has occurred. This may be a bug. Please let us know! + LOG.exception("""An error has occurred. This may be a bug. Please let us know! See http://docs.overviewer.org/en/latest/index.html#help This is the error that occurred:""") diff --git a/overviewer_core/assetmanager.py b/overviewer_core/assetmanager.py index 96d8bb2..b37857d 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()) # Make sure python knows the preferred encoding. If it does not, set it diff --git a/overviewer_core/aux_files/genPOI.py b/overviewer_core/aux_files/genPOI.py index ad8858d..b049463 100755 --- a/overviewer_core/aux_files/genPOI.py +++ b/overviewer_core/aux_files/genPOI.py @@ -31,6 +31,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 = [" ", "(", ")"] @@ -66,7 +69,7 @@ def handleEntities(rset, outputdir, render, rname, config): 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=[]) @@ -106,7 +109,7 @@ def handleEntities(rset, outputdir, render, rname, config): 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"): @@ -143,7 +146,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: @@ -204,7 +207,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'] @@ -218,7 +221,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'] @@ -233,7 +236,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 the render '%s', but I couldn't find it", render['dimension'][0], rname) + LOG.error("Sorry, you requested dimension '%s' for the render '%s', but I couldn't find it", render['dimension'][0], rname) return 1 for f in render['markers']: @@ -256,8 +259,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 @@ -376,7 +379,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 4fd36a3..48d5bb9 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" @@ -50,6 +50,28 @@ HIGHLIGHT = { 'WARNING': YELLOW, } +LOG = logging.getLogger(__name__) + + +class InverseLevelFilter(object): + """ + This filter removes all messages *above* a certain threshold + (``max_level``). By default, setting a logger level will log all messages + *above* that level and ignore all messages *below* it. This filter + inverses this logic and only logs messages *below* the given level. + + Note that the given level in ``max_level`` is *excluded* as well. This + means that ``InverseLevelFilter(logging.WARN)`` (the default) will log + messages with the level ``DEBUG`` and ``INFO`` (and everything in + between), but *not* ``WARN`` and above!. + """ + + def __init__(self, max_level=logging.WARN): + self.max_level = max_level + + def filter(self, record): + return record.levelno < self.max_level + class WindowsOutputStream(object): """A file-like object that proxies sys.stderr and interprets simple ANSI @@ -265,36 +287,44 @@ def configure(loglevel=logging.INFO, verbose=False, simple=False): """ - logger = logging.getLogger() - + logger = logging.getLogger('overviewer_core') + logger.setLevel(loglevel) + is_windows = platform.system() == 'Windows' outstream = sys.stdout - if simple: - formatter = DumbFormatter(verbose) + errstream = sys.stderr + errformatter = DumbFormatter(verbose) + outformatter = DumbFormatter(verbose) - elif platform.system() == 'Windows': - # Our custom output stream processor knows how to deal with select ANSI - # color escape sequences - outstream = WindowsOutputStream(outstream) - formatter = ANSIColorFormatter(verbose) + if (is_windows or outstream.isatty()) and not simple: + # Our custom output stream processor knows how to deal with select + # ANSI color escape sequences + errformatter = ANSIColorFormatter(verbose) + outformatter = ANSIColorFormatter(verbose) - elif outstream.isatty(): - # terminal logging with ANSI color - formatter = ANSIColorFormatter(verbose) - else: - # Let's not assume anything. Just text. - formatter = DumbFormatter(verbose) + if not logger.handlers: + # No handlers have been configure yet... (probably the first call of + # logger.configure) - if hasattr(logger, 'overviewerHandler'): - # we have already set up logging so just replace the formatter - # this time with the new values - logger.overviewerHandler.setFormatter(formatter) - logger.setLevel(loglevel) + if is_windows: + outstream = WindowsOutputStream(outstream) + errstream = WindowsOutputStream(errstream) - else: - # Save our handler here so we can tell which handler was ours if the - # function is called again - logger.overviewerHandler = logging.StreamHandler(outstream) - logger.overviewerHandler.setFormatter(formatter) - logger.addHandler(logger.overviewerHandler) - logger.setLevel(loglevel) + out_handler = logging.StreamHandler(outstream) + out_handler.addFilter(InverseLevelFilter(max_level=logging.WARN)) + out_handler.set_name('overviewer_stdout_handler') + err_handler = logging.StreamHandler(errstream) + err_handler.set_name('overviewer_stderr_handler') + err_handler.setLevel(logging.WARN) + logger.addHandler(out_handler) + logger.addHandler(err_handler) + + try: + out_handler = logging._handlers['overviewer_stdout_handler'] + err_handler = logging._handlers['overviewer_stderr_handler'] + out_handler.setFormatter(outformatter) + err_handler.setFormatter(errformatter) + out_handler.setLevel(loglevel) + except KeyError as exc: + LOG.warn('Unable to change log handler format ' + '(KeyError for {0})'.format(exc)) 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 c7fc482..34f8989 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 @@ -145,7 +148,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 '.' @@ -178,7 +181,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 @@ -190,7 +193,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 @@ -208,24 +211,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. @@ -242,7 +245,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 @@ -271,7 +274,7 @@ class Textures(object): most_recent_version = versionparts if most_recent_version != [0,0,0]: - if verbose: logging.info("Most recent version >=1.7.0: {0}. Searching it for the file...".format(most_recent_version)) + if verbose: LOG.info("Most recent version >=1.7.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") @@ -281,15 +284,15 @@ 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) self.jar, self.jarpath = jar, 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.7.0") + if verbose: LOG.info("Did not find any non-snapshot minecraft jars >=1.7.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 @@ -297,16 +300,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.7-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)) @@ -412,7 +415,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 fe05064..8869788 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()