Merge branch 'kernel-logging' of https://github.com/omazapa/ipython into omazapa-kernel-logging

Fixed conflicts arising from updates to using session send instead of
directly accessing the sockets.

Conflicts:
	IPython/zmq/iostream.py
	IPython/zmq/ipkernel.py

IPython/zmq/iostream.py

@@ -1,3 +1,4 b''
+import logging
 import sys
 import time
 from cStringIO import StringIO
@@ -7,6 +8,13 b' from session import extract_header, Message'
 from IPython.utils import io
 
 #-----------------------------------------------------------------------------
+# Globals
+#-----------------------------------------------------------------------------
+
+# Module-level logger
+logger =  logging.getLogger(__name__)
+
+#-----------------------------------------------------------------------------
 # Stream classes
 #-----------------------------------------------------------------------------
 
@@ -15,7 +23,7 b' class OutStream(object):'
 
     # The time interval between automatic flushes, in seconds.
     flush_interval = 0.05
-
+    
     def __init__(self, session, pub_socket, name):
         self.session = session
         self.pub_socket = pub_socket
@@ -37,10 +45,10 b' class OutStream(object):'
             data = self._buffer.getvalue()
             if data:
                 content = {u'name':self.name, u'data':data}
-                msg = self.session.send(self.pub_socket, u'stream', content=content,
-                                       parent=self.parent_header)
-                io.raw_print(msg)
-                
+                msg = self.session.send(self.pub_socket, u'stream',
+                                        content=content,
+                                        parent=self.parent_header)
+                logger.debug(msg)
                 self._buffer.close()
                 self._new_buffer()
 

IPython/zmq/ipkernel.py

@@ -21,7 +21,7 b' import atexit'
 import sys
 import time
 import traceback
-
+import logging
 # System library imports.
 import zmq
 
@@ -38,6 +38,13 b' from session import Session, Message'
 from zmqshell import ZMQInteractiveShell
 
 #-----------------------------------------------------------------------------
+# Globals
+#-----------------------------------------------------------------------------
+
+# Module-level logger
+logger = logging.getLogger(__name__)
+
+#-----------------------------------------------------------------------------
 # Main kernel class
 #-----------------------------------------------------------------------------
 
@@ -79,7 +86,8 b' class Kernel(Configurable):'
     # This is a dict of port number that the kernel is listening on. It is set
     # by record_ports and used by connect_request.
     _recorded_ports = None
-    
+
+
     def __init__(self, **kwargs):
         super(Kernel, self).__init__(**kwargs)
 
@@ -121,21 +129,20 b' class Kernel(Configurable):'
         # easier to trace visually the message chain when debugging.  Each
         # handler prints its message at the end.
         # Eventually we'll move these from stdout to a logger.
-        io.raw_print('\n*** MESSAGE TYPE:', msg['msg_type'], '***')
-        io.raw_print('   Content: ', msg['content'],
-                     '\n   --->\n   ', sep='', end='')
+        logger.debug('\n*** MESSAGE TYPE:'+str(msg['msg_type'])+'***')
+        logger.debug('   Content: '+str(msg['content'])+'\n   --->\n   ')
 
         # Find and call actual handler for message
         handler = self.handlers.get(msg['msg_type'], None)
         if handler is None:
-            io.raw_print_err("UNKNOWN MESSAGE TYPE:", msg)
+            logger.error("UNKNOWN MESSAGE TYPE:" +str(msg))
         else:
             handler(ident, msg)
             
         # Check whether we should exit, in case the incoming message set the
         # exit flag on
         if self.shell.exit_now:
-            io.raw_print('\nExiting IPython kernel...')
+            logger.debug('\nExiting IPython kernel...')
             # We do a normal, clean exit, which allows any actions registered
             # via atexit (such as history saving) to take place.
             sys.exit(0)
@@ -183,8 +190,8 b' class Kernel(Configurable):'
             code = content[u'code']
             silent = content[u'silent'] 
         except:
