Merge pull request #7 from jakobj/enh/logging

Use logging module instead of warnings and manual prints

gymz-controller

@@ -7,17 +7,19 @@ Start threads for running an environment in an emulator and expose
 input/output/reward buffers via ZeroMQ.
 
 Usage:
-    gymz-controller <emulator> <config>
+    gymz-controller <emulator> <config> [--verbosity VERBOSITY]
     gymz-controller -h | --help
     gymz-controller --version
 
 Options:
     -h --help         Show this screen.
     --version         Show version.
+    -v --verbosity    Set logging verbosity level.
 """
 
 import docopt
 import json
+import logging
 import os
 import signal
 import threading
@@ -27,6 +29,13 @@ import gymz
 
 
 def run(args):
+
+    # set up logging
+    if args['--verbosity']:
+        logging.basicConfig(level=args['VERBOSITY'].upper())
+    else:
+        logging.basicConfig(level=logging.WARNING)
+
     # Load default configuration file
     config = gymz.misc.read_default_config()
 

gymz/env_runner_thread.py

@@ -1,13 +1,15 @@
 # -*- coding: utf-8 -*-
 
 import json
+import logging
 import os
 import threading
 import time
-import warnings
 
 from . import misc
 
+logger = logging.getLogger(__name__)
+
 
 class EnvRunnerThread(threading.Thread):
     """Runs the environment."""
@@ -33,7 +35,7 @@ def _init_reporting(self, config):
 
             if os.path.isfile(self._report_file):  # file already exists
                 if config['All']['overwrite_files']:
-                    warnings.warn('Report file already exists. Truncating.', RuntimeWarning)
+                    logger.warn('report file already exists, truncating')
                     with open(self._report_file, 'w') as f:  # clear file
                         json.dump({}, f)
                 else:
@@ -69,7 +71,7 @@ def run(self):
             t_start = time.time()
 
             if self.emu.done():
-                print('[info] EnvRunnerThread: reset')
+                logger.info('reset')
                 t_start_done = time.time()
 
                 if self._write_report and self._flush_report_interval is None:
@@ -82,7 +84,7 @@ def run(self):
                 self.emu.clear_output_buffer()
                 self.emu.clear_reward_buffer()
                 misc.sleep_remaining(t_start_done, self._inter_trial_duration,
-                                     'EnvRunnerThread: inter trial sleep time negative')
+                                     'inter trial sleep time negative', logger)
                 t_start = time.time()
 
                 # update buffers to reflect initial state of env
@@ -99,5 +101,5 @@ def run(self):
                 self._report()
 
             misc.sleep_remaining(t_start, self._update_interval,
-                                 'EnvRunnerThread: sleep time negative')
-        print('[INFO] EnvRunnerThread shutting down.')
+                                 'sleep time negative', logger)
+        logger.info('shutting down')

gymz/gym_wrapper.py

@@ -1,9 +1,9 @@
 # -*- coding: utf-8 -*-
 
+import logging
 import numpy as np
 import os
 import time
-import warnings
 
 import gym  # openai gym
 import gym.spaces
@@ -12,6 +12,8 @@
 from .wrapper_base import WrapperBase
 from . import messages
 
+logger = logging.getLogger(__name__)
+
 
 class GymWrapper(WrapperBase):
     """Wrapper for the OpenAI Gym toolkit"""
@@ -53,7 +55,7 @@ def load_env(self, env, *args, **kwargs):
             del kwargs['monitor_args']
 
             if not self._monitor and len(monitor_args) > 0:
-                warnings.warn('Monitoring not enabled but passing monitor arguments.', RuntimeWarning)
+                logger.warn('monitoring not enabled but passing monitor arguments')
 
         self._env = gym.make(env, *args, **kwargs)
         self._check_parameters()

gymz/misc.py

@@ -2,10 +2,10 @@
 
 import collections
 import json
+import logging
 import os
 import sys
 import time
-import warnings
 
 
 def read_default_config():
@@ -25,15 +25,16 @@ def recursively_update_dict(d, u):
     return d
 
 
-def sleep_remaining(t_start, t_total, msg=''):
+def sleep_remaining(t_start, t_total, msg='', logger=None):
     """Sleeps the remaining time from now to t_start + t_total."""
     t_end = time.time()
     if t_total > (t_end - t_start):
         time.sleep(t_total - (t_end - t_start))
     else:
-        with warnings.catch_warnings():
-            warnings.simplefilter('always')  # always show desyncing warnings
-            warnings.warn(msg, RuntimeWarning)
+        if logger:
+            logger.warn(msg)
+        else:
+            logging.warn(msg)
 
 
 class SignalHandler(object):
@@ -55,5 +56,8 @@ def __call__(self, signum, frame):
         for thread in self.threads:
             thread.join()
 
+        # Shutdown logging
+        logging.shutdown()
+
         # And exit the program
         sys.exit(0)

gymz/zmq_command_receiver_thread.py

@@ -1,10 +1,12 @@
 # -*- coding: utf-8 -*-
 
+import logging
 import threading
 import time
-import warnings
 import zmq
 
+logger = logging.getLogger(__name__)
+
 
 class ZMQCommandReceiverThread(threading.Thread):
     """Receives command via zmq socket."""
@@ -36,7 +38,7 @@ def _recv_command(self):
         self.command_buffer[0] = self.command_socket.recv_json()
         ts = time.time()
         if abs(ts - self.command_buffer[0][0]['ts']) > self._time_stamp_tolerance:
-            warnings.warn('CommandReceiverThread desynchronized.', RuntimeWarning)
+            logger.warn('thread desynchronized')
 
     def run(self):
         while not self.exit_event.is_set():
@@ -46,7 +48,7 @@ def run(self):
                 self._recv_command()
             except:
                 pass
-        print('[INFO] CommandReceiverThread shutting down.')
+        logger.info('shutting down')
 
     def done(self):
         return self.done_buffer[0]

gymz/zmq_observation_sender_thread.py

@@ -1,11 +1,14 @@
 # -*- coding: utf-8 -*-
 
+import logging
 import threading
 import time
 import zmq
 
 from . import misc
 
+logger = logging.getLogger(__name__)
+
 
 class ZMQObservationSenderThread(threading.Thread):
     """Sends observations via zmq sockets."""
@@ -39,8 +42,8 @@ def run(self):
         while not self.exit_event.is_set():
             t_start = time.time()
             self._send_output()
-            misc.sleep_remaining(t_start, self._update_interval, 'ObservationSenderThread: sleep time negative')
-        print('[INFO] ObservationSenderThread shutting down.')
+            misc.sleep_remaining(t_start, self._update_interval, 'sleep time negative', logger)
+        logger.info('shutting down')
 
     def done(self):
         return self.done_buffer[0]

gymz/zmq_reward_sender_thread.py

@@ -1,11 +1,14 @@
 # -*- coding: utf-8 -*-
 
+import logging
 import threading
 import time
 import zmq
 
 from . import misc
 
+logger = logging.getLogger(__name__)
+
 
 class ZMQRewardSenderThread(threading.Thread):
     """Sends rewards via zmq sockets."""
@@ -40,8 +43,8 @@ def run(self):
         while not self.exit_event.is_set():
             t_start = time.time()
             self._send()
-            misc.sleep_remaining(t_start, self._update_inteval, 'RewardSenderThread: sleep time negative')
-        print('[INFO] RewardSenderThread shutting down.')
+            misc.sleep_remaining(t_start, self._update_inteval, 'sleep time negative', logger)
+        logger.info('shutting down')
 
     def done(self):
         return self.done_buffer[0]