Bitmessage/PyBitmessage-2025-01-25
Archived
2
0
Fork 0
Code Issues 167 Pull Requests 53 Actions Packages Projects Releases 5 Wiki Activity

Converted a bunch more print statements to logger calls, fixed some long comments

Browse Source
This commit is contained in:
Carlos Killpack 2013-06-20 17:23:10 -06:00
parent a46e4e457e
commit ab1164f4b6
1 changed files with 37 additions and 68 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

105
src/bitmessagemain.py Normal file → Executable file
View File

@ -305,7 +305,6 @@ class receiveDataThread(threading.Thread):
except Exception as err: except Exception as err:
logger.exception('sock.recv error. Closing recieveData thread (HOST: %s, ID: %s): %s' % (self.HOST, str(id(self)), str(err))) logger.exception('sock.recv error. Closing recieveData thread (HOST: %s, ID: %s): %s' % (self.HOST, str(id(self)), str(err)))
break break
logger.debug('Recieved %s' % str(repr(self.data)))
if self.data == "": if self.data == "":
logger.debug('Connection to %s closed. Closing recieveData thread. (ID: %s)' % (self.HOST, str(id(self)))) logger.debug('Connection to %s closed. Closing recieveData thread. (ID: %s)' % (self.HOST, str(id(self))))
break break
@ -339,17 +338,14 @@ class receiveDataThread(threading.Thread):
if len(self.data) < 20: # if so little of the data has arrived that we can't even unpack the payload length if len(self.data) < 20: # if so little of the data has arrived that we can't even unpack the payload length
return return
if self.data[0:4] != '\xe9\xbe\xb4\xd9': if self.data[0:4] != '\xe9\xbe\xb4\xd9':
if verbose >= 1: logger.info('The magic bytes were not correct. First 40 bytes of data: %s' % str(repr(self.data[0:40])))
shared.printLock.acquire()
print 'The magic bytes were not correct. First 40 bytes of data: ' + repr(self.data[0:40])
shared.printLock.release()
self.data = "" self.data = ""
return return
self.payloadLength, = unpack('>L', self.data[16:20]) self.payloadLength, = unpack('>L', self.data[16:20])
if len(self.data) < self.payloadLength + 24: # check if the whole message has arrived yet. if len(self.data) < self.payloadLength + 24: # check if the whole message has arrived yet.
return return
if self.data[20:24] != hashlib.sha512(self.data[24:self.payloadLength + 24]).digest()[0:4]: # test the checksum in the message. If it is correct... if self.data[20:24] != hashlib.sha512(self.data[24:self.payloadLength + 24]).digest()[0:4]: # test the checksum in the message. If it is correct...
print 'Checksum incorrect. Clearing this message.' logger.info('Checksum incorrect. Clearning this message.')
self.data = self.data[self.payloadLength + 24:] self.data = self.data[self.payloadLength + 24:]
self.processData() self.processData()
return return
@ -363,9 +359,7 @@ class receiveDataThread(threading.Thread):
shared.knownNodesLock.release() shared.knownNodesLock.release()
if self.payloadLength <= 180000000: # If the size of the message is greater than 180MB, ignore it. (I get memory errors when processing messages much larger than this though it is concievable that this value will have to be lowered if some systems are less tolarant of large messages.) if self.payloadLength <= 180000000: # If the size of the message is greater than 180MB, ignore it. (I get memory errors when processing messages much larger than this though it is concievable that this value will have to be lowered if some systems are less tolarant of large messages.)
remoteCommand = self.data[4:16] remoteCommand = self.data[4:16]
shared.printLock.acquire() logger.info('remoteCommand %s from %s' % (repr(remoteCommand.replace('\x00', '')), self.HOST))
print 'remoteCommand', repr(remoteCommand.replace('\x00', '')), ' from', self.HOST
shared.printLock.release()
if remoteCommand == 'version\x00\x00\x00\x00\x00': if remoteCommand == 'version\x00\x00\x00\x00\x00':
self.recversion(self.data[24:self.payloadLength + 24]) self.recversion(self.data[24:self.payloadLength + 24])
elif remoteCommand == 'verack\x00\x00\x00\x00\x00\x00': elif remoteCommand == 'verack\x00\x00\x00\x00\x00\x00':
@ -399,16 +393,11 @@ class receiveDataThread(threading.Thread):
objectHash, = random.sample( objectHash, = random.sample(
self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave, 1) self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave, 1)
if objectHash in shared.inventory: if objectHash in shared.inventory:
shared.printLock.acquire() logger.info('Inventory (in memory) already has object listen in inv message.')
print 'Inventory (in memory) already has object listed in inv message.'
shared.printLock.release()
del self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave[ del self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave[
objectHash] objectHash]
elif isInSqlInventory(objectHash): elif isInSqlInventory(objectHash):
if verbose >= 3: logger.info('Inventory (SQL on disk) alredy has object listen in inv message.')
shared.printLock.acquire()
print 'Inventory (SQL on disk) already has object listed in inv message.'
shared.printLock.release()
del self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave[ del self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave[
objectHash] objectHash]
else: else:
@ -416,9 +405,7 @@ class receiveDataThread(threading.Thread):
del self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave[ del self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave[
objectHash] # It is possible that the remote node doesn't respond with the object. In that case, we'll very likely get it from someone else anyway. objectHash] # It is possible that the remote node doesn't respond with the object. In that case, we'll very likely get it from someone else anyway.
if len(self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave) == 0: if len(self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave) == 0:
shared.printLock.acquire() logger.info('(concerning %s) Number of objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave is now: 0' % self.HOST)
print '(concerning', self.HOST + ')', 'number of objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave is now', len(self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave)
shared.printLock.release()
try: try:
del numberOfObjectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHavePerPeer[ del numberOfObjectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHavePerPeer[
self.HOST] # this data structure is maintained so that we can keep track of how many total objects, across all connections, are currently outstanding. If it goes too high it can indicate that we are under attack by multiple nodes working together. self.HOST] # this data structure is maintained so that we can keep track of how many total objects, across all connections, are currently outstanding. If it goes too high it can indicate that we are under attack by multiple nodes working together.
@ -426,18 +413,15 @@ class receiveDataThread(threading.Thread):
pass pass
break break
if len(self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave) == 0: if len(self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave) == 0:
shared.printLock.acquire() logger.info('(concerning %s) number of objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave is now 0' % self.HOST)
print '(concerning', self.HOST + ')', 'number of objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave is now', len(self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave)
shared.printLock.release()
try: try:
del numberOfObjectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHavePerPeer[ del numberOfObjectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHavePerPeer[
self.HOST] # this data structure is maintained so that we can keep track of how many total objects, across all connections, are currently outstanding. If it goes too high it can indicate that we are under attack by multiple nodes working together. self.HOST] # this data structure is maintained so that we can keep track of how many total objects, across all connections, are currently outstanding. If it goes too high it can indicate that we are under attack by multiple nodes working together.
except: except:
pass pass
if len(self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave) > 0: if len(self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave) > 0:
shared.printLock.acquire() logger.info('(concerning %s ) number of objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave is now %d' %
print '(concerning', self.HOST + ')', 'number of objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave is now', len(self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave) (self.HOST, len(self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave)))
shared.printLock.release()
numberOfObjectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHavePerPeer[self.HOST] = len( numberOfObjectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHavePerPeer[self.HOST] = len(
self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave) # this data structure is maintained so that we can keep track of how many total objects, across all connections, are currently outstanding. If it goes too high it can indicate that we are under attack by multiple nodes working together. self.objectsThatWeHaveYetToCheckAndSeeWhetherWeAlreadyHave) # this data structure is maintained so that we can keep track of how many total objects, across all connections, are currently outstanding. If it goes too high it can indicate that we are under attack by multiple nodes working together.
if len(self.ackDataThatWeHaveYetToSend) > 0: if len(self.ackDataThatWeHaveYetToSend) > 0:
@ -465,9 +449,7 @@ class receiveDataThread(threading.Thread):
'\xE9\xBE\xB4\xD9\x70\x6F\x6E\x67\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xcf\x83\xe1\x35') '\xE9\xBE\xB4\xD9\x70\x6F\x6E\x67\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xcf\x83\xe1\x35')
except Exception as err: except Exception as err:
# if not 'Bad file descriptor' in err: # if not 'Bad file descriptor' in err:
shared.printLock.acquire() logger.exception(err)
sys.stderr.write('sock.sendall error: %s\n' % err)
shared.printLock.release()
def recverack(self): def recverack(self):
print 'verack received' print 'verack received'
@ -485,19 +467,14 @@ class receiveDataThread(threading.Thread):
shared.UISignalQueue.put(('updateNetworkStatusTab', 'no data')) shared.UISignalQueue.put(('updateNetworkStatusTab', 'no data'))
remoteNodeIncomingPort, remoteNodeSeenTime = shared.knownNodes[ remoteNodeIncomingPort, remoteNodeSeenTime = shared.knownNodes[
self.streamNumber][self.HOST] self.streamNumber][self.HOST]
shared.printLock.acquire() logger.info('Connection fully established with %s:%d' % (self.HOST, remoteNodeIncomingPort))
print 'Connection fully established with', self.HOST, remoteNodeIncomingPort logger.info('The size of the connectedHostsList is now %d' % len(shared.connectedHostsList))
print 'The size of the connectedHostsList is now', len(shared.connectedHostsList) logger.info('Broadcasting addr from within connectionFullyEstablished()')
print 'The length of sendDataQueues is now:', len(shared.sendDataQueues)
print 'broadcasting addr from within connectionFullyEstablished function.'
shared.printLock.release()
self.broadcastaddr([(int(time.time()), self.streamNumber, 1, self.HOST, self.broadcastaddr([(int(time.time()), self.streamNumber, 1, self.HOST,
remoteNodeIncomingPort)]) # This lets all of our peers know about this new node. remoteNodeIncomingPort)]) # This lets all of our peers know about this new node.
self.sendaddr() # This is one large addr message to this one peer. self.sendaddr() # This is one large addr message to this one peer.
if not self.initiatedConnection and len(shared.connectedHostsList) > 200: if not self.initiatedConnection and len(shared.connectedHostsList) > 200:
shared.printLock.acquire() logger.info('We are connected to too many people. Closing connection.')
print 'We are connected to too many people. Closing connection.'
shared.printLock.release()
shared.broadcastToSendDataQueues((0, 'shutdown', self.HOST)) shared.broadcastToSendDataQueues((0, 'shutdown', self.HOST))
return return
self.sendBigInv() self.sendBigInv()
@ -532,7 +509,9 @@ class receiveDataThread(threading.Thread):
for hash, storedValue in bigInvList.items(): for hash, storedValue in bigInvList.items():
payload += hash payload += hash
numberOfObjectsInInvMessage += 1 numberOfObjectsInInvMessage += 1
if numberOfObjectsInInvMessage >= 50000: # We can only send a max of 50000 items per inv message but we may have more objects to advertise. They must be split up into multiple inv messages. if numberOfObjectsInInvMessage >= 50000:
# We can only send a max of 50000 items per inv message but we may have more
# objects to advertise. They must be split up into multiple inv messages.
self.sendinvMessageToJustThisOnePeer( self.sendinvMessageToJustThisOnePeer(
numberOfObjectsInInvMessage, payload) numberOfObjectsInInvMessage, payload)
payload = '' payload = ''
@ -549,23 +528,19 @@ class receiveDataThread(threading.Thread):
headerData += 'inv\x00\x00\x00\x00\x00\x00\x00\x00\x00' headerData += 'inv\x00\x00\x00\x00\x00\x00\x00\x00\x00'
headerData += pack('>L', len(payload)) headerData += pack('>L', len(payload))
headerData += hashlib.sha512(payload).digest()[:4] headerData += hashlib.sha512(payload).digest()[:4]
shared.printLock.acquire() logger.info('Sending huge inv message with %d objects to just this one peer.' % numberOfObjects)
print 'Sending huge inv message with', numberOfObjects, 'objects to just this one peer'
shared.printLock.release()
try: try:
self.sock.sendall(headerData + payload) self.sock.sendall(headerData + payload)
except Exception as err: except Exception as err:
# if not 'Bad file descriptor' in err: # if not 'Bad file descriptor' in err:
shared.printLock.acquire() logger.exception('sock.sendall error: %s' % str(err))
sys.stderr.write('sock.sendall error: %s\n' % err)
shared.printLock.release()
# We have received a broadcast message # We have received a broadcast message
def recbroadcast(self, data): def recbroadcast(self, data):
self.messageProcessingStartTime = time.time() self.messageProcessingStartTime = time.time()
# First we must check to make sure the proof of work is sufficient. # First we must check to make sure the proof of work is sufficient.
if not self.isProofOfWorkSufficient(data): if not self.isProofOfWorkSufficient(data):
print 'Proof of work in broadcast message insufficient.' logger.info('Proof of work in broadcast message insufficient.')
return return
readPosition = 8 # bypass the nonce readPosition = 8 # bypass the nonce
embeddedTime, = unpack('>I', data[readPosition:readPosition + 4]) embeddedTime, = unpack('>I', data[readPosition:readPosition + 4])
@ -579,13 +554,13 @@ class receiveDataThread(threading.Thread):
readPosition += 4 readPosition += 4
if embeddedTime > (int(time.time()) + 10800): # prevent funny business if embeddedTime > (int(time.time()) + 10800): # prevent funny business
print 'The embedded time in this broadcast message is more than three hours in the future. That doesn\'t make sense. Ignoring message.' logger.info('The embedded time in this broadcast message in more than three hours in the future. Ignoring message.')
return return
if embeddedTime < (int(time.time()) - maximumAgeOfAnObjectThatIAmWillingToAccept): if embeddedTime < (int(time.time()) - maximumAgeOfAnObjectThatIAmWillingToAccept):
print 'The embedded time in this broadcast message is too old. Ignoring message.' logger.info('The embedded time in this broadcast message is too old. Ignoring message.')
return return
if len(data) < 180: if len(data) < 180:
print 'The payload length of this broadcast packet is unreasonably low. Someone is probably trying funny business. Ignoring message.' logger.info('The payload length of this broadcast packet is unreasonably low. Ignoring message.')
return return
# Let us check to make sure the stream number is correct (thus # Let us check to make sure the stream number is correct (thus
# preventing an individual from sending broadcasts out on the wrong # preventing an individual from sending broadcasts out on the wrong
@ -596,17 +571,18 @@ class receiveDataThread(threading.Thread):
streamNumber, streamNumberLength = decodeVarint(data[ streamNumber, streamNumberLength = decodeVarint(data[
readPosition + broadcastVersionLength:readPosition + broadcastVersionLength + 10]) readPosition + broadcastVersionLength:readPosition + broadcastVersionLength + 10])
if streamNumber != self.streamNumber: if streamNumber != self.streamNumber:
print 'The stream number encoded in this broadcast message (' + str(streamNumber) + ') does not match the stream number on which it was received. Ignoring it.' logger.info("The stream number encoded in this broadcast message (%d) doesn't match the stream number it was recieved on. Ignoring it." %
streamNumber)
return return
shared.inventoryLock.acquire() shared.inventoryLock.acquire()
self.inventoryHash = calculateInventoryHash(data) self.inventoryHash = calculateInventoryHash(data)
if self.inventoryHash in shared.inventory: if self.inventoryHash in shared.inventory:
print 'We have already received this broadcast object. Ignoring.' logger.info('We have already recieved this broadcast object. Ignoring.')
shared.inventoryLock.release() shared.inventoryLock.release()
return return
elif isInSqlInventory(self.inventoryHash): elif isInSqlInventory(self.inventoryHash):
print 'We have already received this broadcast object (it is stored on disk in the SQL inventory). Ignoring it.' logger.info('We have already received this broadcast object (it is stored on disk in the SQL inventory). Ignoring it.')
shared.inventoryLock.release() shared.inventoryLock.release()
return return
# It is valid so far. Let's let our peers know about it. # It is valid so far. Let's let our peers know about it.
@ -648,7 +624,7 @@ class receiveDataThread(threading.Thread):
data[readPosition:readPosition + 9]) data[readPosition:readPosition + 9])
readPosition += broadcastVersionLength readPosition += broadcastVersionLength
if broadcastVersion < 1 or broadcastVersion > 2: if broadcastVersion < 1 or broadcastVersion > 2:
print 'Cannot decode incoming broadcast versions higher than 2. Assuming the sender isn\'t being silly, you should upgrade Bitmessage because this message shall be ignored.' logger.info('Cannot decode incoming broadcast versions higher than 2. Ignoring.')
return return
if broadcastVersion == 1: if broadcastVersion == 1:
beginningOfPubkeyPosition = readPosition # used when we add the pubkey to our pubkey table beginningOfPubkeyPosition = readPosition # used when we add the pubkey to our pubkey table
@ -676,8 +652,8 @@ class receiveDataThread(threading.Thread):
sendersHash = data[readPosition:readPosition + 20] sendersHash = data[readPosition:readPosition + 20]
if sendersHash not in shared.broadcastSendersForWhichImWatching: if sendersHash not in shared.broadcastSendersForWhichImWatching:
# Display timing data # Display timing data
logger.info('Time spent deciding that we are not interested in this v1 broadcast: %s' % logger.info('Time spent deciding that we are not interested in this v1 broadcast: %d' %
str(time.time() - self.messageProcessingStartTime)) time.time() - self.messageProcessingStartTime)
return return
# At this point, this message claims to be from sendersHash and # At this point, this message claims to be from sendersHash and
# we are interested in it. We still have to hash the public key # we are interested in it. We still have to hash the public key
@ -713,7 +689,7 @@ class receiveDataThread(threading.Thread):
return return
logger.info('ECDSA verify passed') logger.info('ECDSA verify passed')
except Exception as err: except Exception as err:
logger.debug('ECDSA verify failed: %s' % str(err)) logger.exception('ECDSA verify failed: %s' % str(err))
return return
# verify passed # verify passed
@ -740,9 +716,7 @@ class receiveDataThread(threading.Thread):
fromAddress = encodeAddress( fromAddress = encodeAddress(
sendersAddressVersion, sendersStream, ripe.digest()) sendersAddressVersion, sendersStream, ripe.digest())
shared.printLock.acquire() logger.info('fromAddress: %s' str(fromAddress))
print 'fromAddress:', fromAddress
shared.printLock.release()
if messageEncodingType == 2: if messageEncodingType == 2:
bodyPositionIndex = string.find(message, '\nBody:') bodyPositionIndex = string.find(message, '\nBody:')
if bodyPositionIndex > 1: if bodyPositionIndex > 1:
@ -755,7 +729,7 @@ class receiveDataThread(threading.Thread):
body = message body = message
subject = '' subject = ''
elif messageEncodingType == 0: elif messageEncodingType == 0:
print 'messageEncodingType == 0. Doing nothing with the message.' logger.info('messageEncodingType == 0. Doing nothing with the message.')
else: else:
body = 'Unknown encoding type.\n\n' + repr(message) body = 'Unknown encoding type.\n\n' + repr(message)
subject = '' subject = ''
@ -787,9 +761,7 @@ class receiveDataThread(threading.Thread):
call([apiNotifyPath, "newBroadcast"]) call([apiNotifyPath, "newBroadcast"])
# Display timing data # Display timing data
shared.printLock.acquire() logger.info('Time spent processing this interesting broadcast: %d' % time.time() - self.messageProcessingStartTime)
print 'Time spent processing this interesting broadcast:', time.time() - self.messageProcessingStartTime
shared.printLock.release()
if broadcastVersion == 2: if broadcastVersion == 2:
cleartextStreamNumber, cleartextStreamNumberLength = decodeVarint( cleartextStreamNumber, cleartextStreamNumberLength = decodeVarint(
data[readPosition:readPosition + 10]) data[readPosition:readPosition + 10])
@ -800,16 +772,13 @@ class receiveDataThread(threading.Thread):
decryptedData = cryptorObject.decrypt(data[readPosition:]) decryptedData = cryptorObject.decrypt(data[readPosition:])
toRipe = key # This is the RIPE hash of the sender's pubkey. We need this below to compare to the RIPE hash of the sender's address to verify that it was encrypted by with their key rather than some other key. toRipe = key # This is the RIPE hash of the sender's pubkey. We need this below to compare to the RIPE hash of the sender's address to verify that it was encrypted by with their key rather than some other key.
initialDecryptionSuccessful = True initialDecryptionSuccessful = True
print 'EC decryption successful using key associated with ripe hash:', key.encode('hex') logger.info('EC decryption successful using key associated with ripe hash: %d' % key.encode('hex'))
break break
except Exception as err: except Exception as err:
pass logger.exception('cryptorObject.decrypt Exception: %s' % str(err))
# print 'cryptorObject.decrypt Exception:', err
if not initialDecryptionSuccessful: if not initialDecryptionSuccessful:
# This is not a broadcast I am interested in. # This is not a broadcast I am interested in.
shared.printLock.acquire() logger.info('Length of time program spent failinf to decrypt this v2 broadcast %ds' % time.time() - self.messageProcessingStartTime)
print 'Length of time program spent failing to decrypt this v2 broadcast:', time.time() - self.messageProcessingStartTime, 'seconds.'
shared.printLock.release()
return return
# At this point this is a broadcast I have decrypted and thus am # At this point this is a broadcast I have decrypted and thus am
# interested in. # interested in.