Fix #611; also swap print statements out for loggers

This commit is contained in:
Jonathan Warren 2014-01-16 20:10:04 -05:00
parent f6d2a6029e
commit 85a409636a
2 changed files with 186 additions and 207 deletions

View File

@ -100,53 +100,45 @@ class objectProcessor(threading.Thread):
readPosition += streamNumberLength readPosition += streamNumberLength
if requestedAddressVersionNumber == 0: if requestedAddressVersionNumber == 0:
print 'The requestedAddressVersionNumber of the pubkey request is zero. That doesn\'t make any sense. Ignoring it.' logger.debug('The requestedAddressVersionNumber of the pubkey request is zero. That doesn\'t make any sense. Ignoring it.')
return return
elif requestedAddressVersionNumber == 1: elif requestedAddressVersionNumber == 1:
print 'The requestedAddressVersionNumber of the pubkey request is 1 which isn\'t supported anymore. Ignoring it.' logger.debug('The requestedAddressVersionNumber of the pubkey request is 1 which isn\'t supported anymore. Ignoring it.')
return return
elif requestedAddressVersionNumber > 4: elif requestedAddressVersionNumber > 4:
print 'The requestedAddressVersionNumber of the pubkey request is too high. Can\'t understand. Ignoring it.' logger.debug('The requestedAddressVersionNumber of the pubkey request is too high. Can\'t understand. Ignoring it.')
return return
myAddress = '' myAddress = ''
if requestedAddressVersionNumber <= 3 : if requestedAddressVersionNumber <= 3 :
requestedHash = data[readPosition:readPosition + 20] requestedHash = data[readPosition:readPosition + 20]
if len(requestedHash) != 20: if len(requestedHash) != 20:
print 'The length of the requested hash is not 20 bytes. Something is wrong. Ignoring.' logger.debug('The length of the requested hash is not 20 bytes. Something is wrong. Ignoring.')
return return
with shared.printLock: logger.info('the hash requested in this getpubkey request is: %s' % requestedHash.encode('hex'))
print 'the hash requested in this getpubkey request is:', requestedHash.encode('hex')
if requestedHash in shared.myAddressesByHash: # if this address hash is one of mine if requestedHash in shared.myAddressesByHash: # if this address hash is one of mine
myAddress = shared.myAddressesByHash[requestedHash] myAddress = shared.myAddressesByHash[requestedHash]
elif requestedAddressVersionNumber >= 4: elif requestedAddressVersionNumber >= 4:
requestedTag = data[readPosition:readPosition + 32] requestedTag = data[readPosition:readPosition + 32]
if len(requestedTag) != 32: if len(requestedTag) != 32:
print 'The length of the requested tag is not 32 bytes. Something is wrong. Ignoring.' logger.debug('The length of the requested tag is not 32 bytes. Something is wrong. Ignoring.')
return return
with shared.printLock: logger.debug('the tag requested in this getpubkey request is: %s' % requestedTag.encode('hex'))
print 'the tag requested in this getpubkey request is:', requestedTag.encode('hex')
if requestedTag in shared.myAddressesByTag: if requestedTag in shared.myAddressesByTag:
myAddress = shared.myAddressesByTag[requestedTag] myAddress = shared.myAddressesByTag[requestedTag]
if myAddress == '': if myAddress == '':
with shared.printLock: logger.info('This getpubkey request is not for any of my keys.')
print 'This getpubkey request is not for any of my keys.'
return return
if decodeAddress(myAddress)[1] != requestedAddressVersionNumber: if decodeAddress(myAddress)[1] != requestedAddressVersionNumber:
with shared.printLock: logger.warning('(Within the processgetpubkey function) Someone requested one of my pubkeys but the requestedAddressVersionNumber doesn\'t match my actual address version number. Ignoring.')
sys.stderr.write(
'(Within the recgetpubkey function) Someone requested one of my pubkeys but the requestedAddressVersionNumber doesn\'t match my actual address version number. Ignoring.\n')
return return
if decodeAddress(myAddress)[2] != streamNumber: if decodeAddress(myAddress)[2] != streamNumber:
with shared.printLock: logger.warning('(Within the processgetpubkey function) Someone requested one of my pubkeys but the stream number on which we heard this getpubkey object doesn\'t match this address\' stream number. Ignoring.')
sys.stderr.write(
'(Within the recgetpubkey function) Someone requested one of my pubkeys but the stream number on which we heard this getpubkey object doesn\'t match this address\' stream number. Ignoring.\n')
return return
if shared.safeConfigGetBoolean(myAddress, 'chan'): if shared.safeConfigGetBoolean(myAddress, 'chan'):
with shared.printLock: logger.info('Ignoring getpubkey request because it is for one of my chan addresses. The other party should already have the pubkey.')
print 'Ignoring getpubkey request because it is for one of my chan addresses. The other party should already have the pubkey.'
return return
try: try:
lastPubkeySendTime = int(shared.config.get( lastPubkeySendTime = int(shared.config.get(
@ -154,12 +146,9 @@ class objectProcessor(threading.Thread):
except: except:
lastPubkeySendTime = 0 lastPubkeySendTime = 0
if lastPubkeySendTime > time.time() - shared.lengthOfTimeToHoldOnToAllPubkeys: # If the last time we sent our pubkey was more recent than 28 days ago... if lastPubkeySendTime > time.time() - shared.lengthOfTimeToHoldOnToAllPubkeys: # If the last time we sent our pubkey was more recent than 28 days ago...
with shared.printLock: logger.info('Found getpubkey-requested-item in my list of EC hashes BUT we already sent it recently. Ignoring request. The lastPubkeySendTime is: %s' % lastPubkeySendTime)
print 'Found getpubkey-requested-item in my list of EC hashes BUT we already sent it recently. Ignoring request. The lastPubkeySendTime is:', lastPubkeySendTime
return return
logger.info('Found getpubkey-requested-hash in my list of EC hashes. Telling Worker thread to do the POW for a pubkey message and send it out.')
with shared.printLock:
print 'Found getpubkey-requested-hash in my list of EC hashes. Telling Worker thread to do the POW for a pubkey message and send it out.'
if requestedAddressVersionNumber == 2: if requestedAddressVersionNumber == 2:
shared.workerQueue.put(( shared.workerQueue.put((
'doPOWForMyV2Pubkey', requestedHash)) 'doPOWForMyV2Pubkey', requestedHash))
@ -193,15 +182,14 @@ class objectProcessor(threading.Thread):
data[readPosition:readPosition + 10]) data[readPosition:readPosition + 10])
readPosition += varintLength readPosition += varintLength
if addressVersion == 0: if addressVersion == 0:
print '(Within processpubkey) addressVersion of 0 doesn\'t make sense.' logger.debug('(Within processpubkey) addressVersion of 0 doesn\'t make sense.')
return return
if addressVersion > 4 or addressVersion == 1: if addressVersion > 4 or addressVersion == 1:
with shared.printLock: logger.info('This version of Bitmessage cannot handle version %s addresses.' % addressVersion)
print 'This version of Bitmessage cannot handle version', addressVersion, 'addresses.'
return return
if addressVersion == 2: if addressVersion == 2:
if len(data) < 146: # sanity check. This is the minimum possible length. if len(data) < 146: # sanity check. This is the minimum possible length.
print '(within processpubkey) payloadLength less than 146. Sanity check failed.' logger.debug('(within processpubkey) payloadLength less than 146. Sanity check failed.')
return return
bitfieldBehaviors = data[readPosition:readPosition + 4] bitfieldBehaviors = data[readPosition:readPosition + 4]
readPosition += 4 readPosition += 4
@ -212,7 +200,7 @@ class objectProcessor(threading.Thread):
readPosition += 64 readPosition += 64
publicEncryptionKey = data[readPosition:readPosition + 64] publicEncryptionKey = data[readPosition:readPosition + 64]
if len(publicEncryptionKey) < 64: if len(publicEncryptionKey) < 64:
print 'publicEncryptionKey length less than 64. Sanity check failed.' logger.debug('publicEncryptionKey length less than 64. Sanity check failed.')
return return
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
sha.update( sha.update(
@ -221,20 +209,25 @@ class objectProcessor(threading.Thread):
ripeHasher.update(sha.digest()) ripeHasher.update(sha.digest())
ripe = ripeHasher.digest() ripe = ripeHasher.digest()
with shared.printLock:
print 'within recpubkey, addressVersion:', addressVersion, ', streamNumber:', streamNumber
print 'ripe', ripe.encode('hex')
print 'publicSigningKey in hex:', publicSigningKey.encode('hex')
print 'publicEncryptionKey in hex:', publicEncryptionKey.encode('hex')
logger.info('within recpubkey, addressVersion: %s, streamNumber: %s \n\
ripe %s\n\
publicSigningKey in hex: %s\n\
publicEncryptionKey in hex: %s' % (addressVersion,
streamNumber,
ripe.encode('hex'),
publicSigningKey.encode('hex'),
publicEncryptionKey.encode('hex')
)
)
queryreturn = sqlQuery( queryreturn = sqlQuery(
'''SELECT usedpersonally FROM pubkeys WHERE hash=? AND addressversion=? AND usedpersonally='yes' ''', ripe, addressVersion) '''SELECT usedpersonally FROM pubkeys WHERE hash=? AND addressversion=? AND usedpersonally='yes' ''', ripe, addressVersion)
if queryreturn != []: # if this pubkey is already in our database and if we have used it personally: if queryreturn != []: # if this pubkey is already in our database and if we have used it personally:
print 'We HAVE used this pubkey personally. Updating time.' logger.info('We HAVE used this pubkey personally. Updating time.')
t = (ripe, addressVersion, data, embeddedTime, 'yes') t = (ripe, addressVersion, data, embeddedTime, 'yes')
else: else:
print 'We have NOT used this pubkey personally. Inserting in database.' logger.info('We have NOT used this pubkey personally. Inserting in database.')
t = (ripe, addressVersion, data, embeddedTime, 'no') t = (ripe, addressVersion, data, embeddedTime, 'no')
# This will also update the embeddedTime. # This will also update the embeddedTime.
sqlExecute('''INSERT INTO pubkeys VALUES (?,?,?,?,?)''', *t) sqlExecute('''INSERT INTO pubkeys VALUES (?,?,?,?,?)''', *t)
@ -242,7 +235,7 @@ class objectProcessor(threading.Thread):
self.possibleNewPubkey(ripe = ripe) self.possibleNewPubkey(ripe = ripe)
if addressVersion == 3: if addressVersion == 3:
if len(data) < 170: # sanity check. if len(data) < 170: # sanity check.
print '(within processpubkey) payloadLength less than 170. Sanity check failed.' logger.warning('(within processpubkey) payloadLength less than 170. Sanity check failed.')
return return
bitfieldBehaviors = data[readPosition:readPosition + 4] bitfieldBehaviors = data[readPosition:readPosition + 4]
readPosition += 4 readPosition += 4
@ -266,11 +259,11 @@ class objectProcessor(threading.Thread):
signature = data[readPosition:readPosition + signatureLength] signature = data[readPosition:readPosition + signatureLength]
try: try:
if not highlevelcrypto.verify(data[8:endOfSignedDataPosition], signature, publicSigningKey.encode('hex')): if not highlevelcrypto.verify(data[8:endOfSignedDataPosition], signature, publicSigningKey.encode('hex')):
print 'ECDSA verify failed (within processpubkey)' logger.warning('ECDSA verify failed (within processpubkey)')
return return
print 'ECDSA verify passed (within processpubkey)' logger.info('ECDSA verify passed (within processpubkey)')
except Exception as err: except Exception as err:
print 'ECDSA verify failed (within processpubkey)', err logger.warning('ECDSA verify failed (within processpubkey) %s' % err)
return return
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
@ -278,20 +271,25 @@ class objectProcessor(threading.Thread):
ripeHasher = hashlib.new('ripemd160') ripeHasher = hashlib.new('ripemd160')
ripeHasher.update(sha.digest()) ripeHasher.update(sha.digest())
ripe = ripeHasher.digest() ripe = ripeHasher.digest()
with shared.printLock: logger.info('within recpubkey, addressVersion: %s, streamNumber: %s \n\
print 'within recpubkey, addressVersion:', addressVersion, ', streamNumber:', streamNumber ripe %s\n\
print 'ripe', ripe.encode('hex') publicSigningKey in hex: %s\n\
print 'publicSigningKey in hex:', publicSigningKey.encode('hex') publicEncryptionKey in hex: %s' % (addressVersion,
print 'publicEncryptionKey in hex:', publicEncryptionKey.encode('hex') streamNumber,
ripe.encode('hex'),
publicSigningKey.encode('hex'),
publicEncryptionKey.encode('hex')
)
)
queryreturn = sqlQuery('''SELECT usedpersonally FROM pubkeys WHERE hash=? AND addressversion=? AND usedpersonally='yes' ''', ripe, addressVersion) queryreturn = sqlQuery('''SELECT usedpersonally FROM pubkeys WHERE hash=? AND addressversion=? AND usedpersonally='yes' ''', ripe, addressVersion)
if queryreturn != []: # if this pubkey is already in our database and if we have used it personally: if queryreturn != []: # if this pubkey is already in our database and if we have used it personally:
print 'We HAVE used this pubkey personally. Updating time.' logger.info('We HAVE used this pubkey personally. Updating time.')
t = (ripe, addressVersion, data, embeddedTime, 'yes') t = (ripe, addressVersion, data, embeddedTime, 'yes')
else: else:
print 'We have NOT used this pubkey personally. Inserting in database.' logger.info('We have NOT used this pubkey personally. Inserting in database.')
t = (ripe, addressVersion, data, embeddedTime, 'no') t = (ripe, addressVersion, data, embeddedTime, 'no')
# This will also update the embeddedTime. # This will also update the embeddedTime.
sqlExecute('''INSERT INTO pubkeys VALUES (?,?,?,?,?)''', *t) sqlExecute('''INSERT INTO pubkeys VALUES (?,?,?,?,?)''', *t)
@ -308,15 +306,14 @@ class objectProcessor(threading.Thread):
would run and handle that event quite quickly. would run and handle that event quite quickly.
""" """
if len(data) < 350: # sanity check. if len(data) < 350: # sanity check.
print '(within processpubkey) payloadLength less than 350. Sanity check failed.' logger.debug('(within processpubkey) payloadLength less than 350. Sanity check failed.')
return return
signedData = data[8:readPosition] # Some of the signed data is not encrypted so let's keep it for now. signedData = data[8:readPosition] # Some of the signed data is not encrypted so let's keep it for now.
tag = data[readPosition:readPosition + 32] tag = data[readPosition:readPosition + 32]
readPosition += 32 readPosition += 32
encryptedData = data[readPosition:] encryptedData = data[readPosition:]
if tag not in shared.neededPubkeys: if tag not in shared.neededPubkeys:
with shared.printLock: logger.info('We don\'t need this v4 pubkey. We didn\'t ask for it.')
print 'We don\'t need this v4 pubkey. We didn\'t ask for it.'
return return
# Let us try to decrypt the pubkey # Let us try to decrypt the pubkey
@ -326,8 +323,7 @@ class objectProcessor(threading.Thread):
except: except:
# Someone must have encrypted some data with a different key # Someone must have encrypted some data with a different key
# but tagged it with a tag for which we are watching. # but tagged it with a tag for which we are watching.
with shared.printLock: logger.info('Pubkey decryption was unsuccessful.')
print 'Pubkey decryption was unsuccessful.'
return return
readPosition = 0 readPosition = 0
@ -353,11 +349,11 @@ class objectProcessor(threading.Thread):
signature = decryptedData[readPosition:readPosition + signatureLength] signature = decryptedData[readPosition:readPosition + signatureLength]
try: try:
if not highlevelcrypto.verify(signedData, signature, publicSigningKey.encode('hex')): if not highlevelcrypto.verify(signedData, signature, publicSigningKey.encode('hex')):
print 'ECDSA verify failed (within processpubkey)' logger.info('ECDSA verify failed (within processpubkey)')
return return
print 'ECDSA verify passed (within processpubkey)' logger.info('ECDSA verify passed (within processpubkey)')
except Exception as err: except Exception as err:
print 'ECDSA verify failed (within processpubkey)', err logger.info('ECDSA verify failed (within processpubkey) %s' % err)
return return
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
@ -369,17 +365,19 @@ class objectProcessor(threading.Thread):
# We need to make sure that the tag on the outside of the encryption # We need to make sure that the tag on the outside of the encryption
# is the one generated from hashing these particular keys. # is the one generated from hashing these particular keys.
if tag != hashlib.sha512(hashlib.sha512(encodeVarint(addressVersion) + encodeVarint(streamNumber) + ripe).digest()).digest()[32:]: if tag != hashlib.sha512(hashlib.sha512(encodeVarint(addressVersion) + encodeVarint(streamNumber) + ripe).digest()).digest()[32:]:
with shared.printLock: logger.info('Someone was trying to act malicious: tag doesn\'t match the keys in this pubkey message. Ignoring it.')
print 'Someone was trying to act malicious: tag doesn\'t match the keys in this pubkey message. Ignoring it.'
return return
else:
print 'Tag successfully matches keys in pubkey message' # testing. Will remove soon. logger.info('within recpubkey, addressVersion: %s, streamNumber: %s \n\
ripe %s\n\
with shared.printLock: publicSigningKey in hex: %s\n\
print 'within recpubkey, addressVersion:', addressVersion, ', streamNumber:', streamNumber publicEncryptionKey in hex: %s' % (addressVersion,
print 'ripe', ripe.encode('hex') streamNumber,
print 'publicSigningKey in hex:', publicSigningKey.encode('hex') ripe.encode('hex'),
print 'publicEncryptionKey in hex:', publicEncryptionKey.encode('hex') publicSigningKey.encode('hex'),
publicEncryptionKey.encode('hex')
)
)
t = (ripe, addressVersion, signedData, embeddedTime, 'yes') t = (ripe, addressVersion, signedData, embeddedTime, 'yes')
sqlExecute('''INSERT INTO pubkeys VALUES (?,?,?,?,?)''', *t) sqlExecute('''INSERT INTO pubkeys VALUES (?,?,?,?,?)''', *t)
@ -393,8 +391,7 @@ class objectProcessor(threading.Thread):
# Display timing data # Display timing data
timeRequiredToProcessPubkey = time.time( timeRequiredToProcessPubkey = time.time(
) - pubkeyProcessingStartTime ) - pubkeyProcessingStartTime
with shared.printLock: logger.debug('Time required to process this pubkey: %s' % timeRequiredToProcessPubkey)
print 'Time required to process this pubkey:', timeRequiredToProcessPubkey
def processmsg(self, data): def processmsg(self, data):
@ -419,9 +416,7 @@ class objectProcessor(threading.Thread):
initialDecryptionSuccessful = False initialDecryptionSuccessful = False
# Let's check whether this is a message acknowledgement bound for us. # Let's check whether this is a message acknowledgement bound for us.
if data[readPosition:] in shared.ackdataForWhichImWatching: if data[readPosition:] in shared.ackdataForWhichImWatching:
with shared.printLock: logger.info('This msg IS an acknowledgement bound for me.')
print 'This msg IS an acknowledgement bound for me.'
del shared.ackdataForWhichImWatching[data[readPosition:]] del shared.ackdataForWhichImWatching[data[readPosition:]]
sqlExecute('UPDATE sent SET status=? WHERE ackdata=?', sqlExecute('UPDATE sent SET status=? WHERE ackdata=?',
'ackreceived', data[readPosition:]) 'ackreceived', data[readPosition:])
@ -429,9 +424,7 @@ class objectProcessor(threading.Thread):
time.strftime(shared.config.get('bitmessagesettings', 'timeformat'), time.localtime(int(time.time()))), 'utf-8'))))) time.strftime(shared.config.get('bitmessagesettings', 'timeformat'), time.localtime(int(time.time()))), 'utf-8')))))
return return
else: else:
with shared.printLock: logger.info('This was NOT an acknowledgement bound for me.')
print 'This was NOT an acknowledgement bound for me.'
# print 'shared.ackdataForWhichImWatching', shared.ackdataForWhichImWatching
# This is not an acknowledgement bound for me. See if it is a message # This is not an acknowledgement bound for me. See if it is a message
@ -442,16 +435,14 @@ class objectProcessor(threading.Thread):
data[readPosition:]) data[readPosition:])
toRipe = key # This is the RIPE hash of my pubkeys. We need this below to compare to the destination_ripe included in the encrypted data. toRipe = key # This is the RIPE hash of my pubkeys. We need this below to compare to the destination_ripe included in the encrypted data.
initialDecryptionSuccessful = True initialDecryptionSuccessful = True
with shared.printLock: logger.info('EC decryption successful using key associated with ripe hash: %s' % key.encode('hex'))
print 'EC decryption successful using key associated with ripe hash:', key.encode('hex')
break break
except Exception as err: except Exception as err:
pass pass
# print 'cryptorObject.decrypt Exception:', err # print 'cryptorObject.decrypt Exception:', err
if not initialDecryptionSuccessful: if not initialDecryptionSuccessful:
# This is not a message bound for me. # This is not a message bound for me.
with shared.printLock: logger.info('Length of time program spent failing to decrypt this message: %s seconds.' % (time.time() - messageProcessingStartTime,))
print 'Length of time program spent failing to decrypt this message:', time.time() - messageProcessingStartTime, 'seconds.'
return return
# This is a message bound for me. # This is a message bound for me.
@ -462,24 +453,24 @@ class objectProcessor(threading.Thread):
decryptedData[readPosition:readPosition + 10]) decryptedData[readPosition:readPosition + 10])
readPosition += messageVersionLength readPosition += messageVersionLength
if messageVersion != 1: if messageVersion != 1:
print 'Cannot understand message versions other than one. Ignoring message.' logger.info('Cannot understand message versions other than one. Ignoring message.')
return return
sendersAddressVersionNumber, sendersAddressVersionNumberLength = decodeVarint( sendersAddressVersionNumber, sendersAddressVersionNumberLength = decodeVarint(
decryptedData[readPosition:readPosition + 10]) decryptedData[readPosition:readPosition + 10])
readPosition += sendersAddressVersionNumberLength readPosition += sendersAddressVersionNumberLength
if sendersAddressVersionNumber == 0: if sendersAddressVersionNumber == 0:
print 'Cannot understand sendersAddressVersionNumber = 0. Ignoring message.' logger.info('Cannot understand sendersAddressVersionNumber = 0. Ignoring message.')
return return
if sendersAddressVersionNumber > 4: if sendersAddressVersionNumber > 4:
print 'Sender\'s address version number', sendersAddressVersionNumber, 'not yet supported. Ignoring message.' logger.info('Sender\'s address version number %s not yet supported. Ignoring message.' % sendersAddressVersionNumber)
return return
if len(decryptedData) < 170: if len(decryptedData) < 170:
print 'Length of the unencrypted data is unreasonably short. Sanity check failed. Ignoring message.' logger.info('Length of the unencrypted data is unreasonably short. Sanity check failed. Ignoring message.')
return return
sendersStreamNumber, sendersStreamNumberLength = decodeVarint( sendersStreamNumber, sendersStreamNumberLength = decodeVarint(
decryptedData[readPosition:readPosition + 10]) decryptedData[readPosition:readPosition + 10])
if sendersStreamNumber == 0: if sendersStreamNumber == 0:
print 'sender\'s stream number is 0. Ignoring message.' logger.info('sender\'s stream number is 0. Ignoring message.')
return return
readPosition += sendersStreamNumberLength readPosition += sendersStreamNumberLength
behaviorBitfield = decryptedData[readPosition:readPosition + 4] behaviorBitfield = decryptedData[readPosition:readPosition + 4]
@ -494,18 +485,18 @@ class objectProcessor(threading.Thread):
requiredAverageProofOfWorkNonceTrialsPerByte, varintLength = decodeVarint( requiredAverageProofOfWorkNonceTrialsPerByte, varintLength = decodeVarint(
decryptedData[readPosition:readPosition + 10]) decryptedData[readPosition:readPosition + 10])
readPosition += varintLength readPosition += varintLength
print 'sender\'s requiredAverageProofOfWorkNonceTrialsPerByte is', requiredAverageProofOfWorkNonceTrialsPerByte logger.info('sender\'s requiredAverageProofOfWorkNonceTrialsPerByte is %s' % requiredAverageProofOfWorkNonceTrialsPerByte)
requiredPayloadLengthExtraBytes, varintLength = decodeVarint( requiredPayloadLengthExtraBytes, varintLength = decodeVarint(
decryptedData[readPosition:readPosition + 10]) decryptedData[readPosition:readPosition + 10])
readPosition += varintLength readPosition += varintLength
print 'sender\'s requiredPayloadLengthExtraBytes is', requiredPayloadLengthExtraBytes logger.info('sender\'s requiredPayloadLengthExtraBytes is %s' % requiredPayloadLengthExtraBytes)
endOfThePublicKeyPosition = readPosition # needed for when we store the pubkey in our database of pubkeys for later use. endOfThePublicKeyPosition = readPosition # needed for when we store the pubkey in our database of pubkeys for later use.
if toRipe != decryptedData[readPosition:readPosition + 20]: if toRipe != decryptedData[readPosition:readPosition + 20]:
with shared.printLock: logger.info('The original sender of this message did not send it to you. Someone is attempting a Surreptitious Forwarding Attack.\n\
print 'The original sender of this message did not send it to you. Someone is attempting a Surreptitious Forwarding Attack.' See: http://world.std.com/~dtd/sign_encrypt/sign_encrypt7.html \n\
print 'See: http://world.std.com/~dtd/sign_encrypt/sign_encrypt7.html' your toRipe: %s\n\
print 'your toRipe:', toRipe.encode('hex') embedded destination toRipe: %s' % (toRipe.encode('hex'), decryptedData[readPosition:readPosition + 20].encode('hex'))
print 'embedded destination toRipe:', decryptedData[readPosition:readPosition + 20].encode('hex') )
return return
readPosition += 20 readPosition += 20
messageEncodingType, messageEncodingTypeLength = decodeVarint( messageEncodingType, messageEncodingTypeLength = decodeVarint(
@ -530,14 +521,15 @@ class objectProcessor(threading.Thread):
readPosition:readPosition + signatureLength] readPosition:readPosition + signatureLength]
try: try:
if not highlevelcrypto.verify(decryptedData[:positionOfBottomOfAckData], signature, pubSigningKey.encode('hex')): if not highlevelcrypto.verify(decryptedData[:positionOfBottomOfAckData], signature, pubSigningKey.encode('hex')):
print 'ECDSA verify failed' logger.debug('ECDSA verify failed')
return return
print 'ECDSA verify passed' logger.debug('ECDSA verify passed')
except Exception as err: except Exception as err:
print 'ECDSA verify failed', err logger.debug('ECDSA verify failed %s' % err)
return return
with shared.printLock: logger.debug('As a matter of intellectual curiosity, here is the Bitcoin address associated with the keys owned by the other person: %s ..and here is the testnet address: %s. The other person must take their private signing key from Bitmessage and import it into Bitcoin (or a service like Blockchain.info) for it to be of any use. Do not use this unless you know what you are doing.' %
print 'As a matter of intellectual curiosity, here is the Bitcoin address associated with the keys owned by the other person:', helper_bitcoin.calculateBitcoinAddressFromPubkey(pubSigningKey), ' ..and here is the testnet address:', helper_bitcoin.calculateTestnetAddressFromPubkey(pubSigningKey), '. The other person must take their private signing key from Bitmessage and import it into Bitcoin (or a service like Blockchain.info) for it to be of any use. Do not use this unless you know what you are doing.' (helper_bitcoin.calculateBitcoinAddressFromPubkey(pubSigningKey), helper_bitcoin.calculateTestnetAddressFromPubkey(pubSigningKey))
)
# calculate the fromRipe. # calculate the fromRipe.
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
@ -574,8 +566,10 @@ class objectProcessor(threading.Thread):
self.possibleNewPubkey(address = fromAddress) self.possibleNewPubkey(address = fromAddress)
# If this message is bound for one of my version 3 addresses (or # If this message is bound for one of my version 3 addresses (or
# higher), then we must check to make sure it meets our demanded # higher), then we must check to make sure it meets our demanded
# proof of work requirement. # proof of work requirement. If this is bound for one of my chan
if decodeAddress(toAddress)[1] >= 3: # If the toAddress version number is 3 or higher: # addresses then we skip this check; the minimum network POW is
# fine.
if decodeAddress(toAddress)[1] >= 3 and not shared.safeConfigGetBoolean(toAddress, 'chan'): # If the toAddress version number is 3 or higher and not one of my chan addresses:
if not shared.isAddressInMyAddressBookSubscriptionsListOrWhitelist(fromAddress): # If I'm not friendly with this person: if not shared.isAddressInMyAddressBookSubscriptionsListOrWhitelist(fromAddress): # If I'm not friendly with this person:
requiredNonceTrialsPerByte = shared.config.getint( requiredNonceTrialsPerByte = shared.config.getint(
toAddress, 'noncetrialsperbyte') toAddress, 'noncetrialsperbyte')
@ -590,8 +584,7 @@ class objectProcessor(threading.Thread):
'''SELECT label FROM blacklist where address=? and enabled='1' ''', '''SELECT label FROM blacklist where address=? and enabled='1' ''',
fromAddress) fromAddress)
if queryreturn != []: if queryreturn != []:
with shared.printLock: logger.info('Message ignored because address is in blacklist.')
print 'Message ignored because address is in blacklist.'
blockMessage = True blockMessage = True
else: # We're using a whitelist else: # We're using a whitelist
@ -599,7 +592,7 @@ class objectProcessor(threading.Thread):
'''SELECT label FROM whitelist where address=? and enabled='1' ''', '''SELECT label FROM whitelist where address=? and enabled='1' ''',
fromAddress) fromAddress)
if queryreturn == []: if queryreturn == []:
print 'Message ignored because address not in whitelist.' logger.info('Message ignored because address not in whitelist.')
blockMessage = True blockMessage = True
if not blockMessage: if not blockMessage:
toLabel = shared.config.get(toAddress, 'label') toLabel = shared.config.get(toAddress, 'label')
@ -608,11 +601,12 @@ class objectProcessor(threading.Thread):
if messageEncodingType == 2: if messageEncodingType == 2:
subject, body = self.decodeType2Message(message) subject, body = self.decodeType2Message(message)
logger.info('Message subject (first 100 characters): %s' % repr(subject)[:100])
elif messageEncodingType == 1: elif messageEncodingType == 1:
body = message body = message
subject = '' subject = ''
elif messageEncodingType == 0: elif messageEncodingType == 0:
print 'messageEncodingType == 0. Doing nothing with the message. They probably just sent it so that we would store their public key or send their ack data for them.' logger.info('messageEncodingType == 0. Doing nothing with the message. They probably just sent it so that we would store their public key or send their ack data for them.')
else: else:
body = 'Unknown encoding type.\n\n' + repr(message) body = 'Unknown encoding type.\n\n' + repr(message)
subject = '' subject = ''
@ -682,9 +676,10 @@ class objectProcessor(threading.Thread):
sum = 0 sum = 0
for item in shared.successfullyDecryptMessageTimings: for item in shared.successfullyDecryptMessageTimings:
sum += item sum += item
with shared.printLock: logger.debug('Time to decrypt this message successfully: %s\n\
print 'Time to decrypt this message successfully:', timeRequiredToAttemptToDecryptMessage Average time for all message decryption successes since startup: %s.' %
print 'Average time for all message decryption successes since startup:', sum / len(shared.successfullyDecryptMessageTimings) (timeRequiredToAttemptToDecryptMessage, sum / len(shared.successfullyDecryptMessageTimings))
)
def processbroadcast(self, data): def processbroadcast(self, data):
@ -708,7 +703,7 @@ class objectProcessor(threading.Thread):
data[readPosition:readPosition + 9]) data[readPosition:readPosition + 9])
readPosition += broadcastVersionLength readPosition += broadcastVersionLength
if broadcastVersion < 1 or broadcastVersion > 3: if broadcastVersion < 1 or broadcastVersion > 3:
print 'Cannot decode incoming broadcast versions higher than 3. Assuming the sender isn\'t being silly, you should upgrade Bitmessage because this message shall be ignored.' logger.debug('Cannot decode incoming broadcast versions higher than 3. Assuming the sender isn\'t being silly, you should upgrade Bitmessage because this message shall be ignored.')
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
@ -736,9 +731,7 @@ class objectProcessor(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
with shared.printLock: logger.debug('Time spent deciding that we are not interested in this v1 broadcast: %s' % (time.time() - messageProcessingStartTime,))
print 'Time spent deciding that we are not interested in this v1 broadcast:', time.time() - 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
@ -770,17 +763,16 @@ class objectProcessor(threading.Thread):
signature = data[readPosition:readPosition + signatureLength] signature = data[readPosition:readPosition + signatureLength]
try: try:
if not highlevelcrypto.verify(data[12:readPositionAtBottomOfMessage], signature, sendersPubSigningKey.encode('hex')): if not highlevelcrypto.verify(data[12:readPositionAtBottomOfMessage], signature, sendersPubSigningKey.encode('hex')):
print 'ECDSA verify failed' logger.debug('ECDSA verify failed')
return return
print 'ECDSA verify passed' logger.debug('ECDSA verify passed')
except Exception as err: except Exception as err:
print 'ECDSA verify failed', err logger.debug('ECDSA verify failed %s' % err)
return return
# verify passed # verify passed
fromAddress = encodeAddress( fromAddress = encodeAddress(
sendersAddressVersion, sendersStream, ripe.digest()) sendersAddressVersion, sendersStream, ripe.digest())
with shared.printLock: logger.debug('fromAddress: %s' % fromAddress)
print 'fromAddress:', fromAddress
# Let's store the public key in case we want to reply to this person. # Let's store the public key in case we want to reply to this person.
# We don't have the correct nonce or time (which would let us # We don't have the correct nonce or time (which would let us
@ -803,11 +795,12 @@ class objectProcessor(threading.Thread):
if messageEncodingType == 2: if messageEncodingType == 2:
subject, body = decodeType2Message(message) subject, body = decodeType2Message(message)
logger.info('Broadcast subject (first 100 characters): %s' % repr(subject)[:100])
elif messageEncodingType == 1: elif messageEncodingType == 1:
body = message body = message
subject = '' subject = ''
elif messageEncodingType == 0: elif messageEncodingType == 0:
print 'messageEncodingType == 0. Doing nothing with the message.' logger.debug('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 = ''
@ -835,8 +828,7 @@ class objectProcessor(threading.Thread):
call([apiNotifyPath, "newBroadcast"]) call([apiNotifyPath, "newBroadcast"])
# Display timing data # Display timing data
with shared.printLock: logger.debug('Time spent processing this interesting broadcast: %s' % (time.time() - messageProcessingStartTime,))
print 'Time spent processing this interesting broadcast:', time.time() - messageProcessingStartTime
if broadcastVersion == 2: if broadcastVersion == 2:
cleartextStreamNumber, cleartextStreamNumberLength = decodeVarint( cleartextStreamNumber, cleartextStreamNumberLength = decodeVarint(
@ -848,16 +840,14 @@ class objectProcessor(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: %s' % key.encode('hex'))
break break
except Exception as err: except Exception as err:
pass pass
# print 'cryptorObject.decrypt Exception:', 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.
with shared.printLock: logger.debug('Length of time program spent failing to decrypt this v2 broadcast: %s seconds.' % (time.time() - messageProcessingStartTime,))
print 'Length of time program spent failing to decrypt this v2 broadcast:', time.time() - messageProcessingStartTime, 'seconds.'
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.
@ -867,13 +857,13 @@ class objectProcessor(threading.Thread):
sendersAddressVersion, sendersAddressVersionLength = decodeVarint( sendersAddressVersion, sendersAddressVersionLength = decodeVarint(
decryptedData[readPosition:readPosition + 9]) decryptedData[readPosition:readPosition + 9])
if sendersAddressVersion < 2 or sendersAddressVersion > 3: if sendersAddressVersion < 2 or sendersAddressVersion > 3:
print 'Cannot decode senderAddressVersion other than 2 or 3. Assuming the sender isn\'t being silly, you should upgrade Bitmessage because this message shall be ignored.' logger.info('Cannot decode senderAddressVersion other than 2 or 3. Assuming the sender isn\'t being silly, you should upgrade Bitmessage because this message shall be ignored.')
return return
readPosition += sendersAddressVersionLength readPosition += sendersAddressVersionLength
sendersStream, sendersStreamLength = decodeVarint( sendersStream, sendersStreamLength = decodeVarint(
decryptedData[readPosition:readPosition + 9]) decryptedData[readPosition:readPosition + 9])
if sendersStream != cleartextStreamNumber: if sendersStream != cleartextStreamNumber:
print 'The stream number outside of the encryption on which the POW was completed doesn\'t match the stream number inside the encryption. Ignoring broadcast.' logger.info('The stream number outside of the encryption on which the POW was completed doesn\'t match the stream number inside the encryption. Ignoring broadcast.')
return return
readPosition += sendersStreamLength readPosition += sendersStreamLength
behaviorBitfield = decryptedData[readPosition:readPosition + 4] behaviorBitfield = decryptedData[readPosition:readPosition + 4]
@ -888,11 +878,11 @@ class objectProcessor(threading.Thread):
requiredAverageProofOfWorkNonceTrialsPerByte, varintLength = decodeVarint( requiredAverageProofOfWorkNonceTrialsPerByte, varintLength = decodeVarint(
decryptedData[readPosition:readPosition + 10]) decryptedData[readPosition:readPosition + 10])
readPosition += varintLength readPosition += varintLength
print 'sender\'s requiredAverageProofOfWorkNonceTrialsPerByte is', requiredAverageProofOfWorkNonceTrialsPerByte logger.debug('sender\'s requiredAverageProofOfWorkNonceTrialsPerByte is %s' % requiredAverageProofOfWorkNonceTrialsPerByte)
requiredPayloadLengthExtraBytes, varintLength = decodeVarint( requiredPayloadLengthExtraBytes, varintLength = decodeVarint(
decryptedData[readPosition:readPosition + 10]) decryptedData[readPosition:readPosition + 10])
readPosition += varintLength readPosition += varintLength
print 'sender\'s requiredPayloadLengthExtraBytes is', requiredPayloadLengthExtraBytes logger.debug('sender\'s requiredPayloadLengthExtraBytes is %s' % requiredPayloadLengthExtraBytes)
endOfPubkeyPosition = readPosition endOfPubkeyPosition = readPosition
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
@ -901,7 +891,7 @@ class objectProcessor(threading.Thread):
ripe.update(sha.digest()) ripe.update(sha.digest())
if toRipe != ripe.digest(): if toRipe != ripe.digest():
print 'The encryption key used to encrypt this message doesn\'t match the keys inbedded in the message itself. Ignoring message.' logger.info('The encryption key used to encrypt this message doesn\'t match the keys inbedded in the message itself. Ignoring message.')
return return
messageEncodingType, messageEncodingTypeLength = decodeVarint( messageEncodingType, messageEncodingTypeLength = decodeVarint(
decryptedData[readPosition:readPosition + 9]) decryptedData[readPosition:readPosition + 9])
@ -921,11 +911,11 @@ class objectProcessor(threading.Thread):
readPosition:readPosition + signatureLength] readPosition:readPosition + signatureLength]
try: try:
if not highlevelcrypto.verify(decryptedData[:readPositionAtBottomOfMessage], signature, sendersPubSigningKey.encode('hex')): if not highlevelcrypto.verify(decryptedData[:readPositionAtBottomOfMessage], signature, sendersPubSigningKey.encode('hex')):
print 'ECDSA verify failed' logger.debug('ECDSA verify failed')
return return
print 'ECDSA verify passed' logger.debug('ECDSA verify passed')
except Exception as err: except Exception as err:
print 'ECDSA verify failed', err logger.debug('ECDSA verify failed %s' % err)
return return
# verify passed # verify passed
@ -950,11 +940,12 @@ class objectProcessor(threading.Thread):
if messageEncodingType == 2: if messageEncodingType == 2:
subject, body = self.decodeType2Message(message) subject, body = self.decodeType2Message(message)
logger.info('Broadcast subject (first 100 characters): %s' % repr(subject)[:100])
elif messageEncodingType == 1: elif messageEncodingType == 1:
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 = ''
@ -982,8 +973,7 @@ class objectProcessor(threading.Thread):
call([apiNotifyPath, "newBroadcast"]) call([apiNotifyPath, "newBroadcast"])
# Display timing data # Display timing data
with shared.printLock: logger.info('Time spent processing this interesting broadcast: %s' % (time.time() - messageProcessingStartTime,))
print 'Time spent processing this interesting broadcast:', time.time() - messageProcessingStartTime
if broadcastVersion == 3: if broadcastVersion == 3:
cleartextStreamNumber, cleartextStreamNumberLength = decodeVarint( cleartextStreamNumber, cleartextStreamNumberLength = decodeVarint(
@ -992,17 +982,15 @@ class objectProcessor(threading.Thread):
embeddedTag = data[readPosition:readPosition+32] embeddedTag = data[readPosition:readPosition+32]
readPosition += 32 readPosition += 32
if embeddedTag not in shared.MyECSubscriptionCryptorObjects: if embeddedTag not in shared.MyECSubscriptionCryptorObjects:
with shared.printLock: logger.debug('We\'re not interested in this broadcast.')
print 'We\'re not interested in this broadcast.'
return return
# We are interested in this broadcast because of its tag. # We are interested in this broadcast because of its tag.
cryptorObject = shared.MyECSubscriptionCryptorObjects[embeddedTag] cryptorObject = shared.MyECSubscriptionCryptorObjects[embeddedTag]
try: try:
decryptedData = cryptorObject.decrypt(data[readPosition:]) decryptedData = cryptorObject.decrypt(data[readPosition:])
print 'EC decryption successful' logger.debug('EC decryption successful')
except Exception as err: except Exception as err:
with shared.printLock: logger.debug('Broadcast version 3 decryption Unsuccessful.')
print 'Broadcast version 3 decryption Unsuccessful.'
return return
signedBroadcastVersion, readPosition = decodeVarint( signedBroadcastVersion, readPosition = decodeVarint(
@ -1011,13 +999,13 @@ class objectProcessor(threading.Thread):
sendersAddressVersion, sendersAddressVersionLength = decodeVarint( sendersAddressVersion, sendersAddressVersionLength = decodeVarint(
decryptedData[readPosition:readPosition + 9]) decryptedData[readPosition:readPosition + 9])
if sendersAddressVersion < 4: if sendersAddressVersion < 4:
print 'Cannot decode senderAddressVersion less than 4 for broadcast version number 3. Assuming the sender isn\'t being silly, you should upgrade Bitmessage because this message shall be ignored.' logger.info('Cannot decode senderAddressVersion less than 4 for broadcast version number 3. Assuming the sender isn\'t being silly, you should upgrade Bitmessage because this message shall be ignored.')
return return
readPosition += sendersAddressVersionLength readPosition += sendersAddressVersionLength
sendersStream, sendersStreamLength = decodeVarint( sendersStream, sendersStreamLength = decodeVarint(
decryptedData[readPosition:readPosition + 9]) decryptedData[readPosition:readPosition + 9])
if sendersStream != cleartextStreamNumber: if sendersStream != cleartextStreamNumber:
print 'The stream number outside of the encryption on which the POW was completed doesn\'t match the stream number inside the encryption. Ignoring broadcast.' logger.info('The stream number outside of the encryption on which the POW was completed doesn\'t match the stream number inside the encryption. Ignoring broadcast.')
return return
readPosition += sendersStreamLength readPosition += sendersStreamLength
behaviorBitfield = decryptedData[readPosition:readPosition + 4] behaviorBitfield = decryptedData[readPosition:readPosition + 4]
@ -1032,11 +1020,11 @@ class objectProcessor(threading.Thread):
requiredAverageProofOfWorkNonceTrialsPerByte, varintLength = decodeVarint( requiredAverageProofOfWorkNonceTrialsPerByte, varintLength = decodeVarint(
decryptedData[readPosition:readPosition + 10]) decryptedData[readPosition:readPosition + 10])
readPosition += varintLength readPosition += varintLength
print 'sender\'s requiredAverageProofOfWorkNonceTrialsPerByte is', requiredAverageProofOfWorkNonceTrialsPerByte logger.debug('sender\'s requiredAverageProofOfWorkNonceTrialsPerByte is %s' % requiredAverageProofOfWorkNonceTrialsPerByte)
requiredPayloadLengthExtraBytes, varintLength = decodeVarint( requiredPayloadLengthExtraBytes, varintLength = decodeVarint(
decryptedData[readPosition:readPosition + 10]) decryptedData[readPosition:readPosition + 10])
readPosition += varintLength readPosition += varintLength
print 'sender\'s requiredPayloadLengthExtraBytes is', requiredPayloadLengthExtraBytes logger.debug('sender\'s requiredPayloadLengthExtraBytes is %s' % requiredPayloadLengthExtraBytes)
endOfPubkeyPosition = readPosition endOfPubkeyPosition = readPosition
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
@ -1048,7 +1036,7 @@ class objectProcessor(threading.Thread):
calculatedTag = hashlib.sha512(hashlib.sha512(encodeVarint( calculatedTag = hashlib.sha512(hashlib.sha512(encodeVarint(
sendersAddressVersion) + encodeVarint(sendersStream) + calculatedRipe).digest()).digest()[32:] sendersAddressVersion) + encodeVarint(sendersStream) + calculatedRipe).digest()).digest()[32:]
if calculatedTag != embeddedTag: if calculatedTag != embeddedTag:
print 'The tag and encryption key used to encrypt this message doesn\'t match the keys inbedded in the message itself. Ignoring message.' logger.debug('The tag and encryption key used to encrypt this message doesn\'t match the keys inbedded in the message itself. Ignoring message.')
return return
messageEncodingType, messageEncodingTypeLength = decodeVarint( messageEncodingType, messageEncodingTypeLength = decodeVarint(
decryptedData[readPosition:readPosition + 9]) decryptedData[readPosition:readPosition + 9])
@ -1068,18 +1056,17 @@ class objectProcessor(threading.Thread):
readPosition:readPosition + signatureLength] readPosition:readPosition + signatureLength]
try: try:
if not highlevelcrypto.verify(decryptedData[:readPositionAtBottomOfMessage], signature, sendersPubSigningKey.encode('hex')): if not highlevelcrypto.verify(decryptedData[:readPositionAtBottomOfMessage], signature, sendersPubSigningKey.encode('hex')):
print 'ECDSA verify failed' logger.debug('ECDSA verify failed')
return return
print 'ECDSA verify passed' logger.debug('ECDSA verify passed')
except Exception as err: except Exception as err:
print 'ECDSA verify failed', err logger.debug('ECDSA verify failed %s' % err)
return return
# verify passed # verify passed
fromAddress = encodeAddress( fromAddress = encodeAddress(
sendersAddressVersion, sendersStream, calculatedRipe) sendersAddressVersion, sendersStream, calculatedRipe)
with shared.printLock: logger.info('fromAddress: %s' % fromAddress)
print 'fromAddress:', fromAddress
# Let's store the public key in case we want to reply to this person. # Let's store the public key in case we want to reply to this person.
sqlExecute( sqlExecute(
@ -1096,11 +1083,12 @@ class objectProcessor(threading.Thread):
if messageEncodingType == 2: if messageEncodingType == 2:
subject, body = self.decodeType2Message(message) subject, body = self.decodeType2Message(message)
logger.info('Broadcast subject (first 100 characters): %s' % repr(subject)[:100])
elif messageEncodingType == 1: elif messageEncodingType == 1:
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 = ''
@ -1128,9 +1116,7 @@ class objectProcessor(threading.Thread):
call([apiNotifyPath, "newBroadcast"]) call([apiNotifyPath, "newBroadcast"])
# Display timing data # Display timing data
with shared.printLock: logger.debug('Time spent processing this interesting broadcast: %s' % (time.time() - messageProcessingStartTime,))
print 'Time spent processing this interesting broadcast:', time.time() - messageProcessingStartTime
# We have inserted a pubkey into our pubkey table which we received from a # We have inserted a pubkey into our pubkey table which we received from a
# pubkey, msg, or broadcast message. It might be one that we have been # pubkey, msg, or broadcast message. It might be one that we have been
@ -1139,15 +1125,14 @@ class objectProcessor(threading.Thread):
# For address versions <= 3, we wait on a key with the correct ripe hash # For address versions <= 3, we wait on a key with the correct ripe hash
if ripe != None: if ripe != None:
if ripe in shared.neededPubkeys: if ripe in shared.neededPubkeys:
print 'We have been awaiting the arrival of this pubkey.' logger.info('We have been awaiting the arrival of this pubkey.')
del shared.neededPubkeys[ripe] del shared.neededPubkeys[ripe]
sqlExecute( sqlExecute(
'''UPDATE sent SET status='doingmsgpow' WHERE toripe=? AND (status='awaitingpubkey' or status='doingpubkeypow') and folder='sent' ''', '''UPDATE sent SET status='doingmsgpow' WHERE toripe=? AND (status='awaitingpubkey' or status='doingpubkeypow') and folder='sent' ''',
ripe) ripe)
shared.workerQueue.put(('sendmessage', '')) shared.workerQueue.put(('sendmessage', ''))
else: else:
with shared.printLock: logger.debug('We don\'t need this pub key. We didn\'t ask for it. Pubkey hash: %s' % ripe.encode('hex'))
print 'We don\'t need this pub key. We didn\'t ask for it. Pubkey hash:', ripe.encode('hex')
# For address versions >= 4, we wait on a pubkey with the correct tag. # For address versions >= 4, we wait on a pubkey with the correct tag.
# Let us create the tag from the address and see if we were waiting # Let us create the tag from the address and see if we were waiting
# for it. # for it.
@ -1156,7 +1141,7 @@ class objectProcessor(threading.Thread):
tag = hashlib.sha512(hashlib.sha512(encodeVarint( tag = hashlib.sha512(hashlib.sha512(encodeVarint(
addressVersion) + encodeVarint(streamNumber) + ripe).digest()).digest()[32:] addressVersion) + encodeVarint(streamNumber) + ripe).digest()).digest()[32:]
if tag in shared.neededPubkeys: if tag in shared.neededPubkeys:
print 'We have been awaiting the arrival of this pubkey.' logger.info('We have been awaiting the arrival of this pubkey.')
del shared.neededPubkeys[tag] del shared.neededPubkeys[tag]
sqlExecute( sqlExecute(
'''UPDATE sent SET status='doingmsgpow' WHERE toripe=? AND (status='awaitingpubkey' or status='doingpubkeypow') and folder='sent' ''', '''UPDATE sent SET status='doingmsgpow' WHERE toripe=? AND (status='awaitingpubkey' or status='doingpubkeypow') and folder='sent' ''',
@ -1165,17 +1150,17 @@ class objectProcessor(threading.Thread):
def ackDataHasAVaildHeader(self, ackData): def ackDataHasAVaildHeader(self, ackData):
if len(ackData) < 24: if len(ackData) < 24:
print 'The length of ackData is unreasonably short. Not sending ackData.' logger.info('The length of ackData is unreasonably short. Not sending ackData.')
return False return False
if ackData[0:4] != '\xe9\xbe\xb4\xd9': if ackData[0:4] != '\xe9\xbe\xb4\xd9':
print 'Ackdata magic bytes were wrong. Not sending ackData.' logger.info('Ackdata magic bytes were wrong. Not sending ackData.')
return False return False
ackDataPayloadLength, = unpack('>L', ackData[16:20]) ackDataPayloadLength, = unpack('>L', ackData[16:20])
if len(ackData) - 24 != ackDataPayloadLength: if len(ackData) - 24 != ackDataPayloadLength:
print 'ackData payload length doesn\'t match the payload length specified in the header. Not sending ackdata.' logger.info('ackData payload length doesn\'t match the payload length specified in the header. Not sending ackdata.')
return False return False
if ackData[20:24] != hashlib.sha512(ackData[24:]).digest()[0:4]: # test the checksum in the message. if ackData[20:24] != hashlib.sha512(ackData[24:]).digest()[0:4]: # test the checksum in the message.
print 'ackdata checksum wrong. Not sending ackdata.' logger.info('ackdata checksum wrong. Not sending ackdata.')
return False return False
if ackDataPayloadLength > 180000000: # If the size of the message is greater than 180MB, ignore it. if ackDataPayloadLength > 180000000: # If the size of the message is greater than 180MB, ignore it.
return False return False

View File

@ -290,7 +290,6 @@ def isProofOfWorkSufficient(
payloadLengthExtraBytes = networkDefaultPayloadLengthExtraBytes payloadLengthExtraBytes = networkDefaultPayloadLengthExtraBytes
POW, = unpack('>Q', hashlib.sha512(hashlib.sha512(data[ POW, = unpack('>Q', hashlib.sha512(hashlib.sha512(data[
:8] + hashlib.sha512(data[8:]).digest()).digest()).digest()[0:8]) :8] + hashlib.sha512(data[8:]).digest()).digest()).digest()[0:8])
# print 'POW:', POW
return POW <= 2 ** 64 / ((len(data) + payloadLengthExtraBytes) * (nonceTrialsPerByte)) return POW <= 2 ** 64 / ((len(data) + payloadLengthExtraBytes) * (nonceTrialsPerByte))
def doCleanShutdown(): def doCleanShutdown():
@ -431,15 +430,13 @@ def decryptAndCheckPubkeyPayload(payload, address):
embeddedVersionNumber, varintLength = decodeVarint( embeddedVersionNumber, varintLength = decodeVarint(
payload[readPosition:readPosition + 10]) payload[readPosition:readPosition + 10])
if embeddedVersionNumber != addressVersion: if embeddedVersionNumber != addressVersion:
with shared.printLock: logger.info('Pubkey decryption was UNsuccessful due to address version mismatch. This shouldn\'t have happened.')
print 'Pubkey decryption was UNsuccessful due to address version mismatch. This shouldn\'t have happened.'
return 'failed' return 'failed'
readPosition += varintLength readPosition += varintLength
embeddedStreamNumber, varintLength = decodeVarint( embeddedStreamNumber, varintLength = decodeVarint(
payload[readPosition:readPosition + 10]) payload[readPosition:readPosition + 10])
if embeddedStreamNumber != streamNumber: if embeddedStreamNumber != streamNumber:
with shared.printLock: logger.info('Pubkey decryption was UNsuccessful due to stream number mismatch. This shouldn\'t have happened.')
print 'Pubkey decryption was UNsuccessful due to stream number mismatch. This shouldn\'t have happened.'
return 'failed' return 'failed'
readPosition += varintLength readPosition += varintLength
signedData = payload[8:readPosition] # Some of the signed data is not encrypted so let's keep it for now. signedData = payload[8:readPosition] # Some of the signed data is not encrypted so let's keep it for now.
@ -454,10 +451,9 @@ def decryptAndCheckPubkeyPayload(payload, address):
except: except:
# Someone must have encrypted some data with a different key # Someone must have encrypted some data with a different key
# but tagged it with a tag for which we are watching. # but tagged it with a tag for which we are watching.
with shared.printLock: logger.info('Pubkey decryption was UNsuccessful. This shouldn\'t have happened.')
print 'Pubkey decryption was UNsuccessful. This shouldn\'t have happened.'
return 'failed' return 'failed'
print 'Pubkey decryption successful' logger.debug('Pubkey decryption successful')
readPosition = 4 # bypass the behavior bitfield readPosition = 4 # bypass the behavior bitfield
publicSigningKey = '\x04' + decryptedData[readPosition:readPosition + 64] publicSigningKey = '\x04' + decryptedData[readPosition:readPosition + 64]
# Is it possible for a public key to be invalid such that trying to # Is it possible for a public key to be invalid such that trying to
@ -479,11 +475,11 @@ def decryptAndCheckPubkeyPayload(payload, address):
signature = decryptedData[readPosition:readPosition + signatureLength] signature = decryptedData[readPosition:readPosition + signatureLength]
try: try:
if not highlevelcrypto.verify(signedData, signature, publicSigningKey.encode('hex')): if not highlevelcrypto.verify(signedData, signature, publicSigningKey.encode('hex')):
print 'ECDSA verify failed (within decryptAndCheckPubkeyPayload).' logger.info('ECDSA verify failed (within decryptAndCheckPubkeyPayload).')
return 'failed' return 'failed'
print 'ECDSA verify passed (within decryptAndCheckPubkeyPayload)' logger.debug('ECDSA verify passed (within decryptAndCheckPubkeyPayload)')
except Exception as err: except Exception as err:
print 'ECDSA verify failed (within decryptAndCheckPubkeyPayload)', err logger.debug('ECDSA verify failed (within decryptAndCheckPubkeyPayload) %s' % err)
return 'failed' return 'failed'
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
@ -496,8 +492,7 @@ def decryptAndCheckPubkeyPayload(payload, address):
# Although this pubkey object had the tag were were looking for and was # Although this pubkey object had the tag were were looking for and was
# encrypted with the correct encryption key, it doesn't contain the # encrypted with the correct encryption key, it doesn't contain the
# correct keys. Someone is either being malicious or using buggy software. # correct keys. Someone is either being malicious or using buggy software.
with shared.printLock: logger.info('Pubkey decryption was UNsuccessful due to RIPE mismatch. This shouldn\'t have happened.')
print 'Pubkey decryption was UNsuccessful due to RIPE mismatch. This shouldn\'t have happened.'
return 'failed' return 'failed'
t = (ripe, addressVersion, signedData, int(time.time()), 'yes') t = (ripe, addressVersion, signedData, int(time.time()), 'yes')
@ -509,7 +504,7 @@ Peer = collections.namedtuple('Peer', ['host', 'port'])
def checkAndShareMsgWithPeers(data): def checkAndShareMsgWithPeers(data):
# Let us check to make sure that the proof of work is sufficient. # Let us check to make sure that the proof of work is sufficient.
if not isProofOfWorkSufficient(data): if not isProofOfWorkSufficient(data):
print 'Proof of work in msg message insufficient.' logger.debug('Proof of work in msg message insufficient.')
return return
readPosition = 8 readPosition = 8
@ -523,21 +518,27 @@ def checkAndShareMsgWithPeers(data):
else: else:
readPosition += 4 readPosition += 4
if embeddedTime > (int(time.time()) + 10800):
logger.debug('The embedded time in this msg message is more than three hours in the future. That doesn\'t make sense. Ignoring message.')
return
if embeddedTime < (int(time.time()) - maximumAgeOfAnObjectThatIAmWillingToAccept):
logger.debug('The embedded time in this msg message is too old. Ignoring message.')
return
streamNumberAsClaimedByMsg, streamNumberAsClaimedByMsgLength = decodeVarint( streamNumberAsClaimedByMsg, streamNumberAsClaimedByMsgLength = decodeVarint(
data[readPosition:readPosition + 9]) data[readPosition:readPosition + 9])
if not streamNumberAsClaimedByMsg in streamsInWhichIAmParticipating: if not streamNumberAsClaimedByMsg in streamsInWhichIAmParticipating:
print 'The streamNumber', streamNumberAsClaimedByMsg, 'isn\'t one we are interested in.' logger.debug('The streamNumber %s isn\'t one we are interested in.' % streamNumberAsClaimedByMsg)
return return
readPosition += streamNumberAsClaimedByMsgLength readPosition += streamNumberAsClaimedByMsgLength
inventoryHash = calculateInventoryHash(data) inventoryHash = calculateInventoryHash(data)
shared.numberOfInventoryLookupsPerformed += 1 shared.numberOfInventoryLookupsPerformed += 1
inventoryLock.acquire() inventoryLock.acquire()
if inventoryHash in inventory: if inventoryHash in inventory:
print 'We have already received this msg message. Ignoring.' logger.debug('We have already received this msg message. Ignoring.')
inventoryLock.release() inventoryLock.release()
return return
elif isInSqlInventory(inventoryHash): elif isInSqlInventory(inventoryHash):
print 'We have already received this msg message (it is stored on disk in the SQL inventory). Ignoring it.' logger.debug('We have already received this msg message (it is stored on disk in the SQL inventory). Ignoring it.')
inventoryLock.release() inventoryLock.release()
return return
# This msg message is valid. Let's let our peers know about it. # This msg message is valid. Let's let our peers know about it.
@ -546,8 +547,7 @@ def checkAndShareMsgWithPeers(data):
objectType, streamNumberAsClaimedByMsg, data, embeddedTime,'') objectType, streamNumberAsClaimedByMsg, data, embeddedTime,'')
inventorySets[streamNumberAsClaimedByMsg].add(inventoryHash) inventorySets[streamNumberAsClaimedByMsg].add(inventoryHash)
inventoryLock.release() inventoryLock.release()
with printLock: logger.debug('advertising inv with hash: %s' % inventoryHash.encode('hex'))
print 'advertising inv with hash:', inventoryHash.encode('hex')
broadcastToSendDataQueues((streamNumberAsClaimedByMsg, 'advertiseobject', inventoryHash)) broadcastToSendDataQueues((streamNumberAsClaimedByMsg, 'advertiseobject', inventoryHash))
# Now let's enqueue it to be processed ourselves. # Now let's enqueue it to be processed ourselves.
@ -560,10 +560,10 @@ def checkAndShareMsgWithPeers(data):
def checkAndSharegetpubkeyWithPeers(data): def checkAndSharegetpubkeyWithPeers(data):
if not isProofOfWorkSufficient(data): if not isProofOfWorkSufficient(data):
print 'Proof of work in getpubkey message insufficient.' logger.debug('Proof of work in getpubkey message insufficient.')
return return
if len(data) < 34: if len(data) < 34:
print 'getpubkey message doesn\'t contain enough data. Ignoring.' logger.debug('getpubkey message doesn\'t contain enough data. Ignoring.')
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])
@ -577,10 +577,10 @@ def checkAndSharegetpubkeyWithPeers(data):
readPosition += 4 readPosition += 4
if embeddedTime > int(time.time()) + 10800: if embeddedTime > int(time.time()) + 10800:
print 'The time in this getpubkey message is too new. Ignoring it. Time:', embeddedTime logger.debug('The time in this getpubkey message is too new. Ignoring it. Time: %s' % embeddedTime)
return return
if embeddedTime < int(time.time()) - maximumAgeOfAnObjectThatIAmWillingToAccept: if embeddedTime < int(time.time()) - maximumAgeOfAnObjectThatIAmWillingToAccept:
print 'The time in this getpubkey message is too old. Ignoring it. Time:', embeddedTime logger.debug('The time in this getpubkey message is too old. Ignoring it. Time: %s' % embeddedTime)
return return
requestedAddressVersionNumber, addressVersionLength = decodeVarint( requestedAddressVersionNumber, addressVersionLength = decodeVarint(
data[readPosition:readPosition + 10]) data[readPosition:readPosition + 10])
@ -588,7 +588,7 @@ def checkAndSharegetpubkeyWithPeers(data):
streamNumber, streamNumberLength = decodeVarint( streamNumber, streamNumberLength = decodeVarint(
data[readPosition:readPosition + 10]) data[readPosition:readPosition + 10])
if not streamNumber in streamsInWhichIAmParticipating: if not streamNumber in streamsInWhichIAmParticipating:
print 'The streamNumber', streamNumber, 'isn\'t one we are interested in.' logger.debug('The streamNumber %s isn\'t one we are interested in.' % streamNumber)
return return
readPosition += streamNumberLength readPosition += streamNumberLength
@ -596,11 +596,11 @@ def checkAndSharegetpubkeyWithPeers(data):
inventoryHash = calculateInventoryHash(data) inventoryHash = calculateInventoryHash(data)
inventoryLock.acquire() inventoryLock.acquire()
if inventoryHash in inventory: if inventoryHash in inventory:
print 'We have already received this getpubkey request. Ignoring it.' logger.debug('We have already received this getpubkey request. Ignoring it.')
inventoryLock.release() inventoryLock.release()
return return
elif isInSqlInventory(inventoryHash): elif isInSqlInventory(inventoryHash):
print 'We have already received this getpubkey request (it is stored on disk in the SQL inventory). Ignoring it.' logger.debug('We have already received this getpubkey request (it is stored on disk in the SQL inventory). Ignoring it.')
inventoryLock.release() inventoryLock.release()
return return
@ -610,8 +610,7 @@ def checkAndSharegetpubkeyWithPeers(data):
inventorySets[streamNumber].add(inventoryHash) inventorySets[streamNumber].add(inventoryHash)
inventoryLock.release() inventoryLock.release()
# This getpubkey request is valid. Forward to peers. # This getpubkey request is valid. Forward to peers.
with printLock: logger.debug('advertising inv with hash: %s' % inventoryHash.encode('hex'))
print 'advertising inv with hash:', inventoryHash.encode('hex')
broadcastToSendDataQueues((streamNumber, 'advertiseobject', inventoryHash)) broadcastToSendDataQueues((streamNumber, 'advertiseobject', inventoryHash))
# Now let's queue it to be processed ourselves. # Now let's queue it to be processed ourselves.
@ -627,7 +626,7 @@ def checkAndSharePubkeyWithPeers(data):
return return
# Let us make sure that the proof of work is sufficient. # Let us make sure that the proof of work is sufficient.
if not isProofOfWorkSufficient(data): if not isProofOfWorkSufficient(data):
print 'Proof of work in pubkey message insufficient.' logger.debug('Proof of work in pubkey message insufficient.')
return return
readPosition = 8 # for the nonce readPosition = 8 # for the nonce
@ -642,12 +641,10 @@ def checkAndSharePubkeyWithPeers(data):
readPosition += 4 readPosition += 4
if embeddedTime < int(time.time()) - lengthOfTimeToHoldOnToAllPubkeys: if embeddedTime < int(time.time()) - lengthOfTimeToHoldOnToAllPubkeys:
with printLock: logger.debug('The embedded time in this pubkey message is too old. Ignoring. Embedded time is: %s' % embeddedTime)
print 'The embedded time in this pubkey message is too old. Ignoring. Embedded time is:', embeddedTime
return return
if embeddedTime > int(time.time()) + 10800: if embeddedTime > int(time.time()) + 10800:
with printLock: logger.debug('The embedded time in this pubkey message more than several hours in the future. This is irrational. Ignoring message.')
print 'The embedded time in this pubkey message more than several hours in the future. This is irrational. Ignoring message.'
return return
addressVersion, varintLength = decodeVarint( addressVersion, varintLength = decodeVarint(
data[readPosition:readPosition + 10]) data[readPosition:readPosition + 10])
@ -656,11 +653,11 @@ def checkAndSharePubkeyWithPeers(data):
data[readPosition:readPosition + 10]) data[readPosition:readPosition + 10])
readPosition += varintLength readPosition += varintLength
if not streamNumber in streamsInWhichIAmParticipating: if not streamNumber in streamsInWhichIAmParticipating:
print 'The streamNumber', streamNumber, 'isn\'t one we are interested in.' logger.debug('The streamNumber %s isn\'t one we are interested in.' % streamNumber)
return return
if addressVersion >= 4: if addressVersion >= 4:
tag = data[readPosition:readPosition + 32] tag = data[readPosition:readPosition + 32]
print 'tag in received pubkey is:', tag.encode('hex') logger.debug('tag in received pubkey is: %s' % tag.encode('hex'))
else: else:
tag = '' tag = ''
@ -668,11 +665,11 @@ def checkAndSharePubkeyWithPeers(data):
inventoryHash = calculateInventoryHash(data) inventoryHash = calculateInventoryHash(data)
inventoryLock.acquire() inventoryLock.acquire()
if inventoryHash in inventory: if inventoryHash in inventory:
print 'We have already received this pubkey. Ignoring it.' logger.debug('We have already received this pubkey. Ignoring it.')
inventoryLock.release() inventoryLock.release()
return return
elif isInSqlInventory(inventoryHash): elif isInSqlInventory(inventoryHash):
print 'We have already received this pubkey (it is stored on disk in the SQL inventory). Ignoring it.' logger.debug('We have already received this pubkey (it is stored on disk in the SQL inventory). Ignoring it.')
inventoryLock.release() inventoryLock.release()
return return
objectType = 'pubkey' objectType = 'pubkey'
@ -681,8 +678,7 @@ def checkAndSharePubkeyWithPeers(data):
inventorySets[streamNumber].add(inventoryHash) inventorySets[streamNumber].add(inventoryHash)
inventoryLock.release() inventoryLock.release()
# This object is valid. Forward it to peers. # This object is valid. Forward it to peers.
with printLock: logger.debug('advertising inv with hash: %s' % inventoryHash.encode('hex'))
print 'advertising inv with hash:', inventoryHash.encode('hex')
broadcastToSendDataQueues((streamNumber, 'advertiseobject', inventoryHash)) broadcastToSendDataQueues((streamNumber, 'advertiseobject', inventoryHash))
@ -698,7 +694,7 @@ def checkAndSharePubkeyWithPeers(data):
def checkAndShareBroadcastWithPeers(data): def checkAndShareBroadcastWithPeers(data):
# Let us verify that the proof of work is sufficient. # Let us verify that the proof of work is sufficient.
if not isProofOfWorkSufficient(data): if not isProofOfWorkSufficient(data):
print 'Proof of work in broadcast message insufficient.' logger.debug('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])
@ -712,13 +708,13 @@ def checkAndShareBroadcastWithPeers(data):
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.debug('The embedded time in this broadcast message is more than three hours in the future. That doesn\'t make sense. 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.debug('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.debug('The payload length of this broadcast packet is unreasonably low. Someone is probably trying funny business. Ignoring message.')
return return
broadcastVersion, broadcastVersionLength = decodeVarint( broadcastVersion, broadcastVersionLength = decodeVarint(
data[readPosition:readPosition + 10]) data[readPosition:readPosition + 10])
@ -727,22 +723,21 @@ def checkAndShareBroadcastWithPeers(data):
streamNumber, streamNumberLength = decodeVarint(data[readPosition:readPosition + 10]) streamNumber, streamNumberLength = decodeVarint(data[readPosition:readPosition + 10])
readPosition += streamNumberLength readPosition += streamNumberLength
if not streamNumber in streamsInWhichIAmParticipating: if not streamNumber in streamsInWhichIAmParticipating:
print 'The streamNumber', streamNumber, 'isn\'t one we are interested in.' logger.debug('The streamNumber %s isn\'t one we are interested in.' % streamNumber)
return return
if broadcastVersion >= 3: if broadcastVersion >= 3:
tag = data[readPosition:readPosition+32] tag = data[readPosition:readPosition+32]
print 'debugging. in broadcast, tag is:', tag.encode('hex')
else: else:
tag = '' tag = ''
shared.numberOfInventoryLookupsPerformed += 1 shared.numberOfInventoryLookupsPerformed += 1
inventoryLock.acquire() inventoryLock.acquire()
inventoryHash = calculateInventoryHash(data) inventoryHash = calculateInventoryHash(data)
if inventoryHash in inventory: if inventoryHash in inventory:
print 'We have already received this broadcast object. Ignoring.' logger.debug('We have already received this broadcast object. Ignoring.')
inventoryLock.release() inventoryLock.release()
return return
elif isInSqlInventory(inventoryHash): elif isInSqlInventory(inventoryHash):
print 'We have already received this broadcast object (it is stored on disk in the SQL inventory). Ignoring it.' logger.debug('We have already received this broadcast object (it is stored on disk in the SQL inventory). Ignoring it.')
inventoryLock.release() inventoryLock.release()
return return
# It is valid. Let's let our peers know about it. # It is valid. Let's let our peers know about it.
@ -752,8 +747,7 @@ def checkAndShareBroadcastWithPeers(data):
inventorySets[streamNumber].add(inventoryHash) inventorySets[streamNumber].add(inventoryHash)
inventoryLock.release() inventoryLock.release()
# This object is valid. Forward it to peers. # This object is valid. Forward it to peers.
with printLock: logger.debug('advertising inv with hash: %s' % inventoryHash.encode('hex'))
print 'advertising inv with hash:', inventoryHash.encode('hex')
broadcastToSendDataQueues((streamNumber, 'advertiseobject', inventoryHash)) broadcastToSendDataQueues((streamNumber, 'advertiseobject', inventoryHash))
# Now let's queue it to be processed ourselves. # Now let's queue it to be processed ourselves.