Add logging system #8

Merged
nathanwoodburn merged 4 commits from feat/logging into main 2025-09-11 15:19:26 +10:00
5 changed files with 151 additions and 92 deletions

1
.gitignore vendored
View File

@@ -18,5 +18,6 @@ build/
dist/
hsd/
hsd_data/
logs/
hsd.lock
hsdconfig.json

Binary file not shown.

View File

@@ -13,6 +13,8 @@ import signal
import sys
import threading
import sqlite3
import logging
logger = logging.getLogger("firewallet")
dotenv.load_dotenv()
@@ -270,7 +272,7 @@ def getCachedDomains():
domain_cache[row['name']] = json.loads(row['info'])
domain_cache[row['name']]['last_updated'] = row['last_updated']
except json.JSONDecodeError:
print(f"Error parsing cached data for domain {row['name']}")
logger.error(f"Error parsing cached data for domain {row['name']}")
conn.close()
return domain_cache
@@ -310,7 +312,7 @@ def update_domain_cache(domain_names: list):
domain_info = getDomain(domain_name)
if 'error' in domain_info or not domain_info.get('info'):
print(f"Failed to get info for domain {domain_name}: {domain_info.get('error', 'Unknown error')}", flush=True)
logger.error(f"Failed to get info for domain {domain_name}: {domain_info.get('error', 'Unknown error')}")
continue
# Update or insert into database
@@ -322,9 +324,9 @@ def update_domain_cache(domain_names: list):
(domain_name, serialized_info, now)
)
print(f"Updated cache for domain {domain_name}")
logger.info(f"Updated cache for domain {domain_name}")
except Exception as e:
print(f"Error updating cache for domain {domain_name}: {str(e)}")
logger.error(f"Error updating cache for domain {domain_name}: {str(e)}", exc_info=True)
finally:
# Always remove from active set, even if there was an error
with DOMAIN_UPDATE_LOCK:
@@ -336,20 +338,21 @@ def update_domain_cache(domain_names: list):
conn.close()
except Exception as e:
print(f"Error updating domain cache: {str(e)}", flush=True)
logger.error(f"Error updating domain cache: {str(e)}", exc_info=True)
# Make sure to clean up the active set on any exception
with DOMAIN_UPDATE_LOCK:
for domain in domains_to_update:
if domain in ACTIVE_DOMAIN_UPDATES:
ACTIVE_DOMAIN_UPDATES.remove(domain)
print("Updated cache for domains")
logger.info("Updated cache for domains")
def getBalance(account: str):
# Get the total balance
info = hsw.getBalance('default', account)
if 'error' in info:
logger.error(f"Error getting balance for account {account}: {info['error']}")
return {'available': 0, 'total': 0}
total = info['confirmed']
@@ -359,6 +362,7 @@ def getBalance(account: str):
# Convert to HNS
total = total / 1000000
available = available / 1000000
logger.debug(f"Initial balance for account {account}: total={total}, available={available}, locked={locked}")
domains = getDomains(account)
domainValue = 0
@@ -402,6 +406,7 @@ def getBalance(account: str):
if domain_info.get('info', {}).get('state', "") == "CLOSED":
domainValue += domain_info.get('info', {}).get('value', 0)
except json.JSONDecodeError:
logger.warning(f"Error parsing cached data for domain {domain_name}")
# Only add for update if not already being updated
with DOMAIN_UPDATE_LOCK:
if domain_name not in ACTIVE_DOMAIN_UPDATES:
@@ -424,6 +429,7 @@ def getBalance(account: str):
total = total - (domainValue/1000000)
locked = locked - (domainValue/1000000)
logger.debug(f"Adjusted balance for account {account}: total={total}, available={available}, locked={locked}")
# Only keep 2 decimal places
total = round(total, 2)
@@ -594,14 +600,14 @@ def getTransactions(account, page=1, limit=100):
return []
if response.status_code != 200:
print(response.text)
logger.error(f"Error fetching transactions: {response.status_code} - {response.text}")
return []
data = response.json()
# Refresh the cache if the next page is different
nextPage = getPageTXCache(account, page, limit)
if nextPage is not None and nextPage != data[-1]['hash']:
print(f'Refreshing page {page}')
logger.info(f'Refreshing tx page {page}')
pushPageTXCache(account, page, data[-1]['hash'], limit)
return data
@@ -788,11 +794,12 @@ def getAddressFromCoin(coinhash: str, coinindex = 0):
# Get the address from the hash
response = requests.get(get_node_api_url(f"coin/{coinhash}/{coinindex}"))
if response.status_code != 200:
print("Error getting address from coin")
logger.error("Error getting address from coin")
return "No Owner"
data = response.json()
if 'address' not in data:
print(json.dumps(data, indent=4))
logger.error("Error getting address from coin")
logger.error(json.dumps(data, indent=4))
return "No Owner"
return data['address']
@@ -998,7 +1005,7 @@ def getPendingRedeems(account, password):
else:
pending.append(name['result'])
except Exception as e:
print(f"Failed to parse redeems: {str(e)}")
logger.error(f"Failed to parse redeems: {str(e)}", exc_info=True)
return pending
@@ -1042,7 +1049,7 @@ def getPendingFinalizes(account, password):
else:
pending.append(name['result'])
except Exception as e:
print(f"Failed to parse finalizes: {str(e)}")
logger.error(f"Failed to parse finalizes: {str(e)}", exc_info=True)
return pending
@@ -1052,9 +1059,8 @@ def getRevealTX(reveal):
index = prevout['index']
tx = hsd.getTxByHash(hash)
if 'inputs' not in tx:
print(f'Something is up with this tx: {hash}')
print(tx)
print('---')
logger.error(f'Something is up with this tx: {hash}')
logger.error(tx)
# No idea what happened here
# Check if registered?
return None
@@ -1498,10 +1504,10 @@ def getMempoolBids():
for txid in mempoolTxs:
tx = hsd.getTxByHash(txid)
if 'error' in tx and tx['error'] is not None:
print(f"Error getting tx {txid}: {tx['error']}")
logger.error(f"Error getting tx {txid}: {tx['error']}")
continue
if 'outputs' not in tx:
print(f"Error getting outputs for tx {txid}")
logger.error(f"Error getting outputs for tx {txid}")
continue
for output in tx['outputs']:
if output['covenant']['action'] not in ["BID", "REVEAL"]:
@@ -1679,7 +1685,7 @@ def verifyMessageWithName(domain, signature, message):
return response['result']
return False
except Exception as e:
print(f"Error verifying message with name: {str(e)}")
logger.error(f"Error verifying message with name: {str(e)}", exc_info=True)
return False
@@ -1690,7 +1696,7 @@ def verifyMessage(address, signature, message):
return response['result']
return False
except Exception as e:
print(f"Error verifying message: {str(e)}")
logger.error(f"Error verifying message: {str(e)}", exc_info=True)
return False
# endregion
@@ -1835,7 +1841,7 @@ def hsdInit():
prerequisites = checkPreRequisites()
minNodeVersion = HSD_CONFIG.get("minNodeVersion", 20)
minNPMVersion = HSD_CONFIG.get("minNPMVersion", 8)
minNPMVersion = HSD_CONFIG.get("minNpmVersion", 8)
PREREQ_MESSAGES = {
"node": f"Install Node.js from https://nodejs.org/en/download (Version >= {minNodeVersion})",
"npm": f"Install npm (version >= {minNPMVersion}) - usually comes with Node.js",
@@ -1844,18 +1850,21 @@ def hsdInit():
# Check if all prerequisites are met (except hsd)
if not all(prerequisites[key] for key in prerequisites if key != "hsd"):
print("HSD Internal Node prerequisites not met:")
print("HSD Internal Node prerequisites not met:",flush=True)
logger.error("HSD Internal Node prerequisites not met:")
for key, value in prerequisites.items():
if not value:
print(f" - {key} is missing or does not meet the version requirement.",flush=True)
logger.error(f" - {key} is missing or does not meet the version requirement.")
if key in PREREQ_MESSAGES:
print(PREREQ_MESSAGES[key],flush=True)
logger.error(PREREQ_MESSAGES[key])
exit(1)
return
# Check if hsd is installed
if not prerequisites["hsd"]:
print("HSD not found, installing...")
logger.info("HSD not found, installing...")
# If hsd folder exists, remove it
if os.path.exists("hsd"):
os.rmdir("hsd")
@@ -1863,19 +1872,22 @@ def hsdInit():
# Clone hsd repo
gitClone = subprocess.run(["git", "clone", "--depth", "1", "--branch", HSD_CONFIG.get("version", "latest"), "https://github.com/handshake-org/hsd.git", "hsd"], capture_output=True, text=True)
if gitClone.returncode != 0:
print("Failed to clone hsd repository:")
print(gitClone.stderr)
print("Failed to clone hsd repository:",flush=True)
logger.error("Failed to clone hsd repository:")
print(gitClone.stderr,flush=True)
logger.error(gitClone.stderr)
exit(1)
print("Cloned hsd repository.")
logger.info("Cloned hsd repository.")
logger.info("Installing hsd dependencies...")
# Install hsd dependencies
print("Installing hsd dependencies...")
npmInstall = subprocess.run(["npm", "install"], cwd="hsd", capture_output=True, text=True)
if npmInstall.returncode != 0:
print("Failed to install hsd dependencies:")
print(npmInstall.stderr)
print("Failed to install hsd dependencies:",flush=True)
logger.error("Failed to install hsd dependencies:")
print(npmInstall.stderr,flush=True)
logger.error(npmInstall.stderr)
exit(1)
print("Installed hsd dependencies.")
logger.info("Installed hsd dependencies.")
def hsdStart():
global HSD_PROCESS
global SPV_MODE
@@ -1886,12 +1898,12 @@ def hsdStart():
if os.path.exists("hsd.lock"):
lock_time = os.path.getmtime("hsd.lock")
if time.time() - lock_time < 30:
print("HSD was started recently, skipping start.")
logger.info("HSD was started recently, skipping start.")
return
else:
os.remove("hsd.lock")
print("Starting HSD...")
logger.info("Starting HSD...")
# Create a lock file
with open("hsd.lock", "w") as f:
f.write(str(time.time()))
@@ -1935,7 +1947,7 @@ def hsdStart():
text=True
)
print(f"HSD started with PID {HSD_PROCESS.pid}")
logger.info(f"HSD started with PID {HSD_PROCESS.pid}")
atexit.register(hsdStop)
@@ -1944,7 +1956,7 @@ def hsdStart():
signal.signal(signal.SIGINT, lambda s, f: (hsdStop(), sys.exit(0)))
signal.signal(signal.SIGTERM, lambda s, f: (hsdStop(), sys.exit(0)))
except Exception as e:
print(f"Failed to set signal handlers: {str(e)}")
logger.error(f"Failed to set signal handlers: {str(e)}", exc_info=True)
pass
@@ -1954,16 +1966,16 @@ def hsdStop():
if HSD_PROCESS is None:
return
print("Stopping HSD...")
logger.info("Stopping HSD...")
# Send SIGINT (like Ctrl+C)
HSD_PROCESS.send_signal(signal.SIGINT)
try:
HSD_PROCESS.wait(timeout=10) # wait for graceful exit
print("HSD shut down cleanly.")
logger.info("HSD shut down cleanly.")
except subprocess.TimeoutExpired:
print("HSD did not exit yet, is it alright???")
logger.warning("HSD did not exit yet, is it alright???")
# Clean up lock file
if os.path.exists("hsd.lock"):

