0

Using a dedicated logger inside overviewer_core.

This commit is contained in:
Michel Albert
2013-07-28 15:04:51 +02:00
parent c991135e40
commit 4112b5a72e
10 changed files with 127 additions and 97 deletions

View File

@@ -27,6 +27,10 @@ import world
import util import util
from files import FileReplacer, mirror_dir from files import FileReplacer, mirror_dir
LOG = logging.getLogger(__name__)
class AssetManager(object): class AssetManager(object):
"""\ """\
These objects provide an interface to metadata and persistent data, and at the These objects provide an interface to metadata and persistent data, and at the
@@ -51,8 +55,8 @@ directory.
self.overviewerConfig = json.loads(overviewerConfig_str) self.overviewerConfig = json.loads(overviewerConfig_str)
except Exception, e: except Exception, e:
if os.path.exists(os.path.join(self.outputdir, "overviewerConfig.js")): 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") LOG.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.debug(traceback.format_exc())
self.overviewerConfig = dict(tilesets=dict()) self.overviewerConfig = dict(tilesets=dict())
def get_tileset_config(self, name): def get_tileset_config(self, name):

View File

@@ -24,6 +24,9 @@ from overviewer_core import logger
from overviewer_core import nbt from overviewer_core import nbt
from overviewer_core import configParser, world from overviewer_core import configParser, world
LOG = logging.getLogger(__name__)
def replaceBads(s): def replaceBads(s):
"Replaces bad characters with good characters!" "Replaces bad characters with good characters!"
bads = [" ", "(", ")"] bads = [" ", "(", ")"]
@@ -38,7 +41,7 @@ def handleEntities(rset, outputdir, render, rname):
if hasattr(rset, "_pois"): if hasattr(rset, "_pois"):
return return
logging.info("Looking for entities in %r", rset) LOG.info("Looking for entities in %r", rset)
filters = render['markers'] filters = render['markers']
rset._pois = dict(TileEntities=[], Entities=[]) rset._pois = dict(TileEntities=[], Entities=[])
@@ -48,7 +51,7 @@ def handleEntities(rset, outputdir, render, rname):
rset._pois['TileEntities'] += data['TileEntities'] rset._pois['TileEntities'] += data['TileEntities']
rset._pois['Entities'] += data['Entities'] rset._pois['Entities'] += data['Entities']
logging.info("Done.") LOG.info("Done.")
def handlePlayers(rset, render, worldpath): def handlePlayers(rset, render, worldpath):
if not hasattr(rset, "_pois"): if not hasattr(rset, "_pois"):
@@ -77,7 +80,7 @@ def handlePlayers(rset, render, worldpath):
if isSinglePlayer: if isSinglePlayer:
data = data['Data']['Player'] data = data['Data']['Player']
except IOError: except IOError:
logging.warning("Skipping bad player dat file %r", playerfile) LOG.warning("Skipping bad player dat file %r", playerfile)
continue continue
playername = playerfile.split(".")[0] playername = playerfile.split(".")[0]
if isSinglePlayer: if isSinglePlayer:
@@ -138,7 +141,7 @@ def main():
try: try:
config = mw_parser.get_validated_config() config = mw_parser.get_validated_config()
except Exception: 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 return 1
destdir = config['outputdir'] destdir = config['outputdir']
@@ -152,7 +155,7 @@ def main():
try: try:
worldpath = config['worlds'][render['world']] worldpath = config['worlds'][render['world']]
except KeyError: 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']) rname, render['world'])
return 1 return 1
render['worldname_orig'] = render['world'] render['worldname_orig'] = render['world']
@@ -167,7 +170,7 @@ def main():
rset = w.get_regionset(render['dimension'][1]) rset = w.get_regionset(render['dimension'][1])
if rset == None: # indicates no such dimension was found: 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 return 1
for f in render['markers']: for f in render['markers']:
@@ -190,8 +193,8 @@ def main():
handlePlayers(rset, render, worldpath) handlePlayers(rset, render, worldpath)
handleManual(rset, render['manualpois']) handleManual(rset, render['manualpois'])
logging.info("Done handling POIs") LOG.info("Done handling POIs")
logging.info("Writing out javascript files") LOG.info("Writing out javascript files")
markerSetDict = dict() markerSetDict = dict()
for (flter, rset) in markersets: for (flter, rset) in markersets:
# generate a unique name for this markerset. it will not be user visible # 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('markersDB.js');\n")
output.write("overviewer.util.injectMarkerScript('markers.js');\n") output.write("overviewer.util.injectMarkerScript('markers.js');\n")
output.write("overviewer.collections.haveSigns=true;\n") output.write("overviewer.collections.haveSigns=true;\n")
logging.info("Done") LOG.info("Done")
if __name__ == "__main__": if __name__ == "__main__":
main() main()

