diff --git a/gcs/.prettierignore b/gcs/.prettierignore index dc0172620..9db4c1f0e 100644 --- a/gcs/.prettierignore +++ b/gcs/.prettierignore @@ -3,4 +3,4 @@ build coverage dist dist-electron -data +data \ No newline at end of file diff --git a/gcs/.prettierrc b/gcs/.prettierrc new file mode 100644 index 000000000..6e0789a98 --- /dev/null +++ b/gcs/.prettierrc @@ -0,0 +1,6 @@ +{ + "semi": false, + "singleQuote": false, + "jsxSingleQuote": false, + "trailingComma": "all" +} \ No newline at end of file diff --git a/gcs/data/default_settings.json b/gcs/data/default_settings.json index 1c89cc4cb..d10754b92 100644 --- a/gcs/data/default_settings.json +++ b/gcs/data/default_settings.json @@ -59,5 +59,32 @@ }, "Params": {}, "Config": {}, - "FGCS": {} + "FGCS": {}, + "Development": { + "logToWorkingDirectory": { + "description": "Log files will be placed in gcs/logs instead of appdata/FGCS/logs", + "display": "Log to Development Workspace", + "type": "boolean", + "default": false + }, + "loggingFormat": { + "description": "Format for log messages. See log4js patterns for more info", + "display": "Log Format", + "type": "string", + "default": "[%d{dd/MM/yyyy hh:mm:ss:SSS}] [%p] %c - %m" + }, + "loggingLevel": { + "description": "Current development log level", + "display": "Log Level", + "type": "option", + "options": ["DEBUG", "INFO", "WARNING", "ERROR", "FATAL"], + "default": "INFO" + }, + "combineLogs": { + "description": "Combine frontend and backend logs into a single file", + "display": "Combine Log Files", + "type": "boolean", + "default": false + } + } } diff --git a/gcs/electron/main.ts b/gcs/electron/main.ts index 5afda953b..2e6a3042f 100644 --- a/gcs/electron/main.ts +++ b/gcs/electron/main.ts @@ -17,15 +17,12 @@ import path from "node:path" import packageInfo from "../package.json" // @ts-expect-error - no types available -import openFile, { clearRecentFiles, getRecentFiles } from "./fla" -import registerAboutIPC, { - destroyAboutWindow, - openAboutPopout, -} from "./modules/aboutWindow" -import registerLinkStatsIPC, { - destroyLinkStatsWindow, -} from "./modules/linkStatsWindow" -import registerWebcamIPC, { destroyWebcamWindow } from "./modules/webcam" +import openFile, { clearRecentFiles, getRecentFiles } from './fla' +import registerSettingsIPC, { getSetting } from './modules/settings' +import registerWebcamIPC, { destroyWebcamWindow } from './modules/webcam' +import registerLoggingIPC, { setupLog4js, logFatal, logWarning, logInfo } from './modules/logging' +import registerAboutIPC, { destroyAboutWindow, openAboutPopout } from "./modules/aboutWindow" +import registerLinkStatsIPC, { destroyLinkStatsWindow } from "./modules/linkStatsWindow" // The built directory structure // // ├─┬─┬ dist @@ -64,91 +61,13 @@ function getWindow() { return BrowserWindow.getFocusedWindow() } -// Settings logic +registerLoggingIPC(); +registerSettingsIPC(); -interface Settings { - version: string - settings: object -} - -let userSettings: Settings | null = null - -function saveUserConfiguration(settings: Settings) { - userSettings = settings - fs.writeFileSync( - path.join(app.getPath("userData"), "settings.json"), - JSON.stringify(userSettings, null, 2), - "utf-8", - ) -} - -/** - * Checks the application version within the loaded user settings and updates if it is outdated - * @param configPath The path to the configuration file - * @returns - */ -function checkAppVersion(configPath: string) { - if (userSettings === null) { - console.warn( - "Attempting to check app version when user settings have not been loaded", - ) - return - } - - if (userSettings.version == app.getVersion()) return - - userSettings.version = app.getVersion() - fs.writeFileSync(configPath, JSON.stringify(userSettings)) -} - -/** - * Called when the application requests user settings - * - * @returns - */ -function getUserConfiguration() { - // Return the already loaded user settings if loaded - console.log("Fetching user settings!") - if (userSettings !== null) return userSettings - - // Directories - const userDir = app.getPath("userData") - const config = path.join(userDir, "settings.json") - - // Write version and blank settings to user config if doesn't exist - if (!fs.existsSync(config)) { - console.log("Generating user settings") - userSettings = { version: app.getVersion(), settings: {} } - fs.writeFileSync(config, JSON.stringify(userSettings)) - } else { - console.log("Reading user settings from config file " + config) - userSettings = JSON.parse(fs.readFileSync(config, "utf-8")) - checkAppVersion(config) - } - return userSettings -} - -ipcMain.handle("getSettings", () => { - return getUserConfiguration() -}) -ipcMain.handle("setSettings", (_, settings) => { - saveUserConfiguration(settings) -}) - -ipcMain.handle("isMac", () => { - return process.platform == "darwin" -}) -ipcMain.on("close", () => { - closeWithBackend() -}) -ipcMain.on("minimise", () => { - getWindow()?.minimize() -}) -ipcMain.on("maximise", () => { - getWindow()?.isMaximized() - ? getWindow()?.unmaximize() - : getWindow()?.maximize() -}) +ipcMain.handle("isMac", () => { return process.platform == "darwin" }) +ipcMain.on('close', () => {closeWithBackend()}) +ipcMain.on('minimise', () => {getWindow()?.minimize()}) +ipcMain.on('maximise', () => {getWindow()?.isMaximized() ? getWindow()?.unmaximize() : getWindow()?.maximize()}) ipcMain.on("reload", () => { getWindow()?.reload() @@ -179,6 +98,15 @@ ipcMain.on("openFileInExplorer", (_event, filePath) => { shell.showItemInFolder(filePath) }) +ipcMain.handle('selectDirectory', async () => { + const result = await dialog.showOpenDialog({ + properties: ['openDirectory'], + defaultPath: app.getAppPath() + }); + if (result.canceled) return null; + return result.filePaths[0]; +}); + function createWindow() { win = new BrowserWindow({ icon: path.join(process.env.VITE_PUBLIC, "app_icon.ico"), @@ -291,11 +219,11 @@ function createLoadingWindow() { function startBackend() { if (pythonBackend) { - console.log("Backend already running") - return + logWarning('Backend already running'); + return; } - console.log("Starting backend") + logInfo('Starting backend'); // Add more platforms here const backendPaths: Partial> = { @@ -313,28 +241,25 @@ function startBackend() { const backendPath = backendPaths[process.platform] if (!backendPath) { - console.error("Unsupported platform!") - return + logFatal('Unsupported platform!'); + return; } - console.log(`Starting backend: ${backendPath}`) - pythonBackend = spawn(backendPath) + logInfo(`Starting backend: ${backendPath}`); + pythonBackend = spawn(backendPath); // pythonBackend.stdout.on('data', (data) => console.log(`Backend stdout: ${data}`)); // pythonBackend.stderr.on('data', (data) => console.error(`Backend stderr: ${data}`)); - pythonBackend.on("close", (code) => { - console.log(`Backend process exited with code ${code}`) - pythonBackend = null - }) + pythonBackend.on('close', (code) => { + logInfo(`Backend process exited with code ${code}`); + pythonBackend = null; + }); - pythonBackend.on("error", (error) => { - console.error("Failed to start backend:", error) - dialog.showErrorBox( - "Backend Error", - `Failed to start backend: ${error.message}`, - ) - }) + pythonBackend.on('error', (error) => { + logFatal('Failed to start backend: ' + error); + dialog.showErrorBox('Backend Error', `Failed to start backend: ${error.message}`); + }); } // Quit when all windows are closed, except on macOS. There, it's common @@ -346,9 +271,7 @@ function closeWithBackend() { win = null } destroyWebcamWindow() - destroyAboutWindow() - destroyLinkStatsWindow() - console.log("Killing backend") + logInfo('Killing backend') // kill any processes with the name "fgcs_backend.exe" // Windows spawn("taskkill /f /im fgcs_backend.exe", { shell: true }) @@ -359,10 +282,10 @@ app.on("window-all-closed", () => { // To ensure that the backend process is killed with Cmd + Q on macOS, // listen to the before-quit event. -app.on("before-quit", () => { - if (process.platform === "darwin" && pythonBackend) { - console.log("Stopping backend") - spawnSync("pkill", ["-f", "fgcs_backend"]) +app.on('before-quit', () => { + if(process.platform === 'darwin' && pythonBackend){ + logInfo('Stopping backend') + spawnSync('pkill', ['-f', 'fgcs_backend']); pythonBackend = null destroyWebcamWindow() destroyAboutWindow() @@ -379,6 +302,14 @@ app.on("activate", () => { }) app.whenReady().then(() => { + + setupLog4js( + getSetting("Development", "logToWorkingDirectory"), + getSetting("Development", "combineLogs"), + getSetting("Development", "loggingFormat"), + getSetting("Development", "loggingLevel") + ); + createLoadingWindow() // Open file and Get Recent Logs ipcMain.handle("fla:open-file", openFile) diff --git a/gcs/electron/modules/logging.ts b/gcs/electron/modules/logging.ts new file mode 100644 index 000000000..1da43a39d --- /dev/null +++ b/gcs/electron/modules/logging.ts @@ -0,0 +1,188 @@ +/** + * Functions related to application-wide logging + */ +import path from "node:path"; +import { app, ipcMain } from "electron"; + +import * as log4js from "log4js"; + +// @ts-expect-error Log4js layouts provides no types +import * as layouts from "log4js/lib/layouts"; + +let frontendLogger: log4js.Logger +let backendLogger: log4js.Logger + +let initialised: boolean = false; + +interface BufferedLog { + message: string, + level: log4js.Level, + data: any[] +} +let logBuffer: BufferedLog[] = [] + +/** + * Setup logging for the application. Logs from the frontend are dispatched to this logger + * through ipcRenderer.pushLog. Logs from backend are dispatched to logger through socket, then ipcRenderer.pushLog + * + * @param logToWorkspace Developer setting forcing logs to be stored in gcs/logs + * @param combineLogFiles Developer setting that combines the log files into one "fgcs.log" file + * @param logFormat The format for the logger (see log4js patterns) + * @param loggingLevel The level of the frontend and backend loggers + */ +export function setupLog4js(logToWorkspace: boolean, combineLogFiles: boolean, logFormat: string, loggingLevel: string){ + + if (initialised) { + logWarning("Attempting to initialise log4js when it has already been initialised") + return; + } + + logDebug("Setting up logging with args (%s, %s, %s, %s)", logToWorkspace, combineLogFiles, logFormat, loggingLevel) + + const appenders = [combineLogFiles ? "file" : "multifile"] + const directory = logToWorkspace ? path.join(app.getAppPath(), "logs") : app.getPath("logs") + + // If we are logging to separate files no point including the logger name + const resolvedFormat = logFormat.replace("%c", '').replace(" ", " ") + + // Log to console as well if in dev + if (process.env.NODE_ENV === 'development') appenders.push("console") + + // Since logs coming from the backend supply their own epoch timestamp, file and line no (so that we can log based on when + // the log is sent not when it is recieved), we need a custom layout to deal with it + log4js.addLayout('epochLayout', (config: log4js.Config) => { + return (loggingEvent) => { + const data = loggingEvent.data[0] + return layouts.patternLayout(config.pattern)({...loggingEvent, + startTime: new Date(data._epoch * 1000), + fileName: data._file, + lineNumber: data._lineNo, + data: loggingEvent.data.slice(1) + }); + }; + }); + + log4js.configure({ + appenders: { + file: { + type: 'file', + filename: path.join(directory, "fgcs.log"), + layout: { + type: 'epochLayout', + pattern: logFormat + }, + flags: "w" + }, + console: { + type: "stdout", + layout: { + type: 'epochLayout', + pattern: logFormat + } + }, + multifile: { + type: "multiFile", + base: directory, + property: "categoryName", + extension: ".log", + layout: { + type: 'epochLayout', + pattern: resolvedFormat + }, + flags: "w" + } + }, + categories: { + frontend: { + appenders: appenders, + level: loggingLevel, + enableCallStack: true + }, + backend: { + appenders: appenders, + level: loggingLevel, + enableCallStack: true + }, + default: { + appenders: ["console"], + level: "info" + } + } + }) + + frontendLogger = log4js.getLogger("frontend") + backendLogger = log4js.getLogger("backend") + + // Dispatch log message that arrived before setup + initialised = true + logBuffer.forEach(logHelper) + logBuffer = [] + + logInfo("Setup user logging") +} + +/** + * Log the given buffered log + * + * If logging is initialised, sends the log straight to the frontend log4js logger. + * If logging is not initialised yet, appends to a buffer which gets logged once + * log4js is initialised + * + * @param log The log data + */ +function logHelper(log: BufferedLog) { + if (initialised) { + + // Inspect stack to find file + const err = new Error() + const caller = err.stack?.split('\n').at(3) ?? "unknown" + const file = caller.split("\\").at(-1) ?? ""; + const fileName = file.slice(0, file.indexOf(":")); + + const lineNo = caller.split(":").at(-2); + + (frontendLogger as any)[log.level.levelStr.toLowerCase()]({_epoch: Date.now() / 1000, _file: fileName, _lineNo: lineNo}, log.message, ...log.data) + } + else + logBuffer.push(log) +} + +export function logDebug(message: string, ...args: any[]) { + logHelper({message: message, level: log4js.levels.DEBUG, data: args}) +} + +export function logInfo(message: string, ...args: any[]) { + logHelper({message: message, level: log4js.levels.INFO, data: args}) +} + +export function logWarning(message: string, ...args: any[]) { + logHelper({message: message, level: log4js.levels.WARN, data: args}) +} + +export function logError(message: string, ...args: any[]) { + logHelper({message: message, level: log4js.levels.ERROR, data: args}) +} + +export function logFatal(message: string, ...args: any[]) { + logHelper({message: message, level: log4js.levels.FATAL, data: args}) +} + +interface LogPayload { + level: 'debug' | 'info' | 'warn' | 'error' | 'fatal' | 'critical', + message: string, + timestamp: number, + source: string, + file: string, + line: number +} + +export default function registerLoggingIPC(){ + + ipcMain.handle("logMessage", (_, {level, message, timestamp, source, file, line}: LogPayload) => { + // backend logs from python come in with CRITICAL level, log4js calls it FATAL (like every other logger ever) + const resolvedLevel = level === "critical" ? "fatal" : level + source === "backend" + ? backendLogger[resolvedLevel]({_epoch: timestamp, _file: file, _lineNo: line}, message) + : frontendLogger[resolvedLevel]({_epoch: timestamp, _file: file, _lineNo: line}, message) + }) +} \ No newline at end of file diff --git a/gcs/electron/modules/settings.ts b/gcs/electron/modules/settings.ts new file mode 100644 index 000000000..87a4d0228 --- /dev/null +++ b/gcs/electron/modules/settings.ts @@ -0,0 +1,127 @@ +// This file contains logs of disgusting hacky typescript but it DOES +// make it so that accessing a setting which does not exist in default_settings.json +// causes a build error so we should never crash from accessing non-existant settings + +import fs from 'node:fs' +import path from 'node:path' +import { exit } from 'node:process'; +import { app, ipcMain } from 'electron'; + +import Data from "../../data/default_settings.json" +import { logDebug, logFatal, logInfo, logWarning } from './logging'; + + +type SettingsShape = typeof Data; +type SettingsGroup = keyof SettingsShape; +type Setting = keyof SettingsShape[G]; + +type SettingValue> = + SettingsShape[G][S] extends { default: infer V } ? V : never; + +interface DefaultSetting> { + default: SettingValue, + [k: string]: any +} + +// Hack to create a type which MAY contain keys from the default_settings.json, and each of those keys +// MAY contain any number of the settings listed in that section of default_settings.json +type DeepPartial = { + [K in keyof T]?: T[K] extends object ? DeepPartial : T[K]; +}; +type PartialSettings = DeepPartial + +interface Settings { + version: string, + settings: PartialSettings +} + +let userSettings: Settings | null = null +const defaultSettings: SettingsShape = Data + +function saveUserConfiguration(settings: Settings){ + userSettings = settings; + fs.writeFileSync(path.join(app.getPath('userData'), 'settings.json'), JSON.stringify(userSettings, null, 2), 'utf-8'); +} + +/** + * Checks the application version within the loaded user settings and updates if it is outdated + * @param configPath The path to the configuration file + * @returns + */ +function checkAppVersion(configPath: string){ + + if (userSettings === null){ + logWarning("Attempting to check app version when user settings have not been loaded"); + return; + } + + if (userSettings.version == app.getVersion()) + return; + + userSettings.version = app.getVersion(); + fs.writeFileSync(configPath, JSON.stringify(userSettings)) +} + +/** + * Called when the application requests user settings + * + * @returns Settings + */ +export function getUserConfiguration(): Settings{ + + // Return the already loaded user settings if loaded + if (userSettings !== null) return userSettings + logDebug("Fetching user settings") + + // Directories + const userDir = app.getPath('userData'); + const config = path.join(userDir, 'settings.json'); + + // Write version and blank settings to user config if doesn't exist + if (!fs.existsSync(config)) { + logInfo("Generating user setings") + userSettings = {version: app.getVersion(), settings: {}} + fs.writeFileSync(config, JSON.stringify(userSettings)) + } else{ + logInfo("Reading user settings from config file " + config) + userSettings = JSON.parse(fs.readFileSync(config, 'utf-8')) + checkAppVersion(config) + } + if (userSettings != null) return userSettings + + logFatal("Could not create settings for some reason") + exit(-1); +} + +function getDefault>(group: G, setting: S): SettingValue { + const df = defaultSettings[group][setting] as DefaultSetting + return df.default +} + +/** + * Get the given user setting (or the default value from default_settings.json) + * + * A method exists for this in the frontend (see the settings provider) + * but this is useful to have if you need to access a setting in electron + * (for example for logging) + * + * @param group + * @param setting + */ +export function getSetting>(group: G, setting: S): SettingValue { + + // Development settings only take effect in development! + if (process.env.NODE_ENV == "production" && group == "Development") return getDefault(group, setting) + + //Get user setting or return default if it doesn't exist + const userConfig = getUserConfiguration().settings[group] as Partial; + const userSetting = userConfig?.[setting]; + + if (userSetting) return userSetting as SettingValue + return getDefault(group, setting) +} + +export default function registerSettingsIPC(){ + ipcMain.handle("getSettings", () => {return getUserConfiguration(); }) + ipcMain.handle("setSettings", (_, settings) => {saveUserConfiguration(settings)}) +} \ No newline at end of file diff --git a/gcs/electron/modules/webcam.ts b/gcs/electron/modules/webcam.ts index 4d0451135..157d55275 100644 --- a/gcs/electron/modules/webcam.ts +++ b/gcs/electron/modules/webcam.ts @@ -1,5 +1,6 @@ import path from "path"; import { BrowserWindow, ipcMain } from "electron"; +import { logInfo, logWarning } from "./logging"; let webcamPopoutWin: BrowserWindow | null = null @@ -43,7 +44,7 @@ export function openWebcamPopout(videoStreamId: string, name: string, aspect: nu fullscreenable: false, }); } else{ - console.warn("HOW ARE YOU CREATEING 2 WEBCAM WINDOWS TELL ME") + logWarning("Somehow creating multiple webcams. This should not be happening") } loadWebcam(videoStreamId, name); @@ -75,7 +76,7 @@ export function openWebcamPopout(videoStreamId: string, name: string, aspect: nu } export function closeWebcamPopout(mainWindow: BrowserWindow | null){ - console.log("Destroying webcam window") + logInfo("Destroying webcam window") destroyWebcamWindow(); mainWindow?.webContents.send("webcam-closed"); } diff --git a/gcs/electron/preload.js b/gcs/electron/preload.js index bbb174752..b3b15ccf8 100644 --- a/gcs/electron/preload.js +++ b/gcs/electron/preload.js @@ -9,6 +9,7 @@ contextBridge.exposeInMainWorld("ipcRenderer", { getSaveMissionFilePath: (options) => ipcRenderer.invoke("missions:get-save-mission-file-path", options), getNodeEnv: () => ipcRenderer.invoke("app:get-node-env"), + isDev: () => ipcRenderer.invoke("app:get-node-env") != "production", getVersion: () => ipcRenderer.invoke("app:get-version"), getSettings: () => ipcRenderer.invoke("getSettings"), saveSettings: (settings) => ipcRenderer.invoke("setSettings", settings), @@ -17,6 +18,8 @@ contextBridge.exposeInMainWorld("ipcRenderer", { closeWebcamWindow: () => ipcRenderer.invoke("closeWebcamWindow"), onCameraWindowClose: (callback) => ipcRenderer.on("webcam-closed", () => callback()), + pushLog: (msg) => ipcRenderer.invoke("logMessage", msg), + selectDirectory: () => ipcRenderer.invoke('selectDirectory'), openAboutWindow: () => ipcRenderer.invoke("openAboutWindow"), closeAboutWindow: () => ipcRenderer.invoke("closeAboutWindow"), openLinkStatsWindow: () => ipcRenderer.invoke("openLinkStatsWindow"), diff --git a/gcs/package.json b/gcs/package.json index a847cbd38..e072f3de6 100644 --- a/gcs/package.json +++ b/gcs/package.json @@ -50,6 +50,7 @@ "colormap": "^2.3.2", "eslint-config-prettier": "^9.1.0", "glob": "^10.3.12", + "log4js": "^6.9.1", "mapbox-gl": "^3.0.1", "maplibre-gl": "^3.6.2", "moment": "^2.29.4", diff --git a/gcs/src/components/config/motorTest.jsx b/gcs/src/components/config/motorTest.jsx index 66aa897dc..26604a448 100644 --- a/gcs/src/components/config/motorTest.jsx +++ b/gcs/src/components/config/motorTest.jsx @@ -172,7 +172,8 @@ export default function MotorTestPanel() { return (

