Fixing debug calls to be lazy when debug is off.

6 files changed, 93 insertions, 101 deletions

diff --git a/tftpy/TftpClient.py b/tftpy/TftpClient.py
index f84d801..a935b34 100644
--- a/tftpy/TftpClient.py
+++ b/tftpy/TftpClient.py
@@ -38,10 +38,10 @@ class TftpClient(TftpSession):
         Note: If output is a hyphen, stdout is used."""
         # We're downloading.
         log.debug("Creating download context with the following params:")
-        log.debug("host = %s, port = %s, filename = %s, output = %s"
-            % (self.host, self.iport, filename, output))
-        log.debug("options = %s, packethook = %s, timeout = %s"
-            % (self.options, packethook, timeout))
+        log.debug("host = %s, port = %s, filename = %s, output = %s",
+            self.host, self.iport, filename, output)
+        log.debug("options = %s, packethook = %s, timeout = %s",
+            self.options, packethook, timeout)
         self.context = TftpContextClientDownload(self.host,
                                                  self.iport,
                                                  filename,
diff --git a/tftpy/TftpContexts.py b/tftpy/TftpContexts.py
index b24ea37..eed1cd1 100644
--- a/tftpy/TftpContexts.py
+++ b/tftpy/TftpContexts.py
@@ -43,16 +43,16 @@ class TftpMetrics(object):
         self.duration = self.end_time - self.start_time
         if self.duration == 0:
             self.duration = 1
-        log.debug("TftpMetrics.compute: duration is %s" % self.duration)
+        log.debug("TftpMetrics.compute: duration is %s", self.duration)
         self.bps = (self.bytes * 8.0) / self.duration
         self.kbps = self.bps / 1024.0
-        log.debug("TftpMetrics.compute: kbps is %s" % self.kbps)
+        log.debug("TftpMetrics.compute: kbps is %s", self.kbps)
         for key in self.dups:
             self.dupcount += self.dups[key]
 
     def add_dup(self, pkt):
         """This method adds a dup for a packet to the metrics."""
-        log.debug("Recording a dup of %s" % pkt)
+        log.debug("Recording a dup of %s", pkt)
         s = str(pkt)
         if self.dups.has_key(s):
             self.dups[s] += 1
@@ -110,7 +110,7 @@ class TftpContext(object):
     def checkTimeout(self, now):
         """Compare current time with last_update time, and raise an exception
         if we're over the timeout time."""
-        log.debug("checking for timeout on session %s" % self)
+        log.debug("checking for timeout on session %s", self)
         if now - self.last_update > self.timeout:
             raise TftpTimeout, "Timeout waiting for traffic"
 
@@ -160,8 +160,8 @@ class TftpContext(object):
             raise TftpTimeout, "Timed-out waiting for traffic"
 
         # Ok, we've received a packet. Log it.
-        log.debug("Received %d bytes from %s:%s"
-                        % (len(buffer), raddress, rport))
+        log.debug("Received %d bytes from %s:%s",
+                        len(buffer), raddress, rport)
         # And update our last updated time.
         self.last_update = time.time()
 
