r199 - in /debtorrent/trunk: ./ DebTorrent/ DebTorrent/BT1/
camrdale-guest at users.alioth.debian.org
camrdale-guest at users.alioth.debian.org
Mon Aug 6 00:50:01 UTC 2007
Author: camrdale-guest
Date: Mon Aug 6 00:50:01 2007
New Revision: 199
URL: http://svn.debian.org/wsvn/debtorrent/?sc=1&rev=199
Log:
Add lots more log messages.
Modified:
debtorrent/trunk/DebTorrent/BT1/AptListener.py
debtorrent/trunk/DebTorrent/BT1/Connecter.py
debtorrent/trunk/DebTorrent/BT1/Downloader.py
debtorrent/trunk/DebTorrent/BT1/Encrypter.py
debtorrent/trunk/DebTorrent/BT1/HTTPDownloader.py
debtorrent/trunk/DebTorrent/BT1/NatCheck.py
debtorrent/trunk/DebTorrent/BT1/PiecePicker.py
debtorrent/trunk/DebTorrent/BT1/Rerequester.py
debtorrent/trunk/DebTorrent/BT1/Storage.py
debtorrent/trunk/DebTorrent/BT1/StorageWrapper.py
debtorrent/trunk/DebTorrent/BT1/StreamCheck.py
debtorrent/trunk/DebTorrent/BT1/Uploader.py
debtorrent/trunk/DebTorrent/BT1/btformats.py
debtorrent/trunk/DebTorrent/BT1/makemetafile.py
debtorrent/trunk/DebTorrent/BT1/track.py
debtorrent/trunk/DebTorrent/HTTPCache.py
debtorrent/trunk/DebTorrent/HTTPHandler.py
debtorrent/trunk/DebTorrent/RawServer.py
debtorrent/trunk/DebTorrent/ServerPortHandler.py
debtorrent/trunk/DebTorrent/SocketHandler.py
debtorrent/trunk/DebTorrent/__init__.py
debtorrent/trunk/DebTorrent/bencode.py
debtorrent/trunk/DebTorrent/download_bt1.py
debtorrent/trunk/DebTorrent/launchmanycore.py
debtorrent/trunk/TODO
Modified: debtorrent/trunk/DebTorrent/BT1/AptListener.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/AptListener.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/AptListener.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/AptListener.py Mon Aug 6 00:50:01 2007
@@ -180,6 +180,7 @@
# Check for a closed connection
if c.closed:
closed_conns.append(c)
+ logger.warning('connection closed while request queued for file '+str(v[1]))
continue
# Remove the downloaded pieces from the list of needed ones
@@ -343,6 +344,7 @@
if path[-1] in ('Packages', 'Packages.gz', 'Packages.bz2'):
if r[0] == 304:
# Oops, we do need the cached file after all to start the torrent
+ logger.info('retrieving the cached Packages file to start the torrent')
r2 = self.Cache.cache_get(path)
self.got_Packages(path, r2[3])
else:
@@ -351,6 +353,7 @@
return r
except IOError, e:
+ logger.exception('While retrieving cache file: ' + '/'.join(path))
try:
(msg, status) = e
except:
@@ -382,6 +385,7 @@
for connection in connections:
# Check to make sure the requester is still waiting
if connection.closed:
+ logger.warning('Retrieved the file, but the requester is gone: '+'/'.join(path))
continue
connection.answer(r)
@@ -403,6 +407,7 @@
d, f = self.handler.find_file(path[0], path[1:])
if d is None:
+ logger.warning('Unable to find the file in any torrents: '+'/'.join(path))
return (404, 'Not Found', {'Server': VERSION, 'Content-Type': 'text/plain', 'Pragma': 'no-cache'}, alas)
# Check if the file has already been downloaded
@@ -420,6 +425,7 @@
# Check if the torrent is running/not paused
if d.doneflag.isSet():
+ logger.error('The needed torrent is not running')
return (404, 'Not Found', {'Server': VERSION, 'Content-Type': 'text/plain', 'Pragma': 'no-cache'}, alas)
if not d.unpauseflag.isSet():
@@ -493,7 +499,7 @@
assert data[:8] == "Package:"
h = data.split('\n')
except:
- logger.warning('Packages file could not be converted to a torrent')
+ logger.warning('Packages file is not in the correct format')
return
sub_pieces = getsubpieces('_'.join(path))
@@ -548,6 +554,7 @@
setkey('announce-list')
a['metainfo'] = response
+ logger.info('Adding torrent '+name+': '+b2a_hex(infohash))
self.handler.add(infohash, a)
@@ -563,11 +570,13 @@
"""
if not self.allow_get:
+ logger.warning('Unauthorized request for torrent file: '+b2a_hex(hash))
return (400, 'Not Authorized', {'Server': VERSION,
'Content-Type': 'text/plain',
'Pragma': 'no-cache'},
'get function is not available with this tracker.')
if hash not in self.handler.torrent_cache:
+ logger.warning('Request for unknown torrent file: '+b2a_hex(hash))
return (404, 'Not Found', {'Server': VERSION,
'Content-Type': 'text/plain',
'Pragma': 'no-cache'},
@@ -575,6 +584,7 @@
fname = self.handler.torrent_cache[hash]['file'] + '.dtorrent'
response = self.handler.configdir.getTorrentFile(hash)
if not response:
+ logger.warning('Could not retrieve torrent file: '+b2a_hex(hash))
return (404, 'Not Found', {'Server': VERSION,
'Content-Type': 'text/plain',
'Pragma': 'no-cache'},
@@ -603,7 +613,6 @@
"""
-# return (404, 'Not Found', {'Content-Type': 'text/plain', 'Pragma': 'no-cache'}, alas)
real_ip = connection.get_ip()
ip = real_ip
if not is_ipv4(ip):
@@ -614,6 +623,7 @@
if ( (self.allowed_IPs and not self.allowed_IPs.includes(ip))
or (self.banned_IPs and self.banned_IPs.includes(ip)) ):
+ logger.warning('Unauthorized request from '+ip+' for: '+path)
return (400, 'Not Authorized', {'Server': VERSION, 'Content-Type': 'text/plain', 'Pragma': 'no-cache'},
bencode({'failure reason':
'your IP is not allowed on this proxy'}))
@@ -672,6 +682,7 @@
return self.get_cached(connection, path, headers)
except ValueError, e:
+ logger.exception('Bad request from: '+ip)
return (400, 'Bad Request', {'Server': VERSION, 'Content-Type': 'text/plain'},
'you sent me garbage - ' + str(e))
@@ -687,7 +698,7 @@
self.allowed_IPs.read_fieldlist(f)
self.allowed_ip_mtime = os.path.getmtime(f)
except (IOError, OSError):
- logger.warning('unable to read allowed_IP list')
+ logger.exception('unable to read allowed_IP list')
f = self.config['banned_ips']
if f and self.banned_ip_mtime != os.path.getmtime(f):
@@ -696,7 +707,7 @@
self.banned_IPs.read_rangelist(f)
self.banned_ip_mtime = os.path.getmtime(f)
except (IOError, OSError):
- logger.warning('unable to read banned_IP list')
+ logger.exception('unable to read banned_IP list')
def size_format(s):
Modified: debtorrent/trunk/DebTorrent/BT1/Connecter.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/Connecter.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/Connecter.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/Connecter.py Mon Aug 6 00:50:01 2007
@@ -81,7 +81,7 @@
class Connection:
"""A connection to an individual peer.
- @type connection: L{DebTorrent.SocketHandler.SingleSocket}
+ @type connection: L{Encrypter.Connection}
@ivar connection: the connection
@type connecter: L{Connecter}
@ivar connecter: the collection of all connections
@@ -89,7 +89,7 @@
@ivar ccount: the number of the connection
@type got_anything: C{boolean}
@ivar got_anything: whether a message has ever been received on the connection
- @type next_upload: L{DebTorrent.SocketHandler.SingleSocket}
+ @type next_upload: L{Encrypter.Connection}
@ivar next_upload: the connection that will next be allowed to upload
@type outqueue: C{list}
@ivar outqueue: the queue of messages to send on the connection that are
@@ -110,7 +110,7 @@
def __init__(self, connection, connecter, ccount):
"""Initialize the class.
- @type connection: L{DebTorrent.SocketHandler.SingleSocket}
+ @type connection: L{Encrypter.Connection}
@param connection: the connection
@type connecter: L{Connecter}
@param connecter: the collection of all connections
@@ -208,7 +208,7 @@
"""Send the L{UNCHOKE} message."""
if self.send_choke_queued:
self.send_choke_queued = False
- logger.info(self.get_ip()+': CHOKE SUPPRESSED')
+ logger.info(self.get_ip()+': UNCHOKE SUPPRESSED')
else:
self._send_message(UNCHOKE)
if ( self.partial_message or self.just_unchoked is None
@@ -231,7 +231,7 @@
self._send_message(REQUEST + tobinary(index) +
tobinary(begin) + tobinary(length))
- logger.debug(self.get_ip()+': sent request '+str(index)+', '+str(begin)+', '+str(begin+length))
+ logger.debug(self.get_ip()+': sent request '+str(index)+', '+str(begin)+'-'+str(begin+length))
def send_cancel(self, index, begin, length):
"""Send the L{CANCEL} message.
@@ -249,7 +249,7 @@
self._send_message(CANCEL + tobinary(index) +
tobinary(begin) + tobinary(length))
- logger.debug(self.get_ip()+': sent cancel '+str(index)+', '+str(begin)+', '+str(begin+length))
+ logger.debug(self.get_ip()+': sent cancel '+str(index)+', '+str(begin)+'-'+str(begin+length))
def send_bitfield(self, bitfield):
"""Send the L{BITFIELD} message.
@@ -313,7 +313,7 @@
self.partial_message = ''.join((
tobinary(len(piece) + 9), PIECE,
tobinary(index), tobinary(begin), piece.tostring() ))
- logger.debug(self.get_ip()+': sending chunk '+str(index)+', '+str(begin)+', '+str(begin+len(piece)))
+ logger.debug(self.get_ip()+': sending chunk '+str(index)+', '+str(begin)+'-'+str(begin+len(piece)))
if bytes < len(self.partial_message):
self.connection.send_message_raw(self.partial_message[:bytes])
@@ -385,6 +385,7 @@
"""
+ logger.debug(self.get_ip()+': got request '+str(i)+', '+str(p)+'-'+str(p+l))
self.upload.got_request(i, p, l)
if self.just_unchoked:
self.connecter.ratelimiter.ping(clock() - self.just_unchoked)
@@ -474,7 +475,7 @@
def connection_made(self, connection):
"""Make a new connection.
- @type connection: L{DebTorrent.SocketHandler.SingleSocket}
+ @type connection: L{Encrypter.Connection}
@param connection: the new connection to make
@rtype: L{Connection}
@return: the new connection
@@ -493,13 +494,13 @@
def connection_lost(self, connection):
"""Process a lost connection.
- @type connection: L{DebTorrent.SocketHandler.SingleSocket}
+ @type connection: L{Encrypter.Connection}
@param connection: the connection that was lost
"""
c = self.connections[connection]
- logger.debug(c.get_ip()+': connection closed')
+ logger.debug(c.get_ip()+': connection lost')
del self.connections[connection]
if c.download:
c.download.disconnected()
@@ -508,7 +509,7 @@
def connection_flushed(self, connection):
"""Process a flushed connection.
- @type connection: L{DebTorrent.SocketHandler.SingleSocket}
+ @type connection: L{Encrypter.Connection}
@param connection: the connection that was flushed
"""
@@ -532,7 +533,7 @@
def got_message(self, connection, message):
"""Process a received message on a connection.
- @type connection: L{DebTorrent.SocketHandler.SingleSocket}
+ @type connection: L{Encrypter.Connection}
@param connection: the connection that the message was received on
@type message: C{string}
@param message: the message that was received
@@ -541,15 +542,15 @@
c = self.connections[connection]
t = message[0]
- logger.debug(c.get_ip()+': message received '+str(ord(t)))
+ logger.debug(c.get_ip()+': message received '+str(ord(t))+' ('+str(len(message))+')')
if t == BITFIELD and c.got_anything:
- logger.info(c.get_ip()+': misplaced bitfield, closing connection')
+ logger.warning(c.get_ip()+': misplaced bitfield, closing connection')
connection.close()
return
c.got_anything = True
if (t in [CHOKE, UNCHOKE, INTERESTED, NOT_INTERESTED] and
len(message) != 1):
- logger.debug(c.get_ip()+': bad message length, closing connection')
+ logger.warning(c.get_ip()+': bad message length, closing connection')
connection.close()
return
if t == CHOKE:
@@ -563,12 +564,12 @@
c.upload.got_not_interested()
elif t == HAVE:
if len(message) != 5:
- logger.debug(c.get_ip()+': bad message length, closing connection')
+ logger.warning(c.get_ip()+': bad message length, closing connection')
connection.close()
return
i = toint(message[1:])
if i >= self.numpieces:
- logger.debug(c.get_ip()+': bad piece number, closing connection')
+ logger.warning(c.get_ip()+': bad piece number, closing connection')
connection.close()
return
if c.download.got_have(i):
@@ -577,47 +578,47 @@
try:
b = Bitfield(self.numpieces, message[1:])
except ValueError:
- logger.debug(c.get_ip()+': bad bitfield, closing connection')
+ logger.warning(c.get_ip()+': bad bitfield, closing connection')
connection.close()
return
if c.download.got_have_bitfield(b):
c.upload.got_not_interested()
elif t == REQUEST:
if len(message) != 13:
- logger.debug(c.get_ip()+': bad message length, closing connection')
+ logger.warning(c.get_ip()+': bad message length, closing connection')
connection.close()
return
i = toint(message[1:5])
if i >= self.numpieces:
- logger.debug(c.get_ip()+': bad piece number, closing connection')
+ logger.warning(c.get_ip()+': bad piece number, closing connection')
connection.close()
return
c.got_request(i, toint(message[5:9]),
toint(message[9:]))
elif t == CANCEL:
if len(message) != 13:
- logger.debug(c.get_ip()+': bad message length, closing connection')
+ logger.warning(c.get_ip()+': bad message length, closing connection')
connection.close()
return
i = toint(message[1:5])
if i >= self.numpieces:
- logger.debug(c.get_ip()+': bad piece number, closing connection')
+ logger.warning(c.get_ip()+': bad piece number, closing connection')
connection.close()
return
c.upload.got_cancel(i, toint(message[5:9]),
toint(message[9:]))
elif t == PIECE:
if len(message) <= 9:
- logger.debug(c.get_ip()+': bad message length, closing connection')
+ logger.warning(c.get_ip()+': bad message length, closing connection')
connection.close()
return
i = toint(message[1:5])
if i >= self.numpieces:
- logger.debug(c.get_ip()+': bad piece number, closing connection')
+ logger.warning(c.get_ip()+': bad piece number, closing connection')
connection.close()
return
if c.download.got_piece(i, toint(message[5:9]), message[9:]):
self.got_piece(i)
else:
- logger.debug(c.get_ip()+': unknown message type, closing connection')
+ logger.warning(c.get_ip()+': unknown message type, closing connection')
connection.close()
Modified: debtorrent/trunk/DebTorrent/BT1/Downloader.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/Downloader.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/Downloader.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/Downloader.py Mon Aug 6 00:50:01 2007
@@ -6,6 +6,8 @@
"""Download pieces from remote peers.
+ at type logger: C{logging.Logger}
+ at var logger: the logger to send all log messages to for this module
@type EXPIRE_TIME: C{int}
@var EXPIRE_TIME: number of seconds after which disconnected seeds are expired
@@ -15,11 +17,14 @@
from DebTorrent.bitfield import Bitfield
from random import shuffle
from DebTorrent.clock import clock
+import logging
try:
True
except:
True = 1
False = 0
+
+logger = logging.getLogger('DebTorrent.BT1.Downloader')
EXPIRE_TIME = 60 * 60
@@ -255,7 +260,7 @@
self._letgo()
def got_unchoke(self):
- """Update the status and request any needed pieces."""
+ """Update the choked status and request any needed pieces."""
if self.choked:
self.choked = False
if self.interested:
@@ -317,6 +322,8 @@
try:
self.active_requests.remove((index, begin, length))
except ValueError:
+ logger.warning('received an unrequested piece from '+self.ip+': '+
+ str(index)+', '+str(begin)+'-'+str(begin+len(piece)))
self.downloader.discarded += length
return False
if self.downloader.endgamemode:
@@ -870,6 +877,7 @@
id = download.connection.get_readable_id()
self.kicked[ip] = id
self.perip[ip].peerid = id
+ logger.warning('kicking peer '+ip+' ('+id+')')
self.kickfunc(download.connection)
def try_ban(self, ip):
@@ -881,6 +889,7 @@
"""
if self._check_kicks_ok():
+ logger.warning('banning peer IP '+ip)
self.banfunc(ip)
self.banned[ip] = self.perip[ip].peerid
if self.kicked.has_key(ip):
@@ -998,6 +1007,7 @@
def start_endgame(self):
"""Switch to endgame mode."""
assert not self.endgamemode
+ logger.info('Switching to endgame mode')
self.endgamemode = True
assert not self.all_requests
for d in self.downloads:
Modified: debtorrent/trunk/DebTorrent/BT1/Encrypter.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/Encrypter.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/Encrypter.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/Encrypter.py Mon Aug 6 00:50:01 2007
@@ -40,6 +40,8 @@
bool = lambda x: not not x
logger = logging.getLogger('DebTorrent.BT1.Encrypter')
+
+DEBUG = False
MAX_INCOMPLETE = 8
@@ -251,10 +253,12 @@
if self.locally_initiated:
incompletecounter.increment()
if encrypted:
+ logger.info('Initiating an encrypted connection to '+self.readable_id)
self.encrypted = True
self.encrypter = Crypto(True)
self.write(self.encrypter.pubkey+self.encrypter.padding())
else:
+ logger.info('Initiating an unencrypted connection to '+self.readable_id)
self.encrypted = False
self.write(chr(len(protocol_name)) + protocol_name +
option_pattern + self.Encoder.download_id )
@@ -262,17 +266,20 @@
elif ext_handshake:
self.Encoder.connecter.external_connection_made += 1
if encrypted: # passed an already running encrypter
+ logger.info('Received an external encrypted connection from '+self.readable_id)
self.encrypter = encrypted
self.encrypted = True
self._start_crypto()
self.next_len, self.next_func = 14, self.read_crypto_block3c
else:
+ logger.info('Received an external unencrypted connection from '+self.readable_id)
self.encrypted = False
self.options = options
self.write(chr(len(protocol_name)) + protocol_name +
option_pattern + self.Encoder.download_id + self.Encoder.my_id)
self.next_len, self.next_func = 20, self.read_peer_id
else:
+ logger.info('Received an unknown connection from '+self.readable_id)
self.encrypted = None # don't know yet
self.next_len, self.next_func = 1+len(protocol_name), self.read_header
self.Encoder.raw_server.add_task(self._auto_close, 30)
@@ -398,11 +405,14 @@
if self._read_header(s):
if self.encrypted or self.Encoder.config['crypto_stealth']:
+ logger.info('Dropped the connection as it was unencrypted: '+self.readable_id)
return None
return 8, self.read_options
if self.locally_initiated and not self.encrypted:
+ logger.info('Got a bad protocol name: '+self.readable_id)
return None
elif not self.Encoder.config['crypto_allowed']:
+ logger.info('Dropped the connection as it was encrypted: '+self.readable_id)
return None
if not self.encrypted:
self.encrypted = True
@@ -511,6 +521,7 @@
"""
if s != self.encrypter.block3b:
+ logger.info('Dropped the encrypted connection due to a bad block3b: '+self.readable_id)
return None
self.Encoder.connecter.external_connection_made += 1
self._start_crypto()
@@ -528,15 +539,19 @@
"""
if s[:8] != ('\x00'*8): # check VC
+ logger.info('Dropped the encrypted connection due to a bad VC: '+self.readable_id)
return None
self.cryptmode = toint(s[8:12]) % 4
if self.cryptmode == 0:
+ logger.info('Dropped the encrypted connection due to a bad crypt mode: '+self.readable_id)
return None # no encryption selected
if ( self.cryptmode == 1 # only header encryption
and self.Encoder.config['crypto_only'] ):
+ logger.info('Dropped the header-only encrypted connection: '+self.readable_id)
return None
padlen = (ord(s[12])<<8)+ord(s[13])
if padlen > 512:
+ logger.info('Dropped the encrypted connection due to bad padding: '+self.readable_id)
return None
return padlen+2, self.read_crypto_pad3
@@ -554,6 +569,7 @@
s = s[-2:]
ialen = (ord(s[0])<<8)+ord(s[1])
if ialen > 65535:
+ logger.info('Dropped the encrypted connection due to very long padding: '+self.readable_id)
return None
if self.cryptmode == 1:
cryptmode = '\x00\x00\x00\x01' # header only encryption
@@ -639,11 +655,14 @@
self.cryptmode = toint(s[:4]) % 4
if self.cryptmode == 1: # only header encryption
if self.Encoder.config['crypto_only']:
+ logger.info('Dropped the header-only encrypted connection: '+self.readable_id)
return None
elif self.cryptmode != 2:
+ logger.info('Dropped the encrypted connection due to an unknown crypt mode: '+self.readable_id)
return None # unknown encryption
padlen = (ord(s[4])<<8)+ord(s[5])
if padlen > 512:
+ logger.info('Dropped the encrypted connection due to bad padding: '+self.readable_id)
return None
if padlen:
return padlen, self.read_crypto_pad4
@@ -676,6 +695,7 @@
self._log_start()
if self.cryptmode == 1: # only handshake encryption
if not self.buffer: # oops; check for exceptions to this
+ logger.info('Dropped the encrypted connection due to a lack of buffer: '+self.readable_id)
return None
self._end_crypto()
self.write(chr(len(protocol_name)) + protocol_name +
@@ -726,6 +746,7 @@
if ( s != self.Encoder.download_id
or not self.Encoder.check_ip(ip=self.get_ip()) ):
+ logger.warning('IPs or torrent info hashes do not match: '+self.readable_id)
return None
if not self.locally_initiated:
if not self.encrypted:
@@ -746,6 +767,7 @@
"""
if not self.encrypted and self.Encoder.config['crypto_only']:
+ logger.info('Dropped the unencrypted connection: '+self.readable_id)
return None # allows older trackers to ping,
# but won't proceed w/ connections
if not self.id:
@@ -753,14 +775,17 @@
self.readable_id = make_readable(s)
else:
if s != self.id:
+ logger.info('Peer ID does not match: '+self.readable_id)
return None
self.complete = self.Encoder.got_id(self)
if not self.complete:
+ logger.warning('Connection disallowed for security: '+self.readable_id)
return None
if self.locally_initiated:
self.write(self.Encoder.my_id)
incompletecounter.decrement()
self._switch_to_read2()
+ logger.info('Handshake complete: '+self.readable_id)
c = self.Encoder.connecter.connection_made(self)
self.keepalive = c.send_keepalive
return 4, self.read_len
@@ -778,6 +803,7 @@
l = toint(s)
if l > self.Encoder.max_len:
+ logger.warning('Dropped the connection due to bad length message: '+self.readable_id)
return None
return l, self.read_message
@@ -811,6 +837,7 @@
def _auto_close(self):
"""Close the connection if the handshake is not yet complete."""
if not self.complete:
+ logger.warning('Connection dropped due to handshake taking too long: '+self.readable_id)
self.close()
def close(self):
@@ -904,6 +931,7 @@
try:
x = self.next_func(m)
except:
+ logger.exception('Dropped connection due to exception: '+self.readable_id)
self.next_len, self.next_func = 1, self.read_dead
raise
if x is None:
@@ -975,6 +1003,7 @@
try:
x = self.next_func(m)
except:
+ logger.exception('Dropped connection due to exception: '+self.readable_id)
self.next_len, self.next_func = 1, self.read_dead
raise
if x is None:
@@ -1114,6 +1143,7 @@
self.schedulefunc(self.send_keepalives, self.keepalive_delay)
if self.paused:
return
+ logger.debug('Sending keepalive messages to all connected peers')
for c in self.connections.values():
c.keepalive()
@@ -1162,23 +1192,33 @@
"""
- if ( self.paused
- or len(self.connections) >= self.max_connections
- or id == self.my_id
- or not self.check_ip(ip=dns[0]) ):
+ if self.paused:
+ logger.info('Not connecting due to being paused')
+ return True
+ if len(self.connections) >= self.max_connections:
+ logger.info('Not connecting due to too many connections: '+str(len(self.connections))+' >= '+str(self.max_connections))
+ return True
+ if id == self.my_id:
+ logger.info('Not connecting due to it being my ID: '+id)
+ return True
+ if not self.check_ip(ip=dns[0]):
+ logger.info('Not connecting due to the IP being banned: '+dns[0])
return True
if self.config['crypto_only']:
if encrypted is None or encrypted: # fails on encrypted = 0
encrypted = True
else:
+ logger.info('Not connecting due to not being encrypted: '+dns[0])
return True
for v in self.connections.values():
if v is None:
continue
if id and v.id == id:
+ logger.info('Not connecting due to a matching peer ID: '+id)
return True
ip = v.get_ip(True)
if self.config['security'] and ip != 'unknown' and ip == dns[0]:
+ logger.info('Not connecting due to a matching IP: '+ip)
return True
try:
logger.debug('initiating connection to: '+str(dns)+', '+str(id)+', '+str(encrypted))
@@ -1245,16 +1285,20 @@
if connection.id == self.my_id:
self.connecter.external_connection_made -= 1
+ logger.debug('New connection matches our peer ID')
return False
ip = connection.get_ip(True)
for v in self.connections.values():
if connection is not v:
if connection.id == v.id:
if ip == v.get_ip(True):
+ logger.debug('Closing an old connection to the same peer')
v.close()
else:
+ logger.debug('New peer ID is already connected')
return False
if self.config['security'] and ip != 'unknown' and ip == v.get_ip(True):
+ logger.debug('Closing an old connection to the same IP')
v.close()
return True
@@ -1269,6 +1313,11 @@
"""
if self.paused or len(self.connections) >= self.max_connections:
+ if self.paused:
+ logger.info('Not allowing connection due to being paused')
+ else:
+ logger.info('Not allowing connection due to too many connections: '+
+ str(len(self.connections))+' >= '+str(self.max_connections))
connection.close()
return False
con = Connection(self, connection, None)
@@ -1295,9 +1344,17 @@
"""
- if ( self.paused
- or len(self.connections) >= self.max_connections
- or not self.check_ip(connection=connection) ):
+ if self.paused:
+ logger.info('Not allowing external connection due to being paused')
+ connection.close()
+ return False
+ if len(self.connections) >= self.max_connections:
+ logger.info('Not allowing external connection due to too many connections: '+
+ str(len(self.connections))+' >= '+str(self.max_connections))
+ connection.close()
+ return False
+ if not self.check_ip(connection=connection):
+ logger.info('Not allowing external connection due to the IP being banned: '+dns[0])
connection.close()
return False
con = Connection(self, connection, None,
@@ -1322,6 +1379,7 @@
"""
+ logger.info('Banned: '+ip)
self.banned[ip] = 1
def pause(self, flag):
Modified: debtorrent/trunk/DebTorrent/BT1/HTTPDownloader.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/HTTPDownloader.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/HTTPDownloader.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/HTTPDownloader.py Mon Aug 6 00:50:01 2007
@@ -214,7 +214,7 @@
self.endflag = True
self.resched()
else:
- logger.debug('HTTPDownloader: downloading piece '+str(self.index))
+ logger.info('downloading piece '+str(self.index))
(start, end, length, file) = self.downloader.storage.storage.get_file_range(self.index)
filename = self.downloader.filenamefunc()
if len(filename) > 0 and file.startswith(filename):
@@ -244,7 +244,7 @@
self.error = None
self.received_data = None
try:
- logger.debug('HTTPDownloader: sending request: GET '+self.url+' '+str(self.headers))
+ logger.debug('sending request: GET '+self.url+' '+str(self.headers))
self.connection.request('GET',self.url, None, self.headers)
# Check for closed persistent connection due to server timeout
@@ -257,7 +257,7 @@
self.connection.request('GET',self.url, None, self.headers)
r = self.connection.getresponse()
- logger.debug('HTTPDownloader: got response: '+str(r.status)+', '+r.reason+', '+str(r.getheaders()))
+ logger.debug('got response: '+str(r.status)+', '+r.reason+', '+str(r.getheaders()))
self.connection_status = r.status
self.received_data = r.read()
except Exception, e:
@@ -306,12 +306,13 @@
"""
if self.connection_status not in [200, 206]:
+ logger.warning('bad status from http seed: '+str(self.connection_status))
self.errorcount += 1
return False
self._retry_period = 1
if len(self.received_data) != self.request_size:
if self.goodseed:
- logger.warning('corrupt data from http seed - redownloading')
+ logger.warning('corrupt data from http seed')
self.downloader.errorfunc('corrupt data from http seed - redownloading')
return False
self.measure.update_rate(len(self.received_data))
@@ -353,6 +354,7 @@
begin, length = self.requests.pop(0)
if not self.downloader.storage.piece_came_in(self.index, begin,
self.received_data[start:start+length]):
+ logger.warning('piece failed hash check')
success = False
break
start += length
Modified: debtorrent/trunk/DebTorrent/BT1/NatCheck.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/NatCheck.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/NatCheck.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/NatCheck.py Mon Aug 6 00:50:01 2007
@@ -15,6 +15,7 @@
from socket import error as socketerror
from DebTorrent.BTcrypto import Crypto, CRYPTO_OK
from DebTorrent.__init__ import protocol_name
+from binascii import b2a_hex
try:
True
@@ -92,6 +93,8 @@
self.resultfunc = resultfunc
self.downloadid = downloadid
self.peerid = peerid
+ self.readable_id = b2a_hex(peerid)
+ logger.info('Starting a NAT check for '+self.readable_id)
self.ip = ip
self.port = port
self.encrypted = encrypted
@@ -102,16 +105,18 @@
try:
self.connection = rawserver.start_connection((ip, port), self)
if encrypted:
+ logger.info('Initiating an encrypted connection to '+self.readable_id)
self._dc = not(CRYPTO_OK and CHECK_PEER_ID_ENCRYPTED)
self.encrypter = Crypto(True, disable_crypto = self._dc)
self.write(self.encrypter.pubkey+self.encrypter.padding())
else:
+ logger.info('Initiating an unencrypted connection to '+self.readable_id)
self.encrypter = None
self.write(chr(len(protocol_name)) + protocol_name +
(chr(0) * 8) + downloadid)
- except socketerror:
- self.answer(False)
- except IOError:
+ except (socketerror, IOError):
+ logger.exception('Could not initiate a connection to %s:%d for %s',
+ ip, port, self.readable_id)
self.answer(False)
self.next_len, self.next_func = 1+len(protocol_name), self.read_header
@@ -128,6 +133,7 @@
self.connection.close()
except AttributeError:
pass
+ logger.info('Result was '+str(result)+' for: '+self.readable_id)
self.resultfunc(result, self.downloadid, self.peerid, self.ip, self.port)
def _read_header(self, s):
@@ -158,9 +164,11 @@
if self._read_header(s):
if self.encrypted:
+ logger.info('Dropped the connection as it was unencrypted: '+self.readable_id)
return None
return 8, self.read_options
if not self.encrypted:
+ logger.info('Got a bad protocol name: '+self.readable_id)
return None
self._write_buffer(s)
return self.encrypter.keylength, self.read_crypto_header
@@ -259,9 +267,11 @@
self.cryptmode = toint(s[:4]) % 4
if self.cryptmode != 2:
+ logger.info('Dropped the encrypted connection due to an unknown crypt mode: '+self.readable_id)
return None # unknown encryption
padlen = (ord(s[4])<<8)+ord(s[5])
if padlen > 512:
+ logger.info('Dropped the encrypted connection due to bad padding: '+self.readable_id)
return None
if padlen:
return padlen, self.read_crypto_pad4
@@ -292,6 +302,7 @@
if self.cryptmode == 1: # only handshake encryption
if not self.buffer: # oops; check for exceptions to this
+ logger.info('Dropped the encrypted connection due to a lack of buffer: '+self.readable_id)
return None
self._end_crypto()
self.write(chr(len(protocol_name)) + protocol_name +
@@ -340,6 +351,7 @@
"""
if s != self.downloadid:
+ logger.warning('Torrent info hash does not match: '+self.readable_id)
return None
return 20, self.read_peer_id
@@ -354,6 +366,7 @@
"""
if s != self.peerid:
+ logger.info('Peer ID does not match: '+self.readable_id)
return None
self.answer(True)
return None
@@ -418,6 +431,7 @@
try:
x = self.next_func(m)
except:
+ logger.exception('Dropped connection due to exception: '+self.readable_id)
if not self.closed:
self.answer(False)
return
@@ -438,6 +452,7 @@
"""
if not self.closed:
+ logger.warning('Connection was dropped externally: '+self.readable_id)
self.closed = True
self.resultfunc(False, self.downloadid, self.peerid, self.ip, self.port)
Modified: debtorrent/trunk/DebTorrent/BT1/PiecePicker.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/PiecePicker.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/PiecePicker.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/PiecePicker.py Mon Aug 6 00:50:01 2007
@@ -4,15 +4,23 @@
#
# $Id$
-"""Choose pieces to download."""
+"""Choose pieces to download.
+
+ at type logger: C{logging.Logger}
+ at var logger: the logger to send all log messages to for this module
+
+"""
from random import randrange, shuffle
from DebTorrent.clock import clock
+import logging
try:
True
except:
True = 1
False = 0
+
+logger = logging.getLogger('DebTorrent.BT1.Rerequester')
class PiecePicker:
"""Choose pieces to download.
@@ -326,6 +334,8 @@
@type complete_first: C{boolean}
@param complete_first: whether to complete a partially dowloaded piece
before requsting a new one (optional, defaults to False)
+ @rtype: C{int}
+ @return: the index of the piece to download
"""
@@ -340,6 +350,7 @@
bestnum = self.level_in_interests[i]
if best is not None:
if complete_first or (cutoff and len(self.interests) > self.cutoff):
+ logger.info('Next piece to download/request: '+str(best))
return best
if haves.complete():
r = [ (0, min(bestnum,len(self.interests))) ]
@@ -352,8 +363,10 @@
for i in xrange(lo,hi):
for j in self.interests[i]:
if haves[j] and wantfunc(j):
+ logger.info('Next piece to download/request: '+str(j))
return j
if best is not None:
+ logger.info('Next piece to download/request: '+str(best))
return best
return None
Modified: debtorrent/trunk/DebTorrent/BT1/Rerequester.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/Rerequester.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/Rerequester.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/Rerequester.py Mon Aug 6 00:50:01 2007
@@ -441,6 +441,7 @@
self.rerequest(s, callback)
self.sched(retry,5) # retry in 5 seconds
return
+ logger.info('Sending request: '+s)
self.lock.reset()
rq = Thread(target = self._rerequest, args = [s, callback],
name = 'Rerequester._rerequest')
@@ -471,15 +472,19 @@
for t in range(len(self.trackerlist)):
for tr in range(len(self.trackerlist[t])):
tracker = self.trackerlist[t][tr]
+ logger.debug('Trying tracker: '+tracker)
if self.rerequest_single(tracker, s, callback):
if not self.last_failed and tr != 0:
del self.trackerlist[t][tr]
self.trackerlist[t] = [tracker] + self.trackerlist[t]
+ logger.info('Succesful with tracker: '+tracker)
return
else:
tracker = self.special
self.special = None
+ logger.debug('Trying special tracker: '+tracker)
if self.rerequest_single(tracker, s, callback):
+ logger.info('Succesful with special tracker: '+tracker)
return
# no success from any tracker
self.externalsched(fail)
@@ -673,7 +678,7 @@
x = p[i]
peers.append(((x['ip'].strip(), x['port']),
x.get('peer id',0), cflags[i]))
- logger.debug('received from tracker: '+str(peers))
+ logger.info('received from tracker: '+str(peers))
ps = len(peers) + self.howmany()
if ps < self.maxpeers:
if self.doneflag.isSet():
Modified: debtorrent/trunk/DebTorrent/BT1/Storage.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/Storage.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/Storage.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/Storage.py Mon Aug 6 00:50:01 2007
@@ -521,8 +521,8 @@
for l in self.working_ranges:
self.ranges.extend(l)
self.begins = [i[0] for i in self.ranges]
- logger.debug('file ranges: '+str(self.ranges))
- logger.debug('file begins: '+str(self.begins))
+ logger.debug('new file ranges: '+str(self.ranges))
+ logger.debug('new file begins: '+str(self.begins))
def get_file_range(self, index):
"""Get the file name and range that corresponds to this piece.
@@ -635,6 +635,7 @@
file = split(file)[0]
if file != '' and not exists(file):
+ logger.debug('creating directories: '+file)
makedirs(file)
def top_off(self):
Modified: debtorrent/trunk/DebTorrent/BT1/StorageWrapper.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/StorageWrapper.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/StorageWrapper.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/StorageWrapper.py Mon Aug 6 00:50:01 2007
@@ -512,6 +512,7 @@
logger.info('StorageWrapper initialize complete')
return
msg, done, init, next = self.initialize_tasks.pop(0)
+ logger.debug('Starting initialization task: %s', msg)
if init():
self.statusfunc(activity = msg, fractionDone = done)
self.initialize_next = next
@@ -580,7 +581,7 @@
"""
- logger.debug(str(piece)+' at '+str(pos))
+ logger.debug('Marking '+str(piece)+' at '+str(pos)+' as complete')
self.places[piece] = pos
self.have[piece] = True
len = self._piecelen(piece)
Modified: debtorrent/trunk/DebTorrent/BT1/StreamCheck.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/StreamCheck.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/StreamCheck.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/StreamCheck.py Mon Aug 6 00:50:01 2007
@@ -71,12 +71,12 @@
def read_header_len(self, s):
if ord(s) != len(protocol_name):
- logger.warn(str(self.no)+' BAD HEADER LENGTH')
+ logger.warning(str(self.no)+' BAD HEADER LENGTH')
return len(protocol_name), self.read_header
def read_header(self, s):
if s != protocol_name:
- logger.warn(str(self.no)+' BAD HEADER')
+ logger.warning(str(self.no)+' BAD HEADER')
return 8, self.read_reserved
def read_reserved(self, s):
@@ -93,7 +93,7 @@
def read_len(self, s):
l = toint(s)
if l > 2 ** 23:
- logger.warn(str(self.no)+' BAD LENGTH: '+str(l)+' ('+s+')')
+ logger.warning(str(self.no)+' BAD LENGTH: '+str(l)+' ('+s+')')
return l, self.read_message
def read_message(self, s):
@@ -101,10 +101,10 @@
return 4, self.read_len
m = s[0]
if ord(m) > 8:
- logger.warn(str(self.no)+' BAD MESSAGE: '+str(ord(m)))
+ logger.warning(str(self.no)+' BAD MESSAGE: '+str(ord(m)))
if m == Connecter.REQUEST:
if len(s) != 13:
- logger.warn(str(self.no)+' BAD REQUEST SIZE: '+str(len(s)))
+ logger.warning(str(self.no)+' BAD REQUEST SIZE: '+str(len(s)))
return 4, self.read_len
index = toint(s[1:5])
begin = toint(s[5:9])
@@ -112,7 +112,7 @@
logger.info(str(self.no)+' Request: '+str(index)+': '+str(begin)+'-'+str(begin)+'+'+str(length))
elif m == Connecter.CANCEL:
if len(s) != 13:
- logger.warn(str(self.no)+' BAD CANCEL SIZE: '+str(len(s)))
+ logger.warning(str(self.no)+' BAD CANCEL SIZE: '+str(len(s)))
return 4, self.read_len
index = toint(s[1:5])
begin = toint(s[5:9])
Modified: debtorrent/trunk/DebTorrent/BT1/Uploader.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/Uploader.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/Uploader.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/Uploader.py Mon Aug 6 00:50:01 2007
@@ -17,7 +17,7 @@
class Upload:
"""Manage uploading to a single peer.
- @type connection: L{DebTorrent.SocketHandler.SingleSocket}
+ @type connection: L{Connecter.Connection}
@ivar connection: the connection to the peer
@type ratelimiter: L{RateLimiter.RateLimiter}
@ivar ratelimiter: the RateLimiter instance to use
@@ -66,7 +66,7 @@
picker, config):
"""Initialize the instance and send the initial bitfield.
- @type connection: L{DebTorrent.SocketHandler.SingleSocket}
+ @type connection: L{Connecter.Connection}
@param connection: the connection to the peer
@type ratelimiter: L{RateLimiter.RateLimiter}
@param ratelimiter: the RateLimiter instance to use
Modified: debtorrent/trunk/DebTorrent/BT1/btformats.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/btformats.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/btformats.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/btformats.py Mon Aug 6 00:50:01 2007
@@ -43,7 +43,7 @@
raise ValueError, 'bad metainfo - bad pieces key'
piecelengths = info.get('piece lengths')
if type(piecelengths) != ListType:
- raise ValueError
+ raise ValueError, 'bad metainfo - bad piece lengths list'
total_length = 0L
piece_bounds = [0L]
for length in piecelengths:
@@ -55,7 +55,7 @@
raise ValueError, 'single/multiple file mix'
files = info.get('files')
if type(files) != ListType:
- raise ValueError
+ raise ValueError, 'bad metainfo - bad files list'
total_length = 0L
for f in files:
if type(f) != DictType:
@@ -93,13 +93,13 @@
"""
if type(message) != DictType:
- raise ValueError
+ raise ValueError, 'bad dictionary'
check_info(message.get('info'))
if type(message.get('announce')) != StringType:
- raise ValueError
+ raise ValueError, 'bad announce'
name = message.get('name')
if type(name) != StringType:
- raise ValueError, 'bad metainfo - bad name'
+ raise ValueError, 'bad name'
if not reg.match(name):
raise ValueError, 'name %s disallowed for security reasons' % name
@@ -116,41 +116,41 @@
"""
if type(message) != DictType:
- raise ValueError
+ raise ValueError, 'bad dictionary'
if message.has_key('failure reason'):
if type(message['failure reason']) != StringType:
- raise ValueError
+ raise ValueError, 'bad failure reason'
return
peers = message.get('peers')
if type(peers) == ListType:
for p in peers:
if type(p) != DictType:
- raise ValueError
+ raise ValueError, 'bad peers - bad dictionary'
if type(p.get('ip')) != StringType:
- raise ValueError
+ raise ValueError, 'bad peers - bad ip'
port = p.get('port')
if type(port) not in ints or p <= 0:
- raise ValueError
+ raise ValueError, 'bad peers - bad port'
if p.has_key('peer id'):
id = p['peer id']
if type(id) != StringType or len(id) != 20:
- raise ValueError
+ raise ValueError, 'bad peers - bad peer ID'
elif type(peers) != StringType or len(peers) % 6 != 0:
- raise ValueError
+ raise ValueError, 'bad compact peers'
interval = message.get('interval', 1)
if type(interval) not in ints or interval <= 0:
- raise ValueError
+ raise ValueError, 'bad interval'
minint = message.get('min interval', 1)
if type(minint) not in ints or minint <= 0:
- raise ValueError
+ raise ValueError, 'bad min interval'
if type(message.get('tracker id', '')) != StringType:
- raise ValueError
+ raise ValueError, 'bad tracker id'
npeers = message.get('num peers', 0)
if type(npeers) not in ints or npeers < 0:
- raise ValueError
+ raise ValueError, 'bad num peers'
dpeers = message.get('done peers', 0)
if type(dpeers) not in ints or dpeers < 0:
- raise ValueError
+ raise ValueError, 'bad done peers'
last = message.get('last', 0)
if type(last) not in ints or last < 0:
- raise ValueError
+ raise ValueError, 'bad last'
Modified: debtorrent/trunk/DebTorrent/BT1/makemetafile.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/makemetafile.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/makemetafile.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/makemetafile.py Mon Aug 6 00:50:01 2007
@@ -284,11 +284,13 @@
pieces = {}
packages = 0
-
+ piece_url = ''
+
if pieces_file:
try:
f = open(pieces_file)
except:
+ logger.exception('sub-pieces file not found: '+pieces_file)
return {}
elif 'dists' in file.split('_'):
try:
@@ -320,8 +322,10 @@
pass
f = piece_data.split('\n')
except:
+ logger.exception('sub-pieces URL not working: '+piece_url)
return {}
else:
+ logger.warning('unable to find sub-pieces data')
return {}
p = [None, [], []]
@@ -350,6 +354,8 @@
except:
pass
+ logger.info('successfully retrieved sub-piece data for '+str(len(pieces))+' files')
+
return pieces
def getpieces(f, encoding = None, progress = lambda x: None, separate_all = 0, sub_pieces = {}):
@@ -428,8 +434,12 @@
if packages[0] > 0:
info = {'pieces': ''.join(pieces[0]), 'piece lengths': lengths[0], 'files': fs[0]}
+ logger.info('got metainfo for torrent of '+str(len(pieces[0]))+
+ ' pieces for '+str(len(fs[0]))+' files')
if packages[1] > 0:
info_all = {'pieces': ''.join(pieces[1]), 'piece lengths': lengths[1], 'files': fs[1]}
+ logger.info('got metainfo for torrent of '+str(len(pieces[0]))+
+ ' pieces for '+str(len(fs[0]))+' files')
return (info, info_all)
@@ -458,8 +468,6 @@
sub_pieces = getsubpieces(file, pieces_file)
- logger.warning('WARNING: Pieces file could not be found, not using sub-package pieces.')
-
file = abspath(file)
f = open(file)
(info, info_all) = getpieces(f, encoding, progress, separate_all = separate_all, sub_pieces = sub_pieces)
Modified: debtorrent/trunk/DebTorrent/BT1/track.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/BT1/track.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/BT1/track.py (original)
+++ debtorrent/trunk/DebTorrent/BT1/track.py Mon Aug 6 00:50:01 2007
@@ -769,9 +769,11 @@
"""
if not self.allow_get:
+ logger.warning('Unauthorized request for torrent file: '+b2a_hex(hash))
return (400, 'Not Authorized', {'Content-Type': 'text/plain', 'Pragma': 'no-cache'},
'get function is not available with this tracker.')
if not self.allowed.has_key(hash):
+ logger.warning('Request for unknown torrent file: '+b2a_hex(hash))
return (404, 'Not Found', {'Content-Type': 'text/plain', 'Pragma': 'no-cache'}, alas)
fname = self.allowed[hash]['file']
fpath = self.allowed[hash]['path']
@@ -1154,6 +1156,7 @@
if ( (self.allowed_IPs and not self.allowed_IPs.includes(ip))
or (self.banned_IPs and self.banned_IPs.includes(ip)) ):
+ logger.warning('Unauthorized request from '+ip+' for: '+path)
return (400, 'Not Authorized', {'Content-Type': 'text/plain', 'Pragma': 'no-cache'},
bencode({'failure reason':
'your IP is not allowed on this tracker'}))
@@ -1235,6 +1238,7 @@
rsize = self.add_data(infohash, event, ip, paramslist)
except ValueError, e:
+ logger.exception('Bad request from: '+ip)
return (400, 'Bad Request', {'Content-Type': 'text/plain'},
'you sent me garbage - ' + str(e))
@@ -1385,7 +1389,7 @@
(self.allowed, added, garbage2) = r
self.state['allowed_list'] = self.allowed
except (IOError, OSError):
- logger.warning('unable to read allowed torrent list')
+ logger.exception('unable to read allowed torrent list')
return
self.allowed_list_mtime = os.path.getmtime(f)
@@ -1406,7 +1410,7 @@
self.allowed_IPs.read_fieldlist(f)
self.allowed_ip_mtime = os.path.getmtime(f)
except (IOError, OSError):
- logger.warning('unable to read allowed_IP list')
+ logger.exception('unable to read allowed_IP list')
f = self.config['banned_ips']
if f and self.banned_ip_mtime != os.path.getmtime(f):
@@ -1415,7 +1419,7 @@
self.banned_IPs.read_rangelist(f)
self.banned_ip_mtime = os.path.getmtime(f)
except (IOError, OSError):
- logger.warning('unable to read banned_IP list')
+ logger.exception('unable to read banned_IP list')
def delete_peer(self, infohash, peerid):
Modified: debtorrent/trunk/DebTorrent/HTTPCache.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/HTTPCache.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/HTTPCache.py (original)
+++ debtorrent/trunk/DebTorrent/HTTPCache.py Mon Aug 6 00:50:01 2007
@@ -85,12 +85,12 @@
try:
self.connection = HTTPConnection(self.server)
except:
- logger.error('cannot connect to http seed: '+self.server)
+ logger.exception('cannot connect to http seed: '+self.server)
return
self.headers = {'User-Agent': VERSION}
self.active = False
- logger.info('CacheRequest: downloading '+self.url)
+ logger.debug('starting thread to download '+self.url)
rq = Thread(target = self._request, name = 'HTTPCache.CacheRequest._request')
rq.setDaemon(False)
rq.start()
@@ -103,12 +103,12 @@
import encodings.idna
try:
- logger.debug('CacheRequest: sending request GET '+self.url+', '+str(self.headers))
+ logger.debug('sending request GET '+self.url+', '+str(self.headers))
self.connection.request('GET',self.url, None, self.headers)
r = self.connection.getresponse()
- logger.debug('CacheRequest: got response '+str(r.status)+', '+r.reason+', '+str(r.getheaders()))
+ logger.debug('got response '+str(r.status)+', '+r.reason+', '+str(r.getheaders()))
self.connection_status = r.status
self.connection_response = r.reason
self.headers = dict(r.getheaders())
@@ -166,7 +166,7 @@
"""
- logger.info('Starting a HttpCache downloader for: http://'+'/'.join(path))
+ logger.info('Starting a downloader for: http://'+'/'.join(path))
self.downloads.append(CacheRequest(self, path, func))
def download_complete(self, d, path, func, r):
@@ -187,7 +187,7 @@
"""
- logger.info('HttpCache download completed for: http://'+'/'.join(path))
+ logger.info('download completed for: http://'+'/'.join(path))
self.downloads.remove(d)
if r[0] in (200, 206):
@@ -247,6 +247,7 @@
# Check if the file isn't in the cache
if not exists(file):
+ logger.info('cache miss: '+file)
return (404, 'Not Found', {'Server': VERSION, 'Content-Type': 'text/plain', 'Pragma': 'no-cache'}, alas)
if uptodate:
@@ -259,10 +260,12 @@
# Check if the cached data is stale
if self.check_mtime(last_modified, file = file) > 0:
+ logger.info('cache out of date: '+file)
return (405, 'Method Not Allowed', {'Server': VERSION, 'Content-Type': 'text/plain', 'Pragma': 'no-cache'}, alas)
# Check if the request needs the data
if if_modified_time and self.check_mtime(if_modified_time, file = file) >= 0:
+ logger.info('cache up to date and so is request: '+file)
return (304, 'Not Modified', {'Server': VERSION, 'Pragma': 'no-cache'}, '')
# Read in the file and return the data
@@ -271,6 +274,7 @@
f.close()
mtime_string = strftime(time_format+' GMT', gmtime(getmtime(file)))
+ logger.info('cache hit: '+file)
return (200, 'OK', {'Server': VERSION, 'Content-Type': 'text/plain', 'Last-Modified': mtime_string}, data)
def get_filename(self, path):
Modified: debtorrent/trunk/DebTorrent/HTTPHandler.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/HTTPHandler.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/HTTPHandler.py (original)
+++ debtorrent/trunk/DebTorrent/HTTPHandler.py Mon Aug 6 00:50:01 2007
@@ -157,10 +157,13 @@
self.command, self.path = words
self.pre1 = True
if self.command != 'GET':
+ logger.warning('connection closed, improper command: '+self.command)
return None
else:
+ logger.warning('connection closed, corrupt header line: '+data)
return None
if self.command not in ('HEAD', 'GET'):
+ logger.warning('connection closed, improper command: '+self.command)
return None
self.headers = {}
return self.read_header
@@ -189,6 +192,7 @@
try:
i = data.index(':')
except ValueError:
+ logger.warning('connection closed, corrupt header: '+data)
return None
self.headers[data[:i].strip().lower()] = data[i+1:].strip()
logger.debug(data[:i].strip() + ": " + data[i+1:].strip())
@@ -209,6 +213,7 @@
"""
if self.closed:
+ logger.warning('connection closed before anwswer, dropping data')
return
if self.encoding == 'gzip':
compressed = StringIO()
@@ -233,6 +238,8 @@
self.headers.get('referer','-'),
self.headers.get('user-agent','-') )
self.done = True
+ logger.info('sending response: '+str(responsecode)+' '+responsestring+
+ ' ('+str(len(data))+' bytes)')
r = StringIO()
r.write('HTTP/1.0 ' + str(responsecode) + ' ' +
responsestring + '\r\n')
Modified: debtorrent/trunk/DebTorrent/RawServer.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/RawServer.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/RawServer.py (original)
+++ debtorrent/trunk/DebTorrent/RawServer.py Mon Aug 6 00:50:01 2007
@@ -334,7 +334,7 @@
return
except KeyboardInterrupt:
signal(SIGINT, SIG_DFL)
-# self.exception(True)
+ self.exception(True)
return
except:
self.exception()
@@ -351,7 +351,7 @@
return
except KeyboardInterrupt:
signal(SIGINT, SIG_DFL)
-# self.exception(True)
+ self.exception(True)
return
except:
self.exception()
Modified: debtorrent/trunk/DebTorrent/ServerPortHandler.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/ServerPortHandler.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/ServerPortHandler.py (original)
+++ debtorrent/trunk/DebTorrent/ServerPortHandler.py Mon Aug 6 00:50:01 2007
@@ -6,6 +6,8 @@
"""Wrappers to handle multiple torrent downloads.
+ at type logger: C{logging.Logger}
+ at var logger: the logger to send all log messages to for this module
@type default_task_id: C{mutable}
@var default_task_id: the default task ID to use for scheduling all unspecified tasks
@@ -14,6 +16,8 @@
from cStringIO import StringIO
#from RawServer import RawServer
from BTcrypto import Crypto
+from binascii import b2a_hex
+import logging
try:
True
except:
@@ -21,6 +25,8 @@
False = 0
from BT1.Encrypter import protocol_name
+
+logger = logging.getLogger('DebTorrent.ServerPortHandler')
default_task_id = []
@@ -252,6 +258,7 @@
def _auto_close(self):
"""Automatically close the connection if it is not fully connected."""
if not self.complete:
+ logger.warning('Connection dropped due to handshake taking too long')
self.close()
def close(self):
@@ -291,9 +298,11 @@
if self._read_header(s):
if self.multihandler.config['crypto_only']:
+ logger.info('Dropped the connection as it was unencrypted')
return None
return 8, self.read_options
if not self.multihandler.config['crypto_allowed']:
+ logger.info('Dropped the connection as it was encrypted')
return None
self.encrypted = True
self.encrypter = Crypto(False)
@@ -370,7 +379,9 @@
self.multihandler.singlerawservers[k]._external_connection_made(
self.connection, None, self.buffer,
encrypted = self.encrypter )
+ logger.info('Found the encrypted download ID: '+b2a_hex(k))
return True
+ logger.info('Dropped the encrypted connection to an unknown torrent')
return None
def read_options(self, s):
@@ -402,7 +413,9 @@
if self.multihandler.singlerawservers[s].protocol == self.protocol:
self.multihandler.singlerawservers[s]._external_connection_made(
self.connection, self.options, self.buffer)
+ logger.info('Found the unencrypted download ID: '+b2a_hex(s))
return True
+ logger.info('Dropped the unencrypted connection to an unknown torrent: '+b2a_hex(s))
return None
@@ -475,6 +488,7 @@
try:
x = self.next_func(m)
except:
+ logger.exception('Dropped connection due to exception')
self.next_len, self.next_func = 1, self.read_dead
raise
if x is None:
Modified: debtorrent/trunk/DebTorrent/SocketHandler.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/SocketHandler.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/SocketHandler.py (original)
+++ debtorrent/trunk/DebTorrent/SocketHandler.py Mon Aug 6 00:50:01 2007
@@ -192,6 +192,7 @@
if self.skipped >= 3:
dead = True
if dead:
+ logger.debug('Socket is dead from write: '+self.ip)
self.socket_handler.dead_from_write.append(self)
return
if self.buffer:
@@ -258,7 +259,6 @@
self.ipv6_enable = ipv6_enable
self.readsize = readsize
self.poll = poll()
- # {socket: SingleSocket}
self.single_sockets = {}
self.dead_from_write = []
self.max_connects = 1000
@@ -351,6 +351,7 @@
self.servers[key] = value
for item in newinterfaces:
self.interfaces.append(item)
+ logger.info('Successfully bound to port '+str(port))
def find_and_bind(self, minport, maxport, bind = '', reuse = False,
ipv6_socket_style = 1, randomizer = False):
Modified: debtorrent/trunk/DebTorrent/__init__.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/__init__.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/__init__.py (original)
+++ debtorrent/trunk/DebTorrent/__init__.py Mon Aug 6 00:50:01 2007
@@ -8,6 +8,8 @@
This package, and it's subpackage L{BT1}, contains all the modules needed
to implement the DebTorrent protocol.
+ at type logger: C{logging.Logger}
+ at var logger: the logger to send all log messages to for this module
@type product_name: C{string}
@var product_name: the name given for the package
@type version_short: C{string}
@@ -28,11 +30,15 @@
from types import StringType
from sha import sha
from time import time, clock
+from binascii import b2a_hex
+import logging
try:
from os import getpid
except ImportError:
def getpid():
return 1
+
+logger = logging.getLogger('DebTorrent')
protocol_name = product_name+'/'+'.'.join(version_short[2:].split('.')[:2])
@@ -57,6 +63,7 @@
except:
x = ''
+ logger.info('Resetting the peer ID generation')
l1 = 0
t = clock()
while t == clock():
@@ -95,4 +102,5 @@
assert type(ins) is StringType
assert len(ins) == 3
+ logger.info('New peer ID: '+b2a_hex(_idprefix + ins + _idrandom[0]))
return _idprefix + ins + _idrandom[0]
Modified: debtorrent/trunk/DebTorrent/bencode.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/bencode.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/bencode.py (original)
+++ debtorrent/trunk/DebTorrent/bencode.py Mon Aug 6 00:50:01 2007
@@ -476,7 +476,7 @@
try:
encode_func[type(x)](x, r)
except:
- logger.error('could not encode type '+str(type(x))+' (value: '+str(x)+')')
+ logger.exception('could not encode type '+str(type(x))+' (value: '+str(x)+')')
assert 0
return ''.join(r)
Modified: debtorrent/trunk/DebTorrent/download_bt1.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/download_bt1.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/download_bt1.py (original)
+++ debtorrent/trunk/DebTorrent/download_bt1.py Mon Aug 6 00:50:01 2007
@@ -852,8 +852,10 @@
self.config, self.unpauseflag)
except ValueError, e:
+ logger.exception('bad data')
self._failed('bad data - ' + str(e))
except IOError, e:
+ logger.exception('IOError')
self._failed('IOError - ' + str(e))
if self.doneflag.isSet():
return None
@@ -1177,6 +1179,7 @@
"""
+ logger.info('Download shutdown')
if self.checking or self.started:
self.storagewrapper.sync()
self.storage.close()
@@ -1429,6 +1432,7 @@
def onPause(self):
"""Pause the download."""
+ logger.info('Download paused')
self.whenpaused = clock()
if not self.downloader:
return
@@ -1443,6 +1447,7 @@
def onUnpause(self):
"""Resume the download."""
+ logger.info('Download unpaused')
if not self.downloader:
return
self.downloader.pause(False)
Modified: debtorrent/trunk/DebTorrent/launchmanycore.py
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/DebTorrent/launchmanycore.py?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/DebTorrent/launchmanycore.py (original)
+++ debtorrent/trunk/DebTorrent/launchmanycore.py Mon Aug 6 00:50:01 2007
@@ -233,6 +233,7 @@
if self.closed:
return
+ logger.info('Download shutdown')
self.doneflag.set()
self.rawserver.shutdown()
if self.checking or self.working:
@@ -485,6 +486,7 @@
"""
+ logger.info('Removing torrent: '+str(binascii.b2a_hex(hash)))
self.torrent_list.remove(hash)
self.downloads[hash].shutdown()
del self.downloads[hash]
@@ -543,6 +545,7 @@
logger.error('Asked to start a torrent that is not in the cache')
return
+ logger.info('Starting torrent: '+str(binascii.b2a_hex(hash)))
c = self.counter
self.counter += 1
x = ''
@@ -620,7 +623,7 @@
"""
file = '/'.join(path)
- logger.debug('Trying to find file: '+file)
+ logger.info('Trying to find file: '+file)
found_torrents = []
# Check each torrent in the cache
Modified: debtorrent/trunk/TODO
URL: http://svn.debian.org/wsvn/debtorrent/debtorrent/trunk/TODO?rev=199&op=diff
==============================================================================
--- debtorrent/trunk/TODO (original)
+++ debtorrent/trunk/TODO Mon Aug 6 00:50:01 2007
@@ -78,13 +78,6 @@
file are used, an allocation method could be used within a file.
-Comments
-
-Comments are needed, both for new code, and the original. Variable naming
-could aslo be dramatically improved. This might break merging in new upstreams
-though (but this might already be broken).
-
-
Statistics for the swarm are incorrect
The statistics for file completion in the swarm are incorrect. This is due to
More information about the Debtorrent-commits
mailing list