{" "} - Motor number: {mappedMotorNumber}, {frameTypeDirection[idx]}{" "} + Motor number: {mappedMotorNumber},{" "} + {frameTypeDirection[idx]}{" "}

) })} diff --git a/gcs/src/components/dashboard/preFlightChecklist/checkListArea.jsx b/gcs/src/components/dashboard/preFlightChecklist/checkListArea.jsx index 51b33c977..1e5a44dee 100644 --- a/gcs/src/components/dashboard/preFlightChecklist/checkListArea.jsx +++ b/gcs/src/components/dashboard/preFlightChecklist/checkListArea.jsx @@ -15,6 +15,7 @@ import EditCheckList from "./checkListEdit.jsx" import resolveConfig from "tailwindcss/resolveConfig" import tailwindConfig from "../../../../tailwind.config.js" import { IconCheckbox, IconEdit, IconTrashX } from "@tabler/icons-react" +import { logInfo } from "../../../helpers/logging.js" const tailwindColors = resolveConfig(tailwindConfig).theme.colors export default function CheckListArea({ @@ -51,7 +52,6 @@ export default function CheckListArea({ function generateCheckboxList(defaultCheck = false) { // Go from string to list, does not return - console.log(checkBoxListString) var final = [] checkBoxListString .split("

  • ") diff --git a/gcs/src/components/mainContent.jsx b/gcs/src/components/mainContent.jsx index 7a8e41251..cf13091b1 100644 --- a/gcs/src/components/mainContent.jsx +++ b/gcs/src/components/mainContent.jsx @@ -28,11 +28,20 @@ import { ErrorBoundary } from "react-error-boundary" import AlertProvider from "./dashboard/alertProvider" import ErrorBoundaryFallback from "./error/errorBoundary" import { initSocket } from "../redux/slices/socketSlice" +import { registerHandler } from "../redux/slices/loggingSlice" +import { consoleLogHandler, electronLogHandler } from "../helpers/logHandlers" export default function AppContent() { // Setup sockets for redux const dispatch = useDispatch() useEffect(() => { + // Only add console log handler in dev mode + if (window.ipcRenderer.isDev()) { + dispatch(registerHandler(consoleLogHandler)) + } + + dispatch(registerHandler(electronLogHandler)) + dispatch(initSocket()) }, []) diff --git a/gcs/src/components/settingsModal.jsx b/gcs/src/components/settingsModal.jsx index c1062eccc..3d9b9692f 100644 --- a/gcs/src/components/settingsModal.jsx +++ b/gcs/src/components/settingsModal.jsx @@ -21,13 +21,14 @@ const isValidNumber = (num, range) => { ) } -function TextSetting({ settingName, hidden }) { +function TextSetting({ settingName, hidden, regex = null }) { const { getSetting, setSetting } = useSettings() return ( setSetting(settingName, e.currentTarget.value)} type={hidden ? "password" : "text"} + pattern={regex === null ? "" : regex} /> ) } @@ -125,6 +126,28 @@ function ExtendableNumberSetting({ settingName, range }) { ) } +function DirectorySetting({ settingName }) { + const { getSetting, setSetting } = useSettings() + + const setDirectory = async () => { + const dirHandle = await window.ipcRenderer.selectDirectory() + if (dirHandle !== null) setSetting(settingName, dirHandle) + } + + return ( + // +

    + {getSetting(settingName)} + +
    + ) +} + function Setting({ settingName, df }) { return (
    ) : df.type == "option" ? ( + ) : df.type == "directory" ? ( + ) : ( -
    ) @@ -157,6 +186,8 @@ function SettingsModal() { const { opened, close } = useSettings() + const settingsWithoutDev = settingTabs.filter((t) => t !== "Development") + return ( - {settingTabs.map((t) => { - return ( - - {t} - - ) - })} + {settingsWithoutDev + .filter((t) => t !== "Development") + .map((t) => { + return ( + + {t} + + ) + })} + + {window.ipcRenderer.isDev() && ( + + Development + + )} - {settingTabs.map((t) => { + {settingsWithoutDev.map((t) => { return ( {Object.keys(DefaultSettings[t]).map((s) => { @@ -207,6 +246,27 @@ function SettingsModal() { ) })} + + {window.ipcRenderer.isDev() && ( + + {Object.keys(DefaultSettings["Development"]).map((s) => { + return ( + + ) + })} + {Object.keys(DefaultSettings["Development"]).length == 0 && ( +

    No settings available right now.

    + )} +     + )}     ) diff --git a/gcs/src/components/spotlight/commandHandler.js b/gcs/src/components/spotlight/commandHandler.js index 3406d713c..c9738c0f3 100644 --- a/gcs/src/components/spotlight/commandHandler.js +++ b/gcs/src/components/spotlight/commandHandler.js @@ -8,6 +8,7 @@ import { useNavigate } from "react-router" import { useSettings } from "../../helpers/settings" import { useState, useEffect } from "react" import { useHotkeys } from "@mantine/hooks" +import { logError, logWarning } from "../../helpers/logging" let commands = [] @@ -73,7 +74,7 @@ export function AddCommand(id, command, shortcut = null, macShortcut = null) { macShortcut: macShortcut, }) } else { - console.log(`Attempting to add command that already exists: ${id}`) + logWarning(`Attempting to add command that already exists: ${id}`) } } @@ -81,15 +82,10 @@ export function RunCommand(id) { // Search for a command by id var cmd = commands.find((entry) => entry.id == id) + if (cmd !== undefined) { cmd.command() } else { - console.log(`Couldn't find command ${id} to run`) - } - - try { - commands.find((entry) => entry.id == id).command() - } catch { - console.log(`Couldn't find command, ${id}, to run`) + logError(`Couldn't find command ${id} to run`) } } diff --git a/gcs/src/helpers/logHandlers.js b/gcs/src/helpers/logHandlers.js new file mode 100644 index 000000000..c44df9cce --- /dev/null +++ b/gcs/src/helpers/logHandlers.js @@ -0,0 +1,16 @@ +export function consoleLogHandler(msg) { + + const message = `[${msg.level}] [${msg.timestamp}] ${msg.source} - ${msg.message}` + switch (msg.level) + { + case 'debug': console.log(message); break + case 'info': console.info(message); break + case 'warning': console.warn(message); break + case 'error' || 'critical' || 'fatal': console.error(message); break + default: console.log(message) + } +} + +export async function electronLogHandler(msg) { + await window.ipcRenderer.pushLog(msg) +} diff --git a/gcs/src/helpers/logging.js b/gcs/src/helpers/logging.js new file mode 100644 index 000000000..5cdba7064 --- /dev/null +++ b/gcs/src/helpers/logging.js @@ -0,0 +1,54 @@ +import { emitLog } from "../redux/slices/loggingSlice" + +let dispatch; + +export function registerLoggingStore(store) { + dispatch = store.dispatch; +} + +function logHelper(level, msg) { + const err = new Error() + const caller = err.stack.split("\n")[3] + + const file = caller.split("/").at(-1) + const fileName = file.slice(0, file.indexOf(":")) + const lineNo = caller.split(":").at(-2) + + dispatch( + emitLog({ + message: msg, + level: level, + timestamp: new Date() / 1000, + source: "frontend", + file: fileName, + line: lineNo, + }), + ) +} + +export function logDebug(msg) { + logHelper("DEBUG", msg) +} + +export function logInfo(msg) { + logHelper("INFO", msg) +} + +export function logWarning(msg) { + logHelper("WARNING", msg) +} + +export function logError(msg) { + logHelper("ERROR", msg) +} + +export function logFatal(msg) { + logHelper("FATAL", msg) +} + +// Now these are global and don't need to be imported :D +globalThis.logInfo = logInfo +globalThis.logDebug = logDebug +globalThis.logError = logError +globalThis.logWarn = logWarning +globalThis.logFatal = logFatal diff --git a/gcs/src/helpers/socket.js b/gcs/src/helpers/socket.js index c8cbb701e..2f650949c 100644 --- a/gcs/src/helpers/socket.js +++ b/gcs/src/helpers/socket.js @@ -1,14 +1,15 @@ "use client" import { io } from "socket.io-client" +import { logInfo } from "./logging" export const socket = io(import.meta.env.VITE_BACKEND_URL) socket.on("connect", () => { - console.log(`Connected to socket from legacy, ${socket.id}`) + logInfo(`Connected to socket from legacy, ${socket.id}`) }) socket.on("disconnect", () => { - console.log("Disconnected from socket") + logInfo("Disconnected from legacy socket") }) class SocketConnection { diff --git a/gcs/src/main.jsx b/gcs/src/main.jsx index 31b96bd63..dc43dd9ba 100644 --- a/gcs/src/main.jsx +++ b/gcs/src/main.jsx @@ -21,6 +21,7 @@ import { CustomMantineTheme } from "./components/customMantineTheme.jsx" // Redux import { store } from "./redux/store.js" import { Provider } from "react-redux" +import { logInfo } from "./helpers/logging.js" ReactDOM.createRoot(document.getElementById("root")).render( // @@ -38,5 +39,5 @@ postMessage({ payload: "removeLoading" }, "*") // Use contextBridge window.ipcRenderer.on("main-process-message", (_event, message) => { - console.log(message) + logInfo(message) }) diff --git a/gcs/src/redux/middleware/loggingMiddleware.js b/gcs/src/redux/middleware/loggingMiddleware.js new file mode 100644 index 000000000..4488acdd7 --- /dev/null +++ b/gcs/src/redux/middleware/loggingMiddleware.js @@ -0,0 +1,18 @@ +const loggingMiddleware = (store) => (next) => (action) => { + const result = next(action) + const state = store.getState() + + if (action.type == "logging/emitLog") { + state.logging.handlers.forEach((handler) => { + handler({ + ...action.payload, + timestamp: action.payload.timestamp ?? Date.now() / 1000, + level: action.payload.level.toLowerCase(), + }) + }) + } + + return result +} + +export default loggingMiddleware diff --git a/gcs/src/redux/middleware/socketMiddleware.js b/gcs/src/redux/middleware/socketMiddleware.js index bb9badda2..3ad1240e7 100644 --- a/gcs/src/redux/middleware/socketMiddleware.js +++ b/gcs/src/redux/middleware/socketMiddleware.js @@ -57,6 +57,9 @@ import { queueNotification, } from "../slices/notificationSlice" import { pushMessage } from "../slices/statusTextSlice.js" +import { emitLog } from "../slices/loggingSlice.js" +import { logDebug, logError, logInfo } from "../../helpers/logging.js" + import { handleEmitters } from "./emitters.js" import { dataFormatters } from "../../helpers/dataFormatters.js" @@ -147,21 +150,38 @@ const socketMiddleware = (store) => { ======================== */ + // In development mode, hook socket on and emit so that we can debug log every time we recieve / send a socket message + if (window.ipcRenderer.isDev()) { + const originalEmit = socket.socket.emit.bind(socket.socket) + + socket.socket.emit = (event, ...args) => { + logDebug( + `Event "${event}" emitted by frontend with args (${args.join(", ")})`, + ) + return originalEmit(event, ...args) + } + } + + // debug socket logging // handle socket connection events // EXAMPLE SOCKET.ON EVENT socket.socket.on(SocketEvents.Connect, () => { // DISPATCH ALL ACTIONS HERE // SINCE IT'S MIDDLEWARE, OTHER FUNCTIONS CAN ALSO BE CALLED - console.log(`Connected to socket from redux, ${socket.socket.id}`) + logInfo(`Connected to socket from redux, ${socket.socket.id}`) store.dispatch(socketConnected()) store.dispatch(emitIsConnectedToDrone()) }) socket.socket.on(SocketEvents.Disconnect, () => { - console.log(`Disconnected from socket via redux, ${socket.socket.id}`) + logInfo(`Disconnected from socket via redux, ${socket.socket.id}`) store.dispatch(socketDisconnected()) }) + socket.socket.on("log", (msg) => { + store.dispatch(emitLog({ ...msg, source: "backend" })) + }) + /* ==================== = DRONE CONNECTIONS = @@ -210,7 +230,7 @@ const socketMiddleware = (store) => { // Flags an error with the com port socket.socket.on("connection_error", (msg) => { - console.log("Connection error: " + msg.message) + logError("Connection error: " + msg.message) store.dispatch(queueErrorNotification(msg.message)) store.dispatch(setConnecting(false)) store.dispatch(setConnected(false)) diff --git a/gcs/src/redux/slices/loggingSlice.js b/gcs/src/redux/slices/loggingSlice.js new file mode 100644 index 000000000..b80a5dd14 --- /dev/null +++ b/gcs/src/redux/slices/loggingSlice.js @@ -0,0 +1,32 @@ +import { createSlice } from "@reduxjs/toolkit" + +const KEEP_LATEST_N_LOGS = 50 + +const loggingSlice = createSlice({ + name: "logging", + initialState: { + logHistory: [], + handlers: [], + debugLogCount: 0, + }, + reducers: { + emitLog: (state, action) => { + state.logHistory.push(action.payload) + if (state.logHistory.length > KEEP_LATEST_N_LOGS) state.logHistory.shift() + state.debugLogCount += 1 + }, + registerHandler: (state, action) => { + if (action.payload in state.handlers) return + state.handlers.push(action.payload) + }, + }, + selectors: { + selectRecentLogs: (state) => state.logHistory, + selectMostRecent: (state, n) => state.logHistory.slice(-n, -1), + }, +}) + +export const { emitLog, registerHandler } = loggingSlice.actions +export const { selectMostRecent, selectRecentLogs } = loggingSlice.selectors + +export default loggingSlice diff --git a/gcs/src/redux/store.js b/gcs/src/redux/store.js index b4e2d2d06..c50fe2498 100644 --- a/gcs/src/redux/store.js +++ b/gcs/src/redux/store.js @@ -15,6 +15,9 @@ import droneConnectionSlice, { import missionInfoSlice from "./slices/missionSlice" import statusTextSlice from "./slices/statusTextSlice" import notificationSlice from "./slices/notificationSlice" +import loggingSlice from "./slices/loggingSlice" +import loggingMiddleware from "./middleware/loggingMiddleware" +import { registerLoggingStore } from "../helpers/logging" const rootReducer = combineSlices( logAnalyserSlice, @@ -24,6 +27,7 @@ const rootReducer = combineSlices( missionInfoSlice, statusTextSlice, notificationSlice, + loggingSlice, ) // Get the persisted state, we only want to take a couple of things from here. @@ -37,7 +41,7 @@ export const store = configureStore({ return getDefaultMiddleware({ immutableCheck: false, serializableCheck: false, - }).concat([socketMiddleware]) + }).concat([socketMiddleware, loggingMiddleware]) }, }) @@ -67,6 +71,8 @@ if (droneConnection !== undefined) { } } +registerLoggingStore(store) + // Update states when a new message comes in, probably inefficient // TODO: In the future we should check to see if the variables have changed before updating store.subscribe(() => { diff --git a/gcs/vite.config.ts b/gcs/vite.config.ts index 77b1bff59..c1a298de3 100644 --- a/gcs/vite.config.ts +++ b/gcs/vite.config.ts @@ -11,6 +11,13 @@ export default defineConfig({ main: { // Shortcut of `build.lib.entry`. entry: 'electron/main.ts', + vite: { + build: { + rollupOptions: { + external: ['log4js'] + } + } + } }, preload: { // Shortcut of `build.rollupOptions.input`. @@ -21,5 +28,5 @@ export default defineConfig({ // See 👉 https://github.com/electron-vite/vite-plugin-electron-renderer renderer: {}, }), - ], + ] }) diff --git a/radio/app.py b/radio/app.py index 218c895d7..a17bc00ce 100644 --- a/radio/app.py +++ b/radio/app.py @@ -1,13 +1,13 @@ import os import app.droneStatus as droneStatus -from app import create_app, socketio +from app import create_app, socketio, logger from pathlib import Path from dotenv import load_dotenv app = create_app(debug=True) if __name__ == "__main__": - print("Loading dotenv.") + logger.info("Loading dotenv.") env_path = Path("../gcs/.env") load_dotenv(dotenv_path=env_path) @@ -19,9 +19,9 @@ port = 4237 host = "127.0.0.1" - print("Starting backend.") - print(host) + logger.info(f"Starting backend at {host}:{port}.") socketio.run(app, allow_unsafe_werkzeug=True, host=host, port=port) + if droneStatus.drone: droneStatus.drone.close() - print("Backend closed.") + logger.info("Backend closed.") diff --git a/radio/app/__init__.py b/radio/app/__init__.py index 102ea4678..aa1dc8b00 100644 --- a/radio/app/__init__.py +++ b/radio/app/__init__.py @@ -3,17 +3,10 @@ from flask import Flask from flask_socketio import SocketIO -logging.basicConfig(level=logging.DEBUG) - -logger = logging.getLogger("fgcs") -logger.setLevel(logging.DEBUG) - -flask_logger = logging.getLogger("werkzeug") -flask_logger.setLevel(logging.INFO) - +from app.loggingConfig import setup_logging socketio = SocketIO(cors_allowed_origins="*", async_mode="threading") - +logger = logging.getLogger("fgcs") def create_app(debug: bool = False) -> Flask: """ @@ -22,6 +15,8 @@ def create_app(debug: bool = False) -> Flask: Args: debug: Boolean value for if the debugging should be True or False """ + + from app.endpoints import endpoints app = Flask(__name__) @@ -30,6 +25,8 @@ def create_app(debug: bool = False) -> Flask: app.register_blueprint(endpoints) - logger.info("Initialising app") socketio.init_app(app) + setup_logging(socketio, debug) + + logger.info("Initialising app") return app diff --git a/radio/app/controllers/armController.py b/radio/app/controllers/armController.py index 62a9e58e6..412e0cf34 100644 --- a/radio/app/controllers/armController.py +++ b/radio/app/controllers/armController.py @@ -1,6 +1,7 @@ from __future__ import annotations import time +import logging from typing import TYPE_CHECKING from app.customTypes import Response @@ -10,6 +11,8 @@ if TYPE_CHECKING: from app.drone import Drone +logger = logging.getLogger("fgcs") + class ArmController: def __init__(self, drone: Drone) -> None: @@ -32,6 +35,7 @@ def arm(self, force: bool = False) -> Response: Response: The response from the arm command """ if self.drone.armed: + logger.warning("Arm failed: Drone already armed") return {"success": False, "message": "Already armed"} self.drone.is_listening = False @@ -51,16 +55,18 @@ def arm(self, force: bool = False) -> Response: self.drone.logger.debug("Waiting for arm") while not self.drone.armed: time.sleep(0.05) - self.drone.logger.debug("ARMED") + logger.info("Armed successfully") return {"success": True, "message": "Armed successfully"} else: - self.drone.logger.debug("Arming failed") + logger.warning("Arm failed: command not accepted") except Exception as e: self.drone.is_listening = True - self.drone.logger.error(e, exc_info=True) + logger.error(e, exc_info=True) if self.drone.droneErrorCb: self.drone.droneErrorCb(str(e)) return {"success": False, "message": "Could not arm, serial exception"} + + logger.warning("Arm failed: unknown error") return {"success": False, "message": "Could not arm, command not accepted"} def disarm(self, force: bool = False) -> Response: @@ -74,6 +80,7 @@ def disarm(self, force: bool = False) -> Response: Response: The response from the disarm command """ if not self.drone.armed: + logger.warning("Disarm failed: Drone is already disarmed") return {"success": False, "message": "Already disarmed"} self.drone.is_listening = False @@ -93,15 +100,18 @@ def disarm(self, force: bool = False) -> Response: self.drone.logger.debug("Waiting for disarm") while self.drone.armed: time.sleep(0.05) - self.drone.logger.debug("DISARMED") + logger.debug("Disarmed successfully") return {"success": True, "message": "Disarmed successfully"} else: - self.drone.logger.debug("Could not disarm, command not accepted") + logger.warning("Disarm failed: command not accepted") except Exception as e: self.drone.is_listening = True - self.drone.logger.error(e, exc_info=True) + logger.error(e, exc_info=True) + if self.drone.droneErrorCb: self.drone.droneErrorCb(str(e)) + return {"success": False, "message": "Could not disarm, serial exception"} + logger.warning("Disarm failed: unknown error") return {"success": False, "message": "Could not disarm, command not accepted"} diff --git a/radio/app/controllers/flightModesController.py b/radio/app/controllers/flightModesController.py index 1ab678bf6..4e3a3a3ed 100644 --- a/radio/app/controllers/flightModesController.py +++ b/radio/app/controllers/flightModesController.py @@ -4,6 +4,7 @@ from typing import TYPE_CHECKING, List, Union import serial +import logging from app.customTypes import Response from app.utils import commandAccepted from pymavlink import mavutil @@ -21,6 +22,8 @@ "FLTMODE6", ] +logger = logging.getLogger("fgcs") + class FlightModesController: def __init__(self, drone: Drone) -> None: @@ -42,6 +45,7 @@ def getFlightModes(self) -> None: """ Get the current flight modes of the drone.""" self.flight_modes = [] + logger.info(f"Fetching {len(FLIGHT_MODES)} flight modes") for mode in FLIGHT_MODES: flight_mode = self.drone.paramsController.getSingleParam(mode) if flight_mode.get("success"): @@ -49,7 +53,7 @@ def getFlightModes(self) -> None: if flight_mode_data: self.flight_modes.append(flight_mode_data.param_value) else: - self.drone.logger.error(flight_mode.get("message")) + logger.error(flight_mode.get("message")) self.flight_modes.append("UNKNOWN") def getFlightModeChannel(self) -> None: @@ -63,7 +67,7 @@ def getFlightModeChannel(self) -> None: if flight_mode_channel_data: self.flight_mode_channel = flight_mode_channel_data.param_value else: - self.drone.logger.error(flight_mode_channel.get("message")) + logger.error(flight_mode_channel.get("message")) def refreshData(self) -> None: """ @@ -83,7 +87,7 @@ def setFlightMode(self, mode_number: int, flight_mode: int) -> Response: """ if mode_number < 1 or mode_number > 6: - self.drone.logger.error( + logger.error( "Invalid flight mode number, must be between 1 and 6 inclusive." ) return { @@ -99,6 +103,9 @@ def setFlightMode(self, mode_number: int, flight_mode: int) -> Response: if self.drone.aircraft_type == 1: if (flight_mode < 0) or (flight_mode > 24): + logger.error( + f"Invalid plane flight mode number, must be between 0 and 24 inclusive, got {flight_mode}" + ) return { "success": False, "message": f"Invalid plane flight mode, must be between 0 and 24 inclusive, got {flight_mode}", @@ -106,6 +113,9 @@ def setFlightMode(self, mode_number: int, flight_mode: int) -> Response: mode_name = mavutil.mavlink.enums["PLANE_MODE"][flight_mode].name else: if (flight_mode < 0) or (flight_mode > 27): + logger.error( + f"Invalid copter flight mode number, must be between 0 and 27 inclusive, got {flight_mode}" + ) return { "success": False, "message": f"Invalid copter flight mode, must be between 0 and 27 inclusive, got {flight_mode}", @@ -113,7 +123,7 @@ def setFlightMode(self, mode_number: int, flight_mode: int) -> Response: mode_name = mavutil.mavlink.enums["COPTER_MODE"][flight_mode].name if param_set_success: - self.drone.logger.info(f"Flight mode {mode_number} set to {mode_name}") + logger.info(f"Flight mode {mode_number} set to {mode_name}") self.flight_modes[mode_number - 1] = flight_mode return { @@ -121,6 +131,7 @@ def setFlightMode(self, mode_number: int, flight_mode: int) -> Response: "message": f"Flight mode {mode_number} set to {mode_name}", } else: + logger.error(f"Failed to set flight mode {mode_number} to {mode_name}") return { "success": False, "message": f"Failed to set flight mode {mode_number} to {mode_name}", @@ -137,6 +148,9 @@ def setCurrentFlightMode(self, flightMode: int) -> Response: """ self.drone.is_listening = False time.sleep(0.3) + + logger.info(f"Setting current flight mode to {flightMode}") + self.drone.sendCommand( message=mavutil.mavlink.MAV_CMD_DO_SET_MODE, param1=1, @@ -155,16 +169,18 @@ def setCurrentFlightMode(self, flightMode: int) -> Response: if commandAccepted(response, mavutil.mavlink.MAV_CMD_DO_SET_MODE): self.drone.is_listening = True - self.drone.logger.info("Flight mode set successfully") + logger.debug("Flight mode set successfully") return {"success": True, "message": "Flight mode set successfully"} else: self.drone.is_listening = True + logger.error("Could not set flight mode") return { "success": False, "message": "Could not set flight mode", } - except serial.serialutil.SerialException: + except serial.serialutil.SerialException as e: self.drone.is_listening = True + logger.error(e, exc_info=True) return { "success": False, "message": "Could not set flight mode, serial exception", diff --git a/radio/app/controllers/frameController.py b/radio/app/controllers/frameController.py index 4f16c2535..8e2a94263 100644 --- a/radio/app/controllers/frameController.py +++ b/radio/app/controllers/frameController.py @@ -1,10 +1,14 @@ from __future__ import annotations +import logging + from typing import TYPE_CHECKING if TYPE_CHECKING: from app.drone import Drone +logger = logging.getLogger("fgcs") + class FrameController: def __init__(self, drone: Drone) -> None: @@ -32,8 +36,9 @@ def getFrameType(self) -> None: frame_type_data = frame_type_result.get("data") if frame_type_data: self.frame_type = frame_type_data.param_value + logger.info(f"Found current frame type: {self.frame_type}") else: - self.drone.logger.error(frame_type_result.get("message")) + logger.error(frame_type_result.get("message")) def getFrameClass(self) -> None: """ @@ -44,5 +49,6 @@ def getFrameClass(self) -> None: frame_class_data = frame_class_result.get("data") if frame_class_data: self.frame_class = frame_class_data.param_value + logger.debug(f"Found current frame class: {self.frame_class}") else: - self.drone.logger.error(frame_class_result.get("message")) + logger.error(frame_class_result.get("message")) diff --git a/radio/app/controllers/gripperController.py b/radio/app/controllers/gripperController.py index 4685dd1be..4b7518277 100644 --- a/radio/app/controllers/gripperController.py +++ b/radio/app/controllers/gripperController.py @@ -3,6 +3,8 @@ from typing import TYPE_CHECKING, Optional import serial +import logging + from app.customTypes import Response from app.utils import commandAccepted from pymavlink import mavutil @@ -10,6 +12,8 @@ if TYPE_CHECKING: from app.drone import Drone +logger = logging.getLogger("fgcs") + class GripperController: def __init__(self, drone: Drone) -> None: @@ -23,9 +27,9 @@ def __init__(self, drone: Drone) -> None: self.params = {} if (gripperEnabled := self.getEnabled()) is None: - self.drone.logger.warning("Could not get gripper state from drone.") + logger.warning("Could not get gripper state from drone.") elif gripperEnabled is False: - self.drone.logger.warning("Gripper is not enabled.") + logger.info("Gripper is not enabled.") else: self.params = { "gripAutoclose": self.drone.paramsController.getSingleParam( @@ -62,7 +66,7 @@ def getEnabled(self) -> Optional[bool]: param_name="GRIP_ENABLE" ) if not (gripper_enabled_response.get("success")): - self.drone.logger.warning( + logger.error( f"Gripper state could not be fetched from drone: {gripper_enabled_response.get('message')}" ) return None @@ -84,13 +88,13 @@ def setGripper(self, action: str) -> Response: Response """ if (gripperEnabled := self.getEnabled()) is None: - self.drone.logger.warning("Could not get gripper state from drone.") + logger.error("Could not get gripper state from drone.") return { "success": False, "message": "Could not get gripper state from drone.", } elif gripperEnabled is False: - self.drone.logger.error("Gripper is not enabled") + logger.warning("Could not set gripper, it is not enabled") return { "success": False, "message": "Gripper is not enabled", @@ -121,17 +125,22 @@ def setGripper(self, action: str) -> Response: self.drone.is_listening = True if commandAccepted(response, mavutil.mavlink.MAV_CMD_DO_GRIPPER): + logger.info(f"Sucessfully set gripper state to {action}") return { "success": True, "message": f"Setting gripper to {action}", } else: + logger.error( + f"Could not set gripper state to {action}, command not accepted" + ) return { "success": False, "message": "Setting gripper failed", } - except serial.serialutil.SerialException: + except serial.serialutil.SerialException as e: self.drone.is_listening = True + logger.error(e, exc_info=True) return { "success": False, "message": "Setting gripper failed, serial exception", diff --git a/radio/app/controllers/motorTestController.py b/radio/app/controllers/motorTestController.py index 50bbe5ef7..344eb4a73 100644 --- a/radio/app/controllers/motorTestController.py +++ b/radio/app/controllers/motorTestController.py @@ -3,6 +3,8 @@ from typing import TYPE_CHECKING, Optional import serial +import logging + from app.customTypes import ( MotorTestAllValues, MotorTestThrottleAndDuration, @@ -15,6 +17,8 @@ if TYPE_CHECKING: from app.drone import Drone +logger = logging.getLogger("fgcs") + class MotorTestController: def __init__(self, drone: Drone) -> None: @@ -41,16 +45,12 @@ def checkMotorTestValues( # self.drone.logger.info(f"Testing drone values: {data}") throttle = data.get("throttle", -1) if throttle is None or (not (0 <= throttle <= 100)): - self.drone.logger.error( - f"Invalid value for motor test throttle, got {throttle}" - ) + logger.error(f"Invalid value for motor test throttle, got {throttle}") return 0, 0, "Invalid value for throttle" duration = data.get("duration", -1) if duration is None or duration < 0: - self.drone.logger.error( - f"Invalid value for motor test duration, got {duration}" - ) + logger.error(f"Invalid value for motor test duration, got {duration}") return 0, 0, "Invalid value for duration" return throttle, duration, None @@ -74,9 +74,7 @@ def testOneMotor(self, data: MotorTestAllValues) -> Response: motor_instance = data.get("motorInstance", None) if motor_instance is None or motor_instance < 1: - self.drone.logger.error( - f"Invalid value for motor instance, got {motor_instance}" - ) + logger.error(f"Invalid value for motor instance, got {motor_instance}") return {"success": False, "message": "Invalid value for motorInstance"} self.drone.sendCommand( @@ -97,25 +95,23 @@ def testOneMotor(self, data: MotorTestAllValues) -> Response: self.drone.is_listening = True if commandAccepted(response, mavutil.mavlink.MAV_CMD_DO_MOTOR_TEST): - self.drone.logger.info(f"Motor test started for motor {motor_instance}") + logger.info(f"Motor test started for motor {motor_instance}") return { "success": True, "message": f"Motor test started for motor {motor_letter}", } else: - self.drone.logger.error( - f"Motor test for motor {motor_instance} not started", + logger.error( + f"Motor test for motor {motor_instance} not started: command not accepted", ) return { "success": False, "message": f"Motor test for motor {motor_letter} not started", } - except serial.serialutil.SerialException: + except serial.serialutil.SerialException as e: self.drone.is_listening = True - self.drone.logger.error( - f"Motor test for motor {motor_instance} not started, serial exception" - ) + logger.error(e, exc_info=True) return { "success": False, "message": f"Motor test for motor {motor_letter} not started, serial exception", @@ -139,9 +135,7 @@ def testMotorSequence(self, data: MotorTestThrottleDurationAndNumber) -> Respons num_motors = data.get("number_of_motors", None) if num_motors is None or num_motors < 1: - self.drone.logger.error( - f"Invalid value for number of motors, got {num_motors}" - ) + logger.error(f"Invalid value for number of motors, got {num_motors}") return {"success": False, "message": "Invalid value for number_of_motors"} self.drone.sendCommand( @@ -160,15 +154,18 @@ def testMotorSequence(self, data: MotorTestThrottleDurationAndNumber) -> Respons self.drone.is_listening = True if commandAccepted(response, mavutil.mavlink.MAV_CMD_DO_MOTOR_TEST): - self.drone.logger.info("Motor sequence test started") + logger.info( + "Motor sequence test started for motors " + + "->".join(str(i) for i in range(num_motors)) + ) return {"success": True, "message": "Motor sequence test started"} else: - self.drone.logger.error("Motor sequence test not started") + logger.error("Motor sequence test not started: command not accepted") return {"success": False, "message": "Motor sequence test not started"} - except serial.serialutil.SerialException: + except serial.serialutil.SerialException as e: self.drone.is_listening = True - self.drone.logger.error("Motor sequence test not started, serial exception") + logger.error(e, exc_info=True) return { "success": False, "message": "Motor sequence test not started, serial exception", @@ -196,9 +193,7 @@ def testAllMotors(self, data: MotorTestThrottleDurationAndNumber) -> Response: # Validate number of motors num_motors = data.get("number_of_motors", None) if num_motors is None or num_motors < 1: - self.drone.logger.error( - f"Invalid value for number of motors, got {num_motors}" - ) + logger.error(f"Invalid value for number of motors, got {num_motors}") return {"success": False, "message": "Invalid value for number_of_motors"} # Send all commands @@ -222,10 +217,10 @@ def testAllMotors(self, data: MotorTestThrottleDurationAndNumber) -> Response: ) if commandAccepted(response, mavutil.mavlink.MAV_CMD_DO_MOTOR_TEST): successful_responses += 1 - except serial.serialutil.SerialException: + except serial.serialutil.SerialException as e: self.drone.is_listening = True - self.drone.logger.error("All motor test not started, serial exception") + logger.error(e, exc_info=True) return { "success": False, "message": "All motor test not started, serial exception", @@ -235,10 +230,10 @@ def testAllMotors(self, data: MotorTestThrottleDurationAndNumber) -> Response: # Return data based on the number of successful command acknowledgements if successful_responses == num_motors: - self.drone.logger.info("All motor test started successfully") + logger.info("All motor test started successfully") return {"success": True, "message": "All motor test started successfully"} elif successful_responses < num_motors: - self.drone.logger.warning( + logger.warning( f"Number of successful responses ({successful_responses}) was less than number of motors ({num_motors})" ) return { @@ -246,8 +241,9 @@ def testAllMotors(self, data: MotorTestThrottleDurationAndNumber) -> Response: "message": f"All motor test successfully started {successful_responses} / {num_motors} motors", } else: # pragma: no cover - # We should never reach this (since we should only ever have successful_responses <= num_motors) - self.drone.logger.info( + # Defensive programming: This branch should not normally be reached (since successful_responses <= num_motors), + # but is included to handle unexpected cases, such as bugs in pymavlink or unforeseen input. + logger.warning( f"All motor test potentially started, but received {successful_responses} responses with {num_motors} motors" ) return { diff --git a/radio/app/drone.py b/radio/app/drone.py index cb5e2129a..a3e93f62a 100644 --- a/radio/app/drone.py +++ b/radio/app/drone.py @@ -1,7 +1,6 @@ import copy import os import time -import traceback from logging import Logger, getLogger from pathlib import Path from queue import Queue @@ -99,7 +98,7 @@ def __init__( self.connectionError: Optional[str] = None - self.logger.debug("Trying to setup master") + self.logger.info("Setting up master") if not Drone.checkBaudrateValid(baud): self.connectionError = ( @@ -111,13 +110,11 @@ def __init__( self.sendConnectionStatusUpdate("Connecting to drone") self.master: mavutil.mavserial = mavutil.mavlink_connection(port, baud=baud) except Exception as e: - self.logger.exception(traceback.format_exc()) self.master = None + self.logger.error(str(e)) if isinstance(e, SerialException): - self.logger.error(str(e)) self.connectionError = "Could not connect to drone, invalid port." elif isinstance(e, ConnectionRefusedError): - self.logger.error(str(e)) self.connectionError = "Could not connect to drone, connection refused." else: self.connectionError = str(e) diff --git a/radio/app/endpoints/comPorts.py b/radio/app/endpoints/comPorts.py index daf359cd6..90a66ee14 100644 --- a/radio/app/endpoints/comPorts.py +++ b/radio/app/endpoints/comPorts.py @@ -127,6 +127,7 @@ def connectToDrone(data: ConnectionDataType) -> None: if drone.connectionError is not None: socketio.emit("connection_error", {"message": drone.connectionError}) + logger.error(f"Failed to connect to drone: {drone.connectionError}") droneStatus.drone = None return diff --git a/radio/app/loggingConfig.py b/radio/app/loggingConfig.py new file mode 100644 index 000000000..5b8b364bf --- /dev/null +++ b/radio/app/loggingConfig.py @@ -0,0 +1,51 @@ +import os +import sys +import time +import socket +import logging + +from flask_socketio import SocketIO + + +class SocketIOHandler(logging.Handler): + def __init__(self, sio: SocketIO) -> None: + super().__init__() + self.socket = sio + + def emit(self, record) -> None: + try: + entry = self.format(record) + self.socket.emit( + "log", + { + "level": record.levelname, + "message": entry, + "timestamp": time.time(), + "file": record.filename, + "line": record.lineno, + }, + ) + except socket.error: + self.handleError(record) + + +def setup_logging(conn: SocketIO, debug: bool = False) -> None: + fgcs_logger = logging.getLogger("fgcs") + + fgcs_logger.setLevel(logging.DEBUG if debug else logging.INFO) + + flask_logger = logging.getLogger("werkzeug") + + flask_logger.setLevel(logging.WARNING) + + # Our test suite is stupid and all of them just check the last received message instead of filtering + # for the message they were expecting so we can't do socket logging in test environment + + if os.environ.get("PYTEST_VERSION") is None: + handler = SocketIOHandler(conn) + else: + handler = logging.StreamHandler() + handler.setFormatter(logging.Formatter('%(asctime)s [%(levelname)s] %(name)s: %(message)s')) + + fgcs_logger.addHandler(handler) + flask_logger.addHandler(handler) diff --git a/radio/app/utils.py b/radio/app/utils.py index d336eda34..a958cad0d 100644 --- a/radio/app/utils.py +++ b/radio/app/utils.py @@ -4,6 +4,7 @@ from pymavlink import mavutil from serial.tools import list_ports +from app import logger from app.customTypes import VehicleType from . import socketio @@ -19,10 +20,13 @@ def getComPort() -> str: while True: ports = list(list_ports.comports()) - print("Available COM ports:") - for i in range(len(ports)): - port = ports[i] - print(f"\t[{i}]\t{port.name}: {port.description}") + logger.info( + "Available COM PORTS: \n" + + "\n".join( + f"\t[{i}]\t{port.name}: {port.description}" + for i, port in enumerate(ports) + ) + ) inp_port = input("Enter a port index to connect to: ") if not inp_port.isdigit(): diff --git a/radio/tests/mission_test_files/upload_mission_helper.py b/radio/tests/mission_test_files/upload_mission_helper.py index f81fd4f7f..8c72c9fa7 100644 --- a/radio/tests/mission_test_files/upload_mission_helper.py +++ b/radio/tests/mission_test_files/upload_mission_helper.py @@ -1,5 +1,7 @@ from pymavlink import mavutil, mavwp +from app import logger + def uploadMission(file_name, mission_type, master): with open(file_name, "r") as f: @@ -74,4 +76,4 @@ def uploadMission(file_name, mission_type, master): master.mav.send(loader.wp(msg.seq)) - print(f"Uploaded {mission_type} with {loader.count()} items") + logger.info(f"Uploaded {mission_type} with {loader.count()} items")