View File

@@ -21,7 +21,6 @@ attribute.
""" """
import functools import functools
import logging
import cPickle import cPickle
class LRUCache(object): class LRUCache(object):

View File

@@ -7,6 +7,9 @@ import traceback
import settingsDefinition import settingsDefinition
import settingsValidators import settingsValidators
LOG = logging.getLogger(__name__)
class MissingConfigException(Exception): class MissingConfigException(Exception):
"To be thrown when the config file can't be found" "To be thrown when the config file can't be found"
pass pass
@@ -83,14 +86,14 @@ class MultiWorldParser(object):
except Exception, ex: except Exception, ex:
if isinstance(ex, SyntaxError): if isinstance(ex, SyntaxError):
logging.error("Syntax error parsing %s" % settings_file) LOG.error("Syntax error parsing %s" % settings_file)
logging.error("The traceback below will tell you which line triggered the syntax error\n") LOG.error("The traceback below will tell you which line triggered the syntax error\n")
elif isinstance(ex, NameError): elif isinstance(ex, NameError):
logging.error("NameError parsing %s" % settings_file) LOG.error("NameError parsing %s" % settings_file)
logging.error("The traceback below will tell you which line referenced the non-existent variable\n") LOG.error("The traceback below will tell you which line referenced the non-existent variable\n")
else: else:
logging.error("Error parsing %s" % settings_file) LOG.error("Error parsing %s" % settings_file)
logging.error("The traceback below will tell you which line triggered the error\n") LOG.error("The traceback below will tell you which line triggered the error\n")
# skip the execfile part of the traceback # skip the execfile part of the traceback
exc_type, exc_value, exc_traceback = sys.exc_info() exc_type, exc_value, exc_traceback = sys.exc_info()
@@ -102,8 +105,8 @@ class MultiWorldParser(object):
else: else:
if "execfile" in l: print_rest = True if "execfile" in l: print_rest = True
# on windows, our traceback as no 'execfile'. in this case, print everything # on windows, our traceback as no 'execfile'. in this case, print everything
if print_rest: logging.error("Partial traceback:\n" + "\n".join(lines)) if print_rest: LOG.error("Partial traceback:\n" + "\n".join(lines))
else: logging.error("Partial traceback:\n" + "\n".join(formatted_lines)) else: LOG.error("Partial traceback:\n" + "\n".join(formatted_lines))
sys.exit(1) sys.exit(1)
# At this point, make a pass through the file to possibly set global # At this point, make a pass through the file to possibly set global

View File

@@ -20,6 +20,8 @@ import shutil
import logging import logging
import stat import stat
LOG = logging.getLogger(__name__)
## useful recursive copy, that ignores common OS cruft ## useful recursive copy, that ignores common OS cruft
def mirror_dir(src, dst, entities=None): def mirror_dir(src, dst, entities=None):
'''copies all of the entities from src to dst''' '''copies all of the entities from src to dst'''
@@ -104,7 +106,7 @@ if renameworks:
try: try:
os.remove(self.tmpname) os.remove(self.tmpname)
except Exception, e: 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 " "some cleanup first, but I couldn't remove "
"'%s'!", self.tmpname) "'%s'!", self.tmpname)
else: else:

