[project @ Arch-1:robey@lag.net--2003-public%secsh--dev--1.0--patch-149]

add thread ids to logs
add a logging filter that reports the thread-id of the logger, and use
that for all paramiko logging.  since thread-local stuff didn't appear
until python 2.4, i hacked up my own little version to assign incrementing
numbers to threads as they log.

paramiko/channel.py

@@ -82,7 +82,7 @@ class Channel (object):
         self.out_buffer_cv = threading.Condition(self.lock)
         self.status_event = threading.Event()
         self.name = str(chanid)
-        self.logger = logging.getLogger('paramiko.chan.' + str(chanid))
+        self.logger = util.get_logger('paramiko.chan.' + str(chanid))
         self.pipe_rfd = self.pipe_wfd = None
         self.event = threading.Event()
         self.combine_stderr = False
@@ -324,7 +324,7 @@ class Channel (object):
         @type name: str
         """
         self.name = name
-        self.logger = logging.getLogger(self.transport.get_log_channel() + '.' + self.name)
+        self.logger = util.get_logger(self.transport.get_log_channel() + '.' + self.name)
 
     def get_name(self):
         """
@@ -825,7 +825,7 @@ class Channel (object):
 
     def _set_transport(self, transport):
         self.transport = transport
-        self.logger = logging.getLogger(self.transport.get_log_channel() + '.' + self.name)
+        self.logger = util.get_logger(self.transport.get_log_channel() + '.' + self.name)
 
     def _set_window(self, window_size, max_packet_size):
         self.in_window_size = window_size

paramiko/sftp.py

@@ -93,7 +93,7 @@ class SFTPError (Exception):
 
 class BaseSFTP (object):
     def __init__(self):
-        self.logger = logging.getLogger('paramiko.sftp')
+        self.logger = util.get_logger('paramiko.sftp')
 
 
     ###  internals...

paramiko/sftp_client.py

@@ -51,7 +51,7 @@ class SFTPClient (BaseSFTP):
         if type(sock) is Channel:
             # override default logger
             transport = self.sock.get_transport()
-            self.logger = logging.getLogger(transport.get_log_channel() + '.' +
+            self.logger = util.get_logger(transport.get_log_channel() + '.' +
                                             self.sock.get_name() + '.sftp')
             self.ultra_debug = transport.ultra_debug
         self._send_version()

paramiko/sftp_server.py

@@ -58,7 +58,7 @@ class SFTPServer (BaseSFTP, SubsystemHandler):
         BaseSFTP.__init__(self)
         SubsystemHandler.__init__(self, channel, name)
         transport = channel.get_transport()
-        self.logger = logging.getLogger(transport.get_log_channel() + '.' +
+        self.logger = util.get_logger(transport.get_log_channel() + '.' +
                                         channel.get_name() + '.sftp')
         self.ultra_debug = transport.ultra_debug
         self.next_handle = 1

paramiko/transport.py

@@ -243,7 +243,7 @@ class BaseTransport (threading.Thread):
         self.saved_exception = None
         self.clear_to_send = threading.Event()
         self.log_name = 'paramiko.transport'
-        self.logger = logging.getLogger(self.log_name)
+        self.logger = util.get_logger(self.log_name)
         # used for noticing when to re-key:
         self.received_bytes = 0
         self.received_packets = 0
@@ -793,7 +793,7 @@ class BaseTransport (threading.Thread):
         @since: 1.1
         """
         self.log_name = name
-        self.logger = logging.getLogger(name)
+        self.logger = util.get_logger(name)
 
     def get_log_channel(self):
         """

paramiko/util.py

@@ -24,7 +24,7 @@ from __future__ import generators
 Useful functions used by the rest of paramiko.
 """
 
-import sys, struct, traceback
+import sys, struct, traceback, threading
 from common import *
 
 # Change by RogerB - python < 2.3 doesn't have enumerate so we implement it
@@ -188,6 +188,23 @@ def mod_inverse(x, m):
         u2 += m
     return u2
 
+g_thread_ids = {}
+g_thread_counter = 0
+g_thread_lock = threading.Lock()
+def get_thread_id():
+    global g_thread_ids, g_thread_counter
+    tid = id(threading.currentThread())
+    try:
+        return g_thread_ids[tid]
+    except KeyError:
+        g_thread_lock.acquire()
+        try:
+            g_thread_counter += 1
+            ret = g_thread_ids[tid] = g_thread_counter
+        finally:
+            g_thread_lock.release()
+        return ret
+
 def log_to_file(filename, level=DEBUG):
     "send paramiko logs to a logfile, if they're not already going somewhere"
     l = logging.getLogger("paramiko")
@@ -196,6 +213,15 @@ def log_to_file(filename, level=DEBUG):
     l.setLevel(level)
     f = open(filename, 'w')
     lh = logging.StreamHandler(f)
-    lh.setFormatter(logging.Formatter('%(levelname)-.3s [%(asctime)s] %(name)s: %(message)s',
+    lh.setFormatter(logging.Formatter('%(levelname)-.3s [%(asctime)s] thr=%(_threadid)-3d %(name)s: %(message)s',
                                       '%Y%m%d-%H:%M:%S'))
     l.addHandler(lh)
+
+def get_logger(name):
+    l = logging.getLogger(name)
+    class PFilter (object):
+        def filter(self, record):
+            record._threadid = get_thread_id()
+            return True
+    l.addFilter(PFilter())
+    return l