argparse & logging (#92)

* introduce logcommand.Lager, Whipper(); use argparse for whipper image commands, stub logging

* update Lager docstring to mention config.Config()

* make incorrect subcommand and --version work on toplevel command

* migrate accurip show, expand Lager, do not attempt to return from Lager.__init__.

* migrate offset find, add Lager.error

* correct offset find drive symlink handling

* migrate drive

* change Lager.__init__(prog) to arg from kwarg

* but actually

* remove Whipper.usage

* add and use Lager.device_option() context manager

* help I married an axe murderer

* use unified options namespace for entire command tree

* migrate whipper cd without comprehensive config loading

* switch to logging module

- use logging instead of flog for non-extern modules
- use WHIPPER_DEBUG and WHIPPER_LOGFILE env variables

* convert self.log calls to logger.debug

* convert self.error calls to logger.error

* remove log.Loggable, use logger not logging

* Logging conversion continues

- Convert log.* calls to logger.*
- Remove morituri.common.log imports

* remove morituri.common.log from tests

* remove extern/flog, bare minimum Debug conversion

* update README for logging changes

* update soxi to use logging

* refactor Lager for more declarative subcommands

* Refactor Lager.device_option:

- inline into __init__
- throw IOError instead of Exception for missing drives
- remove CommandError checking in rip/main

* rename rip to whipper in rip.main

* convert rip.debug commands

* Rename logcommand.Lager to command.BaseCommand

- remove command.CommandError occurrences
- remove python-command external module

* remove submodules from README, update rclog formatter

* update minor ambiguity in readme for command invocation

* update version number to match setup.py

* remove gitmodules

* update version number in tests as well (boo)

* convert logger.error to logger.critical

* Change morituri.rip to morituri.command

- mv common.command to command.basecommand
- move TEMPLATES used only by rip.cd out of rip.common
- update entry point for command to command.main

* update basecommand documentation

* go pyflaking: import fixing

* replace self.stdout with sys.stdout

* remove BaseCommand.config, alphabetise imports

* convert self.stdXXX leftovers

* convert last getRootCommand to config.Config

* convert last getExceptionMessage's to str

* change musicbrainz useragent to whipper

morituri/common/task.py

@@ -6,27 +6,29 @@ import signal
 import subprocess
 
 from morituri.extern import asyncsub
-from morituri.extern.log import log
 from morituri.extern.task import task, gstreamer
 
-# log.Loggable first to get logging
+import logging
+logger = logging.getLogger(__name__)
 
 
-class SyncRunner(log.Loggable, task.SyncRunner):
+class SyncRunner(task.SyncRunner):
     pass
 
 
-class LoggableTask(log.Loggable, task.Task):
-    pass
-
-class LoggableMultiSeparateTask(log.Loggable, task.MultiSeparateTask):
-    pass
-
-class GstPipelineTask(log.Loggable, gstreamer.GstPipelineTask):
+class LoggableTask(task.Task):
     pass
 
 
-class PopenTask(log.Loggable, task.Task):
+class LoggableMultiSeparateTask(task.MultiSeparateTask):
+    pass
+
+
+class GstPipelineTask(gstreamer.GstPipelineTask):
+    pass
+
+
+class PopenTask(task.Task):
     """
     I am a task that runs a command using Popen.
     """
@@ -51,7 +53,7 @@ class PopenTask(log.Loggable, task.Task):
 
             raise
 
-        self.debug('Started %r with pid %d', self.command,
+        logger.debug('Started %r with pid %d', self.command,
             self._popen.pid)
 
         self.schedule(1.0, self._read, runner)
@@ -63,14 +65,14 @@ class PopenTask(log.Loggable, task.Task):
             ret = self._popen.recv()
 
             if ret:
-                self.log("read from stdout: %s", ret)
+                logger.debug("read from stdout: %s", ret)
                 self.readbytesout(ret)
                 read = True
 
             ret = self._popen.recv_err()
 
             if ret:
-                self.log("read from stderr: %s", ret)
+                logger.debug("read from stderr: %s", ret)
                 self.readbyteserr(ret)
                 read = True
 
@@ -89,8 +91,7 @@ class PopenTask(log.Loggable, task.Task):
 
             self._done()
         except Exception, e:
-            self.debug('exception during _read()')
-            self.debug(log.getExceptionMessage(e))
+            logger.debug('exception during _read(): %r', str(e))
             self.setException(e)
             self.stop()
 
@@ -98,9 +99,9 @@ class PopenTask(log.Loggable, task.Task):
             assert self._popen.returncode is not None, "No returncode"
 
             if self._popen.returncode >= 0:
-                self.debug('Return code was %d', self._popen.returncode)
+                logger.debug('Return code was %d', self._popen.returncode)
             else:
-                self.debug('Terminated with signal %d',
+                logger.debug('Terminated with signal %d',
                     -self._popen.returncode)
 
             self.setProgress(1.0)
@@ -114,7 +115,7 @@ class PopenTask(log.Loggable, task.Task):
             return
 
     def abort(self):
-        self.debug('Aborting, sending SIGTERM to %d', self._popen.pid)
+        logger.debug('Aborting, sending SIGTERM to %d', self._popen.pid)
         os.kill(self._popen.pid, signal.SIGTERM)
         # self.stop()