138
main.py
View File

@@ -17,6 +17,8 @@ import plugin as plugins_module
import gitinfo
import datetime
import time
import logging
from logging.handlers import RotatingFileHandler
dotenv.load_dotenv()
@@ -32,29 +34,22 @@ revokeCheck = random.randint(100000,999999)
THEME = os.getenv("THEME", "black")
def blocks_to_time(blocks: int) -> str:
"""
Convert blocks to time in a human-readable format.
Blocks are mined approximately every 10 minutes.
"""
if blocks < 0:
return "Invalid time"
# Setup logging
if not os.path.exists('logs'):
os.makedirs('logs')
log_file = 'logs/firewallet.log'
handler = RotatingFileHandler(log_file, maxBytes=1024*1024, backupCount=3)
formatter = logging.Formatter('[%(asctime)s] %(levelname)s in %(module)s: %(message)s')
handler.setFormatter(formatter)
logger = logging.getLogger()
logger.setLevel(logging.WARNING)
if blocks < 6:
return f"{blocks * 10} mins"
elif blocks < 144:
hours = blocks // 6
minutes = (blocks % 6) * 10
if minutes == 0:
return f"{hours} hrs"
# Disable werkzeug logging
logging.getLogger('werkzeug').setLevel(logging.INFO)
logging.getLogger("urllib3").setLevel(logging.ERROR)
logging.getLogger("requests").setLevel(logging.ERROR)
return f"{hours} hrs {minutes} mins"
else:
days = blocks // 144
hours = (blocks % 144) // 6
if hours == 0:
return f"{days} days"
return f"{days} days {hours} hrs"
logger.addHandler(handler)
@app.route('/')
def index():
@@ -76,18 +71,10 @@ def index():
if not os.path.exists(".git"):
return render_template("index.html", account=account, plugins=plugins)
info = gitinfo.get_git_info()
if info is None:
return render_template("index.html", account=account, plugins=plugins)
branch = info['refs']
commit = info['commit']
if commit != latestVersion(branch):
print("New version available",flush=True)
plugins += render_template('components/dashboard-alert.html', name='Update', output='A new version of FireWallet is available')
alerts = get_alerts(account)
for alert in alerts:
output_html = alert['output']
if 'id' in alert:
# Add a dismiss button
output_html += f"&nbsp<a href='/dismiss/{alert['id']}' class='btn btn-secondary btn-sm' style='margin:none;'>Dismiss</a>"
plugins += render_template('components/dashboard-alert.html', name=alert['name'], output=output_html)
@@ -613,7 +600,7 @@ def finalize(domain: str):
domain = domain.lower()
response = account_module.finalize(request.cookies.get("account"),domain)
if response['error'] is not None:
print(response)
logger.error(f"Error finalizing transfer for {domain}: {response['error']}")
return redirect("/manage/" + domain + "?error=" + response['error']['message'])
return redirect("/success?tx=" + response['result']['hash'])
@@ -632,7 +619,7 @@ def cancelTransfer(domain: str):
response = account_module.cancelTransfer(request.cookies.get("account"),domain)
if 'error' in response:
if response['error'] is not None:
print(response)
logger.error(f"Error canceling transfer for {domain}: {response['error']}")
return redirect("/manage/" + domain + "?error=" + response['error']['message'])
return redirect("/success?tx=" + response['result']['hash'])
@@ -688,7 +675,7 @@ def revokeConfirm(domain: str):
response = account_module.revoke(request.cookies.get("account"),domain)
if 'error' in response:
if response['error'] is not None:
print(response)
logger.error(f"Error revoking {domain}: {response['error']}")
return redirect("/manage/" + domain + "?error=" + response['error']['message'])
return redirect(f"/success?tx={response['hash']}")
@@ -794,7 +781,7 @@ def editSave(domain: str):
dns = urllib.parse.unquote(dns)
response = account_module.setDNS(request.cookies.get("account"),domain,dns)
if 'error' in response:
print(response)
logger.error(f"Error setting DNS for {domain}: {response['error']}")
return redirect(f"/manage/{domain}/edit?dns={raw_dns}&error={response['error']}")
return redirect(f"/success?tx={response['hash']}")
@@ -892,7 +879,6 @@ def transferConfirm(domain):
return redirect(f"/success?tx={response['hash']}")
@app.route('/auction/<domain>')
def auction(domain):
# Check if the user is logged in
@@ -941,13 +927,11 @@ def auction(domain):
if state == 'CLOSED':
if not domainInfo['info']['registered']:
if account_module.isOwnDomain(account,domain):
print("Waiting to be registered")
state = 'PENDING REGISTER'
next = "Pending Register"
next_action = f'<a href="/auction/{domain}/register">Register Domain</a>'
else:
print("Not registered")
state = 'AVAILABLE'
next = "Available Now"
next_action = f'<a href="/auction/{domain}/open">Open Auction</a>'
@@ -1249,7 +1233,27 @@ def settings_action(action):
title="API Information",
content=content)
if action == "logs":
if not os.path.exists(log_file):
return jsonify({"error": "Log file not found"}), 404
try:
with open(log_file, 'rb') as f:
response = requests.put(f"https://upload.woodburn.au/{os.path.basename(log_file)}", data=f)
if response.status_code == 200 or response.status_code == 201:
url = response.text.strip().split('\n')[-1]
logger.info(f"Log upload successful: {url}")
return redirect(url)
else:
logger.error(f"Failed to upload log: {response.status_code} {response.text}")
return redirect(f"/settings?error=Failed to upload log: {response.status_code}")
except Exception as e:
logger.error(f"Exception during log upload: {e}", exc_info=True)
return redirect("/settings?error=An error occurred during log upload")
logger.warning(f"Unknown settings action: {action}")
return redirect("/settings?error=Invalid action")
@app.route('/settings/upload', methods=['POST'])
@@ -1492,7 +1496,7 @@ def plugin(ptype,plugin):
plugin = f"{ptype}/{plugin}"
if not plugins_module.pluginExists(plugin):
print(f"Plugin {plugin} not found")
logger.warning(f"Plugin not found: {plugin}")
return redirect("/plugins")
data = plugins_module.getPluginData(plugin)
@@ -1627,13 +1631,11 @@ def api_hsd(function):
if state == 'CLOSED':
if not domainInfo['info']['registered']:
if account_module.isOwnDomain(account,domain):
print("Waiting to be registered")
state = 'PENDING REGISTER'
next = "Pending Register"
next_action = f'<a href="/auction/{domain}/register">Register Domain</a>'
else:
print("Not registered")
state = 'AVAILABLE'
next = "Available Now"
next_action = f'<a href="/auction/{domain}/open">Open Auction</a>'
@@ -1865,6 +1867,29 @@ def api_status():
#endregion
#region Helper functions
def blocks_to_time(blocks: int) -> str:
"""
Convert blocks to time in a human-readable format.
Blocks are mined approximately every 10 minutes.
"""
if blocks < 0:
return "Invalid time"
if blocks < 6:
return f"{blocks * 10} mins"
elif blocks < 144:
hours = blocks // 6
minutes = (blocks % 6) * 10
if minutes == 0:
return f"{hours} hrs"
return f"{hours} hrs {minutes} mins"
else:
days = blocks // 144
hours = (blocks % 144) // 6
if hours == 0:
return f"{days} days"
return f"{days} days {hours} hrs"
def renderDomain(name: str) -> str:
"""
@@ -1888,6 +1913,20 @@ def get_alerts(account:str) -> list:
alerts = []
info = gitinfo.get_git_info()
if info is not None:
branch = info['refs']
commit = info['commit']
if commit != latestVersion(branch):
logger.info("New version available")
alerts.append({
"name": "Update Available",
"output": f"A new version of FireWallet is available. <a href='https://git.woodburn.au/nathanwoodburn/firewalletbrowser/compare/{commit}...{branch}' target='_blank'>Changelog</a>"
})
# Check if the node is connected
if not account_module.hsdConnected():
alerts.append({
@@ -1903,7 +1942,6 @@ def get_alerts(account:str) -> list:
"name": "Wallet",
"output": f"The wallet is not synced ({wallet_status}). Please wait for it to sync."
})
print(account)
# Try to read from notifications sqlite database
if os.path.exists("user_data/notifications.db"):
try:
@@ -1919,7 +1957,7 @@ def get_alerts(account:str) -> list:
})
conn.close()
except Exception as e:
print(f"Error reading notifications: {e}",flush=True)
logger.error(f"Error reading notifications: {e}")
pass
return alerts
@@ -1946,7 +1984,7 @@ def add_alert(name:str,output:str,account:str="all"):
conn.commit()
conn.close()
except Exception as e:
print(f"Error adding notification: {e}",flush=True)
logger.error(f"Error adding notification: {e}")
pass
def dismiss_alert(alert_id:int,account:str="all"):
@@ -1966,7 +2004,7 @@ def dismiss_alert(alert_id:int,account:str="all"):
conn.commit()
conn.close()
except Exception as e:
print(f"Error dismissing notification: {e}",flush=True)
logger.error(f"Error dismissing notification: {e}")
pass
@app.route('/dismiss/<int:alert_id>')
@@ -2020,8 +2058,8 @@ def try_path(path):
@app.errorhandler(404)
def page_not_found(e):
logger.warning(f"404 Not Found: {request.path}")
account = account_module.check_account(request.cookies.get("account"))
return render_template('404.html',account=account), 404
#endregion
@@ -2041,11 +2079,19 @@ if __name__ == '__main__':
port = int(sys.argv[port_index])
except ValueError:
pass
print(f"Starting FireWallet on http://{host}:{port}",flush=True)
# Check to see if --debug is in the command line arguments
if "--debug" in sys.argv:
console_handler = logging.StreamHandler(sys.stdout)
# Use a simple format for console
console_formatter = logging.Formatter('%(message)s')
console_handler.setFormatter(console_formatter)
console_handler.setLevel(logging.WARNING)
logger.addHandler(console_handler)
logger.setLevel(logging.DEBUG)
app.run(debug=True, host=host, port=port)
else:
app.run(host=host, port=port)
def tests():

View File

@@ -133,7 +133,7 @@
<div class="card-body">
<h4 class="card-title">About</h4>
<h6 class="text-muted mb-2 card-subtitle">FireWallet is a UI to allow easy connection with HSD created by <a href="https://nathan.woodburn.au" target="_blank">Nathan.Woodburn/</a> and freely available. Please contact him <a href="https://l.woodburn.au/contact" target="_blank">here</a> if you would like to request any features or report any bugs.<br>FireWallet version: <code>{{version}}</code></h6>
<div class="text-center"><a href="https://github.com/nathanwoodburn/firewalletbrowser" style="margin: 15px;color: var(--bs-emphasis-color);text-decoration:none;" target="_blank"><i class="icon ion-social-github" style="color: var(--bs-emphasis-color);"></i>&nbsp;Github</a><a href="https://firewallet.au" style="margin: 15px;color: var(--bs-emphasis-color);text-decoration:none;" target="_blank"><i class="icon ion-ios-information" style="color: var(--bs-emphasis-color);"></i>&nbsp;Website</a><a href="https://l.woodburn.au/donate" style="margin: 15px;color: var(--bs-emphasis-color);text-decoration:none;" target="_blank"><i class="icon ion-social-usd" style="color: var(--bs-emphasis-color);"></i>&nbsp;Donate to support development</a></div>
<div class="text-center"><a href="https://github.com/nathanwoodburn/firewalletbrowser" style="margin: 15px;color: var(--bs-emphasis-color);text-decoration:none;" target="_blank"><i class="icon ion-social-github" style="color: var(--bs-emphasis-color);"></i>&nbsp;Github</a><a href="https://firewallet.au" style="margin: 15px;color: var(--bs-emphasis-color);text-decoration:none;" target="_blank"><i class="icon ion-ios-information" style="color: var(--bs-emphasis-color);"></i>&nbsp;Website</a><a href="https://l.woodburn.au/donate" style="margin: 15px;color: var(--bs-emphasis-color);text-decoration:none;" target="_blank"><i class="icon ion-social-usd" style="color: var(--bs-emphasis-color);"></i>&nbsp;Donate to support development</a><a href="/settings/logs" style="margin: 15px;color: var(--bs-emphasis-color);text-decoration:none;" target="_blank"><i class="icon ion-help" style="color: var(--bs-emphasis-color);"></i>&nbsp;Upload logs for debugging</a></div>
</div>
</div>
</div>