View File

@@ -20,8 +20,8 @@ import platform
import ctypes import ctypes
from cStringIO import StringIO from cStringIO import StringIO
# Some cool code for colored logging: # Some cool code for colored logging: For background, add 40. For foreground,
# For background, add 40. For foreground, add 30 # add 30
BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE = range(8) BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE = range(8)
RESET_SEQ = "\033[0m" RESET_SEQ = "\033[0m"
@@ -277,6 +277,12 @@ def configure(loglevel=logging.INFO, verbose=False, simple=False):
logger = logging.getLogger('overviewer') logger = logging.getLogger('overviewer')
logger.setLevel(loglevel) 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: if not logger.handlers:
# No handlers have been configure yet... (probably the first call of # No handlers have been configure yet... (probably the first call of
# logger.configure) # logger.configure)
@@ -304,3 +310,5 @@ def configure(loglevel=logging.INFO, verbose=False, simple=False):
err_handler.setFormatter(errformatter) err_handler.setFormatter(errformatter)
logger.addHandler(out_handler) logger.addHandler(out_handler)
logger.addHandler(err_handler) logger.addHandler(err_handler)
core_logger.addHandler(out_handler)
core_logger.addHandler(err_handler)

View File

@@ -20,6 +20,8 @@ import sys
import os import os
import json import json
LOG = logging.getLogger(__name__)
class Observer(object): class Observer(object):
"""Base class that defines the observer interface. """Base class that defines the observer interface.
""" """
@@ -93,14 +95,14 @@ class LoggingObserver(Observer):
self.last_update = -101 self.last_update = -101
def finish(self): 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) self.get_max_value(), 100.0)
super(LoggingObserver, self).finish() super(LoggingObserver, self).finish()
def update(self, current_value): def update(self, current_value):
super(LoggingObserver, self).update(current_value) super(LoggingObserver, self).update(current_value)
if self._need_update(): 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_current_value(), self.get_max_value(),
self.get_percentage()) self.get_percentage())
self.last_update = current_value self.last_update = current_value
@@ -137,7 +139,7 @@ class ProgressBarObserver(progressbar.ProgressBar, Observer):
def start(self, max_value): def start(self, max_value):
self._set_max_value(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() super(ProgressBarObserver, self).start()
def is_started(self): def is_started(self):
@@ -147,7 +149,7 @@ class ProgressBarObserver(progressbar.ProgressBar, Observer):
self._end_time = time.time() self._end_time = time.time()
super(ProgressBarObserver, self).finish() super(ProgressBarObserver, self).finish()
self.fd.write('\n') self.fd.write('\n')
logging.info("Rendering complete!") LOG.info("Rendering complete!")
def update(self, current_value): def update(self, current_value):
if super(ProgressBarObserver, self).update(current_value): if super(ProgressBarObserver, self).update(current_value):

View File

@@ -29,6 +29,9 @@ import functools
import util import util
from c_overviewer import alpha_over from c_overviewer import alpha_over
LOG = logging.getLogger(__name__)
class TextureException(Exception): class TextureException(Exception):
"To be thrown when a texture is not found." "To be thrown when a texture is not found."
pass pass
@@ -141,7 +144,7 @@ class Textures(object):
'environment/'. '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, # a list of subdirectories to search for a given file,
# after the obvious '.' # after the obvious '.'
@@ -160,7 +163,7 @@ class Textures(object):
if os.path.isdir(self.find_file_local_path): if os.path.isdir(self.find_file_local_path):
path = search_dir(self.find_file_local_path) path = search_dir(self.find_file_local_path)
if 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) return open(path, mode)
elif os.path.isfile(self.find_file_local_path): elif os.path.isfile(self.find_file_local_path):
# Must be a resource pack. Look for the requested file within # 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 # pack.getinfo() will raise KeyError if the file is
# not found. # not found.
pack.getinfo(packfilename) 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) return pack.open(packfilename)
except (KeyError, IOError): except (KeyError, IOError):
pass pass
@@ -181,24 +184,24 @@ class Textures(object):
# If we haven't returned at this point, then the requested file was NOT # If we haven't returned at this point, then the requested file was NOT
# found in the user-specified texture path or resource pack. # 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 # Look in the location of the overviewer executable for the given path
programdir = util.get_program_path() programdir = util.get_program_path()
path = search_dir(programdir) path = search_dir(programdir)
if 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) return open(path, mode)
if sys.platform.startswith("darwin"): if sys.platform.startswith("darwin"):
path = search_dir("/Applications/Minecraft") path = search_dir("/Applications/Minecraft")
if 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) return open(path, mode)
if verbose: logging.info("Did not find the file in overviewer executable directory") if verbose: LOG.info("Did not find the file in overviewer executable directory")
if verbose: logging.info("Looking for installed minecraft jar files...") if verbose: LOG.info("Looking for installed minecraft jar files...")
# Find an installed minecraft client jar and look in it for the texture # Find an installed minecraft client jar and look in it for the texture
# file we need. # file we need.
@@ -215,7 +218,7 @@ class Textures(object):
try: try:
versions = os.listdir(versiondir) 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: except OSError:
# Directory doesn't exist? Ignore it. It will find no versions and # 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 # fall through the checks below to the error at the bottom of the
@@ -244,7 +247,7 @@ class Textures(object):
most_recent_version = versionparts most_recent_version = versionparts
if most_recent_version != [0,0,0]: 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) jarname = ".".join(str(x) for x in most_recent_version)
jarpath = os.path.join(versiondir, jarname, jarname + ".jar") jarpath = os.path.join(versiondir, jarname, jarname + ".jar")
@@ -254,14 +257,14 @@ class Textures(object):
for jarfilename in search_zip_paths: for jarfilename in search_zip_paths:
try: try:
jar.getinfo(jarfilename) 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) return jar.open(jarfilename)
except (KeyError, IOError), e: except (KeyError, IOError), e:
pass 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: 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 # 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 # 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 # 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 # believe that's not true, but we still have a few files distributed
# with overviewer. # 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")) path = search_dir(os.path.join(programdir, "overviewer_core", "data", "textures"))
if 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) return open(path, mode)
elif hasattr(sys, "frozen") or imp.is_frozen("__main__"): elif hasattr(sys, "frozen") or imp.is_frozen("__main__"):
# windows special case, when the package dir doesn't exist # windows special case, when the package dir doesn't exist
path = search_dir(os.path.join(programdir, "textures")) path = search_dir(os.path.join(programdir, "textures"))
if 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) 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 <http://docs.overviewer.org/en/latest/running/#installing-the-textures>\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)) 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 <http://docs.overviewer.org/en/latest/running/#installing-the-textures>\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: try:
lightcolor = list(self.load_image("light_normal.png").getdata()) lightcolor = list(self.load_image("light_normal.png").getdata())
except Exception: except Exception:
logging.warning("Light color image could not be found.") LOG.warning("Light color image could not be found.")
lightcolor = None lightcolor = None
self.lightcolor = lightcolor self.lightcolor = lightcolor
return lightcolor return lightcolor

