diff --git a/couchpotato/runner.py b/couchpotato/runner.py index 31a8ce32..47c66590 100644 --- a/couchpotato/runner.py +++ b/couchpotato/runner.py @@ -1,9 +1,9 @@ from argparse import ArgumentParser +from cloghandler.cloghandler import ConcurrentRotatingFileHandler from couchpotato import web from couchpotato.api import api, NonBlockHandler from couchpotato.core.event import fireEventAsync, fireEvent from couchpotato.core.helpers.variable import getDataDir, tryInt -from logging import handlers from tornado import autoreload from tornado.httpserver import HTTPServer from tornado.ioloop import IOLoop @@ -156,7 +156,7 @@ def runCouchPotato(options, base_path, args, data_dir = None, log_dir = None, En logger.addHandler(hdlr) # To file - hdlr2 = handlers.RotatingFileHandler(Env.get('log_path'), 'a', 500000, 10) + hdlr2 = ConcurrentRotatingFileHandler(Env.get('log_path'), 'a', 500000, 10) hdlr2.setFormatter(formatter) logger.addHandler(hdlr2) diff --git a/libs/cloghandler/__init__.py b/libs/cloghandler/__init__.py new file mode 100644 index 00000000..e69de29b diff --git a/libs/cloghandler/cloghandler.py b/libs/cloghandler/cloghandler.py new file mode 100644 index 00000000..50debe3f --- /dev/null +++ b/libs/cloghandler/cloghandler.py @@ -0,0 +1,326 @@ +# Copyright 2008 Lowell Alleman +# +# Licensed under the Apache License, Version 2.0 (the "License"); you may not +# use this file except in compliance with the License. You may obtain a copy +# of the License at http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT +# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the +# License for the specific language governing permissions and limitations +# under the License. +""" cloghandler.py: A smart replacement for the standard RotatingFileHandler + +ConcurrentRotatingFileHandler: This class is a log handler which is a drop-in +replacement for the python standard log handler 'RotateFileHandler', the primary +difference being that this handler will continue to write to the same file if +the file cannot be rotated for some reason, whereas the RotatingFileHandler will +strictly adhere to the maximum file size. Unfortunately, if you are using the +RotatingFileHandler on Windows, you will find that once an attempted rotation +fails, all subsequent log messages are dropped. The other major advantage of +this module is that multiple processes can safely write to a single log file. + +To put it another way: This module's top priority is preserving your log +records, whereas the standard library attempts to limit disk usage, which can +potentially drop log messages. If you are trying to determine which module to +use, there are number of considerations: What is most important: strict disk +space usage or preservation of log messages? What OSes are you supporting? Can +you afford to have processes blocked by file locks? + +Concurrent access is handled by using file locks, which should ensure that log +messages are not dropped or clobbered. This means that a file lock is acquired +and released for every log message that is written to disk. (On Windows, you may +also run into a temporary situation where the log file must be opened and closed +for each log message.) This can have potentially performance implications. In my +testing, performance was more than adequate, but if you need a high-volume or +low-latency solution, I suggest you look elsewhere. + +This module currently only support the 'nt' and 'posix' platforms due to the +usage of the portalocker module. I do not have access to any other platforms +for testing, patches are welcome. + +See the README file for an example usage of this module. + +""" + + +__version__ = "$Id: cloghandler.py 6175 2009-11-02 18:40:35Z lowell $" +__author__ = "Lowell Alleman" +__all__ = [ + "ConcurrentRotatingFileHandler", +] + + +import os +import sys +from random import randint +from logging import Handler +from logging.handlers import BaseRotatingHandler + +try: + import codecs +except ImportError: + codecs = None + + + +# Question/TODO: Should we have a fallback mode if we can't load portalocker / +# we should still be better off than with the standard RotattingFileHandler +# class, right? We do some rename checking... that should prevent some file +# clobbering that the builtin class allows. + +# sibling module than handles all the ugly platform-specific details of file locking +from portalocker import lock, unlock, LOCK_EX, LOCK_NB, LockException + + +# A client can set this to true to automatically convert relative paths to +# absolute paths (which will also hide the absolute path warnings) +FORCE_ABSOLUTE_PATH = False + + +class ConcurrentRotatingFileHandler(BaseRotatingHandler): + """ + Handler for logging to a set of files, which switches from one file to the + next when the current file reaches a certain size. Multiple processes can + write to the log file concurrently, but this may mean that the file will + exceed the given size. + """ + def __init__(self, filename, mode='a', maxBytes=0, backupCount=0, + encoding=None, debug=True, supress_abs_warn=False): + """ + Open the specified file and use it as the stream for logging. + + By default, the file grows indefinitely. You can specify particular + values of maxBytes and backupCount to allow the file to rollover at + a predetermined size. + + Rollover occurs whenever the current log file is nearly maxBytes in + length. If backupCount is >= 1, the system will successively create + new files with the same pathname as the base file, but with extensions + ".1", ".2" etc. appended to it. For example, with a backupCount of 5 + and a base file name of "app.log", you would get "app.log", + "app.log.1", "app.log.2", ... through to "app.log.5". The file being + written to is always "app.log" - when it gets filled up, it is closed + and renamed to "app.log.1", and if files "app.log.1", "app.log.2" etc. + exist, then they are renamed to "app.log.2", "app.log.3" etc. + respectively. + + If maxBytes is zero, rollover never occurs. + + On Windows, it is not possible to rename a file that is currently opened + by another process. This means that it is not possible to rotate the + log files if multiple processes is using the same log file. In this + case, the current log file will continue to grow until the rotation can + be completed successfully. In order for rotation to be possible, all of + the other processes need to close the file first. A mechanism, called + "degraded" mode, has been created for this scenario. In degraded mode, + the log file is closed after each log message is written. So once all + processes have entered degraded mode, the next rotate log attempt should + be successful and then normal logging can be resumed. + + This log handler assumes that all concurrent processes logging to a + single file will are using only this class, and that the exact same + parameters are provided to each instance of this class. If, for + example, two different processes are using this class, but with + different values for 'maxBytes' or 'backupCount', then odd behavior is + expected. The same is true if this class is used by one application, but + the RotatingFileHandler is used by another. + + NOTE: You should always provide 'filename' as an absolute path, since + this class will need to re-open the file during rotation. If your + application call os.chdir() then subsequent log files could be created + in the wrong directory. + """ + # The question of absolute paths: I'm not sure what the 'right thing' is + # to do here. RotatingFileHander simply ignores this possibility. I was + # going call os.path.abspath(), but that potentially limits uses. For + # example, on Linux (any posix system?) you can rename a directory of a + # running app, and the app wouldn't notice as long as it only opens new + # files using relative paths. But since that's not a "normal" thing to + # do, and having an app call os.chdir() is a much more likely scenario + # that should be supported. For the moment, we are just going to warn + # the user if they provide a relative path and do some other voodoo + # logic that you'll just have to review for yourself. + + # if the given filename contains no path, we make an absolute path + if not os.path.isabs(filename): + if FORCE_ABSOLUTE_PATH or \ + not os.path.split(filename)[0]: + filename = os.path.abspath(filename) + elif not supress_abs_warn: + from warnings import warn + warn("The given 'filename' should be an absolute path. If your " + "application calls os.chdir(), your logs may get messed up. " + "Use 'supress_abs_warn=True' to hide this message.") + try: + BaseRotatingHandler.__init__(self, filename, mode, encoding) + except TypeError: # Due to a different logging release without encoding support (Python 2.4.1 and earlier?) + BaseRotatingHandler.__init__(self, filename, mode) + self.encoding = encoding + + self._rotateFailed = False + self.maxBytes = maxBytes + self.backupCount = backupCount + # Prevent multiple extensions on the lock file (Only handles the normal "*.log" case.) + if filename.endswith(".log"): + lock_file = filename[:-4] + else: + lock_file = filename + self.stream_lock = open(lock_file + ".lock", "w") + + # For debug mode, swap out the "_degrade()" method with a more a verbose one. + if debug: + self._degrade = self._degrade_debug + + def _openFile(self, mode): + if self.encoding: + self.stream = codecs.open(self.baseFilename, mode, self.encoding) + else: + self.stream = open(self.baseFilename, mode) + + def acquire(self): + """ Acquire thread and file locks. Also re-opening log file when running + in 'degraded' mode. """ + # handle thread lock + Handler.acquire(self) + lock(self.stream_lock, LOCK_EX) + if self.stream.closed: + self._openFile(self.mode) + + def release(self): + """ Release file and thread locks. Flush stream and take care of closing + stream in 'degraded' mode. """ + try: + self.stream.flush() + if self._rotateFailed: + self.stream.close() + finally: + try: + unlock(self.stream_lock) + finally: + # release thread lock + Handler.release(self) + + def close(self): + """ + Closes the stream. + """ + if not self.stream.closed: + self.stream.flush() + self.stream.close() + Handler.close(self) + + def flush(self): + """ flush(): Do nothing. + + Since a flush is issued in release(), we don't do it here. To do a flush + here, it would be necessary to re-lock everything, and it is just easier + and cleaner to do it all in release(), rather than requiring two lock + ops per handle() call. + + Doing a flush() here would also introduces a window of opportunity for + another process to write to the log file in between calling + stream.write() and stream.flush(), which seems like a bad thing. """ + pass + + def _degrade(self, degrade, msg, *args): + """ Set degrade mode or not. Ignore msg. """ + self._rotateFailed = degrade + del msg, args # avoid pychecker warnings + + def _degrade_debug(self, degrade, msg, *args): + """ A more colorful version of _degade(). (This is enabled by passing + "debug=True" at initialization). + """ + if degrade: + if not self._rotateFailed: + sys.stderr.write("Degrade mode - ENTERING - (pid=%d) %s\n" % + (os.getpid(), msg % args)) + self._rotateFailed = True + else: + if self._rotateFailed: + sys.stderr.write("Degrade mode - EXITING - (pid=%d) %s\n" % + (os.getpid(), msg % args)) + self._rotateFailed = False + + def doRollover(self): + """ + Do a rollover, as described in __init__(). + """ + if self.backupCount <= 0: + # Don't keep any backups, just overwrite the existing backup file + # Locking doesn't much matter here; since we are overwriting it anyway + self.stream.close() + self._openFile("w") + return + self.stream.close() + try: + # Attempt to rename logfile to tempname: There is a slight race-condition here, but it seems unavoidable + tmpname = None + while not tmpname or os.path.exists(tmpname): + tmpname = "%s.rotate.%08d" % (self.baseFilename, randint(0,99999999)) + try: + # Do a rename test to determine if we can successfully rename the log file + os.rename(self.baseFilename, tmpname) + except (IOError, OSError): + exc_value = sys.exc_info()[1] + self._degrade(True, "rename failed. File in use? " + "exception=%s", exc_value) + return + + # Q: Is there some way to protect this code from a KeboardInterupt? + # This isn't necessarily a data loss issue, but it certainly would + # break the rotation process during my stress testing. + + # There is currently no mechanism in place to handle the situation + # where one of these log files cannot be renamed. (Example, user + # opens "logfile.3" in notepad) + for i in range(self.backupCount - 1, 0, -1): + sfn = "%s.%d" % (self.baseFilename, i) + dfn = "%s.%d" % (self.baseFilename, i + 1) + if os.path.exists(sfn): + #print "%s -> %s" % (sfn, dfn) + if os.path.exists(dfn): + os.remove(dfn) + os.rename(sfn, dfn) + dfn = self.baseFilename + ".1" + if os.path.exists(dfn): + os.remove(dfn) + os.rename(tmpname, dfn) + #print "%s -> %s" % (self.baseFilename, dfn) + self._degrade(False, "Rotation completed") + finally: + self._openFile(self.mode) + + def shouldRollover(self, record): + """ + Determine if rollover should occur. + + For those that are keeping track. This differs from the standard + library's RotatingLogHandler class. Because there is no promise to keep + the file size under maxBytes we ignore the length of the current record. + """ + del record # avoid pychecker warnings + if self._shouldRollover(): + # if some other process already did the rollover we might + # checked log.1, so we reopen the stream and check again on + # the right log file + self.stream.close() + self._openFile(self.mode) + return self._shouldRollover() + return False + + def _shouldRollover(self): + if self.maxBytes > 0: # are we rolling over? + self.stream.seek(0, 2) #due to non-posix-compliant Windows feature + if self.stream.tell() >= self.maxBytes: + return True + else: + self._degrade(False, "Rotation done or not needed at this time") + return False + + +# Publish this class to the "logging.handlers" module so that it can be use +# from a logging config file via logging.config.fileConfig(). +import logging.handlers +logging.handlers.ConcurrentRotatingFileHandler = ConcurrentRotatingFileHandler diff --git a/libs/cloghandler/portalocker.py b/libs/cloghandler/portalocker.py new file mode 100644 index 00000000..67a01b63 --- /dev/null +++ b/libs/cloghandler/portalocker.py @@ -0,0 +1,158 @@ +# portalocker.py - Cross-platform (posix/nt) API for flock-style file locking. +# Requires python 1.5.2 or better. +"""Cross-platform (posix/nt) API for flock-style file locking. + +Synopsis: + + import portalocker + file = open("somefile", "r+") + portalocker.lock(file, portalocker.LOCK_EX) + file.seek(12) + file.write("foo") + file.close() + +If you know what you're doing, you may choose to + + portalocker.unlock(file) + +before closing the file, but why? + +Methods: + + lock( file, flags ) + unlock( file ) + +Constants: + + LOCK_EX + LOCK_SH + LOCK_NB + +Exceptions: + + LockException + +Notes: + +For the 'nt' platform, this module requires the Python Extensions for Windows. +Be aware that this may not work as expected on Windows 95/98/ME. + +History: + +I learned the win32 technique for locking files from sample code +provided by John Nielsen in the documentation +that accompanies the win32 modules. + +Author: Jonathan Feinberg , + Lowell Alleman +Version: $Id: portalocker.py 5488 2008-05-21 20:49:38Z lowell $ + + +http://aspn.activestate.com/ASPN/Cookbook/Python/Recipe/65203 +""" + + +__all__ = [ + "lock", + "unlock", + "LOCK_EX", + "LOCK_SH", + "LOCK_NB", + "LockException", +] + +import os +from types import IntType + +class LockException(Exception): + # Error codes: + LOCK_FAILED = 1 + +if os.name == 'nt': + import win32con + import win32file + import pywintypes + LOCK_EX = win32con.LOCKFILE_EXCLUSIVE_LOCK + LOCK_SH = 0 # the default + LOCK_NB = win32con.LOCKFILE_FAIL_IMMEDIATELY + # is there any reason not to reuse the following structure? + __overlapped = pywintypes.OVERLAPPED() +elif os.name == 'posix': + import fcntl + LOCK_EX = fcntl.LOCK_EX + LOCK_SH = fcntl.LOCK_SH + LOCK_NB = fcntl.LOCK_NB +else: + raise RuntimeError, "PortaLocker only defined for nt and posix platforms" + + + +def _getfd(file): + """ Get a file-descriptor from a file object or file-descriptor. """ + if hasattr(file, "fileno"): + return file.fileno() + elif type(file) == IntType: + return file + else: + raise TypeError("File object or file descriptor required, but %s " + "was provided." % type(file)) + + +if os.name == 'nt': + def lock(file, flags): + hfile = win32file._get_osfhandle(_getfd(file)) + try: + win32file.LockFileEx(hfile, flags, 0, -0x10000, __overlapped) + except pywintypes.error, exc_value: + # error: (33, 'LockFileEx', 'The process cannot access the file because another process has locked a portion of the file.') + if exc_value[0] == 33: + raise LockException(LockException.LOCK_FAILED, exc_value[2]) + else: + # Q: Are there exceptions/codes we should be dealing with here? + raise + + def unlock(file): + hfile = win32file._get_osfhandle(_getfd(file)) + try: + win32file.UnlockFileEx(hfile, 0, -0x10000, __overlapped) + except pywintypes.error, exc_value: + if exc_value[0] == 158: + # error: (158, 'UnlockFileEx', 'The segment is already unlocked.') + # To match the 'posix' implementation, silently ignore this error + pass + else: + # Q: Are there exceptions/codes we should be dealing with here? + raise + +elif os.name == 'posix': + def lock(file, flags): + try: + fcntl.flock(_getfd(file), flags) + except IOError, exc_value: + # IOError: [Errno 11] Resource temporarily unavailable + if exc_value[0] == 11: + raise LockException(LockException.LOCK_FAILED, exc_value[1]) + else: + raise + + def unlock(file): + fcntl.flock(_getfd(file), fcntl.LOCK_UN) + + + +if __name__ == '__main__': + from time import time, strftime, localtime + import sys + import portalocker + + log = open('log.txt', "a+") + portalocker.lock(log, portalocker.LOCK_EX) + + timestamp = strftime("%m/%d/%Y %H:%M:%S\n", localtime(time())) + log.write( timestamp ) + + print "Wrote lines. Hit enter to release lock." + dummy = sys.stdin.readline() + + log.close() +