diff --git a/.gitignore b/.gitignore index 71ea853..8f88528 100644 --- a/.gitignore +++ b/.gitignore @@ -92,3 +92,6 @@ typings/ out/ database + +# VS Code settings +.vscode/* \ No newline at end of file diff --git a/src/channelHandlers/browserstack-api.ts b/src/channelHandlers/browserstack-api.ts index d32c4db..a659451 100644 --- a/src/channelHandlers/browserstack-api.ts +++ b/src/channelHandlers/browserstack-api.ts @@ -1,5 +1,8 @@ import { parseAutomateTextLogs } from "../utils/text-logs-parser" import CONFIG from "../constants/config" +import { parseAutomateSessionLogs } from "../utils/latency-finder/session-logs-parser" +import { parseAutomateSeleniumLogs } from "../utils/latency-finder/selenium-logs-parser" +import { convertUTCToEpoch } from "../utils/latency-finder/helper" const BASE_URL = 'https://api.browserstack.com' @@ -201,3 +204,27 @@ function replaceElementIdDeep(obj: any, newId: string): any { return obj; } +export const getAutomateParsedSessionLogs = async (session: AutomateSessionResponse)=> { + const logs = await download(session.automation_session.logs); + const result = parseAutomateSessionLogs(logs); + return result; +} +export const getAutomateParsedSeleniumLogs = async (session: AutomateSessionResponse)=> { + const seleniumLogsUrl = `https://api.browserstack.com/automate/sessions/${session.automation_session.hashed_id}/seleniumlogs` + const logs = await download(seleniumLogsUrl); + + // Convert created_at to epoch (UTC) + const sessionCreatedAtUTC = convertUTCToEpoch( + session.automation_session.created_at + ); + // Extract just the date part from created_at + const date = session.automation_session.created_at.split("T")[0]; // date = "2025-11-13" + + const result = parseAutomateSeleniumLogs( + logs, + date, + sessionCreatedAtUTC + ); + + return result; +} diff --git a/src/constants/ipc-channels.ts b/src/constants/ipc-channels.ts index f75ebdc..e2a49cb 100644 --- a/src/constants/ipc-channels.ts +++ b/src/constants/ipc-channels.ts @@ -9,7 +9,9 @@ const CHANNELS = { BROWSERSTACK_START_SESSION:'BROWSERSTACK_START_SESSION', BROWSERSTACK_STOP_SESSION:'BROWSERSTACK_STOP_SESSION', BROWSERSTACK_EXECUTE_SESSION_COMMAND:'BROWSERSTACK_EXECUTE_SESSION_COMMAND', - ELECTRON_OPEN_URL:'ELECTRON_OPEN_URL' + ELECTRON_OPEN_URL:'ELECTRON_OPEN_URL', + GET_BROWSERSTACK_AUTOMATE_PARSED_SESSION_LOGS:'GET_BROWSERSTACK_AUTOMATE_PARSED_SESSION_LOGS', + GET_BROWSERSTACK_AUTOMATE_PARSED_SELENIUM_LOGS:'GET_BROWSERSTACK_AUTOMATE_PARSED_SELENIUM_LOGS' } export default CHANNELS \ No newline at end of file diff --git a/src/global.d.ts b/src/global.d.ts index 52a1047..e30ba7f 100644 --- a/src/global.d.ts +++ b/src/global.d.ts @@ -13,6 +13,8 @@ declare global { startSession: (options: StartSessionOptions) => Promise stopSession: (options: StopSessionOptions) => Promise executeCommand: (options: ExecuteCommandOptions) => any + getAutomateParsedSessionLogs: (session: AutomateSessionResponse) => Promise + getAutomateParsedSeleniumLogs: (session: AutomateSessionResponse) => Promise } type ElectronAPI = { @@ -112,4 +114,137 @@ declare global { hubUrl?: string } + + // latency-finder + + interface LogParams { + [key: string]: any; + } + + interface LogRequest { + created_at: number; + line_number: number; + out_time: number; + http_type: string; + action: string; + params: LogParams; + } + + interface LogResponse { + created_at: number; + line_number: number; + in_time: number; + params: LogParams; + } + + interface LogDebug { + created_at: number; + line_number: number; + url: string; + } + + interface Exchange { + id: number; + request?: LogRequest; + response?: LogResponse; + debug?: LogDebug; + } + + interface Summary { + total_requests: number; + session_started_at: number | null; + session_completed_at: number | null; + session_duration: number | null; + setup_time: number; + execution_time: number; + in_time: number; + out_time: number; + passed_requests: number; + failed_requests: number; + unknown_requests: number; + log_length: number; + setup_time_perc: number; + in_time_perc: number; + out_time_perc: number; + average_cycle_time: number; + average_serve_time: number; + average_wait_time: number; + passed_perc: number; + failed_perc: number; + unknown_perc: number; + } + + interface ScanResult { + summary: Summary; + exchanges: Exchange[]; + } + + + type Phase = "Setup" | "Session" | "Tear Down" | null; + + interface SeleniumLogLineType { + name: string; + identifier: string; + phase?: Phase; + } + + interface LogHeaders { + [key: string]: string; + } + + interface LogRequest { + created_at: number; + line_number: number; + out_time: number; + params?: any; + headers?: LogHeaders; + } + + interface LogResponse { + created_at?: number; + line_number?: number; + in_time?: number; + params?: any; + headers?: LogHeaders; + } + + interface SeleniumExchange { + id: number; + request: LogRequest; + response: LogResponse; + } + + interface SeleniumSummary { + total_requests: number; + dialect: string; + setup_polls: number; + tear_down_polls: number; + session_started_at: number; + session_completed_at: number; + driver_started_at: number; + driver_init_time: number; + session_duration: number | null; + setup_time: number; + execution_time: number; + in_time: number; + out_time: number; + passed_requests: number; + failed_requests: number; + unknown_requests: number; + log_length: number; + setup_time_perc: number; + in_time_perc: number; + out_time_perc: number; + average_cycle_time: number; + average_serve_time: number; + average_wait_time: number; + passed_perc: number; + failed_perc: number; + unknown_perc: number; + } + + interface SeleniumScanResult { + summary: SeleniumSummary; + exchanges: SeleniumExchange[]; + } } \ No newline at end of file diff --git a/src/index.ts b/src/index.ts index 66488cf..f77959e 100644 --- a/src/index.ts +++ b/src/index.ts @@ -8,8 +8,10 @@ import StorageKeys from './constants/storage-keys'; import CONFIG from './constants/config'; import { mkdirSync } from 'fs' -import { executeCommand, getAutomateSessionDetails, getParsedAutomateTextLogs, startBrowserStackSession, stopBrowserStackSession } from './channelHandlers/browserstack-api'; +import { executeCommand, getAutomateSessionDetails, getParsedAutomateTextLogs, startBrowserStackSession, stopBrowserStackSession, getAutomateParsedSeleniumLogs, getAutomateParsedSessionLogs, } from './channelHandlers/browserstack-api'; import { openExternalUrl } from './channelHandlers/electron-api'; + +import { get } from 'http'; // This allows TypeScript to pick up the magic constants that's auto-generated by Forge's Webpack // plugin that tells the Electron app where to look for the Webpack-bundled app code (depending on // whether you're running in development or production). @@ -93,6 +95,8 @@ app.whenReady().then(() => { ipcMain.handle(CHANNELS.GET_DEMO_CREDENTIALS, getBrowserStackDemoCredentials); ipcMain.handle(CHANNELS.GET_BROWSERSTACK_AUTOMATE_SESSION, (_, id) => getAutomateSessionDetails(id)) ipcMain.handle(CHANNELS.GET_BROWSERSTACK_AUTOMATE_PARSED_TEXT_LOGS, (_, session) => getParsedAutomateTextLogs(session)) + ipcMain.handle(CHANNELS.GET_BROWSERSTACK_AUTOMATE_PARSED_SESSION_LOGS, (_, session) => getAutomateParsedSessionLogs(session)) + ipcMain.handle(CHANNELS.GET_BROWSERSTACK_AUTOMATE_PARSED_SELENIUM_LOGS, (_, session) => getAutomateParsedSeleniumLogs(session)) ipcMain.handle(CHANNELS.BROWSERSTACK_START_SESSION, (_, options) => startBrowserStackSession(options)) ipcMain.handle(CHANNELS.BROWSERSTACK_STOP_SESSION, (_, options) => stopBrowserStackSession(options)) ipcMain.handle(CHANNELS.BROWSERSTACK_EXECUTE_SESSION_COMMAND, (_, options) => executeCommand(options)) diff --git a/src/preload.ts b/src/preload.ts index e8d35cc..a4fe37c 100644 --- a/src/preload.ts +++ b/src/preload.ts @@ -14,7 +14,9 @@ const browserstackAPI: BrowserStackAPI = { getAutomateParsedTextLogs: (session) => ipcRenderer.invoke(CHANNELS.GET_BROWSERSTACK_AUTOMATE_PARSED_TEXT_LOGS, session), startSession: (options) => ipcRenderer.invoke(CHANNELS.BROWSERSTACK_START_SESSION, options), stopSession: (options) => ipcRenderer.invoke(CHANNELS.BROWSERSTACK_STOP_SESSION, options), - executeCommand: (options) => ipcRenderer.invoke(CHANNELS.BROWSERSTACK_EXECUTE_SESSION_COMMAND, options) + executeCommand: (options) => ipcRenderer.invoke(CHANNELS.BROWSERSTACK_EXECUTE_SESSION_COMMAND, options), + getAutomateParsedSessionLogs: (session)=>ipcRenderer.invoke(CHANNELS.GET_BROWSERSTACK_AUTOMATE_PARSED_SESSION_LOGS,session), + getAutomateParsedSeleniumLogs: (session)=>ipcRenderer.invoke(CHANNELS.GET_BROWSERSTACK_AUTOMATE_PARSED_SELENIUM_LOGS,session), } const electronAPI: ElectronAPI = { diff --git a/src/renderer/components/sidebar.tsx b/src/renderer/components/sidebar.tsx index fea9a56..0272eb0 100644 --- a/src/renderer/components/sidebar.tsx +++ b/src/renderer/components/sidebar.tsx @@ -1,51 +1,57 @@ -import { NavLink, useLocation } from "react-router-dom" -import Products from "../products" +import { NavLink, useLocation } from "react-router-dom"; +import Products from "../products"; const TopMenu = [ - { - title: "Configurations", - path: '/' - }, -] + { + title: "Configurations", + path: "/", + }, +]; const ProductsMenu = [ - { - title: "Automate", - path: '/automate' - }, - { - title: "App Automate", - path: '/app-automate' - }, - { - title: "Percy", - path: '/percy' - }, - { - title: "Accessibility", - path: '/accessibility' - } -] + { + title: "Automate", + path: "/automate", + }, + { + title: "App Automate", + path: "/app-automate", + }, + { + title: "Percy", + path: "/percy", + }, + { + title: "Accessibility", + path: "/accessibility", + }, +]; export default function Sidebar() { - const location = useLocation() - console.log(location) - return ( -
-
    - {TopMenu.map((item) => { - const isActive = location.pathname == item.path - return ( -
  • {item.title}
  • - ) - })} - - {Products.map((item) => { - const isActive = location.pathname.includes(item.path) - return ( -
  • {item.name}
  • - ) - })} -
