Add different log levels

bitcoin/bci.py

@@ -40,7 +40,7 @@ def make_request_blockr(*args):
     while True:
         data = json.loads(make_request(*args))
         if data['status'] == 'error' and data['code'] == 429:
-            log.debug('Blockr service error: ' + data['message'])
+            log.error('Blockr service error: ' + data['message'])
             time.sleep(min(60, 2**counter / 2.))
             counter += 1
             continue

broadcast-tx.py

@@ -26,7 +26,7 @@ def run(self):
             'SELECT DISTINCT counterparty FROM orderbook ORDER BY RANDOM() LIMIT 1;'
         ).fetchone()
         counterparty = crow['counterparty']
-        log.debug('sending tx to ' + counterparty)
+        log.info('sending tx to ' + counterparty)
         self.taker.msgchan.push_tx(counterparty, self.taker.txhex)
         time.sleep(30) #wait for the irc throttle thread to send everything
         #when the tx notify callback is written, use that instead of a hardcoded wait
@@ -71,12 +71,12 @@ def main():
     mcs = [IRCMessageChannel(c) for c in get_irc_mchannels()]
     mcc = MessageChannelCollection(mcs)
     taker = Broadcaster(mcc, options.waittime, txhex)
-    log.debug('starting broadcast-tx')
+    log.info('starting broadcast-tx')
     try:
-        log.debug('starting message channels')
+        log.info('starting message channels')
         mcc.run()
     except:
-        log.debug('CRASHING, DUMPING EVERYTHING')
+        log.warn('CRASHING, DUMPING EVERYTHING')
         debug_dump_object(taker)
         import traceback
         log.debug(traceback.format_exc())

cmttools/sendtomany.py

@@ -38,7 +38,7 @@ def sign(utxo, priv, destaddrs):
     share = int((amt - estfee) / len(destaddrs))
     fee = amt - share*len(destaddrs)
     assert fee >= estfee
-    log.debug("Using fee: " + str(fee))
+    log.info("Using fee: " + str(fee))
     for i, addr in enumerate(destaddrs):
         outs.append({'address': addr, 'value': share})
     unsigned_tx = btc.mktx(ins, outs)
@@ -101,7 +101,7 @@ def main():
     log.debug("Deserialized:")
     log.debug(pformat(btc.deserialize(txsigned)))
     if raw_input('Would you like to push to the network? (y/n):')[0] != 'y':
-        log.debug("You chose not to broadcast the transaction, quitting.")
+        log.info("You chose not to broadcast the transaction, quitting.")
         return
     jm_single().bc_interface.pushtx(txsigned)
 

create-unsigned-tx.py

@@ -56,9 +56,9 @@ def create_tx(self):
                 self.taker.options.makercount, self.taker.chooseOrdersFunc,
                 self.ignored_makers)
             if not self.taker.options.answeryes:
-                log.debug('total cj fee = ' + str(total_cj_fee))
+                log.info('total cj fee = ' + str(total_cj_fee))
                 total_fee_pc = 1.0 * total_cj_fee / cjamount
