From 4748df61fe65ff84e5fa249d47cb7ed608d98e31 Mon Sep 17 00:00:00 2001 From: Kim Neunert Date: Mon, 27 Sep 2021 14:09:43 +0200 Subject: [PATCH] Feature: Better Error-management, logging for the APP and Macos builds improvements (#1405) * tiny changes * more documentation * added upload-instructions * better traceability of startup * logs for signing results * bugfix for sign_results * winston logging * error-management and check for specterd-exit * adding locale * distinguish logging properly * don't throw that error unfortunately * fix accidental change * increase memory + cpu for cirrus * increase to 8CPUs but only for cirrus * decrease resources again --- .cirrus.yml | 2 + pyinstaller/build-osx.sh | 47 +++++++- pyinstaller/electron/error_logs.html | 22 ++++ pyinstaller/electron/helpers.js | 11 +- pyinstaller/electron/main.js | 141 +++++++++++++++++++--- pyinstaller/electron/package.json | 4 +- pyinstaller/specterd.py | 27 +---- src/cryptoadvance/specter/cli/__init__.py | 8 +- 8 files changed, 209 insertions(+), 53 deletions(-) create mode 100644 pyinstaller/electron/error_logs.html diff --git a/.cirrus.yml b/.cirrus.yml index 57ddb3751..6bd87299e 100644 --- a/.cirrus.yml +++ b/.cirrus.yml @@ -65,6 +65,8 @@ test_task: cypress_test_task: container: image: registry.gitlab.com/cryptoadvance/specter-desktop/cypress-python:latest + cpu: 6 + memory: 6G pre_prep_script: - apt-get update && apt-get install -y --no-install-recommends python3-dev python3-pip python3-virtualenv bc # The stupid old debian-package is not installing a proper binary but just the python-package diff --git a/pyinstaller/build-osx.sh b/pyinstaller/build-osx.sh index 7336b333d..334a4fc6f 100755 --- a/pyinstaller/build-osx.sh +++ b/pyinstaller/build-osx.sh @@ -1,4 +1,34 @@ #!/usr/bin/env bash +set -exo +# possible prerequisites +# brew install gmp # to prevent module 'embit.util' has no attribute 'ctypes_secp256k1' +# npm install --global create-dmg + +# Download into torbrowser: +# wget -P torbrowser https://archive.torproject.org/tor-package-archive/torbrowser/10.0.15/TorBrowser-10.0.15-osx64_en-US.dmg + +# Currently, only MacOS Catalina is supported to build the dmg-file +# Therefore we expect xcode 12.1 (according to google) +# After installation of xcode: sudo xcode-select -s /Applications/Xcode.app/Contents/Developer +# otherwise you get xcrun: error: unable to find utility "altool", not a developer tool or in PATH + +# Fill the keychain with your password like this +# xcrun altool --store-password-in-keychain-item AC_PASSWORD -u '' -p apassword + +# You need to participate in the Apple-Developer Program (Eur 99,- yearly fee) +# https://developer.apple.com/programs/enroll/ + +# Then you need to create a cert which you need to store in the keychain +# https://developer.apple.com/account/resources/certificates/list + +# If you have the common issue "errSecInternalComponent" while signing the code: +# https://medium.com/@ceyhunkeklik/how-to-fix-ios-application-code-signing-error-4818bd331327 + +# create-dmg issue? Note that there are 2 create-dmg scripts out there. We use: +# https://github.com/sindresorhus/create-dmg + +# Example-call: +# ./build-osx.sh v1.6.1-pre1 "Kim Neunert (FWV59JHV83)" "kneunert@gmail.com" "make-hash" echo $1 > version.txt pip3 install -r requirements.txt --require-hashes @@ -7,7 +37,7 @@ cd .. python3 setup.py install cd pyinstaller rm -rf build/ dist/ release/ electron/release/ electron/dist -rm *.dmg +rm *.dmg || true pyinstaller specterd.spec cd electron npm ci @@ -30,8 +60,14 @@ if [[ "$2" != '' ]] then echo 'Attempting to code sign...' ditto -c -k --keepParent "dist/mac/Specter.app" dist/Specter.zip - xcrun altool --notarize-app -t osx -f dist/Specter.zip --primary-bundle-id "solutions.specter.desktop" -u "$3" --password "@keychain:AC_PASSWORD" + output_json=$(xcrun altool --notarize-app -t osx -f dist/Specter.zip --primary-bundle-id "solutions.specter.desktop" -u "$3" --password "@keychain:AC_PASSWORD" --output-format json) + echo "JSON-Output:" + requestuuid=$(echo $output_json | jq -r '."notarization-upload".RequestUUID') sleep 180 + sign_result_json=$(xcrun altool --notarization-info $requestuuid -u "$3" --password "@keychain:AC_PASSWORD" --output-format json) + mkdir -p signing_logs + timestamp=$(date +"%Y%m%d-%H%M") + echo $sign_result_json | jq . > ./signing_logs/${timestamp}_${requestuuid}.log xcrun stapler staple "dist/mac/Specter.app" fi @@ -48,3 +84,10 @@ cd .. sha256sum ./release/specterd-$1-osx.zip sha256sum ./release/SpecterDesktop-$1.dmg + +# "In order to upload these artifacts to github, do:" +# export CI_PROJECT_ROOT_NAMESPACE=cryptoadvance +# export CI_COMMIT_TAG=$1 +# export GH_BIN_UPLOAD_PW=YourSecretHere +# python ./utils/github.py upload ./release/specterd-$1-osx.zip +# python ./utils/github.py upload ./release/SpecterDesktop-$1.dmg \ No newline at end of file diff --git a/pyinstaller/electron/error_logs.html b/pyinstaller/electron/error_logs.html new file mode 100644 index 000000000..09577c439 --- /dev/null +++ b/pyinstaller/electron/error_logs.html @@ -0,0 +1,22 @@ + + + +
+ This window show you the Logs of specter. It might give you hints on why specter is not coming up properly. +
+
+ +
+ + + \ No newline at end of file diff --git a/pyinstaller/electron/helpers.js b/pyinstaller/electron/helpers.js index df744927a..3d1266a34 100644 --- a/pyinstaller/electron/helpers.js +++ b/pyinstaller/electron/helpers.js @@ -14,6 +14,7 @@ try { } const appSettingsPath = path.resolve(require('os').homedir(), '.specter/app_settings.json') const specterdDirPath = path.resolve(require('os').homedir(), '.specter/specterd-binaries') +const specterAppLogPath = path.resolve(require('os').homedir(), '.specter/specterApp.log') function getFileHash(filename, callback) { let shasum = crypto.createHash('sha256') @@ -59,11 +60,17 @@ function getAppSettings() { } return appSettings - } +} + +function getSpecterAppLogs() { + return fs.readFileSync(specterAppLogPath, 'utf8') +} module.exports = { getFileHash: getFileHash, appSettingsPath: appSettingsPath, getAppSettings: getAppSettings, - specterdDirPath: specterdDirPath + specterdDirPath: specterdDirPath, + getSpecterAppLogs: getSpecterAppLogs, + specterAppLogPath: specterAppLogPath } diff --git a/pyinstaller/electron/main.js b/pyinstaller/electron/main.js index 9cd25e857..0217b87ad 100644 --- a/pyinstaller/electron/main.js +++ b/pyinstaller/electron/main.js @@ -1,5 +1,6 @@ // Modules to control application life and create native browser window const { app, BrowserWindow, Menu, Tray, screen, shell, dialog, ipcMain } = require('electron') + const path = require('path') const fs = require('fs') const request = require('request') @@ -11,11 +12,37 @@ const getFileHash = helpers.getFileHash const getAppSettings = helpers.getAppSettings const appSettingsPath = helpers.appSettingsPath const specterdDirPath = helpers.specterdDirPath + +// Logging +const {transports, format, createLogger } = require('winston') +const combinedLog = new transports.File({ filename: helpers.specterAppLogPath }); +const winstonOptions = { + exitOnError: false, + format: format.combine( + format.timestamp(), + // format.timestamp({format:'MM/DD/YYYY hh:mm:ss.SSS'}), + format.json(), + format.printf(info => { + return `${info.timestamp} [${info.level}] : ${info.message}`; + }) + ), + transports: [ + new transports.Console({json:false}), + combinedLog + ], + exceptionHandlers: [ + combinedLog + ] +} +const logger = createLogger(winstonOptions) + + let appSettings = getAppSettings() let dimensions = { widIth: 1500, height: 1000 }; const contextMenu = require('electron-context-menu'); +const { options } = require('request') contextMenu({ menu: (actions) => [ @@ -40,8 +67,8 @@ contextMenu({ const download = (uri, filename, callback) => { request.head(uri, (err, res, body) => { - console.log('content-type:', res.headers['content-type']) - console.log('content-length:', res.headers['content-length']) + logger.info('content-type:', res.headers['content-type']) + logger.info('content-length:', res.headers['content-length']) if (res.statusCode != 404) { request(uri).pipe(fs.createWriteStream(filename)).on('close', callback) } else { @@ -102,6 +129,7 @@ function createWindow (specterURL) { // Some APIs can only be used after this event occurs. app.whenReady().then(() => { // Start the tray icon + logger.info("Framework Ready! Starting tray Icon ..."); tray = new Tray(path.join(__dirname, 'assets/icon.png')) trayMenu = [ { label: 'Launching Specter...', enabled: false }, @@ -115,6 +143,7 @@ app.whenReady().then(() => { dimensions = screen.getPrimaryDisplay().size; // create a new `splash`-Window + logger.info("Framework Ready! Initializing Main-Window, popultaing Menu ..."); initMainWindow() setMainMenu(); @@ -122,11 +151,13 @@ app.whenReady().then(() => { mainWindow.loadURL(`file://${__dirname}/splash.html`); if (!fs.existsSync(specterdDirPath)){ - fs.mkdirSync(specterdDirPath, { recursive: true }); + logger.info("Creating specterd-binaries folder"); + fs.mkdirSync(specterdDirPath, { recursive: true }); } let versionData = require('./version-data.json') if (!appSettings.versionInitialized || appSettings.versionInitialized != versionData.version) { + logger.info(`Updating ${appSettingsPath} : ${JSON.stringify(appSettings)}`); appSettings.specterdVersion = versionData.version appSettings.specterdHash = versionData.sha256 appSettings.versionInitialized = versionData.version @@ -136,6 +167,7 @@ app.whenReady().then(() => { if (fs.existsSync(specterdPath + (platformName == 'win64' ? '.exe' : ''))) { getFileHash(specterdPath + (platformName == 'win64' ? '.exe' : ''), function (specterdHash) { if (appSettings.specterdHash.toLowerCase() == specterdHash || appSettings.specterdHash == "") { + startSpecterd(specterdPath) } else if (appSettings.specterdVersion != "") { updatingLoaderMsg('Specterd version could not be validated.
Retrying fetching specterd...
This might take a minute...') @@ -187,8 +219,8 @@ function initMainWindow(specterURL) { function downloadSpecterd(specterdPath) { updatingLoaderMsg('Fetching the Specter binary...
This might take a minute...') updateSpecterdStatus('Fetching Specter binary...') - console.log("Using version ", appSettings.specterdVersion); - console.log(`https://github.com/cryptoadvance/specter-desktop/releases/download/${appSettings.specterdVersion}/specterd-${appSettings.specterdVersion}-${platformName}.zip`); + logger.info("Using version ", appSettings.specterdVersion); + logger.info(`https://github.com/cryptoadvance/specter-desktop/releases/download/${appSettings.specterdVersion}/specterd-${appSettings.specterdVersion}-${platformName}.zip`); download(`https://github.com/cryptoadvance/specter-desktop/releases/download/${appSettings.specterdVersion}/specterd-${appSettings.specterdVersion}-${platformName}.zip`, specterdPath + '.zip', function(errored) { if (errored == true) { updatingLoaderMsg('Fetching specter binary from the server failed, could not reach the server or the file could not have been found.') @@ -249,6 +281,11 @@ function updatingLoaderMsg(msg) { } } +function hasSuccessfullyStarted(logs) { + return logs.toString().includes(' * Running on http') + //return logs.toString().includes('Serving Flask app "cryptoadvance.specter.server"') +} + function startSpecterd(specterdPath) { if (platformName == 'win64') { specterdPath += '.exe' @@ -257,7 +294,9 @@ function startSpecterd(specterdPath) { let hwiBridgeMode = appSettings.mode == 'hwibridge' updatingLoaderMsg('Launching Specter Desktop...') updateSpecterdStatus('Launching Specter...') - let specterdArgs = hwiBridgeMode ? ['--hwibridge'] : null + let specterdArgs = ["server"] + specterdArgs.push("--no-filelog") + if (hwiBridgeMode) specterdArgs.push('--hwibridge') if (appSettings.specterdCLIArgs != '') { if (specterdArgs == null) { specterdArgs = [] @@ -268,17 +307,47 @@ function startSpecterd(specterdPath) { specterdArgs = specterdArgs.concat(specterdExtraArgs) } - specterdProcess = spawn(specterdPath, specterdArgs); + + + logger.info(`Starting specterd ${specterdPath} ${specterdArgs}`); + // locale fix (copying from nodejs-env + adding locales) + const options = { + env: { ...process.env} + } + options.env['LC_ALL']='en_US.utf-8' + options.env['LANG'] = 'en_US.utf-8' + options.env['SPECTER_LOGFORMAT'] = 'SPECTERD: %(levelname)s in %(module)s: %(message)s' + specterdProcess = spawn(specterdPath, specterdArgs, options); + var procStdout = "" + var procStderr = "" specterdProcess.stdout.on('data', (data) => { - if(data.toString().includes('Serving Flask app "cryptoadvance.specter.server"')) { + procStdout += data + logger.info("stdout-"+data.toString()) + if(hasSuccessfullyStarted(data)) { + logger.info(`App seem to to run ...`); if (mainWindow) { + logger.info(`... creating window ...`); createWindow(appSettings.specterURL) + } } }); - specterdProcess.stderr.on('data', function(_) { - // https://stackoverflow.com/questions/20792427/why-is-my-node-child-process-that-i-created-via-spawn-hanging - // needed so specterd won't get stuck + specterdProcess.stderr.on('data', (data) => { + procStderr += data + logger.info("stderr-"+data.toString()) + if(hasSuccessfullyStarted(data)) { + logger.info(`App seem to to run ...`); + if (mainWindow) { + logger.info(`... creating window ...`); + createWindow(appSettings.specterURL) + + } + } + }); + + specterdProcess.on('exit', (code) => { + logger.error(`specterd exited with code ${code}`); + showError(`specterd exited with code ${code}. Check the logs in the menu!`) }); app.on('activate', function () { @@ -289,7 +358,7 @@ function startSpecterd(specterdPath) { // since these are streams, you can pipe them elsewhere specterdProcess.on('close', (code) => { updateSpecterdStatus('Specter stopped...') - console.log(`child process exited with code ${code}`); + logger.info(`child process exited with code ${code}`); }); } @@ -322,7 +391,7 @@ ipcMain.on('request-mainprocess-action', (event, arg) => { prefWindow.webContents.executeJavaScript(`savePreferences()`); } else { specterdProcess.on('close', (code) => { - console.log(`child process exited with code ${code}`); + logger.info(`child process exited with code ${code}`); prefWindow.webContents.executeJavaScript(`savePreferences()`); }); quitSpecterd() @@ -345,7 +414,7 @@ function quitSpecterd() { } specterdProcess.kill('SIGINT') } catch (e) { - console.log('Specterd quit warning: ' + e) + logger.info('Specterd quit warning: ' + e) } } } @@ -362,14 +431,28 @@ function setMainMenu() { accelerator: "CmdOrCtrl+," } ); + menu[0].submenu.splice(1, 0, + { + label: 'Specter Logs', + click: openErrorLog, + accelerator: "CmdOrCtrl+," + } + ); } else { menu.unshift({ label: 'Specter', - submenu: [{ + submenu: [ + { label: 'Preferences', click: openPreferences, accelerator: "CmdOrCtrl+," - }] + }, + { + label: 'Specter Logs', + click: openErrorLog, + accelerator: "CmdOrCtrl+," + } + ] } ); } @@ -377,32 +460,50 @@ function setMainMenu() { Menu.setApplicationMenu(Menu.buildFromTemplate(menu)); } -function openPreferences() { + +function openNewWindow(htmlContentFile) { prefWindow = new BrowserWindow({ width: 700, height: 750, + autoHideMenuBar: true, webPreferences: { nodeIntegration: true, - enableRemoteModule: true + enableRemoteModule: true, + } }) prefWindow.webContents.on('new-window', function(e, url) { e.preventDefault(); shell.openExternal(url); }); - prefWindow.loadURL(`file://${__dirname}/settings.html`) + prefWindow.loadURL(`file://${__dirname}/${htmlContentFile}`) prefWindow.show() } + +function openPreferences() { + openNewWindow("settings.html") +} + +function openErrorLog() { + openNewWindow("error_logs.html") +} + function showError(error) { - console.error('Specter Desktop encounter an error', error.toString()) updatingLoaderMsg('Specter Desktop encounter an error:
' + error.toString()) } process.on('unhandledRejection', error => { showError(error) + logger.error(error.toString(), error.name) }) process.on("uncaughtException", error => { showError(error) + // I would love to rethrow the error here as this would create a stacktrace in the logs + // but this will terminate the whole process even though i've set + // exitOnError: false in the wistonOptions above. + // Unacceptable for the folks which can't use a commandline, clicking an icon + //throw(error) + logger.error(error.toString()) }) diff --git a/pyinstaller/electron/package.json b/pyinstaller/electron/package.json index 873d973ed..68f6e8171 100644 --- a/pyinstaller/electron/package.json +++ b/pyinstaller/electron/package.json @@ -1,6 +1,5 @@ { "name": "specter-desktop", - "version": "v1.6.0", "description": "Specter Desktop Electron application", "main": "main.js", "scripts": { @@ -46,6 +45,7 @@ "electron-context-menu": "^2.3.0", "electron-default-menu": "^1.0.2", "extract-zip": "^2.0.1", - "request": "^2.88.2" + "request": "^2.88.2", + "winston": "^3.3.3" } } diff --git a/pyinstaller/specterd.py b/pyinstaller/specterd.py index fbc1262bd..a173675e6 100644 --- a/pyinstaller/specterd.py +++ b/pyinstaller/specterd.py @@ -1,27 +1,4 @@ -from logging.config import dictConfig -from cryptoadvance.specter.cli import server -import sys -import logging +from cryptoadvance.specter.cli import entry_point if __name__ == "__main__": - # central and early configuring of logging see - # https://flask.palletsprojects.com/en/1.1.x/logging/#basic-configuration - - ch = logging.StreamHandler() - ch.setLevel(logging.INFO) - formatter = logging.Formatter( - "[%(asctime)s] %(levelname)s in %(module)s: %(message)s" - ) - ch.setFormatter(formatter) - logging.getLogger().addHandler(ch) - # However initially, we'll set the root-logger to INFO: - logging.getLogger().setLevel(logging.INFO) - logging.getLogger(__name__).info("Logging configured") - if "--daemon" in sys.argv: - print("Daemon mode is not supported in binaries yet") - sys.exit(1) - if "--debug" in sys.argv: - print("Debug mode is useless in binary mode, don't use it") - sys.exit(1) - print("Starting Specter server. It may take a while, please be patient") - server() + entry_point() diff --git a/src/cryptoadvance/specter/cli/__init__.py b/src/cryptoadvance/specter/cli/__init__.py index 4ac80f61e..bafe69a4c 100644 --- a/src/cryptoadvance/specter/cli/__init__.py +++ b/src/cryptoadvance/specter/cli/__init__.py @@ -1,5 +1,6 @@ import logging import click +import os from .cli_server import server from .cli_noded import bitcoind, elementsd @@ -17,14 +18,17 @@ logger = logging.getLogger(__name__) def entry_point(config_home, debug=False, tracerpc=False): ch = logging.StreamHandler() ch.setLevel(logging.DEBUG) - if debug: # No need for timestamps while developing formatter = logging.Formatter("[%(levelname)7s] in %(module)15s: %(message)s") logging.getLogger("cryptoadvance").setLevel(logging.DEBUG) else: formatter = logging.Formatter( - "[%(asctime)s] %(levelname)s in %(module)s: %(message)s" + # Too early to format that via the flask-config, so let's copy it from there: + os.getenv( + "SPECTER_LOGFORMAT", + "[%(asctime)s] %(levelname)s in %(module)s: %(message)s", + ) ) logging.getLogger("cryptoadvance").setLevel(logging.INFO) ch.setFormatter(formatter)