-            io.raw_print_err("Got bad msg: ")
-            io.raw_print_err(Message(parent))
+            logger.error("Got bad msg: ")
+            logger.error(str(Message(parent)))
             return
 
         shell = self.shell # we'll need this a lot here
@@ -262,8 +269,9 b' class Kernel(Configurable):'
         shell.payload_manager.clear_payload()
 
         # Send the reply.
-        reply_msg = self.session.send(self.reply_socket, u'execute_reply', reply_content, parent, ident=ident)
-        io.raw_print(reply_msg)
+        reply_msg = self.session.send(self.reply_socket, u'execute_reply',
+                                      reply_content, parent, ident=ident)
+        logger.debug(str(reply_msg))
 
         # Flush output before sending the reply.
         sys.stdout.flush()
@@ -290,7 +298,7 b' class Kernel(Configurable):'
                    'status' : 'ok'}
         completion_msg = self.session.send(self.reply_socket, 'complete_reply',
                                            matches, parent, ident)
-        io.raw_print(completion_msg)
+        logger.debug(str(completion_msg))
 
     def object_info_request(self, ident, parent):
         object_info = self.shell.object_inspect(parent['content']['oname'])
@@ -298,7 +306,7 b' class Kernel(Configurable):'
         oinfo = json_clean(object_info)
         msg = self.session.send(self.reply_socket, 'object_info_reply',
                                 oinfo, parent, ident)
-        io.raw_print(msg)
+        logger.debug(msg)
 
     def history_request(self, ident, parent):
         output = parent['content']['output']
@@ -308,7 +316,7 b' class Kernel(Configurable):'
         content = {'history' : hist}
         msg = self.session.send(self.reply_socket, 'history_reply',
                                 content, parent, ident)
-        io.raw_print(msg)
+        logger.debug(str(msg))
 
     def connect_request(self, ident, parent):
         if self._recorded_ports is not None:
@@ -317,7 +325,7 b' class Kernel(Configurable):'
             content = {}
         msg = self.session.send(self.reply_socket, 'connect_reply',
                                 content, parent, ident)
-        io.raw_print(msg)
+        logger.debug(msg)
 
     def shutdown_request(self, ident, parent):
         self.shell.exit_now = True
@@ -336,12 +344,13 b' class Kernel(Configurable):'
             else:
                 assert ident is not None, \
                        "Unexpected missing message part."
-            io.raw_print("Aborting:\n", Message(msg))
+
+            logger.debug("Aborting:\n"+str(Message(msg)))
             msg_type = msg['msg_type']
             reply_type = msg_type.split('_')[0] + '_reply'
             reply_msg = self.session.send(self.reply_socket, reply_type, 
                     {'status' : 'aborted'}, msg, ident=ident)
-            io.raw_print(reply_msg)
+            logger.debug(reply_msg)
             # We need to wait a bit for requests to come in. This can probably
             # be set shorter for true asynchronous clients.
             time.sleep(0.1)
@@ -360,8 +369,8 b' class Kernel(Configurable):'
         try:
             value = reply['content']['value']
         except:
-            io.raw_print_err("Got bad raw_input reply: ")
-            io.raw_print_err(Message(parent))
+            logger.error("Got bad raw_input reply: ")
+            logger.error(str(Message(parent)))
             value = ''
         return value
     
@@ -415,7 +424,7 b' class Kernel(Configurable):'
         if self._shutdown_message is not None:
             self.session.send(self.reply_socket, self._shutdown_message)
             self.session.send(self.pub_socket, self._shutdown_message)
-            io.raw_print(self._shutdown_message)
+            logger.debug(str(self._shutdown_message))
             # A very short sleep to give zmq time to flush its message buffers
             # before Python truly shuts down.
             time.sleep(0.01)

IPython/zmq/kernelmanager.py

@@ -23,6 +23,7 b' import signal'
 import sys
 from threading import Thread
 import time
+import logging
 
 # System library imports.
 import zmq