-
- ) -} \ No newline at end of file + const location = useLocation(); + console.log(location); + return ( +
+
    + {TopMenu.map((item) => { + const isActive = location.pathname == item.path; + return ( +
  • + {item.title} +
  • + ); + })} + + {Products.map((item) => { + const isActive = location.pathname.includes(item.path); + return ( +
  • + {item.name} +
  • + ); + })} +
+
+ ); +} diff --git a/src/renderer/products.ts b/src/renderer/products.ts index b8afc63..ff76a69 100644 --- a/src/renderer/products.ts +++ b/src/renderer/products.ts @@ -1,26 +1,28 @@ import AutomatePage from "./routes/automate"; import ReplayTool from "./routes/automate/tools/replay-tool"; +import LatencyFinder from "./routes/automate/tools/latency-finder"; const Products = [ - { - name:"Automate", - path:'/automate', - page: AutomatePage, - tools:[ - { - title:"Replay Toolkit", - description:"Replays the sessions on BrowserStack by parsing Raw Logs", - path:'/automate/replay-toolkit', - component: ReplayTool - }, - { - title:"Latency Analyser", - description:"Analyses time spend on different actions. Helpful to identify inside/outside time for a customer session.", - path:'/automate/latency-analyser', - component: null - } - ] - } -] + { + name: "Automate", + path: "/automate", + page: AutomatePage, + tools: [ + { + title: "Replay Toolkit", + description: "Replays the sessions on BrowserStack by parsing Raw Logs", + path: "/automate/replay-toolkit", + component: ReplayTool, + }, + { + title: "Latency Analyser", + description: + "Analyses time spend on different actions. Helpful to identify inside/outside time for a customer session.", + path: "/automate/latency-analyser", + component: LatencyFinder, + }, + ], + }, +]; -export default Products; \ No newline at end of file +export default Products; diff --git a/src/renderer/routes/automate/tools/latency-finder.tsx b/src/renderer/routes/automate/tools/latency-finder.tsx new file mode 100644 index 0000000..9589bc0 --- /dev/null +++ b/src/renderer/routes/automate/tools/latency-finder.tsx @@ -0,0 +1,417 @@ +import Form from "rc-field-form"; +import { usePromise } from "../../../hooks/use-promise"; +import { useState } from "react"; +import { toast } from "react-toastify"; + +const { Field } = Form; + +function Info({ label, value }: { label: string; value: string }) { + return ( +
+ + {label} + + + {value} + +
+ ); +} + +export default function LatencyFinder() { + const [fetchSessionDetails, fetchingSession, session] = usePromise( + window.browserstackAPI.getAutomateSessionDetails + ); + + const [parseSessionLogs, parsingSessionLogs, sessionLogsResult] = usePromise( + window.browserstackAPI.getAutomateParsedSessionLogs + ); + + const [parseSeleniumLogs, parsingSeleniumLogs, seleniumLogsResult] = + usePromise(window.browserstackAPI.getAutomateParsedSeleniumLogs); + + const [sessionLogsSummary, setSessionLogsSummary] = + useState(null); + const [seleniumLogsSummary, setSeleniumLogsSummary] = + useState(null); + + const [activeTab, setActiveTab] = useState<"session" | "selenium">("session"); + + const OpenSession = (input: any) => { + toast + .promise( + fetchSessionDetails(input.sessionId).then(async (res) => { + // parse session logs + const sessionLogsRes = await parseSessionLogs(res); + const seleniumRes = await parseSeleniumLogs(res); + + return { + sessionLogsRes, + seleniumRes, + }; + }), + { + pending: "Opening Session...", + success: "Session Loaded", + error: + "Failed to Load session probably invalid session ID. Please check console for errors", + } + ) + .then(({ sessionLogsRes, seleniumRes }) => { + setSessionLogsSummary(sessionLogsRes.summary); + setSeleniumLogsSummary(seleniumRes.summary); + }) + .catch((err) => { + console.error(err); + }); + }; + + return ( +
+

Latency Finder

+ +
+ + + + +
+ + {/* Session Header Card */} + {session && ( +
+
+

+ {session.automation_session.name || "Unnamed Session"} +

+ +
+ + + + + + + + +
+
+
+ )} + + {/* Tabs for Session Logs / Selenium Logs */} + {(sessionLogsSummary || seleniumLogsSummary) && ( +
+
+ + +
+ + {/* Session Logs Tab */} + {activeTab === "session" && sessionLogsSummary && ( + <> +

+ Session Logs +

+
+
+

+ Log Summary +

+
+ + + + +
+ +

+ Time Stats (In Seconds) +

+
+ + + + + + + +
+ +

+ Status Stats +

+
+ + + +
+
+
+ + )} + + {/* Selenium Logs Tab */} + {activeTab === "selenium" && seleniumLogsSummary && ( + <> +

+ Selenium Logs +

+
+
+

+ Log Summary +

+
+ + + + + + + + 0 + ? (seleniumLogsSummary.driver_init_time / 1000).toString() + : "N/A" + } + /> + +
+ +

+ Time Stats (In Seconds) +

+
+ = 0 + ? (seleniumLogsSummary.setup_time / 1000).toString() + : "N/A" + } + /> + = 0 + ? (seleniumLogsSummary.execution_time / 1000).toString() + : "N/A" + } + /> + = 0 + ? (seleniumLogsSummary.in_time / 1000).toString() + : "N/A" + } + /> + = 0 + ? (seleniumLogsSummary.out_time / 1000).toString() + : "N/A" + } + /> + = 0 + ? ( + seleniumLogsSummary.average_cycle_time / 1000 + ).toString() + : "N/A" + } + /> + = 0 + ? ( + seleniumLogsSummary.average_serve_time / 1000 + ).toString() + : "N/A" + } + /> + = 0 + ? ( + seleniumLogsSummary.average_wait_time / 1000 + ).toString() + : "N/A" + } + /> +
+ +

+ Status Stats +

+
+ + + +
+
+
+ + )} +
+ )} +
+ ); +} diff --git a/src/utils/latency-finder/helper.ts b/src/utils/latency-finder/helper.ts new file mode 100644 index 0000000..63958a0 --- /dev/null +++ b/src/utils/latency-finder/helper.ts @@ -0,0 +1,8 @@ +// Helper: convert UTC timestamp to epoch ms +export const convertUTCToEpoch = (time: string): number => { + return Date.parse(time); +}; + +export const nullCheck = (value: number | null | undefined): number => { + return value === null || typeof value === "undefined" ? -1 : value; +}; \ No newline at end of file diff --git a/src/utils/latency-finder/selenium-logs-parser.ts b/src/utils/latency-finder/selenium-logs-parser.ts new file mode 100644 index 0000000..ef37bb0 --- /dev/null +++ b/src/utils/latency-finder/selenium-logs-parser.ts @@ -0,0 +1,505 @@ +import { convertUTCToEpoch, nullCheck } from "./helper"; + +export const parseAutomateSeleniumLogs = ( + logString: string, + date: string, + sessionCreatedAtUTC: number +): SeleniumScanResult => { + const seleniumLogLine: SeleniumLogLineType[] = [ + { + name: "start_session", + identifier: "/session: Executing POST on /session ", + phase: "Setup", + }, + { + name: "polling", + identifier: "Polling http://localhost", + }, + { + name: "dialect", + identifier: "Detected dialect", + }, + { + name: "start_driver", + identifier: "Started new session", + phase: "Session", + }, + { + name: "request", + identifier: "Found handler", + }, + { + name: "request_handler", + identifier: "Handler thread for session", + }, + { + name: "upstream", + identifier: "To upstream", + }, + { + name: "http_request", + identifier: "writeRequests", + }, + { + name: "http_response", + identifier: "getInputStream0", + }, + { + name: "downstream", + identifier: "To downstream", + }, + { + name: "stop_session", + identifier: "Removing session", + phase: "Tear Down", + }, + ]; + + const dataCenters: Record< + string, + { + time_zone: string; + } + > = { + time_zone_1: { time_zone: "-08:00" }, + time_zone_2: { time_zone: "-07:00" }, + time_zone_3: { time_zone: "-05:00" }, + time_zone_4: { time_zone: "-04:00" }, + time_zone_5: { time_zone: "+01:00" }, + time_zone_6: { time_zone: "+02:00" }, + time_zone_7: { time_zone: "+05:30" }, + time_zone_8: { time_zone: "+10:00" }, + }; + + const logLines = logString.split("\n"); + + let phase: Phase = null; + let sessionStartedAt: number | null = null; + let setupPollCount = 0; + let dialect = "Unkown"; + let driverStartedAt: number | null = null; + let currentExchange: Partial & { + request?: LogRequest; + response?: LogResponse; + } = {}; + let exchangeId = 0; + let prevousCreated: number | null = null; + let totalOutTime = 0; + let totalInTime = 0; + let statusUnknown = 0; + let statusPassed = 0; + let statusFailed = 0; + const exchanges: SeleniumExchange[] = []; + let tearDownPollCount = 0; + let sessionCompletedAt: number | null = null; + let sessionDuration: number | null = null; + let row = 1; + + // Find first non-empty line to derive time + let firstLine: string | null = null; + for (let i = 0; i < logLines.length && !firstLine; ++i) { + const trimmed = logLines[i].trim(); + if (trimmed) firstLine = trimmed; + } + + let min = Number.MAX_SAFE_INTEGER; + let currentTimeZone: { time_zone: string } = { time_zone: "+00:00" }; + + if (firstLine) { + Object.keys(dataCenters).forEach((timeZone) => { + const tz = dataCenters[timeZone].time_zone; + const timePart = firstLine!.split(" ")[0]; + const convertedEpoch = convertUTCToEpoch(`${date}T${timePart}${tz}`); + const diff = Math.abs(sessionCreatedAtUTC - convertedEpoch); + if (diff < min) { + min = diff; + currentTimeZone = dataCenters[timeZone]; + } + }); + } + + logLines.forEach((logLine, index) => { + const line = logLine.trim(); + if (!line) return; + + const split = line.split(" "); + const timeStr = split[0]; + + const createdAtUTC = convertUTCToEpoch( + `${date}T${timeStr}${currentTimeZone["time_zone"]}` + ); + + if (isNaN(createdAtUTC)) return; + + let type: SeleniumLogLineType | undefined; + + seleniumLogLine.forEach((lineType) => { + if (line.includes(lineType.identifier)) { + type = lineType; + phase = lineType.phase ?? phase; + } + }); + + sessionCompletedAt = createdAtUTC; + if (sessionStartedAt !== null) { + sessionDuration = sessionCompletedAt - sessionStartedAt; + } + + if (!type) { + console.log(`Line skipped: ${line}`); + return; + } + + const phaseEvent = `${phase}-${type.name}-${row}`; + const lineNumber = index + 1; + + switch (phaseEvent) { + // Setup + case `Setup-${seleniumLogLine[0].name}-1`: { + sessionStartedAt = createdAtUTC; + break; + } + case `Setup-${seleniumLogLine[1].name}-1`: { + setupPollCount++; + break; + } + case `Setup-${seleniumLogLine[2].name}-1`: { + const parts = line.split("Detected dialect:"); + if (parts[1]) { + dialect = parts[1].trim(); + } + break; + } + + // Session: started driver + case `Session-${seleniumLogLine[3].name}-1`: { + driverStartedAt = createdAtUTC; + break; + } + + // Session: Found handler (request start) + case `Session-${seleniumLogLine[4].name}-1`: { + const request: LogRequest = { + created_at: createdAtUTC, + line_number: lineNumber, + out_time: createdAtUTC - (prevousCreated ?? createdAtUTC), + http_type: "", + action: "" + }; + + currentExchange = { + id: ++exchangeId, + request, + }; + + totalOutTime += request.out_time; + row = 2; + break; + } + + // Session: To upstream (request params) + case `Session-${seleniumLogLine[6].name}-2`: { + let params: any = {}; + try { + params = JSON.parse(line.split("To upstream:")[1]); + } catch { + params = { message: line.split("To upstream:")[1] }; + } + + currentExchange = { + ...currentExchange, + request: { + ...(currentExchange.request as LogRequest), + params, + }, + }; + row = 3; + break; + } + + // Session: HTTP request headers + case `Session-${seleniumLogLine[7].name}-3`: { + const headersStr = line.split("pairs:")[1]; + if (headersStr) { + const headers = JSON.parse( + headersStr + .replace(/}{/g, '","') + .replace(/: /g, '": "') + .replace(/{/g, '{"') + .replace(/}/g, '"}') + ) as LogHeaders; + + currentExchange = { + ...currentExchange, + request: { + ...(currentExchange.request as LogRequest), + headers, + }, + }; + } + row = 4; + break; + } + + // Session: HTTP response headers + case `Session-${seleniumLogLine[8].name}-4`: { + const headersStr = line.split("pairs:")[1]; + let headers: LogHeaders = {}; + if (headersStr) { + headers = JSON.parse( + headersStr + .replace(/}{/g, '","') + .replace(/: /g, '": "') + .replace(/{/g, '{"') + .replace(/}/g, '"}') + ); + } + + currentExchange = { + ...currentExchange, + response: { + ...(currentExchange.response || {}), + headers, + }, + }; + row = 5; + break; + } + + // Session: To downstream (response body) + case `Session-${seleniumLogLine[9].name}-5`: { + prevousCreated = createdAtUTC; + + let parsedParams: any = {}; + const downstreamPart = line.split("To downstream:")[1]; + + if (downstreamPart) { + try { + parsedParams = JSON.parse(downstreamPart); + } catch { + parsedParams = { message: downstreamPart }; + } + } + + const request = currentExchange.request as LogRequest; + + const response: LogResponse = { + ...(currentExchange.response || {}), + created_at: createdAtUTC, + line_number: lineNumber, + in_time: createdAtUTC - request.created_at, + params: parsedParams, + }; + + currentExchange = { + ...currentExchange, + response, + }; + + totalInTime += response.in_time ?? 0; + + const headers = response.headers || {}; + const nullHeader = headers["null"]; + + if (typeof nullHeader === "undefined") { + statusUnknown++; + } else if (nullHeader.includes("200 OK")) { + statusPassed++; + } else { + statusFailed++; + } + + exchanges.push(currentExchange as SeleniumExchange); + currentExchange = {}; + row = 1; + break; + } + + // Tear Down: Removing session (request start) + case `Tear Down-${seleniumLogLine[10].name}-1`: { + const request: LogRequest = { + created_at: createdAtUTC, + line_number: lineNumber, + out_time: createdAtUTC - (prevousCreated ?? createdAtUTC), + http_type: "", + action: "" + }; + + currentExchange = { + id: ++exchangeId, + request, + }; + + totalOutTime += request.out_time; + row = 2; + break; + } + + // Tear Down: HTTP request headers + case `Tear Down-${seleniumLogLine[7].name}-2`: { + const headersStr = line.split("pairs:")[1]; + if (headersStr) { + const headers = JSON.parse( + headersStr + .replace(/}{/g, '","') + .replace(/: /g, '": "') + .replace(/{/g, '{"') + .replace(/}/g, '"}') + ) as LogHeaders; + + currentExchange = { + ...currentExchange, + request: { + ...(currentExchange.request as LogRequest), + headers, + }, + }; + } + row = 3; + break; + } + + // Tear Down: HTTP response headers + case `Tear Down-${seleniumLogLine[8].name}-3`: { + const headersStr = line.split("pairs:")[1]; + if (headersStr) { + const headers = JSON.parse( + headersStr + .replace(/}{/g, '","') + .replace(/: /g, '": "') + .replace(/{/g, '{"') + .replace(/}/g, '"}') + ) as LogHeaders; + + currentExchange = { + ...currentExchange, + response: { + ...(currentExchange.response || {}), + headers, + }, + }; + } + row = 4; + break; + } + + // Tear Down: To downstream (response body) + case `Tear Down-${seleniumLogLine[9].name}-4`: { + prevousCreated = createdAtUTC; + + let params: any = {}; + const downstreamPart = line.split("To downstream:")[1]; + if (downstreamPart) { + try { + params = JSON.parse(downstreamPart); + } catch { + params = { message: downstreamPart }; + } + } + + const request = currentExchange.request as LogRequest; + + const response: LogResponse = { + ...(currentExchange.response || {}), + created_at: createdAtUTC, + line_number: lineNumber, + in_time: createdAtUTC - request.created_at, + params, + }; + + currentExchange = { + ...currentExchange, + response, + }; + + totalInTime += response.in_time ?? 0; + + const headers = response.headers || {}; + const nullHeader = headers["null"]; + + if (typeof nullHeader === "undefined") { + statusUnknown++; + } else if (nullHeader.includes("200 OK")) { + statusPassed++; + } else { + statusFailed++; + } + + exchanges.push(currentExchange as SeleniumExchange); + currentExchange = {}; + row = 5; + break; + } + + // Tear Down: polling + case `Tear Down-${seleniumLogLine[1].name}-5`: { + tearDownPollCount++; + row = 1; + break; + } + + default: { + console.log(`Line skipped: ${line}`); + break; + } + } + }); + + const driverInitTime = + driverStartedAt !== null && sessionStartedAt !== null + ? driverStartedAt - sessionStartedAt + : null; + + const executionTime = totalInTime + totalOutTime; + const setupTime = + sessionDuration !== null ? sessionDuration - executionTime : null; + + const summary: SeleniumSummary = { + total_requests: exchanges.length, + dialect, + setup_polls: setupPollCount, + tear_down_polls: tearDownPollCount, + session_started_at: nullCheck(sessionStartedAt), + session_completed_at: nullCheck(sessionCompletedAt), + driver_started_at: nullCheck(driverStartedAt), + driver_init_time: nullCheck(driverInitTime), + session_duration: sessionDuration, + setup_time: nullCheck(setupTime), + execution_time: nullCheck(executionTime), + in_time: totalInTime || -1, + out_time: totalOutTime || -1, + passed_requests: statusPassed, + failed_requests: statusFailed, + unknown_requests: statusUnknown, + log_length: logLines.length, + setup_time_perc: nullCheck( + sessionDuration ? (setupTime! * 100) / sessionDuration : null + ), + in_time_perc: nullCheck( + sessionDuration ? (totalInTime * 100) / sessionDuration : null + ), + out_time_perc: nullCheck( + sessionDuration ? (totalOutTime * 100) / sessionDuration : null + ), + average_cycle_time: nullCheck( + exchanges.length ? executionTime / exchanges.length : null + ), + average_serve_time: nullCheck( + exchanges.length ? totalInTime / exchanges.length : null + ), + average_wait_time: nullCheck( + exchanges.length ? totalOutTime / exchanges.length : null + ), + passed_perc: nullCheck( + exchanges.length ? (statusPassed * 100) / exchanges.length : null + ), + failed_perc: nullCheck( + exchanges.length ? (statusFailed * 100) / exchanges.length : null + ), + unknown_perc: nullCheck( + exchanges.length ? (statusUnknown * 100) / exchanges.length : null + ), + }; + + return { summary, exchanges }; +}; diff --git a/src/utils/latency-finder/session-logs-parser.ts b/src/utils/latency-finder/session-logs-parser.ts new file mode 100644 index 0000000..2d5fc85 --- /dev/null +++ b/src/utils/latency-finder/session-logs-parser.ts @@ -0,0 +1,224 @@ +import { convertUTCToEpoch } from "./helper"; + +export const parseAutomateSessionLogs = ( + logString: string +): ScanResult => { + const sessionLogLine = { + request: { identifier: "REQUEST" }, + start: { identifier: "START_SESSION" }, + debug: { identifier: "DEBUG" }, + response: { identifier: "RESPONSE" }, + stop: { identifier: "STOP_SESSION" }, + }; + + const logLines = logString.split("\n"); + + let sessionStartedAt: number | null = null; + let sessionCompletedAt: number | null = null; + let sessionDuration: number | null = null; + let started = false; + + const exchanges: Exchange[] = []; + let currentExchange: Partial = {}; + let exchangeId = 0; + let prevousCreated: number | null = null; + + let totalInTime = 0; + let totalOutTime = 0; + let statusUnknown = 0; + let statusPassed = 0; + let statusFailed = 0; + + logLines.forEach((logLine, index) => { + const line = logLine.trim(); + if (!line) return; + + const splittedLine = line.split(" "); + const lineNumber = index + 1; + + const createdAt = convertUTCToEpoch( + `${splittedLine[0]} ${splittedLine[1]} UTC` + ); + + const type = splittedLine[2]; + const paramIndex = line.indexOf("{"); + + let params: LogParams = {}; + + // Safe JSON parse + if (paramIndex > -1 && line[paramIndex - 1] !== "[") { + try { + params = JSON.parse(line.substring(paramIndex)); + } catch { + params = {}; + } + } + + sessionStartedAt = sessionStartedAt ?? createdAt; + sessionCompletedAt = createdAt; + sessionDuration = sessionCompletedAt - sessionStartedAt; + + switch (type) { + // REQUEST + case sessionLogLine.request.identifier: { + const request: LogRequest = { + created_at: createdAt, + line_number: lineNumber, + out_time: createdAt - (prevousCreated ?? createdAt), + http_type: splittedLine[5], + action: splittedLine[6], + params, + }; + + currentExchange = { ...currentExchange, request }; + totalOutTime += request.out_time; + break; + } + + // START_SESSION + case sessionLogLine.start.identifier: { + const response: LogResponse = { + created_at: createdAt, + line_number: lineNumber, + in_time: createdAt - (currentExchange.request!.created_at), + params: { ...params, status: "Unknown" }, + }; + + const exchange: Exchange = { + id: ++exchangeId, + ...currentExchange, + response, + }; + + const status = response.params.status; + + if (status === undefined) statusUnknown++; + else if (status === 0) statusPassed++; + else statusFailed++; + + exchanges.push(exchange); + currentExchange = {}; + break; + } + + // DEBUG + case sessionLogLine.debug.identifier: { + const debug: LogDebug = { + created_at: createdAt, + line_number: lineNumber, + url: splittedLine[3], + }; + + currentExchange = { ...currentExchange, debug }; + break; + } + + // RESPONSE + case sessionLogLine.response.identifier: { + prevousCreated = createdAt; + + const response: LogResponse = { + created_at: createdAt, + line_number: lineNumber, + in_time: createdAt - currentExchange.request!.created_at, + params, + }; + + const exchange: Exchange = { + id: ++exchangeId, + ...currentExchange, + response, + }; + + if (started) { + totalInTime += response.in_time; + } else { + started = true; + } + + let status = response.params.status; + + if (response.params.value?.error) { + response.params.status = "Failed"; + statusFailed++; + } else if (typeof status === "undefined") { + response.params.status = "Unknown"; + statusUnknown++; + } else if (status === 0) { + response.params.status = "Passed"; + statusPassed++; + } else { + response.params.status = "Unknown"; + statusUnknown++; + } + + exchanges.push(exchange); + currentExchange = {}; + break; + } + + // STOP_SESSION + case sessionLogLine.stop.identifier: { + const request: LogRequest = { + created_at: createdAt, + line_number: lineNumber, + out_time: createdAt - (prevousCreated ?? createdAt), + http_type: "", + action: "bs_stop", + params: {}, + }; + + const response: LogResponse = { + created_at: createdAt, + line_number: lineNumber, + in_time: 0, + params: { ...params, status: "Unknown" }, + }; + + const exchange: Exchange = { + id: ++exchangeId, + request, + response, + }; + + totalOutTime += request.out_time; + statusUnknown++; + + exchanges.push(exchange); + currentExchange = {}; + break; + } + } + }); + + // Final Computation + + const executionTime = totalInTime + totalOutTime; + const setupTime = (sessionDuration ?? 0) - executionTime; + + const summary: Summary = { + total_requests: exchanges.length, + session_started_at: sessionStartedAt, + session_completed_at: sessionCompletedAt, + session_duration: sessionDuration, + setup_time: setupTime, + execution_time: executionTime, + in_time: totalInTime, + out_time: totalOutTime, + passed_requests: statusPassed, + failed_requests: statusFailed, + unknown_requests: statusUnknown, + log_length: logLines.length, + setup_time_perc: (setupTime * 100) / (sessionDuration ?? 1), + in_time_perc: (totalInTime * 100) / (sessionDuration ?? 1), + out_time_perc: (totalOutTime * 100) / (sessionDuration ?? 1), + average_cycle_time: executionTime / exchanges.length, + average_serve_time: totalInTime / exchanges.length, + average_wait_time: totalOutTime / exchanges.length, + passed_perc: (statusPassed * 100) / exchanges.length, + failed_perc: (statusFailed * 100) / exchanges.length, + unknown_perc: (statusUnknown * 100) / exchanges.length, + }; + + return { summary, exchanges }; +}; \ No newline at end of file