changed prints to logger

This commit is contained in:
merlink 2013-10-29 16:56:17 +01:00
parent 9dd674a117
commit 2f2b074955
12 changed files with 361 additions and 494 deletions

View File

@ -8,7 +8,6 @@
# yet contain logic to expand into further streams. # yet contain logic to expand into further streams.
# The software version variable is now held in shared.py # The software version variable is now held in shared.py
import signal # Used to capture a Ctrl-C keypress so that Bitmessage can shutdown gracefully. import signal # Used to capture a Ctrl-C keypress so that Bitmessage can shutdown gracefully.
# The next 3 are used for the API # The next 3 are used for the API
from SimpleXMLRPCServer import * from SimpleXMLRPCServer import *
@ -32,7 +31,7 @@ from class_singleWorker import *
from class_outgoingSynSender import * from class_outgoingSynSender import *
from class_singleListener import * from class_singleListener import *
from class_addressGenerator import * from class_addressGenerator import *
from debug import logger #~ from debug import logger
# Helper Functions # Helper Functions
import helper_bootstrap import helper_bootstrap
@ -1070,10 +1069,20 @@ class Main:
return {'address':address,'port':port} return {'address':address,'port':port}
if __name__ == "__main__": if __name__ == "__main__":
logger = logging.getLogger()
fmt_string = "[%(levelname)-7s]%(asctime)s.%(msecs)-3d\
%(module)s[%(lineno)-3d]/%(funcName)-10s %(message)-8s "
handler = logging.StreamHandler(sys.stdout)
handler.setFormatter(logging.Formatter(fmt_string, "%H:%M:%S"))
logger.addHandler(handler)
logger.setLevel(logging.ERROR)
mainprogram = Main() mainprogram = Main()
mainprogram.start() mainprogram.start()
# So far, the creation of and management of the Bitmessage protocol and this # So far, the creation of and management of the Bitmessage protocol and this
# client is a one-man operation. Bitcoin tips are quite appreciated. # client is a one-man operation. Bitcoin tips are quite appreciated.
# 1H5XaDA6fYENLbknwZyjiYXYPQaFjjLX2u # 1H5XaDA6fYENLbknwZyjiYXYPQaFjjLX2u

View File