@@ -217,12 +217,12 @@ class TftpContextServer(TftpContext):
         that."""
         log.debug("In TftpContextServer.start")
         self.metrics.start_time = time.time()
-        log.debug("Set metrics.start_time to %s" % self.metrics.start_time)
+        log.debug("Set metrics.start_time to %s", self.metrics.start_time)
         # And update our last updated time.
         self.last_update = time.time()
 
         pkt = self.factory.parse(buffer)
-        log.debug("TftpContextServer.start() - factory returned a %s" % pkt)
+        log.debug("TftpContextServer.start() - factory returned a %s", pkt)
 
         # Call handle once with the initial packet. This should put us into
         # the download or the upload state.
@@ -234,7 +234,7 @@ class TftpContextServer(TftpContext):
         """Finish up the context."""
         TftpContext.end(self)
         self.metrics.end_time = time.time()
-        log.debug("Set metrics.end_time to %s" % self.metrics.end_time)
+        log.debug("Set metrics.end_time to %s", self.metrics.end_time)
         self.metrics.compute()
 
 class TftpContextClientUpload(TftpContext):
@@ -265,8 +265,8 @@ class TftpContextClientUpload(TftpContext):
             self.fileobj = open(input, "rb")
 
         log.debug("TftpContextClientUpload.__init__()")
-        log.debug("file_to_transfer = %s, options = %s" %
-            (self.file_to_transfer, self.options))
+        log.debug("file_to_transfer = %s, options = %s",
+            self.file_to_transfer, self.options)
 
     def __str__(self):
         return "%s:%s %s" % (self.host, self.port, self.state)
@@ -277,7 +277,7 @@ class TftpContextClientUpload(TftpContext):
         log.info("    options -> %s" % self.options)
 
         self.metrics.start_time = time.time()
-        log.debug("Set metrics.start_time to %s" % self.metrics.start_time)
+        log.debug("Set metrics.start_time to %s", self.metrics.start_time)
 
         # FIXME: put this in a sendWRQ method?
         pkt = TftpPacketWRQ()
@@ -294,7 +294,7 @@ class TftpContextClientUpload(TftpContext):
 
         while self.state:
             try:
-                log.debug("State is %s" % self.state)
+                log.debug("State is %s", self.state)
                 self.cycle()
             except TftpTimeout, err:
                 log.error(str(err))
@@ -310,7 +310,7 @@ class TftpContextClientUpload(TftpContext):
         """Finish up the context."""
         TftpContext.end(self)
         self.metrics.end_time = time.time()
-        log.debug("Set metrics.end_time to %s" % self.metrics.end_time)
+        log.debug("Set metrics.end_time to %s", self.metrics.end_time)
         self.metrics.compute()
 
 class TftpContextClientDownload(TftpContext):
@@ -343,8 +343,8 @@ class TftpContextClientDownload(TftpContext):
             self.fileobj = open(output, "wb")
 
         log.debug("TftpContextClientDownload.__init__()")
-        log.debug("file_to_transfer = %s, options = %s" %
-            (self.file_to_transfer, self.options))
+        log.debug("file_to_transfer = %s, options = %s",
+            self.file_to_transfer, self.options)
 
     def __str__(self):
         return "%s:%s %s" % (self.host, self.port, self.state)
@@ -356,7 +356,7 @@ class TftpContextClientDownload(TftpContext):
         log.info("    options -> %s" % self.options)
 
         self.metrics.start_time = time.time()
-        log.debug("Set metrics.start_time to %s" % self.metrics.start_time)
+        log.debug("Set metrics.start_time to %s", self.metrics.start_time)
 
         # FIXME: put this in a sendRRQ method?
         pkt = TftpPacketRRQ()
@@ -371,7 +371,7 @@ class TftpContextClientDownload(TftpContext):
 
         while self.state:
             try:
-                log.debug("State is %s" % self.state)
+                log.debug("State is %s", self.state)
                 self.cycle()
             except TftpTimeout, err:
                 log.error(str(err))
@@ -387,5 +387,5 @@ class TftpContextClientDownload(TftpContext):
         """Finish up the context."""
         TftpContext.end(self)
         self.metrics.end_time = time.time()
-        log.debug("Set metrics.end_time to %s" % self.metrics.end_time)
+        log.debug("Set metrics.end_time to %s", self.metrics.end_time)
         self.metrics.compute()
diff --git a/tftpy/TftpPacketFactory.py b/tftpy/TftpPacketFactory.py
index d689185..154aec8 100644
--- a/tftpy/TftpPacketFactory.py
+++ b/tftpy/TftpPacketFactory.py
@@ -23,9 +23,9 @@ class TftpPacketFactory(object):
         """This method is used to parse an existing datagram into its
         corresponding TftpPacket object. The buffer is the raw bytes off of
         the network."""
-        log.debug("parsing a %d byte packet" % len(buffer))
+        log.debug("parsing a %d byte packet", len(buffer))
         (opcode,) = struct.unpack("!H", buffer[:2])
-        log.debug("opcode is %d" % opcode)
+        log.debug("opcode is %d", opcode)
         packet = self.__create(opcode)
         packet.buffer = buffer
         return packet.decode()
diff --git a/tftpy/TftpPacketTypes.py b/tftpy/TftpPacketTypes.py
index e02381f..4a2a0f1 100644
--- a/tftpy/TftpPacketTypes.py
+++ b/tftpy/TftpPacketTypes.py
@@ -20,15 +20,15 @@ class TftpPacketWithOptions(object):
 
     def setoptions(self, options):
         log.debug("in TftpPacketWithOptions.setoptions")
-        log.debug("options: " + str(options))
+        log.debug("options: %s", str(options))
         myoptions = {}
         for key in options:
             newkey = str(key)
             myoptions[newkey] = str(options[key])
-            log.debug("populated myoptions with %s = %s"
-                         % (newkey, myoptions[newkey]))
+            log.debug("populated myoptions with %s = %s",
+                         newkey, myoptions[newkey])
 
-        log.debug("setting options hash to: " + str(myoptions))
+        log.debug("setting options hash to: %s", str(myoptions))
         self._options = myoptions
 
     def getoptions(self):
@@ -47,8 +47,8 @@ class TftpPacketWithOptions(object):
         format = "!"
         options = {}
 
-        log.debug("decode_options: buffer is: " + repr(buffer))
-        log.debug("size of buffer is %d bytes" % len(buffer))
+        log.debug("decode_options: buffer is: %s", repr(buffer))
+        log.debug("size of buffer is %d bytes", len(buffer))
         if len(buffer) == 0:
             log.debug("size of buffer is zero, returning empty hash")
             return {}
@@ -57,9 +57,8 @@ class TftpPacketWithOptions(object):
         log.debug("about to iterate options buffer counting nulls")
         length = 0
         for c in buffer:
-            #log.debug("iterating this byte: " + repr(c))
             if ord(c) == 0:
-                log.debug("found a null at length %d" % length)
+                log.debug("found a null at length %d", length)
                 if length > 0:
                     format += "%dsx" % length
                     length = -1
@@ -67,14 +66,14 @@ class TftpPacketWithOptions(object):
                     raise TftpException, "Invalid options in buffer"
             length += 1
 
-        log.debug("about to unpack, format is: %s" % format)
+        log.debug("about to unpack, format is: %s", format)
         mystruct = struct.unpack(format, buffer)
 
         tftpassert(len(mystruct) % 2 == 0,
                    "packet with odd number of option/value pairs")
 
         for i in range(0, len(mystruct), 2):
-            log.debug("setting option %s to %s" % (mystruct[i], mystruct[i+1]))
+            log.debug("setting option %s to %s", mystruct[i], mystruct[i+1])
             options[mystruct[i]] = mystruct[i+1]
 
         return options
@@ -122,10 +121,10 @@ class TftpPacketInitial(TftpPacket, TftpPacketWithOptions):
         ptype = None
         if self.opcode == 1: ptype = "RRQ"
         else:                ptype = "WRQ"
-        log.debug("Encoding %s packet, filename = %s, mode = %s"
-                     % (ptype, self.filename, self.mode))
+        log.debug("Encoding %s packet, filename = %s, mode = %s",
+                     ptype, self.filename, self.mode)
         for key in self.options:
-            log.debug("    Option %s = %s" % (key, self.options[key]))
+            log.debug("    Option %s = %s", key, self.options[key])
 
         format = "!H"
         format += "%dsx" % len(self.filename)
@@ -145,9 +144,9 @@ class TftpPacketInitial(TftpPacket, TftpPacketWithOptions):
                 format += "%dsx" % len(str(self.options[key]))
                 options_list.append(str(self.options[key]))
 
-        log.debug("format is %s" % format)
-        log.debug("options_list is %s" % options_list)
-        log.debug("size of struct is %d" % struct.calcsize(format))
+        log.debug("format is %s", format)
+        log.debug("options_list is %s", options_list)
+        log.debug("size of struct is %d", struct.calcsize(format))
 
         self.buffer = struct.pack(format,
                                   self.opcode,
@@ -155,7 +154,7 @@ class TftpPacketInitial(TftpPacket, TftpPacketWithOptions):
                                   self.mode,
                                   *options_list)
 
-        log.debug("buffer is " + repr(self.buffer))
+        log.debug("buffer is %s", repr(self.buffer))
         return self
 
     def decode(self):
@@ -168,11 +167,9 @@ class TftpPacketInitial(TftpPacket, TftpPacketWithOptions):
         log.debug("in decode: about to iterate buffer counting nulls")
         subbuf = self.buffer[2:]
         for c in subbuf:
-            log.debug("iterating this byte: " + repr(c))
             if ord(c) == 0:
                 nulls += 1
-                log.debug("found a null at length %d, now have %d"
-                             % (length, nulls))
+                log.debug("found a null at length %d, now have %d", length, nulls)
                 format += "%dsx" % length
                 length = -1
                 # At 2 nulls, we want to mark that position for decoding.
@@ -181,19 +178,19 @@ class TftpPacketInitial(TftpPacket, TftpPacketWithOptions):
             length += 1
             tlength += 1
 
-        log.debug("hopefully found end of mode at length %d" % tlength)
+        log.debug("hopefully found end of mode at length %d", tlength)
         # length should now be the end of the mode.
         tftpassert(nulls == 2, "malformed packet")
         shortbuf = subbuf[:tlength+1]
-        log.debug("about to unpack buffer with format: %s" % format)
-        log.debug("unpacking buffer: " + repr(shortbuf))
+        log.debug("about to unpack buffer with format: %s", format)
+        log.debug("unpacking buffer: %s", repr(shortbuf))
         mystruct = struct.unpack(format, shortbuf)
 
         tftpassert(len(mystruct) == 2, "malformed packet")
         self.filename = mystruct[0]
         self.mode = mystruct[1].lower() # force lc - bug 17
-        log.debug("set filename to %s" % self.filename)
-        log.debug("set mode to %s" % self.mode)
+        log.debug("set filename to %s", self.filename)
+        log.debug("set mode to %s", self.mode)
 
         self.options = self.decode_options(subbuf[tlength+1:])
         return self
@@ -277,13 +274,11 @@ class TftpPacketDAT(TftpPacket):
         # We know the first 2 bytes are the opcode. The second two are the
         # block number.
         (self.blocknumber,) = struct.unpack("!H", self.buffer[2:4])
-        log.debug("decoding DAT packet, block number %d" % self.blocknumber)
-        log.debug("should be %d bytes in the packet total"
-                     % len(self.buffer))
+        log.debug("decoding DAT packet, block number %d", self.blocknumber)
+        log.debug("should be %d bytes in the packet total", len(self.buffer))
         # Everything else is data.
         self.data = self.buffer[4:]
-        log.debug("found %d bytes of data"
-                     % len(self.data))
+        log.debug("found %d bytes of data", len(self.data))
         return self
 
 class TftpPacketACK(TftpPacket):
@@ -304,15 +299,15 @@ class TftpPacketACK(TftpPacket):
         return 'ACK packet: block %d' % self.blocknumber
 
     def encode(self):
-        log.debug("encoding ACK: opcode = %d, block = %d"
-                     % (self.opcode, self.blocknumber))
+        log.debug("encoding ACK: opcode = %d, block = %d",
+                     self.opcode, self.blocknumber)
         self.buffer = struct.pack("!HH", self.opcode, self.blocknumber)
         return self
 
     def decode(self):
         self.opcode, self.blocknumber = struct.unpack("!HH", self.buffer)
-        log.debug("decoded ACK packet: opcode = %d, block = %d"
-                     % (self.opcode, self.blocknumber))
+        log.debug("decoded ACK packet: opcode = %d, block = %d",
+                     self.opcode, self.blocknumber)
         return self
 
 class TftpPacketERR(TftpPacket):
@@ -365,7 +360,7 @@ class TftpPacketERR(TftpPacket):
         """Encode the DAT packet based on instance variables, populating
         self.buffer, returning self."""
         format = "!HH%dsx" % len(self.errmsgs[self.errorcode])
-        log.debug("encoding ERR packet with format %s" % format)
+        log.debug("encoding ERR packet with format %s", format)
         self.buffer = struct.pack(format,
                                   self.opcode,
                                   self.errorcode,
@@ -376,17 +371,17 @@ class TftpPacketERR(TftpPacket):
         "Decode self.buffer, populating instance variables and return self."
         buflen = len(self.buffer)
         tftpassert(buflen >= 4, "malformed ERR packet, too short")
-        log.debug("Decoding ERR packet, length %s bytes" % buflen)
+        log.debug("Decoding ERR packet, length %s bytes", buflen)
         if buflen == 4:
             log.debug("Allowing this affront to the RFC of a 4-byte packet")
             format = "!HH"
-            log.debug("Decoding ERR packet with format: %s" % format)
+            log.debug("Decoding ERR packet with format: %s", format)
             self.opcode, self.errorcode = struct.unpack(format,
                                                         self.buffer)
         else:
             log.debug("Good ERR packet > 4 bytes")
             format = "!HH%dsx" % (len(self.buffer) - 5)
-            log.debug("Decoding ERR packet with format: %s" % format)
+            log.debug("Decoding ERR packet with format: %s", format)
             self.opcode, self.errorcode, self.errmsg = struct.unpack(format,
                                                                      self.buffer)
         log.error("ERR packet - errorcode: %d, message: %s"
@@ -414,8 +409,8 @@ class TftpPacketOACK(TftpPacket, TftpPacketWithOptions):
         options_list = []
         log.debug("in TftpPacketOACK.encode")
         for key in self.options:
-            log.debug("looping on option key %s" % key)
-            log.debug("value is %s" % self.options[key])
+            log.debug("looping on option key %s", key)
+            log.debug("value is %s", self.options[key])
             format += "%dsx" % len(key)
             format += "%dsx" % len(self.options[key])
             options_list.append(key)
@@ -439,7 +434,7 @@ class TftpPacketOACK(TftpPacket, TftpPacketWithOptions):
                     # We can accept anything between the min and max values.
                     size = self.options[name]
                     if size >= MIN_BLKSIZE and size <= MAX_BLKSIZE:
-                        log.debug("negotiated blksize of %d bytes" % size)
+                        log.debug("negotiated blksize of %d bytes", size)
                         options[blksize] = size
                 else:
                     raise TftpException, "Unsupported option: %s" % name
diff --git a/tftpy/TftpServer.py b/tftpy/TftpServer.py
index 6993d44..e913cac 100644
--- a/tftpy/TftpServer.py
+++ b/tftpy/TftpServer.py
@@ -36,17 +36,17 @@ class TftpServer(TftpSession):
             if not callable(self.dyn_file_func):
                 raise TftpException, "A dyn_file_func supplied, but it is not callable."
         elif os.path.exists(self.root):
-            log.debug("tftproot %s does exist" % self.root)
+            log.debug("tftproot %s does exist", self.root)
             if not os.path.isdir(self.root):
                 raise TftpException, "The tftproot must be a directory."
             else:
-                log.debug("tftproot %s is a directory" % self.root)
+                log.debug("tftproot %s is a directory", self.root)
                 if os.access(self.root, os.R_OK):
-                    log.debug("tftproot %s is readable" % self.root)
+                    log.debug("tftproot %s is readable", self.root)
                 else:
                     raise TftpException, "The tftproot must be readable"
                 if os.access(self.root, os.W_OK):
-                    log.debug("tftproot %s is writable" % self.root)
+                    log.debug("tftproot %s is writable", self.root)
                 else:
                     log.warning("The tftproot %s is not writable" % self.root)
         else:
@@ -97,7 +97,7 @@ class TftpServer(TftpSession):
                 inputlist.append(self.sessions[key].sock)
 
             # Block until some socket has input on it.
-            log.debug("Performing select on this inputlist: %s" % inputlist)
+            log.debug("Performing select on this inputlist: %s", inputlist)
             readyinput, readyoutput, readyspecial = select.select(inputlist,
                                                                   [],
                                                                   [],
@@ -112,7 +112,7 @@ class TftpServer(TftpSession):
                     log.debug("Data ready on our main socket")
                     buffer, (raddress, rport) = self.sock.recvfrom(MAX_BLKSIZE)
 
-                    log.debug("Read %d bytes" % len(buffer))
+                    log.debug("Read %d bytes", len(buffer))
 
                     if self.shutdown_gracefully:
                         log.warn("Discarding data on main port, in graceful shutdown mode")
@@ -124,7 +124,7 @@ class TftpServer(TftpSession):
 
                     if not self.sessions.has_key(key):
                         log.debug("Creating new server context for "
-                                     "session key = %s" % key)
+                                     "session key = %s", key)
                         self.sessions[key] = TftpContextServer(raddress,
                                                                rport,
                                                                timeout,
@@ -176,12 +176,11 @@ class TftpServer(TftpSession):
                     log.error(str(err))
                     self.sessions[key].retry_count += 1
                     if self.sessions[key].retry_count >= TIMEOUT_RETRIES:
-                        log.debug("hit max retries on %s, giving up"
-                            % self.sessions[key])
+                        log.debug("hit max retries on %s, giving up",
+                            self.sessions[key])
                         deletion_list.append(key)
                     else:
-                        log.debug("resending on session %s"
-                            % self.sessions[key])
+                        log.debug("resending on session %s", self.sessions[key])
                         self.sessions[key].state.resendLast()
 
             log.debug("Iterating deletion list.")
@@ -200,9 +199,9 @@ class TftpServer(TftpSession):
                         log.info("Average rate: %.2f kbps" % metrics.kbps)
                     log.info("%.2f bytes in resent data" % metrics.resent_bytes)
                     log.info("%d duplicate packets" % metrics.dupcount)
-                    log.debug("Deleting session %s" % key)
+                    log.debug("Deleting session %s", key)
                     del self.sessions[key]
-                    log.debug("Session list is now %s" % self.sessions)
+                    log.debug("Session list is now %s", self.sessions)
                 else:
                     log.warn("Strange, session %s is not on the deletion list"
                         % key)
diff --git a/tftpy/TftpStates.py b/tftpy/TftpStates.py
index b86c4d2..6f71685 100644
--- a/tftpy/TftpStates.py
+++ b/tftpy/TftpStates.py
@@ -70,7 +70,7 @@ class TftpState(object):
                 accepted_options['tsize'] = 1
             else:
                 log.info("Dropping unsupported option '%s'" % option)
-        log.debug("Returning these accepted options: %s" % accepted_options)
+        log.debug("Returning these accepted options: %s", accepted_options)
         return accepted_options
 
     def sendDAT(self):
@@ -87,7 +87,7 @@ class TftpState(object):
         dat = None
         blksize = self.context.getBlocksize()
         buffer = self.context.fileobj.read(blksize)
-        log.debug("Read %d bytes into buffer" % len(buffer))
+        log.debug("Read %d bytes into buffer", len(buffer))
         if len(buffer) < blksize:
             log.info("Reached EOF on file %s"
                 % self.context.file_to_transfer)
@@ -96,7 +96,7 @@ class TftpState(object):
         dat.data = buffer
         dat.blocknumber = blocknumber
         self.context.metrics.bytes += len(dat.data)
-        log.debug("Sending DAT packet %d" % dat.blocknumber)
+        log.debug("Sending DAT packet %d", dat.blocknumber)
         self.context.sock.sendto(dat.encode().buffer,
                                  (self.context.host, self.context.tidport))
         if self.context.packethook:
@@ -108,7 +108,7 @@ class TftpState(object):
         """This method sends an ack packet to the block number specified. If
         none is specified, it defaults to the next_block property in the
         parent context."""
-        log.debug("In sendACK, passed blocknumber is %s" % blocknumber)
+        log.debug("In sendACK, passed blocknumber is %s", blocknumber)
         if blocknumber is None:
             blocknumber = self.context.next_block
         log.info("Sending ack to block %d" % blocknumber)
@@ -122,7 +122,7 @@ class TftpState(object):
     def sendError(self, errorcode):
         """This method uses the socket passed, and uses the errorcode to
         compose and send an error packet."""
-        log.debug("In sendError, being asked to send error %d" % errorcode)
+        log.debug("In sendError, being asked to send error %d", errorcode)
         errpkt = TftpPacketERR()
         errpkt.errorcode = errorcode
         self.context.sock.sendto(errpkt.encode().buffer,
@@ -133,7 +133,7 @@ class TftpState(object):
     def sendOACK(self):
         """This method sends an OACK packet with the options from the current
         context."""
-        log.debug("In sendOACK with options %s" % self.context.options)
+        log.debug("In sendOACK with options %s", self.context.options)
         pkt = TftpPacketOACK()
         pkt.options = self.context.options
         self.context.sock.sendto(pkt.encode().buffer,
@@ -162,16 +162,14 @@ class TftpState(object):
         """This method handles a DAT packet during a client download, or a
         server upload."""
         log.info("Handling DAT packet - block %d" % pkt.blocknumber)
-        log.debug("Expecting block %s" % self.context.next_block)
+        log.debug("Expecting block %s", self.context.next_block)
         if pkt.blocknumber == self.context.next_block:
-            log.debug("Good, received block %d in sequence"
-                        % pkt.blocknumber)
+            log.debug("Good, received block %d in sequence", pkt.blocknumber)
 
             self.sendACK()
             self.context.next_block += 1
 
-            log.debug("Writing %d bytes to output file"
-                        % len(pkt.data))
+            log.debug("Writing %d bytes to output file", len(pkt.data))
             self.context.fileobj.write(pkt.data)
             self.context.metrics.bytes += len(pkt.data)
             # Check for end-of-file, any less than full data packet.
@@ -186,7 +184,7 @@ class TftpState(object):
                 raise TftpException, "There is no block zero!"
             log.warn("Dropping duplicate block %d" % pkt.blocknumber)
             self.context.metrics.add_dup(pkt)
-            log.debug("ACKing block %d again, just in case" % pkt.blocknumber)
+            log.debug("ACKing block %d again, just in case", pkt.blocknumber)
             self.sendACK(pkt.blocknumber)
 
         else:
@@ -225,7 +223,7 @@ class TftpServerState(TftpState):
         self.context.options = { 'blksize': DEF_BLKSIZE }
 
         if options:
-            log.debug("Options requested: %s" % options)
+            log.debug("Options requested: %s", options)
             supported_options = self.returnSupportedOptions(options)
             self.context.options.update(supported_options)
             sendoack = True
@@ -249,13 +247,13 @@ class TftpServerState(TftpState):
             # Return same state, we're still waiting for valid traffic.
             return self
 
-        log.debug("Requested filename is %s" % pkt.filename)
+        log.debug("Requested filename is %s", pkt.filename)
 
         # Make sure that the path to the file is contained in the server's
         # root directory.
         full_path = os.path.join(self.context.root, pkt.filename)
         self.full_path = os.path.abspath(full_path)
-        log.debug("full_path is %s" % full_path)
+        log.debug("full_path is %s", full_path)
         if self.full_path.startswith(self.context.root):
             log.info("requested file is in the server root - good")
         else:
@@ -282,7 +280,7 @@ class TftpStateServerRecvRRQ(TftpServerState):
             # blows.
             self.context.fileobj = open(path, "rb")
         elif self.context.dyn_file_func:
-            log.debug("No such file %s but using dyn_file_func" % path)
+            log.debug("No such file %s but using dyn_file_func", path)
             self.context.fileobj = \
                 self.context.dyn_file_func(self.context.file_to_transfer)
 
@@ -321,17 +319,17 @@ class TftpStateServerRecvWRQ(TftpServerState):
         subdirectories leading up to the file to the written."""
         # Pull off everything below the root.
         subpath = self.full_path[len(self.context.root):]