-                log.debug('total coinjoin fee = ' + str(float('%.3g' % (
+                log.info('total coinjoin fee = ' + str(float('%.3g' % (
                     100.0 * total_fee_pc))) + '%')
                 sendpayment.check_high_fee(total_fee_pc)
                 if raw_input('send with these orders? (y/n):')[0] != 'y':
@@ -69,7 +69,7 @@ def create_tx(self):
             orders, total_cj_fee = self.sendpayment_choose_orders(
                 self.taker.cjamount, self.taker.options.makercount)
             if not orders:
-                log.debug(
+                log.error(
                     'ERROR not enough liquidity in the orderbook, exiting')
                 return
             total_amount = self.taker.cjamount + total_cj_fee + \
@@ -88,11 +88,11 @@ def finishcallback(self, coinjointx):
         if coinjointx.all_responded:
             tx = btc.serialize(coinjointx.latest_tx)
             print 'unsigned tx = \n\n' + tx + '\n'
-            log.debug('created unsigned tx, ending')
+            log.info('created unsigned tx, ending')
             self.taker.msgchan.shutdown()
             return
         self.ignored_makers += coinjointx.nonrespondants
-        log.debug('recreating the tx, ignored_makers=' + str(
+        log.info('recreating the tx, ignored_makers=' + str(
             self.ignored_makers))
         self.create_tx()
 
@@ -119,11 +119,11 @@ def sendpayment_choose_orders(self,
             else:
                 noun = 'additional'
             total_fee_pc = 1.0 * total_cj_fee / cj_amount
-            log.debug(noun + ' coinjoin fee = ' + str(float('%.3g' % (
+            log.info(noun + ' coinjoin fee = ' + str(float('%.3g' % (
                 100.0 * total_fee_pc))) + '%')
             sendpayment.check_high_fee(total_fee_pc)
             if raw_input('send with these orders? (y/n):')[0] != 'y':
-                log.debug('ending')
+                log.info('ending')
                 self.taker.msgchan.shutdown()
                 return None, -1
         return orders, total_cj_fee
@@ -258,10 +258,10 @@ def main():
                              changeaddr, utxo_data, options, chooseOrdersFunc)
     log.debug('starting create-unsigned-tx')
     try:
-        log.debug('starting message channels')
+        log.info('starting message channels')
         mcc.run()
     except:
-        log.debug('CRASHING, DUMPING EVERYTHING')
+        log.warn('CRASHING, DUMPING EVERYTHING')
         debug_dump_object(wallet, ['addr_cache', 'keys', 'wallet_name', 'seed'])
         debug_dump_object(taker)
         import traceback

joinmarket/blockchaininterface.py

@@ -148,7 +148,7 @@ def __init__(self, testnet=False):
         self.last_sync_unspent = 0
 
     def sync_addresses(self, wallet):
-        log.debug('downloading wallet history')
+        log.info('downloading wallet history')
         # sets Wallet internal indexes to be at the next unused address
         for mix_depth in range(wallet.max_mix_depth):
             for forchange in [0, 1]:
@@ -185,15 +185,15 @@ def sync_unspent(self, wallet):
         # dont refresh unspent dict more often than 10 minutes
         rate_limit_time = 10 * 60
         if st - self.last_sync_unspent < rate_limit_time:
-            log.debug(
+            log.info(
                 'blockr sync_unspent() happened too recently (%dsec), skipping'
                 % (st - self.last_sync_unspent))
             return
         wallet.unspent = {}
 
         addrs = wallet.addr_cache.keys()
         if len(addrs) == 0:
-            log.debug('no tx used')
+            log.info('no tx used')
             return
         i = 0
         while i < len(addrs):
@@ -262,7 +262,7 @@ def run(self):
                 while not unconfirmed_txid:
                     time.sleep(unconfirm_poll_period)
                     if int(time.time()) - st > unconfirm_timeout:
-                        log.debug('checking for unconfirmed tx timed out')
+                        log.warn('checking for unconfirmed tx timed out')
                         if self.timeoutfun:
                             self.timeoutfun(False)
                         return
@@ -281,7 +281,7 @@ def run(self):
                             shared_txid = txs
                         else:
                             shared_txid = shared_txid.intersection(txs)
-                    log.debug('sharedtxid = ' + str(shared_txid))
+                    log.info('sharedtxid = ' + str(shared_txid))
                     if len(shared_txid) == 0:
                         continue
                     time.sleep(
@@ -312,7 +312,7 @@ def run(self):
                 while not confirmed_txid:
                     time.sleep(confirm_poll_period)
                     if int(time.time()) - st > confirm_timeout:
-                        log.debug('checking for confirmed tx timed out')
+                        log.warn('checking for confirmed tx timed out')
                         if self.timeoutfun:
                             self.timeoutfun(True)
                         return
@@ -328,7 +328,7 @@ def run(self):
                             shared_txid = txs
                         else:
                             shared_txid = shared_txid.intersection(txs)
-                    log.debug('sharedtxid = ' + str(shared_txid))
+                    log.info('sharedtxid = ' + str(shared_txid))
                     if len(shared_txid) == 0:
                         continue
                     blockr_url = 'https://' + self.blockr_domain
@@ -360,7 +360,7 @@ def pushtx(self, txhex):
                 log.debug(data)
                 return False
         except Exception:
-            log.debug('failed blockr.io pushtx')
+            log.error('failed blockr.io pushtx')
             log.debug(traceback.format_exc())
             return False
         return True
@@ -469,7 +469,7 @@ def do_HEAD(self):
                     tx_out, unconfirmfun, confirmfun, timeoutfun, uc_called = tnf
                     break
             if unconfirmfun is None:
-                log.debug('txid=' + txid + ' not being listened for')
+                log.info('txid=' + txid + ' not being listened for')
             else:
                 # on rare occasions people spend their output without waiting
                 #  for a confirm
@@ -508,10 +508,10 @@ def do_HEAD(self):
         elif self.path.startswith('/alertnotify?'):
             jm_single().core_alert[0] = urllib.unquote(self.path[len(pages[
                 1]):])
-            log.debug('Got an alert!\nMessage=' + jm_single().core_alert[0])
+            log.warn('Got an alert!\nMessage=' + jm_single().core_alert[0])
 
         else:
-            log.debug(
+            log.warn(
                 'ERROR: This is not a handled URL path.  You may want to check your notify URL for typos.')
 
         request = urllib2.Request('http://localhost:' + str(
@@ -548,10 +548,10 @@ def run(self):
             except Exception:
                 continue
             httpd.btcinterface = self.btcinterface
-            log.debug('started bitcoin core notify listening thread, host=' +
+            log.info('started bitcoin core notify listening thread, host=' +
                       str(notify_host) + ' port=' + str(hostport[1]))
             httpd.serve_forever()
-        log.debug('failed to bind for bitcoin core notify listening')
+        log.error('failed to bind for bitcoin core notify listening')
 
 # must run bitcoind with -server
 # -walletnotify="curl -sI --connect-timeout 1 http://localhost:62602/walletnotify?%s"
@@ -588,7 +588,7 @@ def rpc(self, method, args):
         return res
 
     def add_watchonly_addresses(self, addr_list, wallet_name):
-        log.debug('importing ' + str(len(addr_list)) +
+        log.info('importing ' + str(len(addr_list)) +
                   ' addresses into account ' + wallet_name)
         for addr in addr_list:
             self.rpc('importaddress', [addr, wallet_name, False])
@@ -641,7 +641,7 @@ def get_address_usages(self, wallet):
                 continue
             used_address_dict[addr_info[0]] = (addr_info[1], addr_info[2])
 
-        log.debug("Fast sync in progress. Got this many used addresses: " + str(
+        log.info("Fast sync in progress. Got this many used addresses: " + str(
             len(used_address_dict)))
         #Need to have wallet.index point to the last used address
         #and fill addr_cache.
@@ -671,7 +671,7 @@ def sync_addresses(self, wallet):
 
         if isinstance(wallet, BitcoinCoreWallet):
             return
-        log.debug('requesting detailed wallet history')
+        log.info('requesting detailed wallet history from Bitcoin Core client')
         wallet_name = self.get_wallet_name(wallet)
         #TODO It is worth considering making this user configurable:
         addr_req_count = 20
@@ -783,7 +783,7 @@ def sync_addresses(self, wallet):
         if len(too_few_addr_mix_change) > 0:
             indices = [wallet.index[mc[0]][mc[1]]
                        for mc in too_few_addr_mix_change]
-            log.debug('too few addresses in ' + str(too_few_addr_mix_change) +
+            log.info('too few addresses in ' + str(too_few_addr_mix_change) +
                       ' at ' + str(indices))
             for mix_depth, forchange in too_few_addr_mix_change:
                 wallet_addr_list += [
@@ -858,10 +858,10 @@ def pushtx(self, txhex):
         try:
             txid = self.rpc('sendrawtransaction', [txhex])
         except JsonRpcConnectionError as e:
-            log.debug('error pushing = ' + repr(e))
+            log.info('error pushing = ' + repr(e))
             return False
         except JsonRpcError as e:
-            log.debug('error pushing = ' + str(e.code) + " " + str(e.message))
+            log.info('error pushing = ' + str(e.code) + " " + str(e.message))
             return False
         return True
 
@@ -916,7 +916,7 @@ def estimate_fee_per_kb(self, N):
     def pushtx(self, txhex):
         if self.pushtx_failure_prob != 0 and random.random() <\
                 self.pushtx_failure_prob:
-            log.debug('randomly not broadcasting %0.1f%% of the time' %
+            log.info('randomly not broadcasting %0.1f%% of the time' %
                       (self.pushtx_failure_prob * 100))
             return True
 
@@ -949,7 +949,7 @@ def tick_forward_chain(self, n):
             #can happen if the blockchain is shut down
             #automatically at the end of tests; this shouldn't
             #trigger an error
-            log.debug(
+            log.warn(
                 "Failed to generate blocks, looks like the bitcoin daemon \
 	    has been shut down. Ignoring.")
             pass

joinmarket/configure.py

@@ -7,11 +7,11 @@
 import binascii
 import sys
 
-from ConfigParser import SafeConfigParser, NoOptionError
+from ConfigParser import SafeConfigParser, NoOptionError, NoSectionError
 
 import bitcoin as btc
 from joinmarket.jsonrpc import JsonRpc
-from joinmarket.support import get_log, joinmarket_alert, core_alert, debug_silence
+from joinmarket.support import get_log, joinmarket_alert, core_alert, debug_silence, JoinMarketStreamHandler
 
 log = get_log()
 
@@ -69,6 +69,7 @@ def __getitem__(self, key):
 global_singleton.config = SafeConfigParser()
 global_singleton.config_location = 'joinmarket.cfg'
 global_singleton.commit_file_location = 'cmttools/commitments.json'
+global_singleton.console_log_level = 'INFO'
 global_singleton.wait_for_commitments = 0
 
 def jm_single():
@@ -108,6 +109,12 @@ def jm_single():
 #usessl = true, false
 #socks5 = true, true
 
+[LOGGING]
+# Set the log level for the output to the terminal/console
+# Possible choices: DEBUG / INFO / WARNING / ERROR
+# Log level for the files in the logs-folder will always be DEBUG
+console_log_level = INFO
+
 [TIMEOUT]
 maker_timeout_sec = 30
 unconfirm_timeout_sec = 90
@@ -250,7 +257,7 @@ def donation_address(reusable_donation_pubkey=None):
     sender_pubkey = btc.add_pubkeys([reusable_donation_pubkey,
                                      btc.privtopub(c+'01', True)], True)
     sender_address = btc.pubtoaddr(sender_pubkey, get_p2pk_vbyte())
-    log.debug('sending coins to ' + sender_address)
+    log.info('sending coins to ' + sender_address)
     return sender_address, sign_k
 
 def check_utxo_blacklist(commitment, persist=False):
@@ -282,11 +289,27 @@ def check_utxo_blacklist(commitment, persist=False):
         #usage).
     return True
 
+def initialize_console_logger(log_level):
+    logFormatter = logging.Formatter(
+        "%(asctime)s [%(threadName)-12.12s] [%(levelname)-5.5s]  %(message)s")
+    consoleHandler = JoinMarketStreamHandler(stream=sys.stdout)
+    consoleHandler.setFormatter(logFormatter)
+    consoleHandler.setLevel(log_level)
+    log.addHandler(consoleHandler)
+    log.info('hello joinmarket')
 
 def load_program_config():
+    # set the console log level and initialize console logger
+    try:
+        global_singleton.console_log_level = global_singleton.config.get(
+            "LOGGING", "console_log_level")
+    except (NoSectionError, NoOptionError):
+        log.info("No log level set, using default level INFO ")
+    initialize_console_logger(global_singleton.console_log_level)
+
     #set the location of joinmarket
     jmkt_dir = os.path.dirname(os.path.dirname(os.path.realpath(__file__)))
-    log.debug("Joinmarket directory is: " + str(jmkt_dir))
+    log.info("Joinmarket directory is: " + str(jmkt_dir))
     global_singleton.config.readfp(io.BytesIO(defaultconfig))
     jmkt_config_location = os.path.join(jmkt_dir, global_singleton.config_location)
     loadedFiles = global_singleton.config.read([jmkt_config_location])
@@ -312,7 +335,7 @@ def load_program_config():
         global_singleton.maker_timeout_sec = global_singleton.config.getint(
             'TIMEOUT', 'maker_timeout_sec')
     except NoOptionError:
-        log.debug('TIMEOUT/maker_timeout_sec not found in .cfg file, '
+        log.info('TIMEOUT/maker_timeout_sec not found in .cfg file, '
                   'using default value')
 
     # configure the interface to the blockchain on startup
@@ -323,7 +346,7 @@ def load_program_config():
         global_singleton.commit_file_location = global_singleton.config.get(
             "POLICY", "commit_file_location")
     except NoOptionError:
-            log.debug("No commitment file location in config, using default "
+            log.info("No commitment file location in config, using default "
                       "location cmttools/commitments.json")
     btc.set_commitment_file(os.path.join(jmkt_dir,
                                          global_singleton.commit_file_location))