Merge pull request #62 from Codaone/logging

Logging

dexbot/basestrategy.py

@@ -114,15 +114,18 @@ def __init__(
         # Settings for bitshares instance
         self.bitshares.bundle = bool(self.worker.get("bundle", False))
 
-        # disabled flag - this flag can be flipped to True by a worker and
+        # Disabled flag - this flag can be flipped to True by a worker and
         # will be reset to False after reset only
         self.disabled = False
 
-        # a private logger that adds worker identify data to the LogRecord
-        self.log = logging.LoggerAdapter(logging.getLogger('dexbot.per_worker'), {'worker_name': name,
-                                                                                  'account': self.worker['account'],
-                                                                                  'market': self.worker['market'],
-                                                                                  'is_disabled': lambda: self.disabled})
+        # A private logger that adds worker identify data to the LogRecord
+        self.log = logging.LoggerAdapter(
+            logging.getLogger('dexbot.per_worker'),
+            {'worker_name': name,
+             'account': self.worker['account'],
+             'market': self.worker['market'],
+             'is_disabled': lambda: self.disabled}
+        )
 
     @property
     def calculate_center_price(self):
@@ -257,6 +260,7 @@ def cancel_all(self):
         """ Cancel all orders of the worker's account
         """
         if self.orders:
+            self.log.info('Canceling all orders')
             return self.bitshares.cancel(
                 [o["id"] for o in self.orders],
                 account=self.account

dexbot/cli.py

@@ -1,22 +1,20 @@
 #!/usr/bin/env python3
 import logging
 import os
-import click
 import signal
 import sys
+
 from .ui import (
     verbose,
     chain,
     unlock,
-    configfile,
-    confirmwarning,
-    confirmalert,
-    warning,
-    alert,
+    configfile
 )
 from dexbot.worker import WorkerInfrastructure
 import dexbot.errors as errors
 
+import click
+
 log = logging.getLogger(__name__)
 
 logging.basicConfig(

dexbot/controllers/main_controller.py

@@ -1,3 +1,5 @@
+import logging
+
 from dexbot.worker import WorkerInfrastructure
 
 from ruamel.yaml import YAML
@@ -11,6 +13,15 @@ def __init__(self, bitshares_instance):
         set_shared_bitshares_instance(bitshares_instance)
         self.worker_manager = None
 
+        # Configure logging
+        formatter = logging.Formatter(
+            '%(asctime)s - %(worker_name)s using account %(account)s on %(market)s - %(levelname)s - %(message)s')
+        logger = logging.getLogger("dexbot.per_worker")
+        fh = logging.FileHandler('dexbot.log')
+        fh.setFormatter(formatter)
+        logger.addHandler(fh)
+        logger.setLevel(logging.INFO)
+
     def create_worker(self, worker_name, config, view):
         # Todo: Add some threading here so that the GUI doesn't freeze
         if self.worker_manager and self.worker_manager.is_alive():

dexbot/strategies/relative_orders.py

@@ -49,14 +49,14 @@ def error(self, *args, **kwargs):
         self.log.info(self.execute())
 
     def update_orders(self):
+        self.log.info('Change detected, updating orders')
         amount = self.target['amount']
 
         # Recalculate buy and sell order prices
         self.calculate_order_prices()
 
         # Cancel the orders before redoing them
         self.cancel_all()
-        self.log.info('An order was filled, canceling the orders')
 
         order_ids = []
 
@@ -74,7 +74,9 @@ def update_orders(self):
                 returnOrderId="head"
             )
             buy_order = self.get_order(buy_transaction['orderid'])
-            self.log.info('Placed a buy order for {} {} @ {}'.format(amount, self.market["quote"], self.buy_price))
+            self.log.info('Placed a buy order for {} {} @ {}'.format(amount,
+                                                                     self.market["quote"]['symbol'],
+                                                                     self.buy_price))
             if buy_order:
                 self['buy_order'] = buy_order
                 order_ids.append(buy_transaction['orderid'])
@@ -93,7 +95,9 @@ def update_orders(self):
                 returnOrderId="head"
             )
             sell_order = self.get_order(sell_transaction['orderid'])
-            self.log.info('Placed a sell order for {} {} @ {}'.format(amount, self.market["quote"], self.buy_price))
+            self.log.info('Placed a sell order for {} {} @ {}'.format(amount,
+                                                                      self.market["quote"]['symbol'],
+                                                                      self.sell_price))
             if sell_order:
                 self['sell_order'] = sell_order
                 order_ids.append(sell_transaction['orderid'])

dexbot/ui.py

@@ -1,10 +1,12 @@
 import os
-import click
 import logging
-from ruamel import yaml
 from functools import update_wrapper
+
+import click
+from ruamel import yaml
 from bitshares import BitShares
 from bitshares.instance import set_shared_bitshares_instance
+
 log = logging.getLogger(__name__)
 
 
@@ -14,25 +16,35 @@ def new_func(ctx, *args, **kwargs):
         verbosity = [
             "critical", "error", "warn", "info", "debug"
         ][int(min(ctx.obj.get("verbose", 0), 4))]
-        if ctx.obj.get("systemd",False):
-            # dont print the timestamps: systemd will log it for us
+        if ctx.obj.get("systemd", False):
+            # Don't print the timestamps: systemd will log it for us
             formatter1 = logging.Formatter('%(name)s - %(levelname)s - %(message)s')
-            formatter2 = logging.Formatter('Worker %(worker_name)s using account %(account)s on %(market)s - %(levelname)s - %(message)s')
+            formatter2 = logging.Formatter(
+                '%(worker_name)s using account %(account)s on %(market)s - %(levelname)s - %(message)s')
         elif verbosity == "debug":
-            # when debugging log where the log call came from
+            # When debugging: log where the log call came from
             formatter1 = logging.Formatter('%(asctime)s (%(module)s:%(lineno)d) - %(levelname)s - %(message)s')
-            formatter2 = logging.Formatter('%(asctime)s (%(module)s:%(lineno)d) - worker %(worker_name)s - %(levelname)s - %(message)s')
+            formatter2 = logging.Formatter(
+                '%(asctime)s (%(module)s:%(lineno)d) - %(worker_name)s - %(levelname)s - %(message)s')
         else:
             formatter1 = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
-            formatter2 = logging.Formatter('%(asctime)s - worker %(worker_name)s using account %(account)s on %(market)s - %(levelname)s - %(message)s')
+            formatter2 = logging.Formatter(
+                '%(asctime)s - %(worker_name)s using account %(account)s on %(market)s - %(levelname)s - %(message)s')
 
-        # use special format for special workers logger
+        # Use special format for special workers logger
+        logger = logging.getLogger("dexbot.per_worker")
         ch = logging.StreamHandler()
         ch.setLevel(getattr(logging, verbosity.upper()))
         ch.setFormatter(formatter2)
-        logging.getLogger("dexbot.per_worker").addHandler(ch)
-        logging.getLogger("dexbot.per_worker").propagate = False # don't double up with root logger
-        # set the root logger with basic format
+        logger.addHandler(ch)
+
+        # Logging to a file
+        fh = logging.FileHandler('dexbot.log')
+        fh.setFormatter(formatter2)
+        logger.addHandler(fh)
+
+        logger.propagate = False  # Don't double up with root logger
+        # Set the root logger with basic format
         ch = logging.StreamHandler()
         ch.setLevel(getattr(logging, verbosity.upper()))
         ch.setFormatter(formatter1)
@@ -44,17 +56,17 @@ def new_func(ctx, *args, **kwargs):
             verbosity = [
                 "critical", "error", "warn", "info", "debug"
             ][int(min(ctx.obj.get("verbose", 4) - 4, 4))]
-            log = logging.getLogger("grapheneapi")
-            log.setLevel(getattr(logging, verbosity.upper()))
-            log.addHandler(ch)
+            logger = logging.getLogger("grapheneapi")
+            logger.setLevel(getattr(logging, verbosity.upper()))
+            logger.addHandler(ch)
 
         if ctx.obj["verbose"] > 8:
             verbosity = [
                 "critical", "error", "warn", "info", "debug"
             ][int(min(ctx.obj.get("verbose", 8) - 8, 4))]
-            log = logging.getLogger("graphenebase")
-            log.setLevel(getattr(logging, verbosity.upper()))
-            log.addHandler(ch)
+            logger = logging.getLogger("graphenebase")
+            logger.setLevel(getattr(logging, verbosity.upper()))
+            logger.addHandler(ch)
 
         return ctx.invoke(f, *args, **kwargs)
     return update_wrapper(new_func, f)

dexbot/worker.py

@@ -179,7 +179,6 @@ def stop(self, worker_name=None):
             # Kill all of the workers
             for worker in self.workers:
                 self.workers[worker].cancel_all()
-            self.workers = None
             self.notify.websocket.close()
 
     def remove_worker(self, worker_name=None):