-
Notifications
You must be signed in to change notification settings - Fork 55
feat: Add redirected actor logs #769
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from 21 commits
ab71414
d328ada
a8ae55f
4f2146d
cc7aba9
50b2732
f25935c
4aa0125
c410190
d9a900a
1c293da
0456c20
dc88c2b
ec0d60e
fc7bb6c
bbeeee4
00bf7ea
5fd0fc7
5d4c1f4
51dd246
71d7fb5
0b2e6e6
0440e39
0b84a32
bca27b2
8eb6e71
dfa5dcd
3e48c60
f560b3b
bc2f1e2
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -3,6 +3,7 @@ import ow from 'ow'; | |
|
|
||
| import type { RUN_GENERAL_ACCESS } from '@apify/consts'; | ||
| import { ACT_JOB_STATUSES, ACTOR_PERMISSION_LEVEL, META_ORIGINS } from '@apify/consts'; | ||
| import { Log } from '@apify/log'; | ||
|
|
||
| import type { ApiClientSubResourceOptions } from '../base/api_client'; | ||
| import { ResourceClient } from '../base/resource_client'; | ||
|
|
@@ -139,18 +140,30 @@ export class ActorClient extends ResourceClient { | |
| webhooks: ow.optional.array.ofType(ow.object), | ||
| maxItems: ow.optional.number.not.negative, | ||
| maxTotalChargeUsd: ow.optional.number.not.negative, | ||
| log: ow.optional.any(ow.null, ow.object.instanceOf(Log)), | ||
| restartOnError: ow.optional.boolean, | ||
| forcePermissionLevel: ow.optional.string.oneOf(Object.values(ACTOR_PERMISSION_LEVEL)), | ||
| }), | ||
| ); | ||
|
|
||
| const { waitSecs, ...startOptions } = options; | ||
| const { waitSecs, log, ...startOptions } = options; | ||
| const { id } = await this.start(input, startOptions); | ||
|
|
||
| // Calling root client because we need access to top level API. | ||
| // Creating a new instance of RunClient here would only allow | ||
| // setting it up as a nested route under actor API. | ||
| return this.apifyClient.run(id).waitForFinish({ waitSecs }); | ||
| const newRunClient = this.apifyClient.run(id); | ||
|
|
||
| const streamedLog = await newRunClient.getStreamedLog({ toLog: options?.log }); | ||
| let actorRun: Promise<ActorRun> | undefined; | ||
| try { | ||
| streamedLog?.start(); | ||
| actorRun = this.apifyClient.run(id).waitForFinish({ waitSecs }); | ||
|
Pijukatel marked this conversation as resolved.
Outdated
|
||
| return actorRun; | ||
| } finally { | ||
| await actorRun; | ||
| await streamedLog?.stop(); | ||
| } | ||
| } | ||
|
|
||
| /** | ||
|
|
@@ -426,6 +439,7 @@ export interface ActorStartOptions { | |
|
|
||
| export interface ActorCallOptions extends Omit<ActorStartOptions, 'waitForFinish'> { | ||
| waitSecs?: number; | ||
| log?: Log | null; | ||
|
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. The difference from Python is the name of the argument. While in Python it is called In JS tooling, the
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. What is the reason for accepting
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
In Python, it is similar, but since there is no undefined, there it is like Added description
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Wouldn't using a string literal like in Python work as well? I'd consider that more readable, too.
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Isn't that going to cause more confusion? Aren't the default values in JS commonly applied when the key is undefined in options? Using
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I tried in the last commit. It feels very redundant to me, but I can live with it |
||
| } | ||
|
|
||
| export interface ActorRunListItem { | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -1,5 +1,11 @@ | ||
| // eslint-disable-next-line max-classes-per-file | ||
| import type { Readable } from 'node:stream'; | ||
|
|
||
| import c from 'ansi-colors'; | ||
|
|
||
| import type { Log } from '@apify/log'; | ||
| import { Logger, LogLevel } from '@apify/log'; | ||
|
|
||
| import type { ApifyApiError } from '../apify_api_error'; | ||
| import type { ApiClientSubResourceOptions } from '../base/api_client'; | ||
| import { ResourceClient } from '../base/resource_client'; | ||
|
|
@@ -20,11 +26,11 @@ export class LogClient extends ResourceClient { | |
| /** | ||
| * https://docs.apify.com/api/v2#/reference/logs/log/get-log | ||
| */ | ||
| async get(): Promise<string | undefined> { | ||
| async get(options: LogOptions = {}): Promise<string | undefined> { | ||
| const requestOpts: ApifyRequestConfig = { | ||
| url: this._url(), | ||
| method: 'GET', | ||
| params: this._params(), | ||
| params: this._params(options), | ||
| }; | ||
|
|
||
| try { | ||
|
|
@@ -41,9 +47,10 @@ export class LogClient extends ResourceClient { | |
| * Gets the log in a Readable stream format. Only works in Node.js. | ||
| * https://docs.apify.com/api/v2#/reference/logs/log/get-log | ||
| */ | ||
| async stream(): Promise<Readable | undefined> { | ||
| async stream(options: LogOptions = {}): Promise<Readable | undefined> { | ||
| const params = { | ||
| stream: true, | ||
| raw: options.raw, | ||
| }; | ||
|
|
||
| const requestOpts: ApifyRequestConfig = { | ||
|
|
@@ -63,3 +70,215 @@ export class LogClient extends ResourceClient { | |
| return undefined; | ||
| } | ||
| } | ||
|
|
||
| export interface LogOptions { | ||
| /** @default false */ | ||
| raw?: boolean; | ||
| } | ||
|
|
||
| // Temp create it here and ask Martin where to put it | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. this is where the apify logger is defined, so maybe there? https://github.com/apify/apify-shared-js/tree/master/packages/log it doesnt feel right to have this in the client
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Not sure about that. I can't imagine a scenario where this would be used outside of the client. It is very client-specific code. Maybe I can put it in to separate file? Something like redirection_utils or logging_utils? |
||
|
|
||
| const DEFAULT_OPTIONS = { | ||
| /** Whether to exclude timestamp of log redirection in redirected logs. */ | ||
| skipTime: true, | ||
| /** Level of log redirection */ | ||
| level: LogLevel.DEBUG, | ||
| }; | ||
|
|
||
| /** | ||
| * Logger for redirected actor logs. | ||
| */ | ||
| export class LoggerActorRedirect extends Logger { | ||
| constructor(options = {}) { | ||
| super({ ...DEFAULT_OPTIONS, ...options }); | ||
| } | ||
|
|
||
| override _log(level: LogLevel, message: string, data?: any, exception?: unknown, opts: Record<string, any> = {}) { | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I'm wondering, what's the biggest difference between this implementation and the
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Logger in our codebase is kind of a combination of a formater and a handler in Python terms. While
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Maybe we need to adjust the shared logger to support this use case?
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. It is not really needed for this change. This change works with the current version of the codebase. Changing |
||
| if (level > this.options.level) { | ||
| return; | ||
| } | ||
| if (data || exception) { | ||
| throw new Error('Redirect logger does not use other arguments than level and message'); | ||
| } | ||
| let { prefix } = opts; | ||
| prefix = prefix ? `${prefix}` : ''; | ||
|
|
||
| let maybeDate = ''; | ||
| if (!this.options.skipTime) { | ||
| maybeDate = `${new Date().toISOString().replace('Z', '').replace('T', ' ')} `; | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. do we need to repeat the timestamps?
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Those timestamps will not be the same. One is the timestamp of origin, and the other is the timestamp of redirection. For example> It is important to
|
||
| } | ||
|
|
||
| const line = `${c.gray(maybeDate)}${c.cyan(prefix)}${message || ''}`; | ||
|
|
||
| // All redirected logs are logged at info level to avid any console specific formating for non-info levels, | ||
| // which have already been applied once to the original log. (For example error stack traces etc.) | ||
| this._outputWithConsole(LogLevel.INFO, line); | ||
| return line; | ||
| } | ||
| } | ||
|
|
||
| /** | ||
| * Helper class for redirecting streamed Actor logs to another log. | ||
| */ | ||
| export class StreamedLog { | ||
|
Pijukatel marked this conversation as resolved.
|
||
| private toLog: Log; | ||
|
Pijukatel marked this conversation as resolved.
Outdated
|
||
| private streamBuffer: Buffer[] = []; | ||
| private splitMarker = /(?:\n|^)(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z)/g; | ||
| private relevancyTimeLimit: Date | null; | ||
|
|
||
| private logClient: LogClient; | ||
| private streamingTask: Promise<void> | null = null; | ||
| private stopLogging = false; | ||
|
|
||
| constructor(logClient: LogClient, toLog: Log, fromStart = true) { | ||
|
Pijukatel marked this conversation as resolved.
Outdated
|
||
| this.toLog = toLog; | ||
| this.logClient = logClient; | ||
| this.relevancyTimeLimit = fromStart ? null : new Date(); | ||
| } | ||
|
|
||
| /** | ||
| * Start log redirection. | ||
| */ | ||
| public start(): void { | ||
| if (this.streamingTask) { | ||
| throw new Error('Streaming task already active'); | ||
| } | ||
| this.stopLogging = false; | ||
| this.streamingTask = this.streamLog(); | ||
| } | ||
|
|
||
| /** | ||
| * Stop log redirection. | ||
| */ | ||
| public async stop(): Promise<void> { | ||
| if (!this.streamingTask) { | ||
| throw new Error('Streaming task is not active'); | ||
| } | ||
| this.stopLogging = true; | ||
| try { | ||
| await this.streamingTask; | ||
| } catch (err) { | ||
| if (!(err instanceof Error && err.name === 'AbortError')) { | ||
| throw err; | ||
| } | ||
| } finally { | ||
| this.streamingTask = null; | ||
| } | ||
| } | ||
|
|
||
| /** | ||
| * Get log stream from response and redirect it to another log. | ||
| */ | ||
| private async streamLog(): Promise<void> { | ||
| const twoBytesLimit = 0xc0; | ||
| const threeBytesLimit = 0xe0; | ||
| const fourBytesLimit = 0xf0; | ||
|
|
||
| const logStream = await this.logClient.stream({ raw: true }); | ||
| if (!logStream) { | ||
| return; | ||
| } | ||
| let incompleteCharacter: Uint8Array = new Uint8Array(); | ||
|
|
||
| for await (const chunk of logStream) { | ||
|
Pijukatel marked this conversation as resolved.
|
||
| // Handle possible leftover incomplete multibyte character from previous chunk | ||
| const chunkPrependedWithIncompleteCharacter = new Uint8Array(incompleteCharacter.length + chunk.length); | ||
| chunkPrependedWithIncompleteCharacter.set(incompleteCharacter, 0); | ||
| chunkPrependedWithIncompleteCharacter.set(chunk, incompleteCharacter.length); | ||
|
|
||
| // Extract possible incomplete multibyte character from the end of this chunk | ||
| if ( | ||
| chunkPrependedWithIncompleteCharacter.length > 1 && | ||
| chunkPrependedWithIncompleteCharacter[chunkPrependedWithIncompleteCharacter.length] >= twoBytesLimit | ||
| ) { | ||
| incompleteCharacter = chunkPrependedWithIncompleteCharacter.slice( | ||
| chunkPrependedWithIncompleteCharacter.length - 1, | ||
| ); | ||
| } else if ( | ||
| chunkPrependedWithIncompleteCharacter.length > 2 && | ||
| chunkPrependedWithIncompleteCharacter[chunkPrependedWithIncompleteCharacter.length] >= threeBytesLimit | ||
| ) { | ||
| incompleteCharacter = chunkPrependedWithIncompleteCharacter.slice( | ||
| chunkPrependedWithIncompleteCharacter.length - 2, | ||
| ); | ||
| } else if ( | ||
| chunkPrependedWithIncompleteCharacter.length > 3 && | ||
| chunkPrependedWithIncompleteCharacter[chunkPrependedWithIncompleteCharacter.length] >= fourBytesLimit | ||
| ) { | ||
| incompleteCharacter = chunkPrependedWithIncompleteCharacter.slice( | ||
| chunkPrependedWithIncompleteCharacter.length - 3, | ||
| ); | ||
| } | ||
|
|
||
| // Keep processing the new data until stopped | ||
| this.streamBuffer.push(Buffer.from(chunkPrependedWithIncompleteCharacter)); | ||
| // Log data only if the chunk contains the marker as it indicates previous message is complete | ||
| if (this.splitMarker.test(chunkPrependedWithIncompleteCharacter.toString())) { | ||
| this.logBufferContent(false); | ||
| } | ||
| if (this.stopLogging) { | ||
| break; | ||
| } | ||
| } | ||
|
|
||
| // Process the remaining buffer | ||
| this.logBufferContent(true); | ||
| } | ||
|
|
||
| /** | ||
| * Parse the buffer and log complete messages. | ||
| */ | ||
| private logBufferContent(includeLastPart = false): void { | ||
| const allParts = Buffer.concat(this.streamBuffer).toString().split(this.splitMarker).slice(1); | ||
| let messageMarkers; | ||
| let messageContents; | ||
| // Parse the buffer parts into complete messages | ||
| if (includeLastPart) { | ||
| // This is final call, so log everything. Do not keep anything in the buffer. | ||
| messageMarkers = allParts.filter((_, i) => i % 2 === 0); | ||
| messageContents = allParts.filter((_, i) => i % 2 !== 0); | ||
| this.streamBuffer = []; | ||
| } else { | ||
| messageMarkers = allParts.filter((_, i) => i % 2 === 0).slice(0, -1); | ||
| messageContents = allParts.filter((_, i) => i % 2 !== 0).slice(0, -1); | ||
|
|
||
| // The last two parts (marker and message) are possibly not complete and will be left in the buffer. | ||
| this.streamBuffer = [Buffer.from(allParts.slice(-2).join(''))]; | ||
| } | ||
|
|
||
| messageMarkers.forEach((marker, index) => { | ||
| const decodedMarker = marker; | ||
| const decodedContent = messageContents[index]; | ||
| if (this.relevancyTimeLimit) { | ||
| // Log only relevant messages. Ignore too old log messages. | ||
| const logTime = new Date(decodedMarker); | ||
| if (logTime < this.relevancyTimeLimit) { | ||
| return; | ||
| } | ||
| } | ||
| const message = decodedMarker + decodedContent; | ||
|
|
||
| // Log parsed message at guessed level. | ||
| this.logAtGuessedLevel(message); | ||
| }); | ||
| } | ||
|
|
||
| /** | ||
| * Log messages at appropriate log level guessed from the message content. | ||
| * | ||
| * Original log level information does not have to be included in the message at all. | ||
| * This is methods just guesses, exotic formating or specific keywords can break the guessing logic. | ||
| */ | ||
| private logAtGuessedLevel(message: string) { | ||
| message = message.trim(); | ||
|
|
||
| if (message.includes('ERROR')) this.toLog.error(message); | ||
| else if (message.includes('SOFT_FAIL')) this.toLog.softFail(message); | ||
| else if (message.includes('WARNING')) this.toLog.warning(message); | ||
| else if (message.includes('INFO')) this.toLog.info(message); | ||
| else if (message.includes('DEBUG')) this.toLog.debug(message); | ||
| else if (message.includes('PERF')) this.toLog.perf(message); | ||
| // Fallback in case original log message does not indicate known log level. | ||
| else this.toLog.info(message); | ||
| } | ||
| } | ||
Uh oh!
There was an error while loading. Please reload this page.