View File

@@ -37,6 +37,10 @@ import rendermodes
import c_overviewer import c_overviewer
from c_overviewer import resize_half from c_overviewer import resize_half
LOG = logging.getLogger(__name__)
""" """
tileset.py contains the TileSet class, and in general, routines that manage a 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): if os.path.exists(self.outputdir):
# Somehow there's no config but the output dir DOES exist. # Somehow there's no config but the output dir DOES exist.
# That's strange! # That's strange!
logging.warning( LOG.warning(
"For render '%s' I couldn't find any persistent config, " "For render '%s' I couldn't find any persistent config, "
"but I did find my tile directory already exists. This " "but I did find my tile directory already exists. This "
"shouldn't normally happen, something may be up, but I " "shouldn't normally happen, something may be up, but I "
"think I can continue...", self.options['name']) "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 self.options['renderchecks'] = 1
else: else:
# This is the typical code path for an initial render, make # This is the typical code path for an initial render, make
# this a "forcerender" # this a "forcerender"
self.options['renderchecks'] = 2 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", " a full-render",
self.options['name']) self.options['name'])
elif not os.path.exists(self.outputdir): elif not os.path.exists(self.outputdir):
# Somehow the outputdir got erased but the metadata file is # Somehow the outputdir got erased but the metadata file is
# still there. That's strange! # still there. That's strange!
logging.warning( LOG.warning(
"This is strange. There is metadata for render '%s' but " "This is strange. There is metadata for render '%s' but "
"the output directory is missing. This shouldn't " "the output directory is missing. This shouldn't "
"normally happen. I guess we have no choice but to do a " "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): elif config.get("render_in_progress", False):
# The last render must have been interrupted. The default should be # The last render must have been interrupted. The default should be
# a check-tiles render then # a check-tiles render then
logging.warning( LOG.warning(
"The last render for '%s' didn't finish. I'll be " + "The last render for '%s' didn't finish. I'll be " +
"scanning all the tiles to make sure everything's up "+ "scanning all the tiles to make sure everything's up "+
"to date.", "to date.",
self.options['name'], 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 "+ "wildly) inaccurate, because I don't know how many "+
"tiles need rendering. I'll be checking them as I go") "tiles need rendering. I'll be checking them as I go")
self.options['renderchecks'] = 1 self.options['renderchecks'] = 1
else: 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", "Rendering tile whose chunks have changed since %s",
self.options['name'], self.options['name'],
time.strftime("%x %X", time.localtime(self.last_rendertime)), time.strftime("%x %X", time.localtime(self.last_rendertime)),
@@ -339,7 +343,7 @@ class TileSet(object):
if not os.path.exists(self.outputdir): if not os.path.exists(self.outputdir):
if self.options['renderchecks'] != 2: if self.options['renderchecks'] != 2:
logging.warning( LOG.warning(
"The tile directory didn't exist, but you have specified " "The tile directory didn't exist, but you have specified "
"explicitly not to do a --fullrender (which is the default for " "explicitly not to do a --fullrender (which is the default for "
"this situation). I'm overriding your decision and setting " "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 # This warning goes here so it's only shown once
if self.treedepth >= 15: 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) self.treedepth)
# Do any tile re-arranging if necessary. Skip if there was no config # 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. # The following block of code implementes the changelist functionality.
fd = self.options.get("changelist", None) fd = self.options.get("changelist", None)
if fd: 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() # This re-implements some of the logic from do_work()
def write_out(tilepath): def write_out(tilepath):
if len(tilepath) == self.treedepth: 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 # 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 # when we detect this it usually means the tree is actually empty
return 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'], self.options['name'],
curdepth, self.treedepth) curdepth, self.treedepth)
if self.treedepth != curdepth: if self.treedepth != curdepth:
if self.treedepth > curdepth: if self.treedepth > curdepth:
logging.warning("Your map seems to have expanded beyond its previous bounds.") LOG.warning("Your map seems to have expanded beyond its previous bounds.")
logging.warning( "Doing some tile re-arrangements... just a sec...") LOG.warning( "Doing some tile re-arrangements... just a sec...")
for _ in xrange(self.treedepth-curdepth): for _ in xrange(self.treedepth-curdepth):
self._increase_depth() self._increase_depth()
elif self.treedepth < curdepth: 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): for _ in xrange(curdepth - self.treedepth):
self._decrease_depth() self._decrease_depth()
logging.info( LOG.info(
"There done. I'm switching to --check-tiles mode for " "There done. I'm switching to --check-tiles mode for "
"this one render. This will make sure any old tiles that " "this one render. This will make sure any old tiles that "
"should no longer exist are deleted.") "should no longer exist are deleted.")
@@ -793,7 +797,7 @@ class TileSet(object):
dirty.add(tile.path) dirty.add(tile.path)
t = int(time.time()-stime) 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, self.options['name'], chunkcount, t,
"s" if t != 1 else "") "s" if t != 1 else "")
@@ -856,10 +860,10 @@ class TileSet(object):
# Ignore errors if it's "file doesn't exist" # Ignore errors if it's "file doesn't exist"
if e.errno != errno.ENOENT: if e.errno != errno.ENOENT:
raise 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 return
#logging.debug("writing out compositetile {0}".format(imgpath)) #LOG.debug("writing out compositetile {0}".format(imgpath))
# Create the actual image now # Create the actual image now
img = Image.new("RGBA", (384, 384), self.options['bgcolor']) img = Image.new("RGBA", (384, 384), self.options['bgcolor'])
@@ -876,12 +880,12 @@ class TileSet(object):
resize_half(quad, src) resize_half(quad, src)
img.paste(quad, path[0]) img.paste(quad, path[0])
except Exception, e: except Exception, e:
logging.warning("Couldn't open %s. It may be corrupt. Error was '%s'", path[1], e) LOG.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("I'm going to try and delete it. You will need to run the render again and with --check-tiles")
try: try:
os.unlink(path[1]) os.unlink(path[1])
except Exception, e: 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 # Save it
with FileReplacer(imgpath) as tmppath: with FileReplacer(imgpath) as tmppath:
@@ -917,7 +921,7 @@ class TileSet(object):
if not chunks: if not chunks:
# No chunks were found in this tile # 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: try:
os.unlink(imgpath) os.unlink(imgpath)
except OSError, e: except OSError, e:
@@ -925,7 +929,7 @@ class TileSet(object):
if e.errno != errno.ENOENT: if e.errno != errno.ENOENT:
raise raise
else: else:
logging.debug("%s deleted", tile) LOG.debug("%s deleted", tile)
return return
# Create the directory if not exists # Create the directory if not exists
@@ -940,7 +944,7 @@ class TileSet(object):
if e.errno != errno.EEXIST: if e.errno != errno.EEXIST:
raise raise
#logging.debug("writing out worldtile {0}".format(imgpath)) #LOG.debug("writing out worldtile {0}".format(imgpath))
# Compile this image # Compile this image
tileimg = Image.new("RGBA", (384, 384), self.options['bgcolor']) tileimg = Image.new("RGBA", (384, 384), self.options['bgcolor'])
@@ -965,10 +969,10 @@ class TileSet(object):
except nbt.CorruptionError: except nbt.CorruptionError:
# A warning and traceback was already printed by world.py's # A warning and traceback was already printed by world.py's
# get_chunk() # 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: except Exception, e:
logging.error("Could not render chunk %s,%s for some reason. This is likely a render primitive option error.", chunkx, chunkz) LOG.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("Full error was:", exc_info=1)
sys.exit(1) sys.exit(1)
## Semi-handy routine for debugging the drawing routine ## 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)) max_chunk_mtime = max(c[5] for c in get_chunks_by_tile(tileobj, self.regionset))
except ValueError: except ValueError:
# max got an empty sequence! something went horribly wrong # 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 max_chunk_mtime = 0
if tile_mtime > 120 + max_chunk_mtime: if tile_mtime > 120 + max_chunk_mtime:
# If a tile has been modified more recently than any of its # If a tile has been modified more recently than any of its
# chunks, then this could indicate a potential issue with # chunks, then this could indicate a potential issue with
# this or future renders. # this or future renders.
logging.warning( LOG.warning(
"I found a tile with a more recent modification time " "I found a tile with a more recent modification time "
"than any of its chunks. This can happen when a tile has " "than any of its chunks. This can happen when a tile has "
"been modified with an outside program, or by a copy " "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 " "preserve the mtimes Overviewer sets. Please see our FAQ "
"page on docs.overviewer.org or ask us in IRC for more " "page on docs.overviewer.org or ask us in IRC for more "
"information") "information")
logging.warning("Tile was: %s", imgpath) LOG.warning("Tile was: %s", imgpath)
if max_chunk_mtime > tile_mtime: if max_chunk_mtime > tile_mtime:
# chunks have a more recent mtime than the tile. Render the tile # chunks have a more recent mtime than the tile. Render the tile
@@ -1114,7 +1118,7 @@ class TileSet(object):
# Check this tile's mtime # Check this tile's mtime
imgpath = os.path.join(self.outputdir, *(str(x) for x in path)) imgpath = os.path.join(self.outputdir, *(str(x) for x in path))
imgpath += "." + self.imgextension imgpath += "." + self.imgextension
logging.debug("Testing mtime for composite-tile %s", imgpath) LOG.debug("Testing mtime for composite-tile %s", imgpath)
try: try:
tile_mtime = os.stat(imgpath)[stat.ST_MTIME] tile_mtime = os.stat(imgpath)[stat.ST_MTIME]
except OSError, e: except OSError, e:
@@ -1142,17 +1146,17 @@ class TileSet(object):
if os.path.exists(imgpath): if os.path.exists(imgpath):
# No need to catch ENOENT since this is only called from the # No need to catch ENOENT since this is only called from the
# master process # 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) os.remove(imgpath)
else: else:
# path referrs to a composite tile, and by extension a directory # path referrs to a composite tile, and by extension a directory
dirpath = os.path.join(self.outputdir, *(str(x) for x in path)) dirpath = os.path.join(self.outputdir, *(str(x) for x in path))
imgpath = dirpath + "." + self.imgextension imgpath = dirpath + "." + self.imgextension
if os.path.exists(imgpath): 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) os.remove(imgpath)
if os.path.exists(dirpath): 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) shutil.rmtree(dirpath)
## ##