@ -32,8 +32,10 @@ import os
from pyelliptic.openssl import OpenSSL from pyelliptic.openssl import OpenSSL
import pickle import pickle
import platform import platform
import debug #~ import debug
from debug import logger #~ from debug import logger
import logging
logger = logging.getLogger('bitmessageqt_init')
import subprocess import subprocess
import datetime import datetime
from helper_sql import * from helper_sql import *
@ -1535,8 +1537,7 @@ class MyForm(QtGui.QMainWindow):
status, addressVersionNumber, streamNumber, ripe = decodeAddress( status, addressVersionNumber, streamNumber, ripe = decodeAddress(
toAddress) toAddress)
if status != 'success': if status != 'success':
with shared.printLock: logger.error('Error: Could not decode %s: %s'%(toAddress, status))
print 'Error: Could not decode', toAddress, ':', status
if status == 'missingbm': if status == 'missingbm':
self.statusBar().showMessage(_translate( self.statusBar().showMessage(_translate(
@ -1908,7 +1909,7 @@ class MyForm(QtGui.QMainWindow):
self.ui.tableWidgetBlacklist.setItem(0, 1, newItem) self.ui.tableWidgetBlacklist.setItem(0, 1, newItem)
def click_pushButtonStatusIcon(self): def click_pushButtonStatusIcon(self):
print 'click_pushButtonStatusIcon' logger.info('click_pushButtonStatusIcon')
self.iconGlossaryInstance = iconGlossaryDialog(self) self.iconGlossaryInstance = iconGlossaryDialog(self)
if self.iconGlossaryInstance.exec_(): if self.iconGlossaryInstance.exec_():
pass pass
@ -2181,7 +2182,7 @@ class MyForm(QtGui.QMainWindow):
shared.addressGeneratorQueue.put(('createDeterministicAddresses', 4, streamNumberForAddress, "unused deterministic address", self.dialog.ui.spinBoxNumberOfAddressesToMake.value( shared.addressGeneratorQueue.put(('createDeterministicAddresses', 4, streamNumberForAddress, "unused deterministic address", self.dialog.ui.spinBoxNumberOfAddressesToMake.value(
), self.dialog.ui.lineEditPassphrase.text().toUtf8(), self.dialog.ui.checkBoxEighteenByteRipe.isChecked())) ), self.dialog.ui.lineEditPassphrase.text().toUtf8(), self.dialog.ui.checkBoxEighteenByteRipe.isChecked()))
else: else:
print 'new address dialog box rejected' logger.info('new address dialog box rejected')
# Quit selected from menu or application indicator # Quit selected from menu or application indicator
def quit(self): def quit(self):
@ -2293,7 +2294,7 @@ class MyForm(QtGui.QMainWindow):
# If the previous message was to a chan then we should send our reply to the chan rather than to the particular person who sent the message. # If the previous message was to a chan then we should send our reply to the chan rather than to the particular person who sent the message.
if shared.config.has_section(toAddressAtCurrentInboxRow): if shared.config.has_section(toAddressAtCurrentInboxRow):
if shared.safeConfigGetBoolean(toAddressAtCurrentInboxRow, 'chan'): if shared.safeConfigGetBoolean(toAddressAtCurrentInboxRow, 'chan'):
print 'original sent to a chan. Setting the to address in the reply to the chan address.' logger.info('original sent to a chan. Setting the to address in the reply to the chan address.')
self.ui.lineEditTo.setText(str(toAddressAtCurrentInboxRow)) self.ui.lineEditTo.setText(str(toAddressAtCurrentInboxRow))
self.ui.comboBoxSendFrom.setCurrentIndex(0) self.ui.comboBoxSendFrom.setCurrentIndex(0)
@ -2494,7 +2495,7 @@ class MyForm(QtGui.QMainWindow):
self.click_pushButtonAddSubscription() self.click_pushButtonAddSubscription()
def on_action_SubscriptionsDelete(self): def on_action_SubscriptionsDelete(self):
print 'clicked Delete' logger.info('clicked Delete')
currentRow = self.ui.tableWidgetSubscriptions.currentRow() currentRow = self.ui.tableWidgetSubscriptions.currentRow()
labelAtCurrentRow = self.ui.tableWidgetSubscriptions.item( labelAtCurrentRow = self.ui.tableWidgetSubscriptions.item(
currentRow, 0).text().toUtf8() currentRow, 0).text().toUtf8()
@ -2814,8 +2815,7 @@ class MyForm(QtGui.QMainWindow):
def updateStatusBar(self, data): def updateStatusBar(self, data):
if data != "": if data != "":
with shared.printLock: logger.info('Status bar: %s'%data)
print 'Status bar:', data
self.statusBar().showMessage(data) self.statusBar().showMessage(data)

View File

@ -6,7 +6,9 @@ import socks
import socket import socket
import sys import sys
import tr import tr
import logging
logger = logging.getLogger('OutgoingSynSender')
from class_sendDataThread import * from class_sendDataThread import *
from class_receiveDataThread import * from class_receiveDataThread import *
@ -61,14 +63,12 @@ class outgoingSynSender(threading.Thread):
sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1) sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
sock.settimeout(20) sock.settimeout(20)
if shared.config.get('bitmessagesettings', 'socksproxytype') == 'none' and shared.verbose >= 2: if shared.config.get('bitmessagesettings', 'socksproxytype') == 'none' and shared.verbose >= 2:
with shared.printLock: logger.info('Trying an outgoing connection to %s'%peer)
print 'Trying an outgoing connection to', peer
# sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM) # sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
elif shared.config.get('bitmessagesettings', 'socksproxytype') == 'SOCKS4a': elif shared.config.get('bitmessagesettings', 'socksproxytype') == 'SOCKS4a':
if shared.verbose >= 2: if shared.verbose >= 2:
with shared.printLock: logger.info('(Using SOCKS4a) Trying an outgoing connection to %s'%peer)
print '(Using SOCKS4a) Trying an outgoing connection to', peer
proxytype = socks.PROXY_TYPE_SOCKS4 proxytype = socks.PROXY_TYPE_SOCKS4
sockshostname = shared.config.get( sockshostname = shared.config.get(
@ -88,8 +88,7 @@ class outgoingSynSender(threading.Thread):
proxytype, sockshostname, socksport, rdns) proxytype, sockshostname, socksport, rdns)
elif shared.config.get('bitmessagesettings', 'socksproxytype') == 'SOCKS5': elif shared.config.get('bitmessagesettings', 'socksproxytype') == 'SOCKS5':
if shared.verbose >= 2: if shared.verbose >= 2:
with shared.printLock: logger.info('(Using SOCKS5) Trying an outgoing connection to %s'%peer)
print '(Using SOCKS5) Trying an outgoing connection to', peer
proxytype = socks.PROXY_TYPE_SOCKS5 proxytype = socks.PROXY_TYPE_SOCKS5
sockshostname = shared.config.get( sockshostname = shared.config.get(
@ -116,8 +115,7 @@ class outgoingSynSender(threading.Thread):
rd.setup(sock, peer.host, peer.port, self.streamNumber, rd.setup(sock, peer.host, peer.port, self.streamNumber,
someObjectsOfWhichThisRemoteNodeIsAlreadyAware, self.selfInitiatedConnections) someObjectsOfWhichThisRemoteNodeIsAlreadyAware, self.selfInitiatedConnections)
rd.start() rd.start()
with shared.printLock: logger.info('%s connected to %s during an outgoing attempt.'%(self,peer))
print self, 'connected to', peer, 'during an outgoing attempt.'
sd = sendDataThread() sd = sendDataThread()
@ -128,8 +126,7 @@ class outgoingSynSender(threading.Thread):
except socks.GeneralProxyError as err: except socks.GeneralProxyError as err:
if shared.verbose >= 2: if shared.verbose >= 2:
with shared.printLock: logger.info('Could NOT connect to %s during outgoing attempt. %s'%(peer,err))
print 'Could NOT connect to', peer, 'during outgoing attempt.', err
timeLastSeen = shared.knownNodes[ timeLastSeen = shared.knownNodes[
self.streamNumber][peer] self.streamNumber][peer]
@ -137,8 +134,7 @@ class outgoingSynSender(threading.Thread):
shared.knownNodesLock.acquire() shared.knownNodesLock.acquire()
del shared.knownNodes[self.streamNumber][peer] del shared.knownNodes[self.streamNumber][peer]
shared.knownNodesLock.release() shared.knownNodesLock.release()
with shared.printLock: logger.info('deleting %s from shared.knownNodes because it is more than 48 hours old and we could not connect to it.'%peer)
print 'deleting ', peer, 'from shared.knownNodes because it is more than 48 hours old and we could not connect to it.'
except socks.Socks5AuthError as err: except socks.Socks5AuthError as err:
shared.UISignalQueue.put(( shared.UISignalQueue.put((
@ -146,16 +142,15 @@ class outgoingSynSender(threading.Thread):
"MainWindow", "SOCKS5 Authentication problem: %1").arg(str(err)))) "MainWindow", "SOCKS5 Authentication problem: %1").arg(str(err))))
except socks.Socks5Error as err: except socks.Socks5Error as err:
pass pass
print 'SOCKS5 error. (It is possible that the server wants authentication).)', str(err) logger.info('SOCKS5 error. (It is possible that the server wants authentication).) %s'%str(err))
except socks.Socks4Error as err: except socks.Socks4Error as err:
print 'Socks4Error:', err logger.info('Socks4Error: %s'%err)
except socket.error as err: except socket.error as err:
if shared.config.get('bitmessagesettings', 'socksproxytype')[0:5] == 'SOCKS': if shared.config.get('bitmessagesettings', 'socksproxytype')[0:5] == 'SOCKS':
print 'Bitmessage MIGHT be having trouble connecting to the SOCKS server. ' + str(err) logger.info('Bitmessage MIGHT be having trouble connecting to the SOCKS server. %s'%str(err))
else: else:
if shared.verbose >= 1: if shared.verbose >= 1:
with shared.printLock: logger.info('Could NOT connect to %s during outgoing attempt. %s'%(peer, err))
print 'Could NOT connect to', peer, 'during outgoing attempt.', err
timeLastSeen = shared.knownNodes[ timeLastSeen = shared.knownNodes[
self.streamNumber][peer] self.streamNumber][peer]
@ -163,8 +158,7 @@ class outgoingSynSender(threading.Thread):
shared.knownNodesLock.acquire() shared.knownNodesLock.acquire()
del shared.knownNodes[self.streamNumber][peer] del shared.knownNodes[self.streamNumber][peer]
shared.knownNodesLock.release() shared.knownNodesLock.release()
with shared.printLock: logger.info('deleting %s from knownNodes because it is more than 48 hours old and we could not connect to it.'%str(peer))
print 'deleting ', peer, 'from knownNodes because it is more than 48 hours old and we could not connect to it.'
except Exception as err: except Exception as err:
sys.stderr.write( sys.stderr.write(

View File

@ -20,7 +20,8 @@ import helper_inbox
import helper_sent import helper_sent
from helper_sql import * from helper_sql import *
import tr import tr
from debug import logger import logging
logger = logging.getLogger('RecieveDataThread')
#from bitmessagemain import shared.lengthOfTimeToLeaveObjectsInInventory, shared.lengthOfTimeToHoldOnToAllPubkeys, shared.maximumAgeOfAnObjectThatIAmWillingToAccept, shared.maximumAgeOfObjectsThatIAdvertiseToOthers, shared.maximumAgeOfNodesThatIAdvertiseToOthers, shared.numberOfObjectsThatWeHaveYetToGetPerPeer, shared.neededPubkeys #from bitmessagemain import shared.lengthOfTimeToLeaveObjectsInInventory, shared.lengthOfTimeToHoldOnToAllPubkeys, shared.maximumAgeOfAnObjectThatIAmWillingToAccept, shared.maximumAgeOfObjectsThatIAdvertiseToOthers, shared.maximumAgeOfNodesThatIAdvertiseToOthers, shared.numberOfObjectsThatWeHaveYetToGetPerPeer, shared.neededPubkeys
# This thread is created either by the synSenderThread(for outgoing # This thread is created either by the synSenderThread(for outgoing
@ -61,43 +62,35 @@ class receiveDataThread(threading.Thread):
self.someObjectsOfWhichThisRemoteNodeIsAlreadyAware = someObjectsOfWhichThisRemoteNodeIsAlreadyAware self.someObjectsOfWhichThisRemoteNodeIsAlreadyAware = someObjectsOfWhichThisRemoteNodeIsAlreadyAware
def run(self): def run(self):
with shared.printLock: logger.info('ID of the receiveDataThread is %s. The size of the shared.connectedHostsList is now %s'%(id(self),len(shared.connectedHostsList)))
print 'ID of the receiveDataThread is', str(id(self)) + '. The size of the shared.connectedHostsList is now', len(shared.connectedHostsList)
while True: while True:
dataLen = len(self.data) dataLen = len(self.data)
try: try:
self.data += self.sock.recv(4096) self.data += self.sock.recv(4096)
except socket.timeout: except socket.timeout:
with shared.printLock: logger.info('Timeout occurred waiting for data from %s. Closing receiveData thread. (ID: %s)'%(self.peer,id(self)))
print 'Timeout occurred waiting for data from', self.peer, '. Closing receiveData thread. (ID:', str(id(self)) + ')'
break break
except Exception as err: except Exception as err:
with shared.printLock: logger.info('sock.recv error. Closing receiveData thread (HOST:%s ID:%s ).%s'%(self.peer,id(self),err))
print 'sock.recv error. Closing receiveData thread (HOST:', self.peer, 'ID:', str(id(self)) + ').', err
break break
# print 'Received', repr(self.data) # print 'Received', repr(self.data)
if len(self.data) == dataLen: # If self.sock.recv returned no data: if len(self.data) == dataLen: # If self.sock.recv returned no data:
with shared.printLock: logger.info('Connection to %s closed. Closing receiveData thread. (ID:%s)'%(self.peer,id(self)))
print 'Connection to', self.peer, 'closed. Closing receiveData thread. (ID:', str(id(self)) + ')'
break break
else: else:
self.processData() self.processData()
try: try:
del self.selfInitiatedConnections[self.streamNumber][self] del self.selfInitiatedConnections[self.streamNumber][self]
with shared.printLock: logger.info('removed self (a receiveDataThread) from selfInitiatedConnections')
print 'removed self (a receiveDataThread) from selfInitiatedConnections'
except: except:
pass pass
shared.broadcastToSendDataQueues((0, 'shutdown', self.peer)) shared.broadcastToSendDataQueues((0, 'shutdown', self.peer))
try: try:
del shared.connectedHostsList[self.peer.host] del shared.connectedHostsList[self.peer.host]
except Exception as err: except Exception as err:
with shared.printLock: logger.info('Could not delete %s from shared.connectedHostsList. %s'%(self.peer.host, err))
print 'Could not delete', self.peer.host, 'from shared.connectedHostsList.', err
try: try:
del shared.numberOfObjectsThatWeHaveYetToGetPerPeer[ del shared.numberOfObjectsThatWeHaveYetToGetPerPeer[
@ -105,8 +98,7 @@ class receiveDataThread(threading.Thread):
except: except:
pass pass
shared.UISignalQueue.put(('updateNetworkStatusTab', 'no data')) shared.UISignalQueue.put(('updateNetworkStatusTab', 'no data'))
with shared.printLock: logger.info('The size of the connectedHostsList is now: %s'%len(shared.connectedHostsList))
print 'The size of the connectedHostsList is now:', len(shared.connectedHostsList)
def processData(self): def processData(self):
@ -118,8 +110,7 @@ class receiveDataThread(threading.Thread):
return return
if self.data[0:4] != '\xe9\xbe\xb4\xd9': if self.data[0:4] != '\xe9\xbe\xb4\xd9':
if shared.verbose >= 1: if shared.verbose >= 1:
with shared.printLock: logger.info('The magic bytes were not correct. First 40 bytes of data: %s'%repr(self.data[0:40]))
print 'The magic bytes were not correct. First 40 bytes of data: ' + repr(self.data[0:40])
self.data = "" self.data = ""
return return
@ -127,7 +118,7 @@ class receiveDataThread(threading.Thread):
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. Clearing this message.')
self.data = self.data[self.payloadLength + 24:] self.data = self.data[self.payloadLength + 24:]
self.processData() self.processData()
return return
@ -140,8 +131,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]
with shared.printLock: logger.info('remoteCommand %s from %s'%(repr(remoteCommand.replace('\x00', '')),self.peer))
print 'remoteCommand', repr(remoteCommand.replace('\x00', '')), ' from', self.peer
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])
@ -176,15 +166,13 @@ class receiveDataThread(threading.Thread):
objectHash, = random.sample( objectHash, = random.sample(
self.objectsThatWeHaveYetToGetFromThisPeer, 1) self.objectsThatWeHaveYetToGetFromThisPeer, 1)
if objectHash in shared.inventory: if objectHash in shared.inventory:
with shared.printLock: logger.info('Inventory (in memory) already has object listed in inv message.')
print 'Inventory (in memory) already has object listed in inv message.'
del self.objectsThatWeHaveYetToGetFromThisPeer[ del self.objectsThatWeHaveYetToGetFromThisPeer[
objectHash] objectHash]
elif shared.isInSqlInventory(objectHash): elif shared.isInSqlInventory(objectHash):
if shared.verbose >= 3: if shared.verbose >= 3:
with shared.printLock: logger.info('Inventory (SQL on disk) already has object listed in inv message.')
print 'Inventory (SQL on disk) already has object listed in inv message.'
del self.objectsThatWeHaveYetToGetFromThisPeer[ del self.objectsThatWeHaveYetToGetFromThisPeer[
objectHash] objectHash]
@ -193,8 +181,7 @@ class receiveDataThread(threading.Thread):
del self.objectsThatWeHaveYetToGetFromThisPeer[ del self.objectsThatWeHaveYetToGetFromThisPeer[
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.objectsThatWeHaveYetToGetFromThisPeer) == 0: if len(self.objectsThatWeHaveYetToGetFromThisPeer) == 0:
with shared.printLock: logger.info('(concerning %s) number of objectsThatWeHaveYetToGetFromThisPeer is now %s'%(self.peer,len(self.objectsThatWeHaveYetToGetFromThisPeer)))
print '(concerning', str(self.peer) + ')', 'number of objectsThatWeHaveYetToGetFromThisPeer is now', len(self.objectsThatWeHaveYetToGetFromThisPeer)
try: try:
del shared.numberOfObjectsThatWeHaveYetToGetPerPeer[ del shared.numberOfObjectsThatWeHaveYetToGetPerPeer[
@ -203,8 +190,7 @@ class receiveDataThread(threading.Thread):
pass pass
break break
if len(self.objectsThatWeHaveYetToGetFromThisPeer) == 0: if len(self.objectsThatWeHaveYetToGetFromThisPeer) == 0:
with shared.printLock: logger.info('(concerning %s) number of objectsThatWeHaveYetToGetFromThisPeer is now %s'%(self.peer, len(self.objectsThatWeHaveYetToGetFromThisPeer)))
print '(concerning', str(self.peer) + ')', 'number of objectsThatWeHaveYetToGetFromThisPeer is now', len(self.objectsThatWeHaveYetToGetFromThisPeer)
try: try:
del shared.numberOfObjectsThatWeHaveYetToGetPerPeer[ del shared.numberOfObjectsThatWeHaveYetToGetPerPeer[
@ -212,8 +198,7 @@ class receiveDataThread(threading.Thread):
except: except:
pass pass
if len(self.objectsThatWeHaveYetToGetFromThisPeer) > 0: if len(self.objectsThatWeHaveYetToGetFromThisPeer) > 0:
with shared.printLock: logger.info('(concerning %s) number of objectsThatWeHaveYetToGetFromThisPeer is now %s'%(self.peer,len(self.objectsThatWeHaveYetToGetFromThisPeer)))
print '(concerning', str(self.peer) + ')', 'number of objectsThatWeHaveYetToGetFromThisPeer is now', len(self.objectsThatWeHaveYetToGetFromThisPeer)
shared.numberOfObjectsThatWeHaveYetToGetPerPeer[self.peer] = len( shared.numberOfObjectsThatWeHaveYetToGetPerPeer[self.peer] = len(
self.objectsThatWeHaveYetToGetFromThisPeer) # 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.objectsThatWeHaveYetToGetFromThisPeer) # 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.
@ -236,18 +221,17 @@ class receiveDataThread(threading.Thread):
return POW <= 2 ** 64 / ((len(data) + payloadLengthExtraBytes) * (nonceTrialsPerByte)) return POW <= 2 ** 64 / ((len(data) + payloadLengthExtraBytes) * (nonceTrialsPerByte))
def sendpong(self): def sendpong(self):
print 'Sending pong' logger.info('Sending pong')
try: try:
self.sock.sendall( self.sock.sendall(
'\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:
with shared.printLock: logger.error('sock.sendall error:'%err)
print 'sock.sendall error:', err
def recverack(self): def recverack(self):
print 'verack received' logger.info('verack received')
self.verackReceived = True self.verackReceived = True
if self.verackSent: if self.verackSent:
# We have thus both sent and received a verack. # We have thus both sent and received a verack.
@ -261,11 +245,11 @@ class receiveDataThread(threading.Thread):
self.sock.settimeout( self.sock.settimeout(
600) # We'll send out a pong every 5 minutes to make sure the connection stays alive if there has been no other traffic to send lately. 600) # We'll send out a pong every 5 minutes to make sure the connection stays alive if there has been no other traffic to send lately.
shared.UISignalQueue.put(('updateNetworkStatusTab', 'no data')) shared.UISignalQueue.put(('updateNetworkStatusTab', 'no data'))
with shared.printLock:
print 'Connection fully established with', self.peer logger.info('Connection fully established with %s'%str(self.peer))
print 'The size of the connectedHostsList is now', len(shared.connectedHostsList) logger.info('The size of the connectedHostsList is now %s'%len(shared.connectedHostsList))
print 'The length of sendDataQueues is now:', len(shared.sendDataQueues) logger.info('The length of sendDataQueues is now: %s'%len(shared.sendDataQueues))
print 'broadcasting addr from within connectionFullyEstablished function.' logger.info('broadcasting addr from within connectionFullyEstablished function.')
#self.broadcastaddr([(int(time.time()), self.streamNumber, 1, self.peer.host, #self.broadcastaddr([(int(time.time()), self.streamNumber, 1, self.peer.host,
# self.remoteNodeIncomingPort)]) # This lets all of our peers know about this new node. # self.remoteNodeIncomingPort)]) # This lets all of our peers know about this new node.
@ -275,8 +259,7 @@ class receiveDataThread(threading.Thread):
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:
with shared.printLock: logger.info('We are connected to too many people. Closing connection.')
print 'We are connected to too many people. Closing connection.'
shared.broadcastToSendDataQueues((0, 'shutdown', self.peer)) shared.broadcastToSendDataQueues((0, 'shutdown', self.peer))
return return
@ -327,15 +310,13 @@ 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]
with shared.printLock: logger.info('Sending huge inv message with %s objects to just this one peer'%numberOfObjects)
print 'Sending huge inv message with', numberOfObjects, 'objects to just this one peer'
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:
with shared.printLock: logger.error('sock.sendall error: %s'%err)
print 'sock.sendall error:', err
# We have received a broadcast message # We have received a broadcast message
@ -343,7 +324,7 @@ class receiveDataThread(threading.Thread):
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.warning('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])
@ -357,13 +338,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 is more than three hours in the future. That doesn\'t make sense. Ignoring message.')
return return
if embeddedTime < (int(time.time()) - shared.maximumAgeOfAnObjectThatIAmWillingToAccept): if embeddedTime < (int(time.time()) - shared.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. Someone is probably trying funny business. 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
@ -374,18 +355,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 (%s) does not match the stream number on which it was received. Ignoring it.'%streamNumber)
return return
shared.numberOfInventoryLookupsPerformed += 1 shared.numberOfInventoryLookupsPerformed += 1
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 received this broadcast object. Ignoring.')
shared.inventoryLock.release() shared.inventoryLock.release()
return return
elif shared.isInSqlInventory(self.inventoryHash): elif shared.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.
@ -418,12 +399,10 @@ class receiveDataThread(threading.Thread):
sleepTime = lengthOfTimeWeShouldUseToProcessThisMessage - \ sleepTime = lengthOfTimeWeShouldUseToProcessThisMessage - \
(time.time() - self.messageProcessingStartTime) (time.time() - self.messageProcessingStartTime)
if sleepTime > 0 and doTimingAttackMitigation: if sleepTime > 0 and doTimingAttackMitigation:
with shared.printLock: logger.info('Timing attack mitigation: Sleeping for %s seconds.'%sleepTime)
print 'Timing attack mitigation: Sleeping for', sleepTime, 'seconds.'
time.sleep(sleepTime) time.sleep(sleepTime)
with shared.printLock: logger.info('Total message processing time: %s seconds.'%(time.time() - self.messageProcessingStartTime))
print 'Total message processing time:', time.time() - self.messageProcessingStartTime, 'seconds.'
# A broadcast message has a valid time and POW and requires processing. # A broadcast message has a valid time and POW and requires processing.
@ -433,7 +412,7 @@ class receiveDataThread(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.info('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
@ -461,9 +440,7 @@ 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
with shared.printLock: logger.info('Time spent deciding that we are not interested in this v1 broadcast: %s'%(time.time() - self.messageProcessingStartTime))
print 'Time spent deciding that we are not interested in this v1 broadcast:', 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
@ -495,17 +472,17 @@ class receiveDataThread(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.info('ECDSA verify failed')
return return
print 'ECDSA verify passed' logger.info('ECDSA verify passed')
except Exception as err: except Exception as err:
print 'ECDSA verify failed', err logger.info('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:
print 'fromAddress:', fromAddress logger.info('fromAddress: %s'%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
@ -532,7 +509,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 = ''
@ -560,8 +537,7 @@ class receiveDataThread(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() - self.messageProcessingStartTime))
print 'Time spent processing this interesting broadcast:', time.time() - self.messageProcessingStartTime
if broadcastVersion == 2: if broadcastVersion == 2:
cleartextStreamNumber, cleartextStreamNumberLength = decodeVarint( cleartextStreamNumber, cleartextStreamNumberLength = decodeVarint(
@ -573,16 +549,14 @@ 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: %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.info('Length of time program spent failing to decrypt this v2 broadcast: %s seconds.'%(time.time() - self.messageProcessingStartTime))
print 'Length of time program spent failing to decrypt this v2 broadcast:', time.time() - self.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.
@ -592,7 +566,7 @@ class receiveDataThread(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(
@ -613,11 +587,11 @@ class receiveDataThread(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)
endOfPubkeyPosition = readPosition endOfPubkeyPosition = readPosition
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
@ -626,7 +600,7 @@ class receiveDataThread(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])
@ -646,11 +620,11 @@ class receiveDataThread(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.info('ECDSA verify failed')
return return
print 'ECDSA verify passed' logger.info('ECDSA verify passed')
except Exception as err: except Exception as err:
print 'ECDSA verify failed', err logger.info('ECDSA verify failed %s'%err)
return return
# verify passed # verify passed
@ -670,8 +644,7 @@ class receiveDataThread(threading.Thread):
fromAddress = encodeAddress( fromAddress = encodeAddress(
sendersAddressVersion, sendersStream, ripe.digest()) sendersAddressVersion, sendersStream, ripe.digest())
with shared.printLock: logger.info('fromAddress: %s'%fromAddress)
print 'fromAddress:', fromAddress
if messageEncodingType == 2: if messageEncodingType == 2:
subject, body = self.decodeType2Message(message) subject, body = self.decodeType2Message(message)
@ -679,7 +652,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 = ''
@ -707,8 +680,7 @@ class receiveDataThread(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() - self.messageProcessingStartTime))
print 'Time spent processing this interesting broadcast:', time.time() - self.messageProcessingStartTime
if broadcastVersion == 3: if broadcastVersion == 3:
cleartextStreamNumber, cleartextStreamNumberLength = decodeVarint( cleartextStreamNumber, cleartextStreamNumberLength = decodeVarint(
@ -717,17 +689,15 @@ class receiveDataThread(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.info('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.info('EC decryption successful')
except Exception as err: except Exception as err:
with shared.printLock: logger.info('Broadcast version 3 decryption Unsuccessful.')
print 'Broadcast version 3 decryption Unsuccessful.'
return return
signedBroadcastVersion, readPosition = decodeVarint( signedBroadcastVersion, readPosition = decodeVarint(
@ -736,13 +706,13 @@ class receiveDataThread(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]
@ -757,11 +727,11 @@ class receiveDataThread(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)
endOfPubkeyPosition = readPosition endOfPubkeyPosition = readPosition
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
@ -773,7 +743,7 @@ class receiveDataThread(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.info('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])
@ -793,18 +763,17 @@ class receiveDataThread(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.info('ECDSA verify failed')
return return
print 'ECDSA verify passed' logger.info('ECDSA verify passed')
except Exception as err: except Exception as err:
print 'ECDSA verify failed', err logger.info('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(
@ -825,7 +794,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 = ''
@ -853,15 +822,14 @@ class receiveDataThread(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() - self.messageProcessingStartTime))
print 'Time spent processing this interesting broadcast:', time.time() - self.messageProcessingStartTime
# We have received a msg message. # We have received a msg message.
def recmsg(self, data): def recmsg(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 msg message insufficient.' logger.info('Proof of work in msg message insufficient.')
return return
readPosition = 8 readPosition = 8
@ -876,26 +844,26 @@ class receiveDataThread(threading.Thread):
readPosition += 4 readPosition += 4
if embeddedTime > int(time.time()) + 10800: if embeddedTime > int(time.time()) + 10800:
print 'The time in the msg message is too new. Ignoring it. Time:', embeddedTime logger.info('The time in the msg message is too new. Ignoring it. Time: %s'%embeddedTime)
return return
if embeddedTime < int(time.time()) - shared.maximumAgeOfAnObjectThatIAmWillingToAccept: if embeddedTime < int(time.time()) - shared.maximumAgeOfAnObjectThatIAmWillingToAccept:
print 'The time in the msg message is too old. Ignoring it. Time:', embeddedTime logger.info('The time in the msg message is too old. Ignoring it. Time:'%embeddedTime)
return return
streamNumberAsClaimedByMsg, streamNumberAsClaimedByMsgLength = decodeVarint( streamNumberAsClaimedByMsg, streamNumberAsClaimedByMsgLength = decodeVarint(
data[readPosition:readPosition + 9]) data[readPosition:readPosition + 9])
if streamNumberAsClaimedByMsg != self.streamNumber: if streamNumberAsClaimedByMsg != self.streamNumber:
print 'The stream number encoded in this msg (' + str(streamNumberAsClaimedByMsg) + ') message does not match the stream number on which it was received. Ignoring it.' logger.info('The stream number encoded in this msg ( %s ) message does not match the stream number on which it was received. Ignoring it.'%streamNumberAsClaimedByMsg)
return return
readPosition += streamNumberAsClaimedByMsgLength readPosition += streamNumberAsClaimedByMsgLength
self.inventoryHash = calculateInventoryHash(data) self.inventoryHash = calculateInventoryHash(data)
shared.numberOfInventoryLookupsPerformed += 1 shared.numberOfInventoryLookupsPerformed += 1
shared.inventoryLock.acquire() shared.inventoryLock.acquire()
if self.inventoryHash in shared.inventory: if self.inventoryHash in shared.inventory:
print 'We have already received this msg message. Ignoring.' logger.info('We have already received this msg message. Ignoring.')
shared.inventoryLock.release() shared.inventoryLock.release()
return return
elif shared.isInSqlInventory(self.inventoryHash): elif shared.isInSqlInventory(self.inventoryHash):
print 'We have already received this msg message (it is stored on disk in the SQL inventory). Ignoring it.' logger.info('We have already received this msg message (it is stored on disk in the SQL inventory). Ignoring it.')
shared.inventoryLock.release() shared.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.
@ -927,12 +895,10 @@ class receiveDataThread(threading.Thread):
sleepTime = lengthOfTimeWeShouldUseToProcessThisMessage - \ sleepTime = lengthOfTimeWeShouldUseToProcessThisMessage - \
(time.time() - self.messageProcessingStartTime) (time.time() - self.messageProcessingStartTime)
if sleepTime > 0 and doTimingAttackMitigation: if sleepTime > 0 and doTimingAttackMitigation:
with shared.printLock: logger.info('Timing attack mitigation: Sleeping for %s seconds.'%sleepTime)
print 'Timing attack mitigation: Sleeping for', sleepTime, 'seconds.'
time.sleep(sleepTime) time.sleep(sleepTime)
with shared.printLock: logger.info('Total message processing time: %s seconds.'%(time.time() - self.messageProcessingStartTime))
print 'Total message processing time:', time.time() - self.messageProcessingStartTime, 'seconds.'
# A msg message has a valid time and POW and requires processing. The # A msg message has a valid time and POW and requires processing. The
@ -941,8 +907,7 @@ class receiveDataThread(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 encryptedData[readPosition:] in shared.ackdataForWhichImWatching: if encryptedData[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[encryptedData[readPosition:]] del shared.ackdataForWhichImWatching[encryptedData[readPosition:]]
sqlExecute('UPDATE sent SET status=? WHERE ackdata=?', sqlExecute('UPDATE sent SET status=? WHERE ackdata=?',
@ -951,8 +916,7 @@ class receiveDataThread(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 # print 'shared.ackdataForWhichImWatching', shared.ackdataForWhichImWatching
@ -964,16 +928,14 @@ class receiveDataThread(threading.Thread):
encryptedData[readPosition:]) encryptedData[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() - self.messageProcessingStartTime))
print 'Length of time program spent failing to decrypt this message:', time.time() - self.messageProcessingStartTime, 'seconds.'
else: else:
# This is a message bound for me. # This is a message bound for me.
@ -984,24 +946,24 @@ class receiveDataThread(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]
@ -1016,18 +978,17 @@ class receiveDataThread(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.')
print 'The original sender of this message did not send it to you. Someone is attempting a Surreptitious Forwarding Attack.' logger.info('See: http://world.std.com/~dtd/sign_encrypt/sign_encrypt7.html')
print 'See: http://world.std.com/~dtd/sign_encrypt/sign_encrypt7.html' logger.info('your toRipe: %s'%toRipe.encode('hex'))
print 'your toRipe:', toRipe.encode('hex') logger.info('embedded destination toRipe: %s'%decryptedData[readPosition:readPosition + 20].encode('hex'))
print 'embedded destination toRipe:', decryptedData[readPosition:readPosition + 20].encode('hex')
return return
readPosition += 20 readPosition += 20
@ -1053,14 +1014,13 @@ class receiveDataThread(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.info('ECDSA verify failed')
return return
print 'ECDSA verify passed' logger.info('ECDSA verify passed')
except Exception as err: except Exception as err:
print 'ECDSA verify failed', err logger.info('ECDSA verify failed %s'%err)
return return
with shared.printLock: logger.info('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.'%(helper_bitcoin.calculateBitcoinAddressFromPubkey(pubSigningKey),helper_bitcoin.calculateTestnetAddressFromPubkey(pubSigningKey)))
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.'
# calculate the fromRipe. # calculate the fromRipe.
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
@ -1105,7 +1065,7 @@ class receiveDataThread(threading.Thread):
requiredPayloadLengthExtraBytes = shared.config.getint( requiredPayloadLengthExtraBytes = shared.config.getint(
toAddress, 'payloadlengthextrabytes') toAddress, 'payloadlengthextrabytes')
if not self.isProofOfWorkSufficient(encryptedData, requiredNonceTrialsPerByte, requiredPayloadLengthExtraBytes): if not self.isProofOfWorkSufficient(encryptedData, requiredNonceTrialsPerByte, requiredPayloadLengthExtraBytes):
print 'Proof of work in msg message insufficient only because it does not meet our higher requirement.' logger.info('Proof of work in msg message insufficient only because it does not meet our higher requirement.')
return return
blockMessage = False # Gets set to True if the user shouldn't see the message according to black or white lists. blockMessage = False # Gets set to True if the user shouldn't see the message according to black or white lists.
if shared.config.get('bitmessagesettings', 'blackwhitelist') == 'black': # If we are using a blacklist if shared.config.get('bitmessagesettings', 'blackwhitelist') == 'black': # If we are using a blacklist
@ -1113,8 +1073,7 @@ class receiveDataThread(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
@ -1122,11 +1081,11 @@ class receiveDataThread(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:
print 'fromAddress:', fromAddress logger.info('fromAddress: %s'%fromAddress)
print 'First 150 characters of message:', repr(message[:150]) logger.info('First 150 characters of message: %s'%repr(message[:150]))
toLabel = shared.config.get(toAddress, 'label') toLabel = shared.config.get(toAddress, 'label')
if toLabel == '': if toLabel == '':
@ -1138,7 +1097,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. 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 = ''
@ -1191,7 +1150,7 @@ class receiveDataThread(threading.Thread):
shared.workerQueue.put(('sendbroadcast', '')) shared.workerQueue.put(('sendbroadcast', ''))
if self.isAckDataValid(ackData): if self.isAckDataValid(ackData):
print 'ackData is valid. Will process it.' logger.info('ackData is valid. Will process it.')
self.ackDataThatWeHaveYetToSend.append( self.ackDataThatWeHaveYetToSend.append(
ackData) # When we have processed all data, the processData function will pop the ackData out and process it as if it is a message received from our peer. ackData) # When we have processed all data, the processData function will pop the ackData out and process it as if it is a message received from our peer.
# Display timing data # Display timing data
@ -1202,9 +1161,8 @@ class receiveDataThread(threading.Thread):
sum = 0 sum = 0
for item in shared.successfullyDecryptMessageTimings: for item in shared.successfullyDecryptMessageTimings:
sum += item sum += item
with shared.printLock: logger.info('Time to decrypt this message successfully: %s'%timeRequiredToAttemptToDecryptMessage)
print 'Time to decrypt this message successfully:', timeRequiredToAttemptToDecryptMessage logger.info('Average time for all message decryption successes since startup: %s'%(sum / len(shared.successfullyDecryptMessageTimings)))
print 'Average time for all message decryption successes since startup:', sum / len(shared.successfullyDecryptMessageTimings)
def decodeType2Message(self, message): def decodeType2Message(self, message):
bodyPositionIndex = string.find(message, '\nBody:') bodyPositionIndex = string.find(message, '\nBody:')
@ -1224,14 +1182,14 @@ class receiveDataThread(threading.Thread):
def isAckDataValid(self, ackData): def isAckDataValid(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[4:16] != 'getpubkey\x00\x00\x00' and ackData[4:16] != 'pubkey\x00\x00\x00\x00\x00\x00' and ackData[4:16] != 'msg\x00\x00\x00\x00\x00\x00\x00\x00\x00' and ackData[4:16] != 'broadcast\x00\x00\x00': if ackData[4:16] != 'getpubkey\x00\x00\x00' and ackData[4:16] != 'pubkey\x00\x00\x00\x00\x00\x00' and ackData[4:16] != 'msg\x00\x00\x00\x00\x00\x00\x00\x00\x00' and ackData[4:16] != 'broadcast\x00\x00\x00':
return False return False
@ -1253,15 +1211,14 @@ class receiveDataThread(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.info('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.
@ -1270,7 +1227,7 @@ class receiveDataThread(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' ''',
@ -1284,7 +1241,7 @@ class receiveDataThread(threading.Thread):
return return
# We must check to make sure the proof of work is sufficient. # 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 pubkey message insufficient.' logger.info('Proof of work in pubkey message insufficient.')
return return
readPosition = 8 # for the nonce readPosition = 8 # for the nonce
@ -1299,13 +1256,11 @@ class receiveDataThread(threading.Thread):
readPosition += 4 readPosition += 4
if embeddedTime < int(time.time()) - shared.lengthOfTimeToHoldOnToAllPubkeys: if embeddedTime < int(time.time()) - shared.lengthOfTimeToHoldOnToAllPubkeys:
with shared.printLock: logger.info('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 shared.printLock: logger.info('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(
@ -1315,11 +1270,11 @@ class receiveDataThread(threading.Thread):
data[readPosition:readPosition + 10]) data[readPosition:readPosition + 10])
readPosition += varintLength readPosition += varintLength
if self.streamNumber != streamNumber: if self.streamNumber != streamNumber:
print 'stream number embedded in this pubkey doesn\'t match our stream number. Ignoring.' logger.info('stream number embedded in this pubkey doesn\'t match our stream number. Ignoring.')
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.info('tag in received pubkey is: %s'%tag.encode('hex'))
else: else:
tag = '' tag = ''
@ -1327,11 +1282,11 @@ class receiveDataThread(threading.Thread):
inventoryHash = calculateInventoryHash(data) inventoryHash = calculateInventoryHash(data)
shared.inventoryLock.acquire() shared.inventoryLock.acquire()
if inventoryHash in shared.inventory: if inventoryHash in shared.inventory:
print 'We have already received this pubkey. Ignoring it.' logger.info('We have already received this pubkey. Ignoring it.')
shared.inventoryLock.release() shared.inventoryLock.release()
return return
elif shared.isInSqlInventory(inventoryHash): elif shared.isInSqlInventory(inventoryHash):
print 'We have already received this pubkey (it is stored on disk in the SQL inventory). Ignoring it.' logger.info('We have already received this pubkey (it is stored on disk in the SQL inventory). Ignoring it.')
shared.inventoryLock.release() shared.inventoryLock.release()
return return
objectType = 'pubkey' objectType = 'pubkey'
@ -1350,12 +1305,10 @@ class receiveDataThread(threading.Thread):
sleepTime = lengthOfTimeWeShouldUseToProcessThisMessage - \ sleepTime = lengthOfTimeWeShouldUseToProcessThisMessage - \
(time.time() - self.pubkeyProcessingStartTime) (time.time() - self.pubkeyProcessingStartTime)
if sleepTime > 0 and doTimingAttackMitigation: if sleepTime > 0 and doTimingAttackMitigation:
with shared.printLock: logger.info('Timing attack mitigation: Sleeping for %s seconds.'%sleepTime)
print 'Timing attack mitigation: Sleeping for', sleepTime, 'seconds.'
time.sleep(sleepTime) time.sleep(sleepTime)
with shared.printLock: logger.info('Total pubkey processing time: %s seconds.'%(time.time() - self.pubkeyProcessingStartTime))
print 'Total pubkey processing time:', time.time() - self.pubkeyProcessingStartTime, 'seconds.'
def processpubkey(self, data): def processpubkey(self, data):
@ -1377,16 +1330,14 @@ class receiveDataThread(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.info('(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.info('(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
@ -1397,7 +1348,7 @@ class receiveDataThread(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.info('publicEncryptionKey length less than 64. Sanity check failed.')
return return
sha = hashlib.new('sha512') sha = hashlib.new('sha512')
sha.update( sha.update(
@ -1406,20 +1357,20 @@ class receiveDataThread(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 logger.info('within recpubkey, addressVersion: %s streamNumber: %s'%(addressVersion, streamNumber))
print 'ripe', ripe.encode('hex') logger.info('ripe %s'%ripe.encode('hex'))
print 'publicSigningKey in hex:', publicSigningKey.encode('hex') logger.info('publicSigningKey in hex: %s'%publicSigningKey.encode('hex'))
print 'publicEncryptionKey in hex:', publicEncryptionKey.encode('hex') logger.info('publicEncryptionKey in hex: %s'%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)
@ -1427,7 +1378,7 @@ class receiveDataThread(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.info('(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
@ -1451,11 +1402,11 @@ class receiveDataThread(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.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')
@ -1464,19 +1415,18 @@ class receiveDataThread(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'%(addressVersion, streamNumber))
logger.info('ripe %s'%ripe.encode('hex'))
logger.info('publicSigningKey in hex: %s'%publicSigningKey.encode('hex'))
logger.info('publicEncryptionKey in hex: %s'%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)
@ -1484,15 +1434,14 @@ class receiveDataThread(threading.Thread):
if addressVersion == 4: if addressVersion == 4:
if len(data) < 350: # sanity check. if len(data) < 350: # sanity check.
print '(within processpubkey) payloadLength less than 350. Sanity check failed.' logger.info('(within processpubkey) payloadLength less than 350. Sanity check failed.')
return return
signedData = data[8:readPosition] # Used only for v4 or higher pubkeys signedData = data[8:readPosition] # Used only for v4 or higher pubkeys
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
@ -1502,8 +1451,7 @@ class receiveDataThread(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
@ -1530,11 +1478,11 @@ class receiveDataThread(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')
@ -1546,17 +1494,16 @@ class receiveDataThread(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: else:
print 'Tag successfully matches keys in pubkey message' # testing. Will remove soon. logger.info('Tag successfully matches keys in pubkey message') # testing. Will remove soon.
with shared.printLock:
print 'within recpubkey, addressVersion:', addressVersion, ', streamNumber:', streamNumber logger.info('within recpubkey, addressVersion: %s streamNumber: %s'%(addressVersion, streamNumber))
print 'ripe', ripe.encode('hex') logger.info('ripe %s'%ripe.encode('hex'))
print 'publicSigningKey in hex:', publicSigningKey.encode('hex') logger.info('publicSigningKey in hex: %s'%publicSigningKey.encode('hex'))
print 'publicEncryptionKey in hex:', publicEncryptionKey.encode('hex') logger.info('publicEncryptionKey in hex: %s'%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)
@ -1571,10 +1518,10 @@ class receiveDataThread(threading.Thread):
# We have received a getpubkey message # We have received a getpubkey message
def recgetpubkey(self, data): def recgetpubkey(self, data):
if not self.isProofOfWorkSufficient(data): if not self.isProofOfWorkSufficient(data):
print 'Proof of work in getpubkey message insufficient.' logger.info('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.info('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])
@ -1588,10 +1535,10 @@ class receiveDataThread(threading.Thread):
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.info('The time in this getpubkey message is too new. Ignoring it. Time: %s'%embeddedTime)
return return
if embeddedTime < int(time.time()) - shared.maximumAgeOfAnObjectThatIAmWillingToAccept: if embeddedTime < int(time.time()) - shared.maximumAgeOfAnObjectThatIAmWillingToAccept:
print 'The time in this getpubkey message is too old. Ignoring it. Time:', embeddedTime logger.info('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])
@ -1599,7 +1546,7 @@ class receiveDataThread(threading.Thread):
streamNumber, streamNumberLength = decodeVarint( streamNumber, streamNumberLength = decodeVarint(
data[readPosition:readPosition + 10]) data[readPosition:readPosition + 10])
if streamNumber != self.streamNumber: if streamNumber != self.streamNumber:
print 'The streamNumber', streamNumber, 'doesn\'t match our stream number:', self.streamNumber logger.info('The streamNumber %s doesn\'t match our stream number: %s'%(streamNumber, self.streamNumber))
return return
readPosition += streamNumberLength readPosition += streamNumberLength
@ -1607,11 +1554,11 @@ class receiveDataThread(threading.Thread):
inventoryHash = calculateInventoryHash(data) inventoryHash = calculateInventoryHash(data)
shared.inventoryLock.acquire() shared.inventoryLock.acquire()
if inventoryHash in shared.inventory: if inventoryHash in shared.inventory:
print 'We have already received this getpubkey request. Ignoring it.' logger.info('We have already received this getpubkey request. Ignoring it.')
shared.inventoryLock.release() shared.inventoryLock.release()
return return
elif shared.isInSqlInventory(inventoryHash): elif shared.isInSqlInventory(inventoryHash):
print 'We have already received this getpubkey request (it is stored on disk in the SQL inventory). Ignoring it.' logger.info('We have already received this getpubkey request (it is stored on disk in the SQL inventory). Ignoring it.')
shared.inventoryLock.release() shared.inventoryLock.release()
return return
@ -1624,49 +1571,43 @@ class receiveDataThread(threading.Thread):
self.broadcastinv(inventoryHash) self.broadcastinv(inventoryHash)
if requestedAddressVersionNumber == 0: if requestedAddressVersionNumber == 0:
print 'The requestedAddressVersionNumber of the pubkey request is zero. That doesn\'t make any sense. Ignoring it.' logger.info('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.info('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.info('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.info('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.info('The length of the requested tag is not 32 bytes. Something is wrong. Ignoring.')
return return
with shared.printLock: logger.info('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.info('(Within the recgetpubkey function) Someone requested one of my pubkeys but the requestedAddressVersionNumber doesn\'t match my actual address version number. They shouldn\'t have done that. Ignoring.\n')
sys.stderr.write(
'(Within the recgetpubkey function) Someone requested one of my pubkeys but the requestedAddressVersionNumber doesn\'t match my actual address version number. They shouldn\'t have done that. 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(
@ -1674,12 +1615,10 @@ class receiveDataThread(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
with shared.printLock: 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.')
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))
@ -1697,31 +1636,28 @@ class receiveDataThread(threading.Thread):
if len(shared.numberOfObjectsThatWeHaveYetToGetPerPeer) > 0: if len(shared.numberOfObjectsThatWeHaveYetToGetPerPeer) > 0:
for key, value in shared.numberOfObjectsThatWeHaveYetToGetPerPeer.items(): for key, value in shared.numberOfObjectsThatWeHaveYetToGetPerPeer.items():
totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers += value totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers += value
with shared.printLock: logger.info('number of keys(hosts) in shared.numberOfObjectsThatWeHaveYetToGetPerPeer: %s'%len(shared.numberOfObjectsThatWeHaveYetToGetPerPeer))
print 'number of keys(hosts) in shared.numberOfObjectsThatWeHaveYetToGetPerPeer:', len(shared.numberOfObjectsThatWeHaveYetToGetPerPeer) logger.info('totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers = %s'%totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers)
print 'totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers = ', totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers
numberOfItemsInInv, lengthOfVarint = decodeVarint(data[:10]) numberOfItemsInInv, lengthOfVarint = decodeVarint(data[:10])
if numberOfItemsInInv > 50000: if numberOfItemsInInv > 50000:
sys.stderr.write('Too many items in inv message!') logger.error('Too many items in inv message!')
return return
if len(data) < lengthOfVarint + (numberOfItemsInInv * 32): if len(data) < lengthOfVarint + (numberOfItemsInInv * 32):
print 'inv message doesn\'t contain enough data. Ignoring.' logger.info('inv message doesn\'t contain enough data. Ignoring.')
return return
if numberOfItemsInInv == 1: # we'll just request this data from the person who advertised the object. if numberOfItemsInInv == 1: # we'll just request this data from the person who advertised the object.
if totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers > 200000 and len(self.objectsThatWeHaveYetToGetFromThisPeer) > 1000: # inv flooding attack mitigation if totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers > 200000 and len(self.objectsThatWeHaveYetToGetFromThisPeer) > 1000: # inv flooding attack mitigation
with shared.printLock: logger.info('We already have %s items yet to retrieve from peers and over 1000 from this node in particular. Ignoring this inv message.'%totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers)
print 'We already have', totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers, 'items yet to retrieve from peers and over 1000 from this node in particular. Ignoring this inv message.'
return return
self.someObjectsOfWhichThisRemoteNodeIsAlreadyAware[ self.someObjectsOfWhichThisRemoteNodeIsAlreadyAware[
data[lengthOfVarint:32 + lengthOfVarint]] = 0 data[lengthOfVarint:32 + lengthOfVarint]] = 0
shared.numberOfInventoryLookupsPerformed += 1 shared.numberOfInventoryLookupsPerformed += 1
if data[lengthOfVarint:32 + lengthOfVarint] in shared.inventory: if data[lengthOfVarint:32 + lengthOfVarint] in shared.inventory:
with shared.printLock: logger.info('Inventory (in memory) has inventory item already.')
print 'Inventory (in memory) has inventory item already.'
elif shared.isInSqlInventory(data[lengthOfVarint:32 + lengthOfVarint]): elif shared.isInSqlInventory(data[lengthOfVarint:32 + lengthOfVarint]):
print 'Inventory (SQL on disk) has inventory item already.' logger.info('Inventory (SQL on disk) has inventory item already.')
else: else:
self.sendgetdata(data[lengthOfVarint:32 + lengthOfVarint]) self.sendgetdata(data[lengthOfVarint:32 + lengthOfVarint])
else: else:
@ -1736,8 +1672,7 @@ class receiveDataThread(threading.Thread):
logger.info('inv message lists %s objects. Of those %s are new to me. It took %s seconds to figure that out.', numberOfItemsInInv, len(objectsNewToMe), time.time()-startTime) logger.info('inv message lists %s objects. Of those %s are new to me. It took %s seconds to figure that out.', numberOfItemsInInv, len(objectsNewToMe), time.time()-startTime)
for item in objectsNewToMe: for item in objectsNewToMe:
if totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers > 200000 and len(self.objectsThatWeHaveYetToGetFromThisPeer) > 1000: # inv flooding attack mitigation if totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers > 200000 and len(self.objectsThatWeHaveYetToGetFromThisPeer) > 1000: # inv flooding attack mitigation
with shared.printLock: logger.info('We already have %s items yet to retrieve from peers and over %s from this node in particular. Ignoring the rest of this inv message.'%(totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers,len(self.objectsThatWeHaveYetToGetFromThisPeer)))
print 'We already have', totalNumberOfobjectsThatWeHaveYetToGetFromAllPeers, 'items yet to retrieve from peers and over', len(self.objectsThatWeHaveYetToGetFromThisPeer), 'from this node in particular. Ignoring the rest of this inv message.'
break break
self.someObjectsOfWhichThisRemoteNodeIsAlreadyAware[item] = 0 # helps us keep from sending inv messages to peers that already know about the objects listed therein self.someObjectsOfWhichThisRemoteNodeIsAlreadyAware[item] = 0 # helps us keep from sending inv messages to peers that already know about the objects listed therein
self.objectsThatWeHaveYetToGetFromThisPeer[item] = 0 # upon finishing dealing with an incoming message, the receiveDataThread will request a random object of from peer out of this data structure. This way if we get multiple inv messages from multiple peers which list mostly the same objects, we will make getdata requests for different random objects from the various peers. self.objectsThatWeHaveYetToGetFromThisPeer[item] = 0 # upon finishing dealing with an incoming message, the receiveDataThread will request a random object of from peer out of this data structure. This way if we get multiple inv messages from multiple peers which list mostly the same objects, we will make getdata requests for different random objects from the various peers.
@ -1748,8 +1683,7 @@ class receiveDataThread(threading.Thread):
# Send a getdata message to our peer to request the object with the given # Send a getdata message to our peer to request the object with the given
# hash # hash
def sendgetdata(self, hash): def sendgetdata(self, hash):
with shared.printLock: logger.info('sending getdata to retrieve object with hash: %s'%hash.encode('hex'))
print 'sending getdata to retrieve object with hash:', hash.encode('hex')
payload = '\x01' + hash payload = '\x01' + hash
headerData = '\xe9\xbe\xb4\xd9' # magic bits, slighly different from Bitcoin's magic bits. headerData = '\xe9\xbe\xb4\xd9' # magic bits, slighly different from Bitcoin's magic bits.
@ -1761,8 +1695,7 @@ class receiveDataThread(threading.Thread):
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:
with shared.printLock: logger.info('sock.sendall error: %s'%err)
print 'sock.sendall error:', err
# We have received a getdata request from our peer # We have received a getdata request from our peer
@ -1770,13 +1703,12 @@ class receiveDataThread(threading.Thread):
numberOfRequestedInventoryItems, lengthOfVarint = decodeVarint( numberOfRequestedInventoryItems, lengthOfVarint = decodeVarint(
data[:10]) data[:10])
if len(data) < lengthOfVarint + (32 * numberOfRequestedInventoryItems): if len(data) < lengthOfVarint + (32 * numberOfRequestedInventoryItems):
print 'getdata message does not contain enough data. Ignoring.' logger.info('getdata message does not contain enough data. Ignoring.')
return return
for i in xrange(numberOfRequestedInventoryItems): for i in xrange(numberOfRequestedInventoryItems):
hash = data[lengthOfVarint + ( hash = data[lengthOfVarint + (
i * 32):32 + lengthOfVarint + (i * 32)] i * 32):32 + lengthOfVarint + (i * 32)]
with shared.printLock: logger.info('received getdata request for item: %s'%hash.encode('hex'))
print 'received getdata request for item:', hash.encode('hex')
shared.numberOfInventoryLookupsPerformed += 1 shared.numberOfInventoryLookupsPerformed += 1
shared.inventoryLock.acquire() shared.inventoryLock.acquire()
@ -1795,34 +1727,29 @@ class receiveDataThread(threading.Thread):
objectType, payload = row objectType, payload = row
self.sendData(objectType, payload) self.sendData(objectType, payload)
else: else:
print 'Someone asked for an object with a getdata which is not in either our memory inventory or our SQL inventory. That shouldn\'t have happened.' logger.info('Someone asked for an object with a getdata which is not in either our memory inventory or our SQL inventory. That shouldn\'t have happened.')
# Our peer has requested (in a getdata message) that we send an object. # Our peer has requested (in a getdata message) that we send an object.
def sendData(self, objectType, payload): def sendData(self, objectType, payload):
headerData = '\xe9\xbe\xb4\xd9' # magic bits, slighly different from Bitcoin's magic bits. headerData = '\xe9\xbe\xb4\xd9' # magic bits, slighly different from Bitcoin's magic bits.
if objectType == 'pubkey': if objectType == 'pubkey':
with shared.printLock: logger.info('sending pubkey')
print 'sending pubkey'
headerData += 'pubkey\x00\x00\x00\x00\x00\x00' headerData += 'pubkey\x00\x00\x00\x00\x00\x00'
elif objectType == 'getpubkey' or objectType == 'pubkeyrequest': elif objectType == 'getpubkey' or objectType == 'pubkeyrequest':
with shared.printLock: logger.info('sending getpubkey')
print 'sending getpubkey'
headerData += 'getpubkey\x00\x00\x00' headerData += 'getpubkey\x00\x00\x00'
elif objectType == 'msg': elif objectType == 'msg':
with shared.printLock: logger.info('sending msg')
print 'sending msg'
headerData += 'msg\x00\x00\x00\x00\x00\x00\x00\x00\x00' headerData += 'msg\x00\x00\x00\x00\x00\x00\x00\x00\x00'
elif objectType == 'broadcast': elif objectType == 'broadcast':
with shared.printLock: logger.info('sending broadcast')
print 'sending broadcast'
headerData += 'broadcast\x00\x00\x00' headerData += 'broadcast\x00\x00\x00'
else: else:
sys.stderr.write( logger.info('Error: sendData has been asked to send a strange objectType: %s\n' % str(objectType))
'Error: sendData has been asked to send a strange objectType: %s\n' % str(objectType))
return return
headerData += pack('>L', len(payload)) # payload length. headerData += pack('>L', len(payload)) # payload length.
headerData += hashlib.sha512(payload).digest()[:4] headerData += hashlib.sha512(payload).digest()[:4]
@ -1830,14 +1757,12 @@ class receiveDataThread(threading.Thread):
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:
with shared.printLock: logger.info('sock.sendall error: %s'%err)
print 'sock.sendall error:', err
# Advertise this object to all of our peers # Advertise this object to all of our peers
def broadcastinv(self, hash): def broadcastinv(self, hash):
with shared.printLock: logger.info('broadcasting inv with hash: %s'%hash.encode('hex'))
print 'broadcasting inv with hash:', hash.encode('hex')
shared.broadcastToSendDataQueues((self.streamNumber, 'advertiseobject', hash)) shared.broadcastToSendDataQueues((self.streamNumber, 'advertiseobject', hash))
@ -1849,36 +1774,29 @@ class receiveDataThread(threading.Thread):
data[:10]) data[:10])
if shared.verbose >= 1: if shared.verbose >= 1:
with shared.printLock: logger.info('addr message contains %s IP addresses.'%numberOfAddressesIncluded)
print 'addr message contains', numberOfAddressesIncluded, 'IP addresses.'
if numberOfAddressesIncluded > 1000 or numberOfAddressesIncluded == 0: if numberOfAddressesIncluded > 1000 or numberOfAddressesIncluded == 0:
return return
if len(data) != lengthOfNumberOfAddresses + (38 * numberOfAddressesIncluded): if len(data) != lengthOfNumberOfAddresses + (38 * numberOfAddressesIncluded):
print 'addr message does not contain the correct amount of data. Ignoring.' logger.info('addr message does not contain the correct amount of data. Ignoring.')
return return
for i in range(0, numberOfAddressesIncluded): for i in range(0, numberOfAddressesIncluded):
try: try:
if data[20 + lengthOfNumberOfAddresses + (38 * i):32 + lengthOfNumberOfAddresses + (38 * i)] != '\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xFF\xFF': if data[20 + lengthOfNumberOfAddresses + (38 * i):32 + lengthOfNumberOfAddresses + (38 * i)] != '\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xFF\xFF':
with shared.printLock: logger.info('Skipping IPv6 address. %s'%(repr(data[20 + lengthOfNumberOfAddresses + (38 * i):32 + lengthOfNumberOfAddresses + (38 * i)])))
print 'Skipping IPv6 address.', repr(data[20 + lengthOfNumberOfAddresses + (38 * i):32 + lengthOfNumberOfAddresses + (38 * i)])
continue continue
except Exception as err: except Exception as err:
with shared.printLock: logger.error('ERROR TRYING TO UNPACK recaddr (to test for an IPv6 address). Message: %s\n' % str(err))
sys.stderr.write(
'ERROR TRYING TO UNPACK recaddr (to test for an IPv6 address). Message: %s\n' % str(err))
break # giving up on unpacking any more. We should still be connected however. break # giving up on unpacking any more. We should still be connected however.
try: try:
recaddrStream, = unpack('>I', data[8 + lengthOfNumberOfAddresses + ( recaddrStream, = unpack('>I', data[8 + lengthOfNumberOfAddresses + (
38 * i):12 + lengthOfNumberOfAddresses + (38 * i)]) 38 * i):12 + lengthOfNumberOfAddresses + (38 * i)])
except Exception as err: except Exception as err:
with shared.printLock: logger.error('ERROR TRYING TO UNPACK recaddr (recaddrStream). Message: %s\n' % str(err))
sys.stderr.write(
'ERROR TRYING TO UNPACK recaddr (recaddrStream). Message: %s\n' % str(err))
break # giving up on unpacking any more. We should still be connected however. break # giving up on unpacking any more. We should still be connected however.
if recaddrStream == 0: if recaddrStream == 0:
@ -1889,9 +1807,7 @@ class receiveDataThread(threading.Thread):
recaddrServices, = unpack('>Q', data[12 + lengthOfNumberOfAddresses + ( recaddrServices, = unpack('>Q', data[12 + lengthOfNumberOfAddresses + (
38 * i):20 + lengthOfNumberOfAddresses + (38 * i)]) 38 * i):20 + lengthOfNumberOfAddresses + (38 * i)])
except Exception as err: except Exception as err:
with shared.printLock: logger.error('ERROR TRYING TO UNPACK recaddr (recaddrServices). Message: %s\n' % str(err))
sys.stderr.write(
'ERROR TRYING TO UNPACK recaddr (recaddrServices). Message: %s\n' % str(err))
break # giving up on unpacking any more. We should still be connected however. break # giving up on unpacking any more. We should still be connected however.
@ -1899,9 +1815,7 @@ class receiveDataThread(threading.Thread):
recaddrPort, = unpack('>H', data[36 + lengthOfNumberOfAddresses + ( recaddrPort, = unpack('>H', data[36 + lengthOfNumberOfAddresses + (
38 * i):38 + lengthOfNumberOfAddresses + (38 * i)]) 38 * i):38 + lengthOfNumberOfAddresses + (38 * i)])
except Exception as err: except Exception as err:
with shared.printLock: logger.error('ERROR TRYING TO UNPACK recaddr (recaddrPort). Message: %s\n' % str(err))
sys.stderr.write(
'ERROR TRYING TO UNPACK recaddr (recaddrPort). Message: %s\n' % str(err))
break # giving up on unpacking any more. We should still be connected however. break # giving up on unpacking any more. We should still be connected however.
# print 'Within recaddr(): IP', recaddrIP, ', Port', # print 'Within recaddr(): IP', recaddrIP, ', Port',
@ -1910,13 +1824,13 @@ class receiveDataThread(threading.Thread):
32 + lengthOfNumberOfAddresses + (38 * i):36 + lengthOfNumberOfAddresses + (38 * i)]) 32 + lengthOfNumberOfAddresses + (38 * i):36 + lengthOfNumberOfAddresses + (38 * i)])
# print 'hostFromAddrMessage', hostFromAddrMessage # print 'hostFromAddrMessage', hostFromAddrMessage
if data[32 + lengthOfNumberOfAddresses + (38 * i)] == '\x7F': if data[32 + lengthOfNumberOfAddresses + (38 * i)] == '\x7F':
print 'Ignoring IP address in loopback range:', hostFromAddrMessage logger.info('Ignoring IP address in loopback range: %s'%hostFromAddrMessage)
continue continue
if data[32 + lengthOfNumberOfAddresses + (38 * i)] == '\x0A': if data[32 + lengthOfNumberOfAddresses + (38 * i)] == '\x0A':
print 'Ignoring IP address in private range:', hostFromAddrMessage logger.info('Ignoring IP address in private range: %s'%hostFromAddrMessage)
continue continue
if data[32 + lengthOfNumberOfAddresses + (38 * i):34 + lengthOfNumberOfAddresses + (38 * i)] == '\xC0A8': if data[32 + lengthOfNumberOfAddresses + (38 * i):34 + lengthOfNumberOfAddresses + (38 * i)] == '\xC0A8':
print 'Ignoring IP address in private range:', hostFromAddrMessage logger.info('Ignoring IP address in private range: %s'%hostFromAddrMessage)
continue continue
timeSomeoneElseReceivedMessageFromThisNode, = unpack('>Q', data[lengthOfNumberOfAddresses + ( timeSomeoneElseReceivedMessageFromThisNode, = unpack('>Q', data[lengthOfNumberOfAddresses + (
38 * i):8 + lengthOfNumberOfAddresses + (38 * i)]) # This is the 'time' value in the received addr message. 64-bit. 38 * i):8 + lengthOfNumberOfAddresses + (38 * i)]) # This is the 'time' value in the received addr message. 64-bit.
@ -1931,8 +1845,7 @@ class receiveDataThread(threading.Thread):
shared.knownNodes[recaddrStream][peerFromAddrMessage] = ( shared.knownNodes[recaddrStream][peerFromAddrMessage] = (
timeSomeoneElseReceivedMessageFromThisNode) timeSomeoneElseReceivedMessageFromThisNode)
shared.knownNodesLock.release() shared.knownNodesLock.release()
with shared.printLock: logger.info('added new node %s to knownNodes in stream %s'%(peerFromAddrMessage, recaddrStream))
print 'added new node', peerFromAddrMessage, 'to knownNodes in stream', recaddrStream
shared.needToWriteKnownNodesToDisk = True shared.needToWriteKnownNodesToDisk = True
hostDetails = ( hostDetails = (
@ -1951,8 +1864,7 @@ class receiveDataThread(threading.Thread):
#if listOfAddressDetailsToBroadcastToPeers != []: #if listOfAddressDetailsToBroadcastToPeers != []:
# self.broadcastaddr(listOfAddressDetailsToBroadcastToPeers) # self.broadcastaddr(listOfAddressDetailsToBroadcastToPeers)
with shared.printLock: logger.info('knownNodes currently has %s nodes for this stream.'%len(shared.knownNodes[self.streamNumber]))
print 'knownNodes currently has', len(shared.knownNodes[self.streamNumber]), 'nodes for this stream.'
# Function runs when we want to broadcast an addr message to all of our # Function runs when we want to broadcast an addr message to all of our
@ -2069,13 +1981,11 @@ class receiveDataThread(threading.Thread):
try: try:
self.sock.sendall(datatosend) self.sock.sendall(datatosend)
if shared.verbose >= 1: if shared.verbose >= 1:
with shared.printLock: logger.info('Sending addr with %s entries.'%numberOfAddressesInAddrMessage)
print 'Sending addr with', numberOfAddressesInAddrMessage, 'entries.'
except Exception as err: except Exception as err:
# if not 'Bad file descriptor' in err: # if not 'Bad file descriptor' in err:
with shared.printLock: logger.info('sock.sendall error: %s'%err)
print 'sock.sendall error:', err
# We have received a version message # We have received a version message
@ -2087,8 +1997,7 @@ class receiveDataThread(threading.Thread):
self.remoteProtocolVersion, = unpack('>L', data[:4]) self.remoteProtocolVersion, = unpack('>L', data[:4])
if self.remoteProtocolVersion <= 1: if self.remoteProtocolVersion <= 1:
shared.broadcastToSendDataQueues((0, 'shutdown', self.peer)) shared.broadcastToSendDataQueues((0, 'shutdown', self.peer))
with shared.printLock: logger.info('Closing connection to old protocol version 1 node: %s'%self.peer)
print 'Closing connection to old protocol version 1 node: ', self.peer
return return
# print 'remoteProtocolVersion', self.remoteProtocolVersion # print 'remoteProtocolVersion', self.remoteProtocolVersion
@ -2106,14 +2015,11 @@ class receiveDataThread(threading.Thread):
readPosition += lengthOfNumberOfStreamsInVersionMessage readPosition += lengthOfNumberOfStreamsInVersionMessage
self.streamNumber, lengthOfRemoteStreamNumber = decodeVarint( self.streamNumber, lengthOfRemoteStreamNumber = decodeVarint(
data[readPosition:]) data[readPosition:])
with shared.printLock: logger.info('Remote node useragent: %s stream number: %s'%(useragent,self.streamNumber))
print 'Remote node useragent:', useragent, ' stream number:', self.streamNumber
if self.streamNumber != 1: if self.streamNumber != 1:
shared.broadcastToSendDataQueues((0, 'shutdown', self.peer)) shared.broadcastToSendDataQueues((0, 'shutdown', self.peer))
with shared.printLock: logger.info('Closed connection to %s because they are interested in stream %s.'%(self.peer, self.streamNumber))
print 'Closed connection to', self.peer, 'because they are interested in stream', self.streamNumber, '.'
return return
shared.connectedHostsList[ shared.connectedHostsList[
self.peer.host] = 1 # We use this data structure to not only keep track of what hosts we are connected to so that we don't try to connect to them again, but also to list the connections count on the Network Status tab. self.peer.host] = 1 # We use this data structure to not only keep track of what hosts we are connected to so that we don't try to connect to them again, but also to list the connections count on the Network Status tab.
@ -2124,8 +2030,7 @@ class receiveDataThread(threading.Thread):
0, 'setStreamNumber', (self.peer, self.streamNumber))) 0, 'setStreamNumber', (self.peer, self.streamNumber)))
if data[72:80] == shared.eightBytesOfRandomDataUsedToDetectConnectionsToSelf: if data[72:80] == shared.eightBytesOfRandomDataUsedToDetectConnectionsToSelf:
shared.broadcastToSendDataQueues((0, 'shutdown', self.peer)) shared.broadcastToSendDataQueues((0, 'shutdown', self.peer))
with shared.printLock: logger.info('Closing connection to myself: %s'%self.peer)
print 'Closing connection to myself: ', self.peer
return return
shared.broadcastToSendDataQueues((0, 'setRemoteProtocolVersion', ( shared.broadcastToSendDataQueues((0, 'setRemoteProtocolVersion', (
@ -2142,30 +2047,26 @@ class receiveDataThread(threading.Thread):
# Sends a version message # Sends a version message
def sendversion(self): def sendversion(self):
with shared.printLock: logger.info('Sending version message')
print 'Sending version message'
try: try:
self.sock.sendall(shared.assembleVersionMessage( self.sock.sendall(shared.assembleVersionMessage(
self.peer.host, self.peer.port, self.streamNumber)) self.peer.host, self.peer.port, self.streamNumber))
except Exception as err: except Exception as err:
# if not 'Bad file descriptor' in err: # if not 'Bad file descriptor' in err:
with shared.printLock: logger.info('sock.sendall error: %s'%err)
print 'sock.sendall error:', err
# Sends a verack message # Sends a verack message
def sendverack(self): def sendverack(self):
with shared.printLock: logger.info('Sending verack')
print 'Sending verack'
try: try:
self.sock.sendall( self.sock.sendall(
'\xE9\xBE\xB4\xD9\x76\x65\x72\x61\x63\x6B\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xcf\x83\xe1\x35') '\xE9\xBE\xB4\xD9\x76\x65\x72\x61\x63\x6B\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:
with shared.printLock: logger.info('sock.sendall error: %s'%err)
print 'sock.sendall error:', err
# cf # cf
# 83 # 83

View File

@ -7,7 +7,8 @@ import hashlib
import random import random
import sys import sys
import socket import socket
import logging
logger = logging.getLogger('class_sendDataThread')
from class_objectHashHolder import * from class_objectHashHolder import *
from addresses import * from addresses import *
@ -19,8 +20,7 @@ class sendDataThread(threading.Thread):
threading.Thread.__init__(self) threading.Thread.__init__(self)
self.mailbox = Queue.Queue() self.mailbox = Queue.Queue()
shared.sendDataQueues.append(self.mailbox) shared.sendDataQueues.append(self.mailbox)
with shared.printLock: logger.info('The length of sendDataQueues at sendDataThread init is: %s'%len(shared.sendDataQueues))
print 'The length of sendDataQueues at sendDataThread init is:', len(shared.sendDataQueues)
self.data = '' self.data = ''
self.objectHashHolderInstance = objectHashHolder(self.mailbox) self.objectHashHolderInstance = objectHashHolder(self.mailbox)
@ -42,23 +42,20 @@ class sendDataThread(threading.Thread):
self.lastTimeISentData = int( self.lastTimeISentData = int(
time.time()) # If this value increases beyond five minutes ago, we'll send a pong message to keep the connection alive. time.time()) # If this value increases beyond five minutes ago, we'll send a pong message to keep the connection alive.
self.someObjectsOfWhichThisRemoteNodeIsAlreadyAware = someObjectsOfWhichThisRemoteNodeIsAlreadyAware self.someObjectsOfWhichThisRemoteNodeIsAlreadyAware = someObjectsOfWhichThisRemoteNodeIsAlreadyAware
with shared.printLock: logger.info('The streamNumber of this sendDataThread (ID: %s ) at setup() is %s'%(id(self), self.streamNumber))
print 'The streamNumber of this sendDataThread (ID:', str(id(self)) + ') at setup() is', self.streamNumber
def sendVersionMessage(self): def sendVersionMessage(self):
datatosend = shared.assembleVersionMessage( datatosend = shared.assembleVersionMessage(
self.peer.host, self.peer.port, self.streamNumber) # the IP and port of the remote host, and my streamNumber. self.peer.host, self.peer.port, self.streamNumber) # the IP and port of the remote host, and my streamNumber.
with shared.printLock: logger.info('Sending version packet: %s'%repr(datatosend))
print 'Sending version packet: ', repr(datatosend)
try: try:
self.sock.sendall(datatosend) self.sock.sendall(datatosend)
except Exception as err: except Exception as err:
# if not 'Bad file descriptor' in err: # if not 'Bad file descriptor' in err:
with shared.printLock: logger.info('sock.sendall error: %s\n' % err)
sys.stderr.write('sock.sendall error: %s\n' % err)
self.versionSent = 1 self.versionSent = 1
@ -69,8 +66,7 @@ class sendDataThread(threading.Thread):
if deststream == self.streamNumber or deststream == 0: if deststream == self.streamNumber or deststream == 0:
if command == 'shutdown': if command == 'shutdown':
if data == self.peer or data == 'all': if data == self.peer or data == 'all':
with shared.printLock: logger.info('sendDataThread (associated with %s ) ID: %s shutting down now.'%(self.peer,id(self)))
print 'sendDataThread (associated with', self.peer, ') ID:', id(self), 'shutting down now.'
try: try:
self.sock.shutdown(socket.SHUT_RDWR) self.sock.shutdown(socket.SHUT_RDWR)
@ -78,8 +74,7 @@ class sendDataThread(threading.Thread):
except: except:
pass pass
shared.sendDataQueues.remove(self.mailbox) shared.sendDataQueues.remove(self.mailbox)
with shared.printLock: logger.info('len of sendDataQueues %s'%len(shared.sendDataQueues))
print 'len of sendDataQueues', len(shared.sendDataQueues)
break break
# When you receive an incoming connection, a sendDataThread is # When you receive an incoming connection, a sendDataThread is
@ -91,15 +86,13 @@ class sendDataThread(threading.Thread):
elif command == 'setStreamNumber': elif command == 'setStreamNumber':
peerInMessage, specifiedStreamNumber = data peerInMessage, specifiedStreamNumber = data
if peerInMessage == self.peer: if peerInMessage == self.peer:
with shared.printLock: logger.info('setting the stream number in the sendData thread (ID: %s ) to %s'%(id(self), specifiedStreamNumber))
print 'setting the stream number in the sendData thread (ID:', id(self), ') to', specifiedStreamNumber
self.streamNumber = specifiedStreamNumber self.streamNumber = specifiedStreamNumber
elif command == 'setRemoteProtocolVersion': elif command == 'setRemoteProtocolVersion':
peerInMessage, specifiedRemoteProtocolVersion = data peerInMessage, specifiedRemoteProtocolVersion = data
if peerInMessage == self.peer: if peerInMessage == self.peer:
with shared.printLock: logger.info('setting the remote node\'s protocol version in the sendData thread (ID: %s ) to %s'%(id(self), specifiedRemoteProtocolVersion))
print 'setting the remote node\'s protocol version in the sendData thread (ID:', id(self), ') to', specifiedRemoteProtocolVersion
self.remoteProtocolVersion = specifiedRemoteProtocolVersion self.remoteProtocolVersion = specifiedRemoteProtocolVersion
elif command == 'advertisepeer': elif command == 'advertisepeer':
@ -129,14 +122,14 @@ class sendDataThread(threading.Thread):
self.sock.sendall(datatosend) self.sock.sendall(datatosend)
self.lastTimeISentData = int(time.time()) self.lastTimeISentData = int(time.time())
except: except:
print 'sendaddr: self.sock.sendall failed' logger.info('sendaddr: self.sock.sendall failed')
try: try:
self.sock.shutdown(socket.SHUT_RDWR) self.sock.shutdown(socket.SHUT_RDWR)
self.sock.close() self.sock.close()
except: except:
pass pass
shared.sendDataQueues.remove(self.mailbox) shared.sendDataQueues.remove(self.mailbox)
print 'sendDataThread thread (ID:', str(id(self)) + ') ending now. Was connected to', self.peer logger.info('sendDataThread thread (ID: %s ) ending now. Was connected to %s'%(str(id(self)),self.peer))
break break
elif command == 'advertiseobject': elif command == 'advertiseobject':
self.objectHashHolderInstance.holdHash(data) self.objectHashHolderInstance.holdHash(data)
@ -155,38 +148,36 @@ class sendDataThread(threading.Thread):
self.sock.sendall(headerData + payload) self.sock.sendall(headerData + payload)
self.lastTimeISentData = int(time.time()) self.lastTimeISentData = int(time.time())
except: except:
print 'sendinv: self.sock.sendall failed' logger.info('sendinv: self.sock.sendall failed')
try: try:
self.sock.shutdown(socket.SHUT_RDWR) self.sock.shutdown(socket.SHUT_RDWR)
self.sock.close() self.sock.close()
except: except:
pass pass
shared.sendDataQueues.remove(self.mailbox) shared.sendDataQueues.remove(self.mailbox)
print 'sendDataThread thread (ID:', str(id(self)) + ') ending now. Was connected to', self.peer logger.info('sendDataThread thread (ID: %s ) ending now. Was connected to %s'%(str(id(self)), self.peer))
break break
elif command == 'pong': elif command == 'pong':
self.someObjectsOfWhichThisRemoteNodeIsAlreadyAware.clear() # To save memory, let us clear this data structure from time to time. As its function is to help us keep from sending inv messages to peers which sent us the same inv message mere seconds earlier, it will be fine to clear this data structure from time to time. self.someObjectsOfWhichThisRemoteNodeIsAlreadyAware.clear() # To save memory, let us clear this data structure from time to time. As its function is to help us keep from sending inv messages to peers which sent us the same inv message mere seconds earlier, it will be fine to clear this data structure from time to time.
if self.lastTimeISentData < (int(time.time()) - 298): if self.lastTimeISentData < (int(time.time()) - 298):
# Send out a pong message to keep the connection alive. # Send out a pong message to keep the connection alive.
with shared.printLock: logger.info( 'Sending pong to %s to keep connection alive.'%self.peer)
print 'Sending pong to', self.peer, 'to keep connection alive.'
try: try:
self.sock.sendall( self.sock.sendall(
'\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')
self.lastTimeISentData = int(time.time()) self.lastTimeISentData = int(time.time())
except: except:
print 'send pong failed' logger.info('send pong failed')
try: try:
self.sock.shutdown(socket.SHUT_RDWR) self.sock.shutdown(socket.SHUT_RDWR)
self.sock.close() self.sock.close()
except: except:
pass pass
shared.sendDataQueues.remove(self.mailbox) shared.sendDataQueues.remove(self.mailbox)
print 'sendDataThread thread', self, 'ending now. Was connected to', self.peer logger.info('sendDataThread thread %s ending now. Was connected to %s'%(str(self),self.peer))
break break
else: else:
with shared.printLock: logger.info('sendDataThread ID: %s ignoring command %s because the thread is not in stream %s'%(id(self),command,deststream))
print 'sendDataThread ID:', id(self), 'ignoring command', command, 'because the thread is not in stream', deststream
self.objectHashHolderInstance.close() self.objectHashHolderInstance.close()

View File

@ -6,7 +6,8 @@ import pickle
import tr#anslate import tr#anslate
from helper_sql import * from helper_sql import *
from debug import logger import logging
logger = logging.getLogger('singlecleaner')
'''The singleCleaner class is a timer-driven thread that cleans data structures to free memory, resends messages when a remote node doesn't respond, and sends pong messages to keep connections alive if the network isn't busy. '''The singleCleaner class is a timer-driven thread that cleans data structures to free memory, resends messages when a remote node doesn't respond, and sends pong messages to keep connections alive if the network isn't busy.
It cleans these data structures in memory: It cleans these data structures in memory:
@ -78,8 +79,7 @@ class singleCleaner(threading.Thread):
'''select toaddress, toripe, fromaddress, subject, message, ackdata, lastactiontime, status, pubkeyretrynumber, msgretrynumber FROM sent WHERE ((status='awaitingpubkey' OR status='msgsent') AND folder='sent') ''') # If the message's folder='trash' then we'll ignore it. '''select toaddress, toripe, fromaddress, subject, message, ackdata, lastactiontime, status, pubkeyretrynumber, msgretrynumber FROM sent WHERE ((status='awaitingpubkey' OR status='msgsent') AND folder='sent') ''') # If the message's folder='trash' then we'll ignore it.
for row in queryreturn: for row in queryreturn:
if len(row) < 5: if len(row) < 5:
with shared.printLock: logger.info(
sys.stderr.write(
'Something went wrong in the singleCleaner thread: a query did not return the requested fields. ' + repr(row)) 'Something went wrong in the singleCleaner thread: a query did not return the requested fields. ' + repr(row))
time.sleep(3) time.sleep(3)
@ -87,7 +87,7 @@ class singleCleaner(threading.Thread):
toaddress, toripe, fromaddress, subject, message, ackdata, lastactiontime, status, pubkeyretrynumber, msgretrynumber = row toaddress, toripe, fromaddress, subject, message, ackdata, lastactiontime, status, pubkeyretrynumber, msgretrynumber = row
if status == 'awaitingpubkey': if status == 'awaitingpubkey':
if int(time.time()) - lastactiontime > (shared.maximumAgeOfAnObjectThatIAmWillingToAccept * (2 ** (pubkeyretrynumber))): if int(time.time()) - lastactiontime > (shared.maximumAgeOfAnObjectThatIAmWillingToAccept * (2 ** (pubkeyretrynumber))):
print 'It has been a long time and we haven\'t heard a response to our getpubkey request. Sending again.' logger.info('It has been a long time and we haven\'t heard a response to our getpubkey request. Sending again.')
try: try:
del shared.neededPubkeys[ del shared.neededPubkeys[
toripe] # We need to take this entry out of the shared.neededPubkeys structure because the shared.workerQueue checks to see whether the entry is already present and will not do the POW and send the message because it assumes that it has already done it recently. toripe] # We need to take this entry out of the shared.neededPubkeys structure because the shared.workerQueue checks to see whether the entry is already present and will not do the POW and send the message because it assumes that it has already done it recently.

View File

@ -1,3 +1,6 @@
import logging
logger = logging.getLogger('class_singleLister')
import threading import threading
import shared import shared
import socket import socket
@ -32,8 +35,7 @@ class singleListener(threading.Thread):
while shared.config.get('bitmessagesettings', 'socksproxytype')[0:5] == 'SOCKS' and not shared.config.getboolean('bitmessagesettings', 'sockslisten'): while shared.config.get('bitmessagesettings', 'socksproxytype')[0:5] == 'SOCKS' and not shared.config.getboolean('bitmessagesettings', 'sockslisten'):
time.sleep(5) time.sleep(5)
with shared.printLock: logger.info('Listening for incoming connections.')
print 'Listening for incoming connections.'
HOST = '' # Symbolic name meaning all available interfaces HOST = '' # Symbolic name meaning all available interfaces
PORT = shared.config.getint('bitmessagesettings', 'port') PORT = shared.config.getint('bitmessagesettings', 'port')
@ -52,8 +54,7 @@ class singleListener(threading.Thread):
while shared.config.get('bitmessagesettings', 'socksproxytype')[0:5] == 'SOCKS' and not shared.config.getboolean('bitmessagesettings', 'sockslisten'): while shared.config.get('bitmessagesettings', 'socksproxytype')[0:5] == 'SOCKS' and not shared.config.getboolean('bitmessagesettings', 'sockslisten'):
time.sleep(10) time.sleep(10)
while len(shared.connectedHostsList) > 220: while len(shared.connectedHostsList) > 220:
with shared.printLock: logger.info('We are connected to too many people. Not accepting further incoming connections for ten seconds.')
print 'We are connected to too many people. Not accepting further incoming connections for ten seconds.'
time.sleep(10) time.sleep(10)
a, (HOST, PORT) = sock.accept() a, (HOST, PORT) = sock.accept()
@ -63,8 +64,7 @@ class singleListener(threading.Thread):
# because the two computers will share the same external IP. This # because the two computers will share the same external IP. This
# is here to prevent connection flooding. # is here to prevent connection flooding.
while HOST in shared.connectedHostsList: while HOST in shared.connectedHostsList:
with shared.printLock: logger.info('We are already connected to %s . Ignoring connection.'%HOST)
print 'We are already connected to', HOST + '. Ignoring connection.'
a.close() a.close()
a, (HOST, PORT) = sock.accept() a, (HOST, PORT) = sock.accept()
@ -82,6 +82,5 @@ class singleListener(threading.Thread):
a, HOST, PORT, -1, someObjectsOfWhichThisRemoteNodeIsAlreadyAware, self.selfInitiatedConnections) a, HOST, PORT, -1, someObjectsOfWhichThisRemoteNodeIsAlreadyAware, self.selfInitiatedConnections)
rd.start() rd.start()
with shared.printLock: logger.info('%s connected to %s during INCOMING request.'%(self,HOST))
print self, 'connected to', HOST, 'during INCOMING request.'

View File

@ -1,3 +1,6 @@
import logging
logger = logging.getLogger('class_singleWorker')
import threading import threading
import shared import shared
import time import time
@ -10,7 +13,7 @@ import proofofwork
import sys import sys
from class_addressGenerator import pointMult from class_addressGenerator import pointMult
import tr import tr
from debug import logger #~ from debug import logger
from helper_sql import * from helper_sql import *
import helper_inbox import helper_inbox
@ -45,7 +48,7 @@ class singleWorker(threading.Thread):
'''SELECT ackdata FROM sent where (status='msgsent' OR status='doingmsgpow')''') '''SELECT ackdata FROM sent where (status='msgsent' OR status='doingmsgpow')''')
for row in queryreturn: for row in queryreturn:
ackdata, = row ackdata, = row
print 'Watching for ackdata', ackdata.encode('hex') logger.info('Watching for ackdata %s'%ackdata.encode('hex'))
shared.ackdataForWhichImWatching[ackdata] = 0 shared.ackdataForWhichImWatching[ackdata] = 0
queryreturn = sqlQuery( queryreturn = sqlQuery(
@ -77,9 +80,7 @@ class singleWorker(threading.Thread):
elif command == 'sendOutOrStoreMyV4Pubkey': elif command == 'sendOutOrStoreMyV4Pubkey':
self.sendOutOrStoreMyV4Pubkey(data) self.sendOutOrStoreMyV4Pubkey(data)
else: else:
with shared.printLock: logger.info('Probable programming error: The command sent to the workerThread is weird. It is: %s\n' % command)
sys.stderr.write(
'Probable programming error: The command sent to the workerThread is weird. It is: %s\n' % command)
shared.workerQueue.task_done() shared.workerQueue.task_done()
@ -108,9 +109,7 @@ class singleWorker(threading.Thread):
privEncryptionKeyBase58 = shared.config.get( privEncryptionKeyBase58 = shared.config.get(
myAddress, 'privencryptionkey') myAddress, 'privencryptionkey')
except Exception as err: except Exception as err:
with shared.printLock: logger.info('Error within doPOWForMyV2Pubkey. Could not read the keys from the keys.dat file for a requested address. %s\n' % err)
sys.stderr.write(
'Error within doPOWForMyV2Pubkey. Could not read the keys from the keys.dat file for a requested address. %s\n' % err)
return return
@ -129,10 +128,10 @@ class singleWorker(threading.Thread):
# Do the POW for this pubkey message # Do the POW for this pubkey message
target = 2 ** 64 / ((len(payload) + shared.networkDefaultPayloadLengthExtraBytes + target = 2 ** 64 / ((len(payload) + shared.networkDefaultPayloadLengthExtraBytes +
8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte) 8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte)
print '(For pubkey message) Doing proof of work...' logger.info('(For pubkey message) Doing proof of work...')
initialHash = hashlib.sha512(payload).digest() initialHash = hashlib.sha512(payload).digest()
trialValue, nonce = proofofwork.run(target, initialHash) trialValue, nonce = proofofwork.run(target, initialHash)
print '(For pubkey message) Found proof of work', trialValue, 'Nonce:', nonce logger.info('(For pubkey message) Found proof of work %s Nonce: %s'%(trialValue, nonce))
payload = pack('>Q', nonce) + payload payload = pack('>Q', nonce) + payload
inventoryHash = calculateInventoryHash(payload) inventoryHash = calculateInventoryHash(payload)
@ -141,8 +140,7 @@ class singleWorker(threading.Thread):
objectType, streamNumber, payload, embeddedTime,'') objectType, streamNumber, payload, embeddedTime,'')
shared.inventorySets[streamNumber].add(inventoryHash) shared.inventorySets[streamNumber].add(inventoryHash)
with shared.printLock: logger.info('broadcasting inv with hash: %s'%inventoryHash.encode('hex'))
print 'broadcasting inv with hash:', inventoryHash.encode('hex')
shared.broadcastToSendDataQueues(( shared.broadcastToSendDataQueues((
streamNumber, 'advertiseobject', inventoryHash)) streamNumber, 'advertiseobject', inventoryHash))
@ -159,8 +157,7 @@ class singleWorker(threading.Thread):
def sendOutOrStoreMyV3Pubkey(self, hash): def sendOutOrStoreMyV3Pubkey(self, hash):
myAddress = shared.myAddressesByHash[hash] myAddress = shared.myAddressesByHash[hash]
if shared.safeConfigGetBoolean(myAddress, 'chan'): if shared.safeConfigGetBoolean(myAddress, 'chan'):
with shared.printLock: logger.info('This is a chan address. Not sending pubkey.')
print 'This is a chan address. Not sending pubkey.'
return return
status, addressVersionNumber, streamNumber, hash = decodeAddress( status, addressVersionNumber, streamNumber, hash = decodeAddress(
myAddress) myAddress)
@ -177,10 +174,7 @@ class singleWorker(threading.Thread):
privEncryptionKeyBase58 = shared.config.get( privEncryptionKeyBase58 = shared.config.get(
myAddress, 'privencryptionkey') myAddress, 'privencryptionkey')
except Exception as err: except Exception as err:
with shared.printLock: logger.info('Error within sendOutOrStoreMyV3Pubkey. Could not read the keys from the keys.dat file for a requested address. %s\n'%err)
sys.stderr.write(
'Error within sendOutOrStoreMyV3Pubkey. Could not read the keys from the keys.dat file for a requested address. %s\n' % err)
return return
privSigningKeyHex = shared.decodeWalletImportFormat( privSigningKeyHex = shared.decodeWalletImportFormat(
@ -206,10 +200,10 @@ class singleWorker(threading.Thread):
# Do the POW for this pubkey message # Do the POW for this pubkey message
target = 2 ** 64 / ((len(payload) + shared.networkDefaultPayloadLengthExtraBytes + target = 2 ** 64 / ((len(payload) + shared.networkDefaultPayloadLengthExtraBytes +
8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte) 8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte)
print '(For pubkey message) Doing proof of work...' logger.info('(For pubkey message) Doing proof of work...')
initialHash = hashlib.sha512(payload).digest() initialHash = hashlib.sha512(payload).digest()
trialValue, nonce = proofofwork.run(target, initialHash) trialValue, nonce = proofofwork.run(target, initialHash)
print '(For pubkey message) Found proof of work', trialValue, 'Nonce:', nonce logger.info('(For pubkey message) Found proof of work %s Nonce: %s'%(trialValue, nonce))
payload = pack('>Q', nonce) + payload payload = pack('>Q', nonce) + payload
inventoryHash = calculateInventoryHash(payload) inventoryHash = calculateInventoryHash(payload)
@ -218,8 +212,7 @@ class singleWorker(threading.Thread):
objectType, streamNumber, payload, embeddedTime,'') objectType, streamNumber, payload, embeddedTime,'')
shared.inventorySets[streamNumber].add(inventoryHash) shared.inventorySets[streamNumber].add(inventoryHash)
with shared.printLock: logger.info('broadcasting inv with hash: %s'%inventoryHash.encode('hex'))
print 'broadcasting inv with hash:', inventoryHash.encode('hex')
shared.broadcastToSendDataQueues(( shared.broadcastToSendDataQueues((
streamNumber, 'advertiseobject', inventoryHash)) streamNumber, 'advertiseobject', inventoryHash))
@ -233,8 +226,7 @@ class singleWorker(threading.Thread):
# does the necessary POW and sends it out. # does the necessary POW and sends it out.
def sendOutOrStoreMyV4Pubkey(self, myAddress): def sendOutOrStoreMyV4Pubkey(self, myAddress):
if shared.safeConfigGetBoolean(myAddress, 'chan'): if shared.safeConfigGetBoolean(myAddress, 'chan'):
with shared.printLock: logger.info('This is a chan address. Not sending pubkey.')
print 'This is a chan address. Not sending pubkey.'
return return
status, addressVersionNumber, streamNumber, hash = decodeAddress( status, addressVersionNumber, streamNumber, hash = decodeAddress(
myAddress) myAddress)
@ -253,9 +245,7 @@ class singleWorker(threading.Thread):
privEncryptionKeyBase58 = shared.config.get( privEncryptionKeyBase58 = shared.config.get(
myAddress, 'privencryptionkey') myAddress, 'privencryptionkey')
except Exception as err: except Exception as err:
with shared.printLock: logger.info('Error within sendOutOrStoreMyV4Pubkey. Could not read the keys from the keys.dat file for a requested address. %s\n' % err)
sys.stderr.write(
'Error within sendOutOrStoreMyV4Pubkey. Could not read the keys from the keys.dat file for a requested address. %s\n' % err)
return return
privSigningKeyHex = shared.decodeWalletImportFormat( privSigningKeyHex = shared.decodeWalletImportFormat(
@ -297,10 +287,10 @@ class singleWorker(threading.Thread):
# Do the POW for this pubkey message # Do the POW for this pubkey message
target = 2 ** 64 / ((len(payload) + shared.networkDefaultPayloadLengthExtraBytes + target = 2 ** 64 / ((len(payload) + shared.networkDefaultPayloadLengthExtraBytes +
8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte) 8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte)
print '(For pubkey message) Doing proof of work...' logger.info('(For pubkey message) Doing proof of work...')
initialHash = hashlib.sha512(payload).digest() initialHash = hashlib.sha512(payload).digest()
trialValue, nonce = proofofwork.run(target, initialHash) trialValue, nonce = proofofwork.run(target, initialHash)
print '(For pubkey message) Found proof of work', trialValue, 'Nonce:', nonce logger.info('(For pubkey message) Found proof of work %s Nonce: %s'%(trialValue, nonce))
payload = pack('>Q', nonce) + payload payload = pack('>Q', nonce) + payload
inventoryHash = calculateInventoryHash(payload) inventoryHash = calculateInventoryHash(payload)
@ -309,8 +299,7 @@ class singleWorker(threading.Thread):
objectType, streamNumber, payload, embeddedTime, doubleHashOfAddressData[32:]) objectType, streamNumber, payload, embeddedTime, doubleHashOfAddressData[32:])
shared.inventorySets[streamNumber].add(inventoryHash) shared.inventorySets[streamNumber].add(inventoryHash)
with shared.printLock: logger.info('broadcasting inv with hash: %s'%inventoryHash.encode('hex'))
print 'broadcasting inv with hash:', inventoryHash.encode('hex')
shared.broadcastToSendDataQueues(( shared.broadcastToSendDataQueues((
streamNumber, 'advertiseobject', inventoryHash)) streamNumber, 'advertiseobject', inventoryHash))
@ -333,9 +322,7 @@ class singleWorker(threading.Thread):
status, addressVersionNumber, streamNumber, ripe = decodeAddress( status, addressVersionNumber, streamNumber, ripe = decodeAddress(
fromaddress) fromaddress)
if addressVersionNumber <= 1: if addressVersionNumber <= 1:
with shared.printLock: logger.info('Error: In the singleWorker thread, the sendBroadcast function doesn\'t understand the address version.\n')
sys.stderr.write(
'Error: In the singleWorker thread, the sendBroadcast function doesn\'t understand the address version.\n')
return return
# We need to convert our private keys to public keys in order # We need to convert our private keys to public keys in order
# to include them. # to include them.
@ -405,12 +392,12 @@ class singleWorker(threading.Thread):
target = 2 ** 64 / ((len( target = 2 ** 64 / ((len(
payload) + shared.networkDefaultPayloadLengthExtraBytes + 8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte) payload) + shared.networkDefaultPayloadLengthExtraBytes + 8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte)
print '(For broadcast message) Doing proof of work...' logger.info('(For broadcast message) Doing proof of work...')
shared.UISignalQueue.put(('updateSentItemStatusByAckdata', ( shared.UISignalQueue.put(('updateSentItemStatusByAckdata', (
ackdata, tr.translateText("MainWindow", "Doing work necessary to send broadcast...")))) ackdata, tr.translateText("MainWindow", "Doing work necessary to send broadcast..."))))
initialHash = hashlib.sha512(payload).digest() initialHash = hashlib.sha512(payload).digest()
trialValue, nonce = proofofwork.run(target, initialHash) trialValue, nonce = proofofwork.run(target, initialHash)
print '(For broadcast message) Found proof of work', trialValue, 'Nonce:', nonce logger.info('(For broadcast message) Found proof of work %s Nonce: %s'%(trialValue, nonce))
payload = pack('>Q', nonce) + payload payload = pack('>Q', nonce) + payload
@ -419,8 +406,7 @@ class singleWorker(threading.Thread):
shared.inventory[inventoryHash] = ( shared.inventory[inventoryHash] = (
objectType, streamNumber, payload, int(time.time()),'') objectType, streamNumber, payload, int(time.time()),'')
shared.inventorySets[streamNumber].add(inventoryHash) shared.inventorySets[streamNumber].add(inventoryHash)
with shared.printLock: logger.info('sending inv (within sendBroadcast function) for object: %s'%inventoryHash.encode('hex'))
print 'sending inv (within sendBroadcast function) for object:', inventoryHash.encode('hex')
shared.broadcastToSendDataQueues(( shared.broadcastToSendDataQueues((
streamNumber, 'advertiseobject', inventoryHash)) streamNumber, 'advertiseobject', inventoryHash))
@ -479,7 +465,7 @@ class singleWorker(threading.Thread):
data, = row data, = row
if shared.decryptAndCheckPubkeyPayload(data[8:], toaddress) == 'successful': if shared.decryptAndCheckPubkeyPayload(data[8:], toaddress) == 'successful':
needToRequestPubkey = False needToRequestPubkey = False
print 'debug. successfully decrypted and checked pubkey from sql inventory.' #testing logger.debug('debug. successfully decrypted and checked pubkey from sql inventory.') #testing
sqlExecute( sqlExecute(
'''UPDATE sent SET status='doingmsgpow' WHERE toaddress=? AND status='msgqueued' ''', '''UPDATE sent SET status='doingmsgpow' WHERE toaddress=? AND status='msgqueued' ''',
toaddress) toaddress)
@ -493,7 +479,7 @@ class singleWorker(threading.Thread):
if objectType == 'pubkey' and tag == toTag: if objectType == 'pubkey' and tag == toTag:
result = shared.decryptAndCheckPubkeyPayload(payload[8:], toaddress) #if valid, this function also puts it in the pubkeys table. result = shared.decryptAndCheckPubkeyPayload(payload[8:], toaddress) #if valid, this function also puts it in the pubkeys table.
if result == 'successful': if result == 'successful':
print 'debug. successfully decrypted and checked pubkey from memory inventory.' logger.info('debug. successfully decrypted and checked pubkey from memory inventory.')
needToRequestPubkey = False needToRequestPubkey = False
sqlExecute( sqlExecute(
'''UPDATE sent SET status='doingmsgpow' WHERE toaddress=? AND status='msgqueued' ''', '''UPDATE sent SET status='doingmsgpow' WHERE toaddress=? AND status='msgqueued' ''',
@ -534,9 +520,7 @@ class singleWorker(threading.Thread):
if queryreturn == [] and toripe not in shared.neededPubkeys: if queryreturn == [] and toripe not in shared.neededPubkeys:
# We no longer have the needed pubkey and we haven't requested # We no longer have the needed pubkey and we haven't requested
# it. # it.
with shared.printLock: logger.info('For some reason, the status of a message in our outbox is \'doingmsgpow\' even though we lack the pubkey. Here is the RIPE hash of the needed pubkey: %s\n' % toripe.encode('hex'))
sys.stderr.write(
'For some reason, the status of a message in our outbox is \'doingmsgpow\' even though we lack the pubkey. Here is the RIPE hash of the needed pubkey: %s\n' % toripe.encode('hex'))
sqlExecute( sqlExecute(
'''UPDATE sent SET status='doingpubkeypow' WHERE toaddress=? AND status='doingmsgpow' ''', toaddress) '''UPDATE sent SET status='doingpubkeypow' WHERE toaddress=? AND status='doingmsgpow' ''', toaddress)
shared.UISignalQueue.put(('updateSentItemStatusByHash', ( shared.UISignalQueue.put(('updateSentItemStatusByHash', (
@ -546,8 +530,7 @@ class singleWorker(threading.Thread):
shared.ackdataForWhichImWatching[ackdata] = 0 shared.ackdataForWhichImWatching[ackdata] = 0
shared.UISignalQueue.put(('updateSentItemStatusByAckdata', ( shared.UISignalQueue.put(('updateSentItemStatusByAckdata', (
ackdata, tr.translateText("MainWindow", "Looking up the receiver\'s public key")))) ackdata, tr.translateText("MainWindow", "Looking up the receiver\'s public key"))))
with shared.printLock: logger.info('Sending a message. First 150 characters of message: %s'%repr(message[:150]))
print 'Sending a message. First 150 characters of message:', repr(message[:150])
# mark the pubkey as 'usedpersonally' so that we don't ever delete # mark the pubkey as 'usedpersonally' so that we don't ever delete
@ -564,9 +547,7 @@ class singleWorker(threading.Thread):
toripe, toripe,
toAddressVersionNumber) toAddressVersionNumber)
if queryreturn == []: if queryreturn == []:
with shared.printLock: logger.info('(within sendMsg) The needed pubkey was not found. This should never happen. Aborting send.\n')
sys.stderr.write(
'(within sendMsg) The needed pubkey was not found. This should never happen. Aborting send.\n')
return return
for row in queryreturn: for row in queryreturn:
@ -642,8 +623,7 @@ class singleWorker(threading.Thread):
requiredPayloadLengthExtraBytes) / shared.networkDefaultPayloadLengthExtraBytes)).arg(unicode(strftime(shared.config.get('bitmessagesettings', 'timeformat'), localtime(int(time.time()))), 'utf-8'))))) requiredPayloadLengthExtraBytes) / shared.networkDefaultPayloadLengthExtraBytes)).arg(unicode(strftime(shared.config.get('bitmessagesettings', 'timeformat'), localtime(int(time.time()))), 'utf-8')))))
continue continue
else: # if we are sending a message to ourselves or a chan.. else: # if we are sending a message to ourselves or a chan..
with shared.printLock: logger.info('Sending a message. First 150 characters of message: %s'%repr(message[:150]))
print 'Sending a message. First 150 characters of message:', repr(message[:150])
behaviorBitfield = '\x00\x00\x00\x01' behaviorBitfield = '\x00\x00\x00\x01'
try: try:
@ -651,9 +631,7 @@ class singleWorker(threading.Thread):
toaddress, 'privencryptionkey') toaddress, 'privencryptionkey')
except Exception as err: except Exception as err:
shared.UISignalQueue.put(('updateSentItemStatusByAckdata',(ackdata,tr.translateText("MainWindow",'Problem: You are trying to send a message to yourself or a chan but your encryption key could not be found in the keys.dat file. Could not encrypt message. %1').arg(unicode(strftime(shared.config.get('bitmessagesettings', 'timeformat'),localtime(int(time.time()))),'utf-8'))))) shared.UISignalQueue.put(('updateSentItemStatusByAckdata',(ackdata,tr.translateText("MainWindow",'Problem: You are trying to send a message to yourself or a chan but your encryption key could not be found in the keys.dat file. Could not encrypt message. %1').arg(unicode(strftime(shared.config.get('bitmessagesettings', 'timeformat'),localtime(int(time.time()))),'utf-8')))))
with shared.printLock: logger.info('Error within sendMsg. Could not read the keys from the keys.dat file for our own address. %s\n' % err)
sys.stderr.write(
'Error within sendMsg. Could not read the keys from the keys.dat file for our own address. %s\n' % err)
continue continue
privEncryptionKeyHex = shared.decodeWalletImportFormat( privEncryptionKeyHex = shared.decodeWalletImportFormat(
privEncryptionKeyBase58).encode('hex') privEncryptionKeyBase58).encode('hex')
@ -765,12 +743,10 @@ class singleWorker(threading.Thread):
payload += encodeVarint(len(messageToTransmit)) payload += encodeVarint(len(messageToTransmit))
payload += messageToTransmit payload += messageToTransmit
if shared.config.has_section(toaddress): if shared.config.has_section(toaddress):
with shared.printLock: logger.info('Not bothering to include ackdata because we are sending to ourselves or a chan.')
print 'Not bothering to include ackdata because we are sending to ourselves or a chan.'
fullAckPayload = '' fullAckPayload = ''
elif not shared.isBitSetWithinBitfield(behaviorBitfield,31): elif not shared.isBitSetWithinBitfield(behaviorBitfield,31):
with shared.printLock: logger.info('Not bothering to include ackdata because the receiver said that they won\'t relay it anyway.')
print 'Not bothering to include ackdata because the receiver said that they won\'t relay it anyway.'
fullAckPayload = '' fullAckPayload = ''
else: else:
fullAckPayload = self.generateFullAckMessage( fullAckPayload = self.generateFullAckMessage(
@ -781,7 +757,7 @@ class singleWorker(threading.Thread):
payload += encodeVarint(len(signature)) payload += encodeVarint(len(signature))
payload += signature payload += signature
print 'using pubEncryptionKey:', pubEncryptionKeyBase256.encode('hex') logger.info('using pubEncryptionKey: %s'%pubEncryptionKeyBase256.encode('hex'))
# We have assembled the data that will be encrypted. # We have assembled the data that will be encrypted.
try: try:
encrypted = highlevelcrypto.encrypt(payload,"04"+pubEncryptionKeyBase256.encode('hex')) encrypted = highlevelcrypto.encrypt(payload,"04"+pubEncryptionKeyBase256.encode('hex'))
@ -791,16 +767,14 @@ class singleWorker(threading.Thread):
continue continue
encryptedPayload = embeddedTime + encodeVarint(toStreamNumber) + encrypted encryptedPayload = embeddedTime + encodeVarint(toStreamNumber) + encrypted
target = 2**64 / ((len(encryptedPayload)+requiredPayloadLengthExtraBytes+8) * requiredAverageProofOfWorkNonceTrialsPerByte) target = 2**64 / ((len(encryptedPayload)+requiredPayloadLengthExtraBytes+8) * requiredAverageProofOfWorkNonceTrialsPerByte)
with shared.printLock: logger.info('(For msg message) Doing proof of work. Total required difficulty: %s Required small message difficulty: %s'%(float(requiredAverageProofOfWorkNonceTrialsPerByte) / shared.networkDefaultProofOfWorkNonceTrialsPerByte, float(requiredPayloadLengthExtraBytes) / shared.networkDefaultPayloadLengthExtraBytes))
print '(For msg message) Doing proof of work. Total required difficulty:', float(requiredAverageProofOfWorkNonceTrialsPerByte) / shared.networkDefaultProofOfWorkNonceTrialsPerByte, 'Required small message difficulty:', float(requiredPayloadLengthExtraBytes) / shared.networkDefaultPayloadLengthExtraBytes
powStartTime = time.time() powStartTime = time.time()
initialHash = hashlib.sha512(encryptedPayload).digest() initialHash = hashlib.sha512(encryptedPayload).digest()
trialValue, nonce = proofofwork.run(target, initialHash) trialValue, nonce = proofofwork.run(target, initialHash)
with shared.printLock: logger.info('(For msg message) Found proof of work %s Nonce: %s'%(trialValue, nonce))
print '(For msg message) Found proof of work', trialValue, 'Nonce:', nonce
try: try:
print 'POW took', int(time.time() - powStartTime), 'seconds.', nonce / (time.time() - powStartTime), 'nonce trials per second.' logger.info('POW took %s seconds. %s nonce trials per second.'%(int(time.time() - powStartTime),nonce / (time.time() - powStartTime)))
except: except:
pass pass
@ -818,7 +792,7 @@ class singleWorker(threading.Thread):
# not sending to a chan or one of my addresses # not sending to a chan or one of my addresses
shared.UISignalQueue.put(('updateSentItemStatusByAckdata', (ackdata, tr.translateText("MainWindow", "Message sent. Waiting on acknowledgement. Sent on %1").arg(unicode( shared.UISignalQueue.put(('updateSentItemStatusByAckdata', (ackdata, tr.translateText("MainWindow", "Message sent. Waiting on acknowledgement. Sent on %1").arg(unicode(
strftime(shared.config.get('bitmessagesettings', 'timeformat'), localtime(int(time.time()))), 'utf-8'))))) strftime(shared.config.get('bitmessagesettings', 'timeformat'), localtime(int(time.time()))), 'utf-8')))))
print 'Broadcasting inv for my msg(within sendmsg function):', inventoryHash.encode('hex') logger.info('Broadcasting inv for my msg(within sendmsg function): %s'%inventoryHash.encode('hex'))
shared.broadcastToSendDataQueues(( shared.broadcastToSendDataQueues((
toStreamNumber, 'advertiseobject', inventoryHash)) toStreamNumber, 'advertiseobject', inventoryHash))
@ -857,8 +831,7 @@ class singleWorker(threading.Thread):
toStatus, addressVersionNumber, streamNumber, ripe = decodeAddress( toStatus, addressVersionNumber, streamNumber, ripe = decodeAddress(
toAddress) toAddress)
if toStatus != 'success': if toStatus != 'success':
with shared.printLock: logger.info('Very abnormal error occurred in requestPubKey. toAddress is: ' + repr(
sys.stderr.write('Very abnormal error occurred in requestPubKey. toAddress is: ' + repr(
toAddress) + '. Please report this error to Atheros.') toAddress) + '. Please report this error to Atheros.')
return return
@ -874,12 +847,10 @@ class singleWorker(threading.Thread):
payload += encodeVarint(streamNumber) payload += encodeVarint(streamNumber)
if addressVersionNumber <= 3: if addressVersionNumber <= 3:
payload += ripe payload += ripe
with shared.printLock: logger.info('making request for pubkey with ripe: %s'%ripe.encode('hex'))
print 'making request for pubkey with ripe:', ripe.encode('hex')
else: else:
payload += tag payload += tag
with shared.printLock: logger.info('making request for v4 pubkey with tag: %s'%tag.encode('hex'))
print 'making request for v4 pubkey with tag:', tag.encode('hex')
# print 'trial value', trialValue # print 'trial value', trialValue
statusbar = 'Doing the computations necessary to request the recipient\'s public key.' statusbar = 'Doing the computations necessary to request the recipient\'s public key.'
@ -890,8 +861,7 @@ class singleWorker(threading.Thread):
8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte) 8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte)
initialHash = hashlib.sha512(payload).digest() initialHash = hashlib.sha512(payload).digest()
trialValue, nonce = proofofwork.run(target, initialHash) trialValue, nonce = proofofwork.run(target, initialHash)
with shared.printLock: logger.info('Found proof of work %s Nonce: %s'%(trialValue, nonce))
print 'Found proof of work', trialValue, 'Nonce:', nonce
payload = pack('>Q', nonce) + payload payload = pack('>Q', nonce) + payload
@ -900,7 +870,7 @@ class singleWorker(threading.Thread):
shared.inventory[inventoryHash] = ( shared.inventory[inventoryHash] = (
objectType, streamNumber, payload, int(time.time()),'') objectType, streamNumber, payload, int(time.time()),'')
shared.inventorySets[streamNumber].add(inventoryHash) shared.inventorySets[streamNumber].add(inventoryHash)
print 'sending inv (for the getpubkey message)' logger.info('sending inv (for the getpubkey message)')
shared.broadcastToSendDataQueues(( shared.broadcastToSendDataQueues((
streamNumber, 'advertiseobject', inventoryHash)) streamNumber, 'advertiseobject', inventoryHash))
@ -917,16 +887,14 @@ class singleWorker(threading.Thread):
payload = embeddedTime + encodeVarint(toStreamNumber) + ackdata payload = embeddedTime + encodeVarint(toStreamNumber) + ackdata
target = 2 ** 64 / ((len(payload) + shared.networkDefaultPayloadLengthExtraBytes + target = 2 ** 64 / ((len(payload) + shared.networkDefaultPayloadLengthExtraBytes +
8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte) 8) * shared.networkDefaultProofOfWorkNonceTrialsPerByte)
with shared.printLock: logger.info('(For ack message) Doing proof of work...')
print '(For ack message) Doing proof of work...'
powStartTime = time.time() powStartTime = time.time()
initialHash = hashlib.sha512(payload).digest() initialHash = hashlib.sha512(payload).digest()
trialValue, nonce = proofofwork.run(target, initialHash) trialValue, nonce = proofofwork.run(target, initialHash)
with shared.printLock: logger.info('(For ack message) Found proof of work %s Nonce %s'%(trialValue, nonce))
print '(For ack message) Found proof of work', trialValue, 'Nonce:', nonce
try: try:
print 'POW took', int(time.time() - powStartTime), 'seconds.', nonce / (time.time() - powStartTime), 'nonce trials per second.' logger.info('POW took %s seconds. %s nonce trials per second.'%(int(time.time() - powStartTime),nonce / (time.time() - powStartTime)))
except: except:
pass pass

View File

@ -5,7 +5,10 @@ import time
import shutil # used for moving the messages.dat file import shutil # used for moving the messages.dat file
import sys import sys
import os import os
from debug import logger
import logging
logger = logging.getLogger()
from namecoin import ensureNamecoinOptions from namecoin import ensureNamecoinOptions
import tr#anslate import tr#anslate

View File

@ -3,6 +3,8 @@ import socket
import defaultKnownNodes import defaultKnownNodes
import pickle import pickle
import time import time
import logging
logger = logging.getLogger('helper_bootstrap')
def knownNodes(): def knownNodes():
try: try:
@ -26,7 +28,7 @@ def knownNodes():
except: except:
shared.knownNodes = defaultKnownNodes.createDefaultKnownNodes(shared.appdata) shared.knownNodes = defaultKnownNodes.createDefaultKnownNodes(shared.appdata)
if shared.config.getint('bitmessagesettings', 'settingsversion') > 7: if shared.config.getint('bitmessagesettings', 'settingsversion') > 7:
print 'Bitmessage cannot read future versions of the keys file (keys.dat). Run the newer version of Bitmessage.' logger.info('Bitmessage cannot read future versions of the keys file (keys.dat). Run the newer version of Bitmessage.')
raise SystemExit raise SystemExit
def dns(): def dns():
@ -39,16 +41,16 @@ def dns():
if shared.config.get('bitmessagesettings', 'socksproxytype') == 'none': if shared.config.get('bitmessagesettings', 'socksproxytype') == 'none':
try: try:
for item in socket.getaddrinfo('bootstrap8080.bitmessage.org', 80): for item in socket.getaddrinfo('bootstrap8080.bitmessage.org', 80):
print 'Adding', item[4][0], 'to knownNodes based on DNS boostrap method' logger.info('Adding %s to knownNodes based on DNS boostrap method'%item[4][0])
shared.knownNodes[1][shared.Peer(item[4][0], 8080)] = int(time.time()) shared.knownNodes[1][shared.Peer(item[4][0], 8080)] = int(time.time())
except: except:
print 'bootstrap8080.bitmessage.org DNS bootstrapping failed.' logger.info('bootstrap8080.bitmessage.org DNS bootstrapping failed.')
try: try:
for item in socket.getaddrinfo('bootstrap8444.bitmessage.org', 80): for item in socket.getaddrinfo('bootstrap8444.bitmessage.org', 80):
print 'Adding', item[4][0], 'to knownNodes based on DNS boostrap method' logger.info('Adding %s to knownNodes based on DNS boostrap method'%item[4][0])
shared.knownNodes[1][shared.Peer(item[4][0], 8444)] = int(time.time()) shared.knownNodes[1][shared.Peer(item[4][0], 8444)] = int(time.time())
except: except:
print 'bootstrap8444.bitmessage.org DNS bootstrapping failed.' logger.info('bootstrap8444.bitmessage.org DNS bootstrapping failed.')
else: else:
print 'DNS bootstrap skipped because SOCKS is used.' logger.info('DNS bootstrap skipped because SOCKS is used.')

View File

@ -27,6 +27,8 @@ import os
import shared import shared
import tr # translate import tr # translate
import logging
logger = logging.getLogger('namecoin')
configSection = "bitmessagesettings" configSection = "bitmessagesettings"
@ -94,7 +96,7 @@ class namecoinConnection (object):
else: else:
return (tr.translateText("MainWindow",'The namecoin query failed (%1)').arg(unicode(exc.error["message"])), None) return (tr.translateText("MainWindow",'The namecoin query failed (%1)').arg(unicode(exc.error["message"])), None)
except Exception as exc: except Exception as exc:
print "Namecoin query exception: %s" % str (exc) logger.info( "Namecoin query exception: %s" % str (exc))
return (tr.translateText("MainWindow",'The namecoin query failed.'), None) return (tr.translateText("MainWindow",'The namecoin query failed.'), None)
try: try:
@ -132,14 +134,14 @@ class namecoinConnection (object):
if ("reply" in res) and res["reply"][:len(prefix)] == prefix: if ("reply" in res) and res["reply"][:len(prefix)] == prefix:
return ('success', tr.translateText("MainWindow",'Success! NMControll is up and running.')) return ('success', tr.translateText("MainWindow",'Success! NMControll is up and running.'))
print "Unexpected nmcontrol reply: %s" % res logger.info("Unexpected nmcontrol reply: %s" % res)
return ('failed', tr.translateText("MainWindow",'Couldn\'t understand NMControl.')) return ('failed', tr.translateText("MainWindow",'Couldn\'t understand NMControl.'))
else: else:
assert False assert False
except Exception as exc: except Exception as exc:
print "Namecoin connection test: %s" % str (exc) logger.info("Namecoin connection test: %s" % str (exc))
return ('failed', "The connection to namecoin failed.") return ('failed', "The connection to namecoin failed.")
# Helper routine that actually performs an JSON RPC call. # Helper routine that actually performs an JSON RPC call.
@ -220,7 +222,7 @@ def lookupNamecoinFolder ():
dataFolder = path.join (os.environ["HOME"], dataFolder = path.join (os.environ["HOME"],
"Library/Application Support/", app) + '/' "Library/Application Support/", app) + '/'
else: else:
print ("Could not find home folder, please report this message" logger.info("Could not find home folder, please report this message"
+ " and your OS X version to the BitMessage Github.") + " and your OS X version to the BitMessage Github.")
sys.exit() sys.exit()
@ -270,7 +272,7 @@ def ensureNamecoinOptions ():
nmc.close () nmc.close ()
except Exception as exc: except Exception as exc:
print "Could not read the Namecoin config file probably because you don't have Namecoin installed. That's ok; we don't really need it. Detailed error message: %s" % str (exc) logger.info("Could not read the Namecoin config file probably because you don't have Namecoin installed. That's ok; we don't really need it. Detailed error message: %s" % str (exc))
# If still nothing found, set empty at least. # If still nothing found, set empty at least.
if (not hasUser): if (not hasUser):

View File

@ -21,6 +21,8 @@ import stat
import threading import threading
import time import time
from os import path, environ from os import path, environ
import logging
logger = logging.getLogger('shared')
# Project imports. # Project imports.
from addresses import * from addresses import *
@ -400,15 +402,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[:readPosition] # Some of the signed data is not encrypted so let's keep it for now. signedData = payload[:readPosition] # Some of the signed data is not encrypted so let's keep it for now.
@ -423,8 +423,7 @@ 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' print 'Pubkey decryption successful'
readPosition = 4 # bypass the behavior bitfield readPosition = 4 # bypass the behavior bitfield
@ -465,8 +464,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')
@ -476,4 +474,4 @@ def decryptAndCheckPubkeyPayload(payload, address):
Peer = collections.namedtuple('Peer', ['host', 'port']) Peer = collections.namedtuple('Peer', ['host', 'port'])
helper_startup.loadConfig() helper_startup.loadConfig()
from debug import logger #~ from debug import logger