diff --git a/web/cypress/e2e/integration/logs-page.cy.ts b/web/cypress/e2e/integration/logs-page.cy.ts index 44005dea2..cfcabab5f 100644 --- a/web/cypress/e2e/integration/logs-page.cy.ts +++ b/web/cypress/e2e/integration/logs-page.cy.ts @@ -163,6 +163,62 @@ describe('Logs Page', () => { }); }); + it('displays a Loki error payload returned with HTTP 200', () => { + cy.intercept(QUERY_RANGE_STREAMS_URL_MATCH, { + statusCode: 200, + body: { + status: 'error', + errorType: 'bad_data', + error: 'parse error at line 1, col 1: unexpected IDENTIFIER', + }, + }).as('queryRangeStreams'); + + cy.visit(LOGS_PAGE_URL); + + cy.wait('@queryRangeStreams'); + + cy.byTestID(TestIds.LogsTable) + .should('exist') + .within(() => { + cy.contains(/bad_data/i); + cy.contains('parse error at line 1, col 1: unexpected IDENTIFIER'); + }); + }); + + it('keeps the latest query results when an earlier request completes late', () => { + let requestCount = 0; + + cy.intercept(QUERY_RANGE_STREAMS_URL_MATCH, (req) => { + requestCount += 1; + const body = queryRangeStreamsValidResponse({ + message: + requestCount === 1 + ? 'initial result' + : requestCount === 2 + ? 'stale result' + : 'latest result', + }); + + req.reply(requestCount === 2 ? { body, delay: 3_000 } : body); + }).as('queryRangeStreams'); + + cy.visit(LOGS_PAGE_URL); + cy.wait('@queryRangeStreams'); + + cy.wait(1_100); + cy.byTestID(TestIds.SyncButton).click(); + cy.byTestID(TestIds.TimeRangeDropdown).click(); + cy.contains('Last 6 hours').click(); + + cy.contains('latest result').should('exist'); + cy.byTestID(TestIds.LoadMoreLogs).should('exist'); + + cy.wait(3_100); + cy.contains('latest result').should('exist'); + cy.contains('stale result').should('not.exist'); + cy.byTestID(TestIds.LoadMoreLogs).should('exist'); + }); + it('executes a query when "run query" is pressed', () => { cy.intercept( QUERY_RANGE_STREAMS_URL_MATCH, @@ -318,6 +374,25 @@ describe('Logs Page', () => { cy.byTestID(TestIds.TimeRangeDropdown).find('button').should('contain', 'Last 6 hours'); }); + it('does not refresh while a log request is pending', () => { + cy.intercept(QUERY_RANGE_STREAMS_URL_MATCH, (req) => { + req.reply({ + body: queryRangeStreamsValidResponse({ message: TEST_MESSAGE }), + delay: 30_000, + }); + }).as('queryRangeStreams'); + + cy.visit(LOGS_PAGE_URL); + cy.get('@queryRangeStreams.all').should('have.length', 1); + cy.clock(); + + cy.byTestID(TestIds.RefreshIntervalDropdown).click(); + cy.contains('15 seconds').click(); + cy.tick(15_000); + + cy.get('@queryRangeStreams.all').should('have.length', 1); + }); + it('disables query executors when the query is empty', () => { cy.intercept( QUERY_RANGE_STREAMS_URL_MATCH, diff --git a/web/eslint.config.ts b/web/eslint.config.ts index d32630364..5c6b134dc 100644 --- a/web/eslint.config.ts +++ b/web/eslint.config.ts @@ -20,6 +20,12 @@ const compat = new FlatCompat({ export default defineConfig([ { + linterOptions: { + // eslint --fix will get in a loop where there is no error so it deletes the directive, + // which in turn causes the error to then be shown. + reportUnusedDisableDirectives: 'off', + }, + extends: fixupConfigRules( compat.extends( 'eslint:recommended', diff --git a/web/src/__tests__/loki-client.spec.ts b/web/src/__tests__/loki-client.spec.ts index 5addc369b..483e98b71 100644 --- a/web/src/__tests__/loki-client.spec.ts +++ b/web/src/__tests__/loki-client.spec.ts @@ -1,5 +1,5 @@ import { SchemaConfig } from '../logs.types'; -import { getFetchConfig } from '../loki-client'; +import { assertQueryRangeResponse, getFetchConfig, throwResponseError } from '../loki-client'; jest.mock('@openshift-console/dynamic-plugin-sdk', () => ({ consoleFetchJSON: jest.fn(), @@ -64,4 +64,20 @@ describe('Loki Client', () => { expect(getFetchConfig(config)).toEqual(expectedFetchConfig); }); }); + + it('rejects Loki error responses', () => { + expect(() => + throwResponseError({ + status: 'error', + errorType: 'bad_data', + error: 'parse error at line 1, col 1', + }), + ).toThrow('bad_data: parse error at line 1, col 1'); + }); + + it('rejects malformed successful responses', () => { + expect(() => assertQueryRangeResponse({ status: 'success', data: {} })).toThrow( + 'Invalid Loki query response: missing data.result', + ); + }); }); diff --git a/web/src/components/refresh-interval-dropdown.tsx b/web/src/components/refresh-interval-dropdown.tsx index ae91b6209..2a4840cb6 100644 --- a/web/src/components/refresh-interval-dropdown.tsx +++ b/web/src/components/refresh-interval-dropdown.tsx @@ -29,11 +29,13 @@ const refreshIntervalOptions = [ interface RefreshIntervalDropdownProps { onRefresh?: () => void; isDisabled?: boolean; + refreshEnabled?: boolean; } export const RefreshIntervalDropdown: FC = ({ onRefresh, isDisabled = false, + refreshEnabled = true, }) => { const { t } = useTranslation('plugin__logging-view-plugin'); @@ -51,6 +53,9 @@ export const RefreshIntervalDropdown: FC = ({ const onRefreshRef = useRef(onRefresh); // eslint-disable-next-line react-hooks/refs onRefreshRef.current = onRefresh; + const refreshEnabledRef = useRef(refreshEnabled); + // eslint-disable-next-line react-hooks/refs + refreshEnabledRef.current = refreshEnabled; const clearTimer = () => { if (timer.current) { @@ -70,8 +75,14 @@ export const RefreshIntervalDropdown: FC = ({ clearTimer(); if (delay !== 0) { - onRefreshRef.current?.(); - timer.current = setInterval(() => onRefreshRef.current?.(), delay); + if (refreshEnabledRef.current) { + onRefreshRef.current?.(); + } + timer.current = setInterval(() => { + if (refreshEnabledRef.current) { + onRefreshRef.current?.(); + } + }, delay); } return () => clearTimer(); diff --git a/web/src/components/virtualized-logs-table.tsx b/web/src/components/virtualized-logs-table.tsx index 871b3addf..5b5e00b75 100644 --- a/web/src/components/virtualized-logs-table.tsx +++ b/web/src/components/virtualized-logs-table.tsx @@ -27,6 +27,7 @@ import { import { useTranslation } from 'react-i18next'; import { LogTableData, Schema } from '../logs.types'; import { getSeverityColor, Severity } from '../severity'; +import { TestIds } from '../test-ids'; import { CenteredContainer } from './centered-container'; import { ErrorMessage } from './error-message'; @@ -420,6 +421,7 @@ export const VirtualizedLogsTable = ({ { setScrollToIndex(data.length - 1); onLoadMore?.(); diff --git a/web/src/hooks/useLogs.ts b/web/src/hooks/useLogs.ts index 0db62c714..854fe007e 100644 --- a/web/src/hooks/useLogs.ts +++ b/web/src/hooks/useLogs.ts @@ -24,6 +24,8 @@ import { useContext, useReducer, useRef } from 'react'; const DEFAULT_TIME_SPAN = '1h'; const STREAMING_MAX_LOGS_LIMIT = 1e3; +const DUPLICATE_LOG_QUERY_DELAY = 1_000; +const LOG_QUERY_THROTTLE = 50; const isAbortError = (error: unknown): boolean => error instanceof Error && error.name === 'AbortError'; @@ -159,6 +161,7 @@ const reducer = (state: State, action: Action): State => { return { ...state, isLoadingLogsData: true, + isLoadingMoreLogsData: false, logsData: undefined, logsError: undefined, hasMoreLogsData: false, @@ -252,13 +255,16 @@ export const useLogs = ( const currentQuery = useRef(); const currentTenant = useRef(initialTenant); const currentTimeRange = useRef(initialTimeRange); + const currentNamespace = useRef(); + const currentSchema = useRef(); + const currentLastTimestampNs = useRef(); const lastExecutionTime = useRef<{ logs?: number; histogram?: number; volume?: number }>({ logs: undefined, histogram: undefined, volume: undefined, }); const currentDirection = useRef('backward'); - const logsAbort = useRef<() => void | undefined>(); + const logsRequestID = useRef(0); const histogramAbort = useRef<() => void | undefined>(); const volumeAbort = useRef<() => void | undefined>(); const ws = useRef(); @@ -316,9 +322,42 @@ export const useLogs = ( return; } + const requestTime = Date.now(); + + // Throttle extremely rapid requests + if ( + lastExecutionTime.current.logs && + requestTime - lastExecutionTime.current.logs < LOG_QUERY_THROTTLE + ) { + return; + } + + const sameQuery = currentQuery.current === query; + const sameLastTimestamp = currentLastTimestampNs.current === lastTimestampNs; + const sameDirection = !direction || currentDirection.current === direction; + const sameNamespace = currentNamespace.current === namespace; + const sameSchema = currentSchema.current === schema; + + const sameLogRequest = + sameQuery && sameLastTimestamp && sameDirection && sameNamespace && sameSchema; + + if ( + sameLogRequest && + lastExecutionTime.current.logs && + requestTime - lastExecutionTime.current.logs < DUPLICATE_LOG_QUERY_DELAY + ) { + return; + } + + const requestID = ++logsRequestID.current; + try { currentQuery.current = query; currentDirection.current = direction ?? currentDirection.current; + currentNamespace.current = namespace ?? currentNamespace.current; + currentSchema.current = schema; + currentLastTimestampNs.current = lastTimestampNs; + lastExecutionTime.current.logs = requestTime; const lastTs = BigInt(lastTimestampNs); const oneHourNs = 3_600_000_000_000n; @@ -336,13 +375,9 @@ export const useLogs = ( dispatch({ type: 'moreLogsRequest' }); - if (logsAbort.current) { - logsAbort.current(); - } - const config = configRef.current; - const { request, abort } = executeQueryRange({ + const { request } = executeQueryRange({ query, startNs, endNs, @@ -353,16 +388,16 @@ export const useLogs = ( schema, }); - logsAbort.current = abort; - const queryResponse = await request(); - dispatch({ - type: 'moreLogsResponse', - payload: { logsData: queryResponse, config }, - }); + if (requestID === logsRequestID.current) { + dispatch({ + type: 'moreLogsResponse', + payload: { logsData: queryResponse, config }, + }); + } } catch (error) { - if (!isAbortError(error)) { + if (requestID === logsRequestID.current && !isAbortError(error)) { dispatch({ type: 'logsError', payload: { error } }); } } @@ -388,29 +423,64 @@ export const useLogs = ( return; } - // Throttle requests - if (lastExecutionTime.current.logs && Date.now() - lastExecutionTime.current.logs < 50) { + const requestTime = Date.now(); + + // Throttle extremely rapid requests + if ( + lastExecutionTime.current.logs && + requestTime - lastExecutionTime.current.logs < LOG_QUERY_THROTTLE + ) { + return; + } + + const sameQuery = currentQuery.current === query; + const sameTimeRange = + !timeRange || + (currentTimeRange.current.start === timeRange.start && + currentTimeRange.current.end === timeRange.end); + const sameDirection = !direction || currentDirection.current === direction; + const sameTenant = !tenant || currentTenant.current === tenant; + const sameNamespace = currentNamespace.current === namespace; + const sameSchema = currentSchema.current === schema; + + const sameLogRequest = + sameQuery && + sameTimeRange && + sameDirection && + sameTenant && + sameNamespace && + sameSchema && + // don't throttle if the previous caller was getMoreLogs rather than getLogs + currentLastTimestampNs.current === undefined; + + // Throttle requests that are the same for a longer period of time + if ( + sameLogRequest && + lastExecutionTime.current.logs && + requestTime - lastExecutionTime.current.logs < DUPLICATE_LOG_QUERY_DELAY + ) { return; } + const requestID = ++logsRequestID.current; + try { currentQuery.current = query; currentTenant.current = tenant ?? currentTenant.current; - lastExecutionTime.current.logs = Date.now(); + lastExecutionTime.current.logs = requestTime; currentTimeRange.current = timeRange ?? currentTimeRange.current; currentDirection.current = direction ?? currentDirection.current; + currentNamespace.current = namespace; + currentSchema.current = schema; + currentLastTimestampNs.current = undefined; const { start, end } = numericTimeRange(currentTimeRange.current); dispatch({ type: 'logsRequest' }); - if (logsAbort.current) { - logsAbort.current(); - } - const config = configRef.current; - const { request, abort } = executeQueryRange({ + const { request } = executeQueryRange({ query, startNs: msToNs(start), endNs: msToNs(end), @@ -421,13 +491,13 @@ export const useLogs = ( schema, }); - logsAbort.current = abort; - const queryResponse = await request(); - dispatch({ type: 'logsResponse', payload: { logsData: queryResponse, config } }); + if (requestID === logsRequestID.current) { + dispatch({ type: 'logsResponse', payload: { logsData: queryResponse, config } }); + } } catch (error) { - if (!isAbortError(error)) { + if (requestID === logsRequestID.current && !isAbortError(error)) { dispatch({ type: 'logsError', payload: { error } }); } } @@ -454,6 +524,8 @@ export const useLogs = ( }) => { currentQuery.current = query; currentTenant.current = tenant ?? currentTenant.current; + currentNamespace.current = namespace ?? currentNamespace.current; + currentSchema.current = schema; if (ws.current) { ws.current.destroy(); @@ -507,6 +579,8 @@ export const useLogs = ( }) => { currentQuery.current = query; currentTenant.current = tenant ?? currentTenant.current; + currentNamespace.current = namespace ?? currentNamespace.current; + currentSchema.current = schema; if (isStreaming) { pauseTailLog(); @@ -541,6 +615,8 @@ export const useLogs = ( try { currentQuery.current = query; currentTenant.current = tenant ?? currentTenant.current; + currentNamespace.current = namespace ?? currentNamespace.current; + currentSchema.current = schema; lastExecutionTime.current.volume = Date.now(); currentTimeRange.current = timeRange ?? currentTimeRange.current; @@ -615,6 +691,8 @@ export const useLogs = ( try { currentQuery.current = query; currentTenant.current = tenant ?? currentTenant.current; + currentNamespace.current = namespace ?? currentNamespace.current; + currentSchema.current = schema; lastExecutionTime.current.histogram = Date.now(); currentTimeRange.current = timeRange ?? currentTimeRange.current; diff --git a/web/src/logs.types.ts b/web/src/logs.types.ts index 49320a343..4412b5257 100644 --- a/web/src/logs.types.ts +++ b/web/src/logs.types.ts @@ -79,6 +79,12 @@ export type QueryRangeResponse = { }; }; +export type LokiErrorResponse = { + status: 'error'; + errorType?: string; + error?: string; +}; + export type VolumeRangeResponse = QueryRangeResponse; export type Rule = { diff --git a/web/src/loki-client.ts b/web/src/loki-client.ts index 695b7e50b..68e2d7539 100644 --- a/web/src/loki-client.ts +++ b/web/src/loki-client.ts @@ -61,6 +61,60 @@ type LokiTailQueryParams = { const MAX_RANGE_REQUEST_NS = 21_600_000_000_000n; // 6 hours in nanoseconds +const assertRecord: ( + response: unknown, + errorMessage?: string, +) => asserts response is Record = ( + response, + errorMessage = 'Invalid Loki query response', +) => { + if (typeof response !== 'object' || response === null || Array.isArray(response)) { + throw new Error(errorMessage); + } +}; + +const toRecord = (response: unknown): Record => { + assertRecord(response); + return response; +}; + +export const throwResponseError = (response: Record): Record => { + if (response.status !== 'error') { + return response; + } + + const errorType = typeof response.errorType === 'string' ? response.errorType : undefined; + const error = typeof response.error === 'string' ? response.error : undefined; + throw new Error([errorType, error].filter(Boolean).join(': ') || 'Loki query failed'); +}; + +export const assertQueryRangeResponse: ( + response: Record, +) => asserts response is QueryRangeResponse = (response) => { + const data = response.data; + assertRecord(data, 'Invalid Loki query response: missing data.result'); + if (!Array.isArray(data.result)) { + throw new Error('Invalid Loki query response: missing data.result'); + } +}; + +const toQueryRangeResponse = (response: Record): QueryRangeResponse => { + assertQueryRangeResponse(response); + return response; +}; + +export const validateQueryRangeResponse = (response: QueryRangeResponse): QueryRangeResponse => { + if (response.status !== 'success') { + throw new Error(`Invalid Loki query response status: ${String(response.status)}`); + } + + if (response.data.resultType !== 'streams' && response.data.resultType !== 'matrix') { + throw new Error('Invalid Loki query response: invalid data.resultType'); + } + + return response; +}; + export const getFetchConfig = ({ config, tenant, @@ -147,7 +201,7 @@ export const executeQueryRange = ({ namespace, direction, schema, -}: QueryRangeParams): CancellableFetch => { +}: QueryRangeParams): { request: () => Promise } => { const extendedQuery = queryWithNamespace({ query, namespace, @@ -167,11 +221,22 @@ export const executeQueryRange = ({ const { endpoint, requestInit, timeout } = getFetchConfig({ config, tenant }); - return cancellableFetch( + const { request } = cancellableFetch( `${endpoint}/loki/api/v1/query_range?${new URLSearchParams(params)}`, requestInit, timeout, ); + + return { + // consoleFetchJSON can return null, empty arrays, strings and other primitives + // Perform type narrowing and validations at each layer + request: () => + request() + .then(toRecord) + .then(throwResponseError) + .then(toQueryRangeResponse) + .then(validateQueryRangeResponse), + }; }; export const executeVolumeRange = ({ @@ -242,8 +307,8 @@ export const executeHistogramQuery = ({ schema, }); - // eslint-disable-next-line max-len - const histogramQuery = `sum by (${labelSeverity}) (count_over_time(${extendedQuery} [${intervalString}]))`; + const histogramQuery = + `sum by (${labelSeverity}) ` + `(count_over_time(${extendedQuery} [${intervalString}]))`; const params = { query: histogramQuery, diff --git a/web/src/pages/logs-detail-page.tsx b/web/src/pages/logs-detail-page.tsx index ca538dd9a..1bc018c68 100644 --- a/web/src/pages/logs-detail-page.tsx +++ b/web/src/pages/logs-detail-page.tsx @@ -186,6 +186,8 @@ const LogsDetailPage: FC = ({ const isQueryEmpty = query === ''; + const isLoadingLogs = isLoadingLogsData || isLoadingMoreLogsData; + const resultIsMetric = isMatrixResult(logsData?.data); useEffect(() => { @@ -221,7 +223,11 @@ const LogsDetailPage: FC = ({ isDisabled={isQueryEmpty} /> )} - + Refresh}>