-        log.debug("make_subdirs: subpath is %s" % subpath)
+        log.debug("make_subdirs: subpath is %s", subpath)
         # Split on directory separators, but drop the last one, as it should
         # be the filename.
         dirs = subpath.split(os.sep)[:-1]
-        log.debug("dirs is %s" % dirs)
+        log.debug("dirs is %s", dirs)
         current = self.context.root
         for dir in dirs:
             if dir:
                 current = os.path.join(current, dir)
                 if os.path.isdir(current):
-                    log.debug("%s is already an existing directory" % current)
+                    log.debug("%s is already an existing directory", current)
                 else:
                     os.mkdir(current, 0700)
 
@@ -406,8 +404,8 @@ class TftpStateExpectACK(TftpState):
                 else:
                     log.debug("Good ACK, sending next DAT")
                     self.context.next_block += 1
-                    log.debug("Incremented next_block to %d"
-                        % (self.context.next_block))
+                    log.debug("Incremented next_block to %d",
+                        self.context.next_block)
                     self.context.pending_complete = self.sendDAT()
 
             elif pkt.blocknumber < self.context.next_block:
@@ -459,7 +457,7 @@ class TftpStateSentWRQ(TftpState):
         """Handle a packet we just received."""
         if not self.context.tidport:
             self.context.tidport = rport
-            log.debug("Set remote port for session to %s" % rport)
+            log.debug("Set remote port for session to %s", rport)
 
         # If we're going to successfully transfer the file, then we should see
         # either an OACK for accepted options, or an ACK to ignore options.