View File

@@ -27,6 +27,8 @@ import numpy
from . import nbt from . import nbt
from . import cache from . import cache
LOG = logging.getLogger(__name__)
""" """
This module has routines for extracting information about available worlds This module has routines for extracting information about available worlds
@@ -49,7 +51,7 @@ def log_other_exceptions(func):
except ChunkDoesntExist: except ChunkDoesntExist:
raise raise
except Exception, e: except Exception, e:
logging.exception("%s raised this exception", func.func_name) LOG.exception("%s raised this exception", func.func_name)
raise raise
return newfunc return newfunc
@@ -104,7 +106,7 @@ class World(object):
# Hard-code this to only work with format version 19133, "Anvil" # Hard-code this to only work with format version 19133, "Anvil"
if not ('version' in data and data['version'] == 19133): 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) 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. # This isn't much data, around 15 keys and values for vanilla worlds.
@@ -153,7 +155,7 @@ class World(object):
return self.regionsets[index] return self.regionsets[index]
else: # assume a get_type() value else: # assume a get_type() value
candids = [x for x in self.regionsets if x.get_type() == index] 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: if len(candids) > 0:
return candids[0] return candids[0]
else: else:
@@ -249,8 +251,8 @@ class RegionSet(object):
""" """
self.regiondir = os.path.normpath(regiondir) self.regiondir = os.path.normpath(regiondir)
self.rel = os.path.normpath(rel) self.rel = os.path.normpath(rel)
logging.debug("regiondir is %r" % self.regiondir) LOG.debug("regiondir is %r" % self.regiondir)
logging.debug("rel is %r" % self.rel) LOG.debug("rel is %r" % self.rel)
# we want to get rid of /regions, if it exists # we want to get rid of /regions, if it exists
if self.rel.endswith(os.path.normpath("/region")): if self.rel.endswith(os.path.normpath("/region")):
@@ -259,10 +261,10 @@ class RegionSet(object):
# this is the main world # this is the main world
self.type = None self.type = None
else: else:
logging.warning("Unkown region type in %r", regiondir) LOG.warning("Unkown region type in %r", regiondir)
self.type = "__unknown" 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 # This is populated below. It is a mapping from (x,y) region coords to filename
self.regionfiles = {} self.regionfiles = {}
@@ -275,7 +277,7 @@ class RegionSet(object):
self.regionfiles[(x,y)] = regionfile self.regionfiles[(x,y)] = regionfile
self.empty_chunk = [None,None] self.empty_chunk = [None,None]
logging.debug("Done scanning regions") LOG.debug("Done scanning regions")
# Re-initialize upon unpickling # Re-initialize upon unpickling
def __getstate__(self): def __getstate__(self):
@@ -349,22 +351,22 @@ class RegionSet(object):
if tries > 0: if tries > 0:
# Flush the region cache to possibly read a new region file # Flush the region cache to possibly read a new region file
# header # header
logging.debug("Encountered a corrupt chunk at %s,%s. Flushing cache and retrying", x, z) LOG.debug("Encountered a corrupt chunk at %s,%s. Flushing cache and retrying", x, z)
#logging.debug("Error was:", exc_info=1) #LOG.debug("Error was:", exc_info=1)
del self.regioncache[regionfile] del self.regioncache[regionfile]
time.sleep(0.5) time.sleep(0.5)
continue continue
else: else:
if isinstance(e, nbt.CorruptRegionError): 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) x, z,x//32,z//32)
elif isinstance(e, nbt.CorruptChunkError): 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) x, z)
else: 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) 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 # Let this exception propagate out through the C code into
# tileset.py, where it is caught and gracefully continues # tileset.py, where it is caught and gracefully continues
# with the next chunk # with the next chunk
@@ -454,7 +456,7 @@ class RegionSet(object):
try: try:
mcr = self._get_regionobj(regionfile) mcr = self._get_regionobj(regionfile)
except nbt.CorruptRegionError: 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 continue
for chunkx, chunky in mcr.get_chunks(): for chunkx, chunky in mcr.get_chunks():
yield chunkx+32*regionx, chunky+32*regiony, mcr.get_chunk_timestamp(chunkx, chunky) yield chunkx+32*regionx, chunky+32*regiony, mcr.get_chunk_timestamp(chunkx, chunky)
@@ -472,7 +474,7 @@ class RegionSet(object):
try: try:
data = self._get_regionobj(regionfile) data = self._get_regionobj(regionfile)
except nbt.CorruptRegionError: 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) x,z, x//32,z//32)
return None return None
if data.chunk_exists(x,z): if data.chunk_exists(x,z):
@@ -493,7 +495,7 @@ class RegionSet(object):
Returns (regionx, regiony, filename)""" 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): for f in os.listdir(self.regiondir):
if re.match(r"^r\.-?\d+\.-?\d+\.mca$", f): if re.match(r"^r\.-?\d+\.-?\d+\.mca$", f):
@@ -501,7 +503,7 @@ class RegionSet(object):
x = int(p[1]) x = int(p[1])
y = int(p[2]) y = int(p[2])
if abs(x) > 500000 or abs(y) > 500000: 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)) yield (x, y, os.path.join(self.regiondir, f))
class RegionSetWrapper(object): class RegionSetWrapper(object):
@@ -674,7 +676,7 @@ class CachedRegionSet(RegionSetWrapper):
except AttributeError: except AttributeError:
s += repr(obj) 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() s = hashlib.md5(s).hexdigest()