Skip to content

Commit

Permalink
tentative refactor commit
Browse files Browse the repository at this point in the history
  • Loading branch information
DuncanUszkay1 committed Jul 29, 2024
1 parent 02fd465 commit 52f441b
Show file tree
Hide file tree
Showing 15 changed files with 443 additions and 190 deletions.
4 changes: 2 additions & 2 deletions packages/app/src/cli/commands/app/logs.ts
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
import Dev from './dev.js'
import Command from '../../utilities/app-command.js'
import {checkFolderIsValidApp} from '../../models/app/loader.js'
import {logs} from '../../services/logs.js'
import {logs, Format} from '../../services/logs.js'
import {appLogPollingEnabled} from '../../services/app-logs/utils.js'
import {Flags} from '@oclif/core'
import {AbortError} from '@shopify/cli-kit/node/error'
Expand Down Expand Up @@ -58,7 +58,7 @@ export default class Logs extends Command {
status: flags.status,
configName: flags.config,
reset: flags.reset,
json: flags.json,
format: (flags.json ? 'json' : 'text') as Format,
}

await logs(logOptions)
Expand Down
11 changes: 5 additions & 6 deletions packages/app/src/cli/services/app-logs/dev/poll-app-logs.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -339,7 +339,7 @@ describe('pollAppLogs', () => {

test('calls resubscribe callback if a 401 is received', async () => {
// Given
const response = new Response('errorMessage', {status: 401})
const response = new Response(JSON.stringify({errors: ['Unauthorized']}), {status: 401})
const mockedFetch = vi.fn().mockResolvedValueOnce(response)
vi.mocked(fetch).mockImplementation(mockedFetch)

Expand All @@ -357,7 +357,9 @@ describe('pollAppLogs', () => {
test('displays throttle message, waits, and retries if status is 429', async () => {
// Given
const outputWarnSpy = vi.spyOn(output, 'outputWarn')
const mockedFetch = vi.fn().mockResolvedValueOnce(new Response('error for 429', {status: 429}))
const mockedFetch = vi
.fn()
.mockResolvedValueOnce(new Response(JSON.stringify({errors: ['error for 429']}), {status: 429}))
vi.mocked(fetch).mockImplementation(mockedFetch)

// When/Then
Expand All @@ -369,7 +371,6 @@ describe('pollAppLogs', () => {
})

expect(outputWarnSpy).toHaveBeenCalledWith('Request throttled while polling app logs.')
expect(outputWarnSpy).toHaveBeenCalledWith('Retrying in 60 seconds.')
expect(vi.getTimerCount()).toEqual(1)
})

Expand All @@ -379,7 +380,7 @@ describe('pollAppLogs', () => {
const outputWarnSpy = vi.spyOn(output, 'outputWarn')

// An unexpected error response
const response = new Response('errorMessage', {status: 422})
const response = new Response(JSON.stringify({errors: ['errorMessage']}), {status: 500})
const mockedFetch = vi.fn().mockResolvedValueOnce(response)
vi.mocked(fetch).mockImplementation(mockedFetch)

Expand All @@ -393,8 +394,6 @@ describe('pollAppLogs', () => {

// Then
expect(outputWarnSpy).toHaveBeenCalledWith('Error while polling app logs.')
expect(outputWarnSpy).toHaveBeenCalledWith('Retrying in 5 seconds.')
expect(outputDebugSpy).toHaveBeenCalledWith(expect.stringContaining(`Unhandled bad response: ${response.status}`))
expect(vi.getTimerCount()).toEqual(1)
})
})
69 changes: 38 additions & 31 deletions packages/app/src/cli/services/app-logs/dev/poll-app-logs.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,6 @@ import {writeAppLogsToFile} from './write-app-logs.js'
import {
POLLING_INTERVAL_MS,
POLLING_ERROR_RETRY_INTERVAL_MS,
POLLING_THROTTLE_RETRY_INTERVAL_MS,
ONE_MILLION,
LOG_TYPE_FUNCTION_RUN,
fetchAppLogs,
Expand All @@ -12,8 +11,9 @@ import {
LOG_TYPE_REQUEST_EXECUTION,
REQUEST_EXECUTION_IN_BACKGROUND_NO_CACHED_RESPONSE_REASON,
REQUEST_EXECUTION_IN_BACKGROUND_CACHE_ABOUT_TO_EXPIRE_REASON,
handleFetchAppLogsError,
} from '../utils.js'
import {AppLogData} from '../types.js'
import {AppLogData, ErrorResponse} from '../types.js'
import {outputContent, outputDebug, outputToken, outputWarn} from '@shopify/cli-kit/node/output'
import {useConcurrentOutputContext} from '@shopify/cli-kit/node/ui/components'
import {Writable} from 'stream'
Expand All @@ -27,37 +27,44 @@ export const pollAppLogs = async ({
stdout: Writable
appLogsFetchInput: {jwtToken: string; cursor?: string}
apiKey: string
resubscribeCallback: () => Promise<void>
resubscribeCallback: () => Promise<string>
}) => {
try {
const response = await fetchAppLogs(jwtToken, cursor)

if (!response.ok) {
if (response.status === 401) {
await resubscribeCallback()
} else if (response.status === 429) {
outputWarn(`Request throttled while polling app logs.`)
outputWarn(`Retrying in ${POLLING_THROTTLE_RETRY_INTERVAL_MS / 1000} seconds.`)
setTimeout(() => {
pollAppLogs({
stdout,
appLogsFetchInput: {
jwtToken,
cursor: undefined,
},
apiKey,
resubscribeCallback,
}).catch((error) => {
outputDebug(`Unexpected error during polling: ${error}}\n`)
})
}, POLLING_THROTTLE_RETRY_INTERVAL_MS)
} else {
throw new Error(`Unhandled bad response: ${response.status}`)
let nextJwtToken = jwtToken
let retryIntervalMs = POLLING_INTERVAL_MS

const httpResponse = await fetchAppLogs(jwtToken, cursor)

const response = await httpResponse.json()
const {errors} = response as {errors: string[]}

if (errors) {
const errorResponse = {
errors: errors.map((error) => ({message: error, status: httpResponse.status})),
} as ErrorResponse

const result = await handleFetchAppLogsError({
response: errorResponse,
onThrottle: (retryIntervalMs) => {
outputWarn(`Request throttled while polling app logs.`)
outputWarn(`Retrying in ${retryIntervalMs / 1000} seconds.`)
},
onUnknownError: (retryIntervalMs) => {
outputWarn(`Error while polling app logs.`)
outputWarn(`Retrying in ${retryIntervalMs / 1000} seconds.`)
},
onResubscribe: () => {
return resubscribeCallback()
},
})

if (result.nextJwtToken) {
nextJwtToken = result.nextJwtToken
}
return
retryIntervalMs = result.retryIntervalMs
}

const data = (await response.json()) as {
const data = response as {
app_logs?: AppLogData[]
cursor?: string
errors?: string[]
Expand Down Expand Up @@ -101,15 +108,15 @@ export const pollAppLogs = async ({
pollAppLogs({
stdout,
appLogsFetchInput: {
jwtToken,
cursor: cursorFromResponse,
jwtToken: nextJwtToken,
cursor: cursorFromResponse || cursor,
},
apiKey,
resubscribeCallback,
}).catch((error) => {
outputDebug(`Unexpected error during polling: ${error}}\n`)
})
}, POLLING_INTERVAL_MS)
}, retryIntervalMs)
// eslint-disable-next-line no-catch-all/no-catch-all
} catch (error) {
outputWarn(`Error while polling app logs.`)
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,79 @@
import {renderJsonLogs} from './render-json-logs.js'
import {pollAppLogs} from './poll-app-logs.js'
import {handleFetchAppLogsError} from '../utils.js'
import {testDeveloperPlatformClient} from '../../../models/app/app.test-data.js'
import {outputInfo} from '@shopify/cli-kit/node/output'
import {describe, expect, vi, test, beforeEach, afterEach} from 'vitest'

vi.mock('./poll-app-logs')
vi.mock('../utils', async (importOriginal) => {
const mod = await importOriginal<typeof import('../utils.js')>()
return {
...mod,
fetchAppLogs: vi.fn(),
handleFetchAppLogsError: vi.fn(),
}
})
vi.mock('@shopify/cli-kit/node/output')

describe('renderJsonLogs', () => {
beforeEach(() => {
vi.useFakeTimers()
})

afterEach(() => {
vi.clearAllTimers()
})

test('should handle success response correctly', async () => {
const mockSuccessResponse = {
cursor: 'next-cursor',
appLogs: [{message: 'Log 1'}, {message: 'Log 2'}],
}
const pollAppLogsMock = vi.fn().mockResolvedValue(mockSuccessResponse)
vi.mocked(pollAppLogs).mockImplementation(pollAppLogsMock)

await renderJsonLogs({
pollOptions: {cursor: 'cursor', filters: {status: undefined, source: undefined}, jwtToken: 'jwtToken'},
options: {
variables: {shopIds: ['1'], apiKey: 'key', token: 'token'},
developerPlatformClient: testDeveloperPlatformClient(),
},
})

expect(outputInfo).toHaveBeenNthCalledWith(1, JSON.stringify({message: 'Log 1'}))
expect(outputInfo).toHaveBeenNthCalledWith(2, JSON.stringify({message: 'Log 2'}))
expect(pollAppLogs).toHaveBeenCalled()
expect(vi.getTimerCount()).toEqual(1)
})

test('should handle error response and retry as expected', async () => {
const mockErrorResponse = {
errors: [{status: 500, message: 'Server Error'}],
}
const pollAppLogsMock = vi.fn().mockResolvedValue(mockErrorResponse)
vi.mocked(pollAppLogs).mockImplementation(pollAppLogsMock)
const mockRetryInterval = 1000
const handleFetchAppLogsErrorMock = vi.fn((input) => {
input.onUnknownError(mockRetryInterval)
return new Promise<{retryIntervalMs: number; nextJwtToken: string | null}>((resolve, _reject) => {
resolve({nextJwtToken: 'new-jwt-token', retryIntervalMs: mockRetryInterval})
})
})
vi.mocked(handleFetchAppLogsError).mockImplementation(handleFetchAppLogsErrorMock)

await renderJsonLogs({
pollOptions: {cursor: 'cursor', filters: {status: undefined, source: undefined}, jwtToken: 'jwtToken'},
options: {
variables: {shopIds: [], apiKey: '', token: ''},
developerPlatformClient: testDeveloperPlatformClient(),
},
})

expect(outputInfo).toHaveBeenCalledWith(
JSON.stringify({message: 'Error while polling app logs.', retry_in_ms: mockRetryInterval}),
)
expect(pollAppLogs).toHaveBeenCalled()
expect(vi.getTimerCount()).toEqual(1)
})
})
Original file line number Diff line number Diff line change
@@ -0,0 +1,59 @@
import {pollAppLogs} from './poll-app-logs.js'
import {PollOptions, SubscribeOptions, ErrorResponse, SuccessResponse} from '../types.js'
import {POLLING_INTERVAL_MS, handleFetchAppLogsError, subscribeToAppLogs} from '../utils.js'
import {outputInfo} from '@shopify/cli-kit/node/output'

export async function renderJsonLogs({
pollOptions: {cursor, filters, jwtToken},
options: {variables, developerPlatformClient},
}: {
pollOptions: PollOptions
options: SubscribeOptions
}): Promise<void> {
const response = await pollAppLogs({cursor, filters, jwtToken})
let retryIntervalMs = POLLING_INTERVAL_MS
let nextJwtToken = jwtToken

const errorResponse = response as ErrorResponse

if (errorResponse.errors) {
const result = await handleFetchAppLogsError({
response: errorResponse,
onThrottle: (retryIntervalMs) => {
outputInfo(JSON.stringify({message: 'Request throttled while polling app logs.', retry_in_ms: retryIntervalMs}))
},
onUnknownError: (retryIntervalMs) => {
outputInfo(JSON.stringify({message: 'Error while polling app logs.', retry_in_ms: retryIntervalMs}))
},
onResubscribe: () => {
return subscribeToAppLogs(developerPlatformClient, variables)
},
})

if (result.nextJwtToken) {
nextJwtToken = result.nextJwtToken
}
retryIntervalMs = result.retryIntervalMs
}

const {cursor: nextCursor, appLogs} = response as SuccessResponse

if (appLogs) {
appLogs.forEach((log) => {
outputInfo(JSON.stringify(log))
})
}

setTimeout(() => {
renderJsonLogs({
options: {variables, developerPlatformClient},
pollOptions: {
jwtToken: nextJwtToken || jwtToken,
cursor: nextCursor || cursor,
filters,
},
}).catch((error) => {
throw error
})
}, retryIntervalMs)
}
Original file line number Diff line number Diff line change
Expand Up @@ -344,7 +344,7 @@ describe('usePollAppLogs', () => {
expect(mockedPollAppLogs).toHaveBeenCalledTimes(1)

expect(hook.lastResult?.appLogOutputs).toHaveLength(0)
expect(hook.lastResult?.errors[0]).toEqual('Error Message')
expect(hook.lastResult?.errors[0]).toEqual('Request throttled while polling app logs.')
expect(hook.lastResult?.errors[1]).toEqual('Retrying in 60s')

expect(setTimeout).toHaveBeenCalledWith(expect.any(Function), POLLING_THROTTLE_RETRY_INTERVAL_MS)
Expand Down Expand Up @@ -378,7 +378,7 @@ describe('usePollAppLogs', () => {
expect(mockedPollAppLogs).toHaveBeenCalledTimes(1)

expect(hook.lastResult?.appLogOutputs).toHaveLength(0)
expect(hook.lastResult?.errors[0]).toEqual('Unprocessable')
expect(hook.lastResult?.errors[0]).toEqual('Error while polling app logs')
expect(hook.lastResult?.errors[1]).toEqual('Retrying in 5s')

expect(setTimeout).toHaveBeenCalledWith(expect.any(Function), POLLING_ERROR_RETRY_INTERVAL_MS)
Expand Down
Original file line number Diff line number Diff line change
@@ -1,8 +1,6 @@
import {
POLLING_ERROR_RETRY_INTERVAL_MS,
ONE_MILLION,
POLLING_INTERVAL_MS,
POLLING_THROTTLE_RETRY_INTERVAL_MS,
parseFunctionRunPayload,
LOG_TYPE_FUNCTION_RUN,
LOG_TYPE_RESPONSE_FROM_CACHE,
Expand All @@ -11,6 +9,7 @@ import {
parseNetworkAccessRequestExecutionInBackgroundPayload,
LOG_TYPE_REQUEST_EXECUTION,
parseNetworkAccessRequestExecutedPayload,
handleFetchAppLogsError,
} from '../../../../utils.js'
import {ErrorResponse, SuccessResponse, AppLogOutput, PollFilters, AppLogPayload} from '../../../../types.js'
import {pollAppLogs} from '../../../poll-app-logs.js'
Expand All @@ -28,23 +27,30 @@ export function usePollAppLogs({initialJwt, filters, resubscribeCallback}: UsePo

useEffect(() => {
const poll = async ({jwtToken, cursor, filters}: {jwtToken: string; cursor?: string; filters: PollFilters}) => {
let nextInterval = POLLING_INTERVAL_MS
let nextJwtToken = jwtToken
let retryIntervalMs = POLLING_INTERVAL_MS
const response = await pollAppLogs({jwtToken, cursor, filters})

const {errors} = response as ErrorResponse
const errorResponse = response as ErrorResponse

if (errors && errors.length > 0) {
const errorsStrings = errors.map((error) => error.message)
if (errors.some((error) => error.status === 429)) {
setErrors([...errorsStrings, `Retrying in ${POLLING_THROTTLE_RETRY_INTERVAL_MS / 1000}s`])
nextInterval = POLLING_THROTTLE_RETRY_INTERVAL_MS
} else if (errors.some((error) => error.status === 401)) {
nextJwtToken = await resubscribeCallback()
} else {
setErrors([...errorsStrings, `Retrying in ${POLLING_ERROR_RETRY_INTERVAL_MS / 1000}s`])
nextInterval = POLLING_ERROR_RETRY_INTERVAL_MS
if (errorResponse.errors) {
const result = await handleFetchAppLogsError({
response: errorResponse,
onThrottle: (retryIntervalMs) => {
setErrors(['Request throttled while polling app logs.', `Retrying in ${retryIntervalMs / 1000}s`])
},
onUnknownError: (retryIntervalMs) => {
setErrors(['Error while polling app logs', `Retrying in ${retryIntervalMs / 1000}s`])
},
onResubscribe: () => {
return resubscribeCallback()
},
})

if (result.nextJwtToken) {
nextJwtToken = result.nextJwtToken
}
retryIntervalMs = result.retryIntervalMs
} else {
setErrors([])
}
Expand Down Expand Up @@ -97,7 +103,7 @@ export function usePollAppLogs({initialJwt, filters, resubscribeCallback}: UsePo
poll({jwtToken: nextJwtToken, cursor: nextCursor || cursor, filters}).catch((error) => {
throw error
})
}, nextInterval)
}, retryIntervalMs)
}

poll({jwtToken: initialJwt, cursor: '', filters}).catch((error) => {
Expand Down
Loading

0 comments on commit 52f441b

Please sign in to comment.