Skip to content
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.

Sign up for GitHub

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

Jump to bottom

fix: use trace logging for happy paths #35

Merged
merged 2 commits into from
Apr 16, 2023
Merged

fix: use trace logging for happy paths #35

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
7a68ed2
fix: use trace logging for happy paths
achingbrain Apr 16, 2023
e4270b4
chore: use error log for errors
achingbrain Apr 16, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
28 changes: 16 additions & 12 deletions src/muxer.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -90,7 +90,7 @@ export class YamuxMuxer implements StreamMuxer {

this.source = pushable({
onEnd: (err?: Error): void => {
this.log?.('muxer source ended')
this.log?.trace('muxer source ended')
this.close(err)
}
})
Expand Down Expand Up @@ -139,7 +139,7 @@ export class YamuxMuxer implements StreamMuxer {
}
}

this.log?.('muxer sink ended')
this.log?.trace('muxer sink ended')

this.close(error, reason)
}
Expand All @@ -153,7 +153,7 @@ export class YamuxMuxer implements StreamMuxer {
this.nextPingID = 0
this.rtt = 0

this.log?.('muxer created')
this.log?.trace('muxer created')

if (this.config.enableKeepAlive) {
this.keepAliveLoop().catch(e => this.log?.error('keepalive error: %s', e))
Expand All @@ -180,7 +180,7 @@ export class YamuxMuxer implements StreamMuxer {
throw new CodeError('max outbound streams exceeded', ERR_MAX_OUTBOUND_STREAMS_EXCEEDED)
}

this.log?.('new outgoing stream id=%s', id)
this.log?.trace('new outgoing stream id=%s', id)

const stream = this._newStream(id, name, StreamState.Init, 'outbound')
this._streams.set(id, stream)
Expand Down Expand Up @@ -274,7 +274,11 @@ export class YamuxMuxer implements StreamMuxer {
// If reason was provided, use that, otherwise use the presence of `err` to determine the reason
reason = reason ?? (err === undefined ? GoAwayCode.InternalError : GoAwayCode.NormalTermination)

this.log?.('muxer close reason=%s error=%s', GoAwayCode[reason], err)
if (err != null) {
this.log?.error('muxer close reason=%s error=%s', GoAwayCode[reason], err)
} else {
this.log?.trace('muxer close reason=%s', GoAwayCode[reason])
}

// If err is provided, abort all underlying streams, else close all underlying streams
if (err === undefined) {
Expand Down Expand Up @@ -347,7 +351,7 @@ export class YamuxMuxer implements StreamMuxer {

private async keepAliveLoop (): Promise<void> {
const abortPromise = new Promise((_resolve, reject) => { this.closeController.signal.addEventListener('abort', reject, { once: true }) })
this.log?.('muxer keepalive enabled interval=%s', this.config.keepAliveInterval)
this.log?.trace('muxer keepalive enabled interval=%s', this.config.keepAliveInterval)
while (true) {
let timeoutId
try {
Expand Down Expand Up @@ -399,10 +403,10 @@ export class YamuxMuxer implements StreamMuxer {
private handlePing (header: FrameHeader): void {
// If the ping is initiated by the sender, send a response
if (header.flag === Flag.SYN) {
this.log?.('received ping request pingId=%s', header.length)
this.log?.trace('received ping request pingId=%s', header.length)
this.sendPing(header.length, Flag.ACK)
} else if (header.flag === Flag.ACK) {
this.log?.('received ping response pingId=%s', header.length)
this.log?.trace('received ping response pingId=%s', header.length)
this.handlePingResponse(header.length)
} else {
// Invalid state
Expand All @@ -425,7 +429,7 @@ export class YamuxMuxer implements StreamMuxer {
}

private handleGoAway (reason: GoAwayCode): void {
this.log?.('received GoAway reason=%s', GoAwayCode[reason] ?? 'unknown')
this.log?.trace('received GoAway reason=%s', GoAwayCode[reason] ?? 'unknown')
this.remoteGoAway = reason

// If the other side is friendly, they would have already closed all streams before sending a GoAway
Expand Down Expand Up @@ -482,7 +486,7 @@ export class YamuxMuxer implements StreamMuxer {
return
}

this.log?.('new incoming stream id=%s', id)
this.log?.trace('new incoming stream id=%s', id)

if (this.localGoAway !== undefined) {
// reject (reset) immediately if we are doing a go away
Expand Down Expand Up @@ -530,9 +534,9 @@ export class YamuxMuxer implements StreamMuxer {

private sendPing (pingId: number, flag: Flag = Flag.SYN): void {
if (flag === Flag.SYN) {
this.log?.('sending ping request pingId=%s', pingId)
this.log?.trace('sending ping request pingId=%s', pingId)
} else {
this.log?.('sending ping response pingId=%s', pingId)
this.log?.trace('sending ping response pingId=%s', pingId)
}
this.sendFrame({
type: FrameType.Ping,
Expand Down
29 changes: 19 additions & 10 deletions src/stream.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -114,7 +114,12 @@ export class YamuxStream implements Stream {

this.sourceInput = pushable({
onEnd: (err?: Error) => {
this.log?.('stream source ended id=%s', this._id, err)
if (err != null) {
this.log?.error('stream source ended id=%s', this._id, err)
} else {
this.log?.trace('stream source ended id=%s', this._id)
}

this.closeRead()
}
})
Expand Down Expand Up @@ -145,7 +150,7 @@ export class YamuxStream implements Stream {
} catch (e) {
this.log?.error('stream sink error id=%s', this._id, e)
} finally {
this.log?.('stream sink ended id=%s', this._id)
this.log?.trace('stream sink ended id=%s', this._id)
this.closeWrite()
}
}
Expand All @@ -167,7 +172,7 @@ export class YamuxStream implements Stream {
}

close (): void {
this.log?.('stream close id=%s', this._id)
this.log?.trace('stream close id=%s', this._id)
this.closeRead()
this.closeWrite()
}
Expand All @@ -181,7 +186,7 @@ export class YamuxStream implements Stream {
return
}

this.log?.('stream close read id=%s', this._id)
this.log?.trace('stream close read id=%s', this._id)

this.readState = HalfStreamState.Closed

Expand All @@ -203,7 +208,7 @@ export class YamuxStream implements Stream {
return
}

this.log?.('stream close write id=%s', this._id)
this.log?.trace('stream close write id=%s', this._id)

this.writeState = HalfStreamState.Closed

Expand Down Expand Up @@ -235,7 +240,11 @@ export class YamuxStream implements Stream {
throw new Error('unreachable')
}

this.log?.('stream abort id=%s error=%s', this._id, err)
if (err != null) {
this.log?.error('stream abort id=%s error=%s', this._id, err)
} else {
this.log?.trace('stream abort id=%s', this._id)
}

this.onReset(new CodeError(String(err) ?? 'stream aborted', ERR_STREAM_ABORT))
}
Expand All @@ -245,7 +254,7 @@ export class YamuxStream implements Stream {
return
}

this.log?.('stream reset id=%s', this._id)
this.log?.trace('stream reset id=%s', this._id)

this.onReset(new CodeError('stream reset', ERR_STREAM_RESET))
}
Expand Down Expand Up @@ -301,7 +310,7 @@ export class YamuxStream implements Stream {
* handleWindowUpdate is called when the stream receives a window update frame
*/
handleWindowUpdate (header: FrameHeader): void {
this.log?.('stream received window update id=%s', this._id)
this.log?.trace('stream received window update id=%s', this._id)
this.processFlags(header.flag)

// increase send window
Expand All @@ -317,7 +326,7 @@ export class YamuxStream implements Stream {
* handleData is called when the stream receives a data frame
*/
async handleData (header: FrameHeader, readData: () => Promise<Uint8ArrayList>): Promise<void> {
this.log?.('stream received data id=%s', this._id)
this.log?.trace('stream received data id=%s', this._id)
this.processFlags(header.flag)

// check that our recv window is not exceeded
Expand Down Expand Up @@ -351,7 +360,7 @@ export class YamuxStream implements Stream {
* finish sets the state and triggers eventual garbage collection of the stream
*/
private finish (): void {
this.log?.('stream finished id=%s', this._id)
this.log?.trace('stream finished id=%s', this._id)
this.state = StreamState.Finished
this.stat.timeline.close = Date.now()
this.onStreamEnd()
Expand Down