Skip to content

fix(logging): ensure callback executes even if Application Insights throws #791

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

Open
yashkohli88 wants to merge 3 commits into
base: master
Choose a base branch
from
Open

fix(logging): ensure callback executes even if Application Insights throws #791

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
9410b13
fix(logging): ensure callback executes even if Application Insights t…
yashkohli88 May 20, 2026
af594d3
fix(logging): catch AI client errors and test cases added
yashkohli88 Jun 3, 2026
d0b9955
Merge branch 'master' into yk/logger-callback-safety
qtomlinson Jun 23, 2026
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
34 changes: 19 additions & 15 deletions providers/logging/logger.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -39,28 +39,32 @@ class ApplicationInsightsTransport extends Transport {
return
}

const properties = buildProperties(info)
if (info.level === 'error') {
if (info.stack) {
const err = new Error(info.message)
err.stack = info.stack
this.aiClient.trackException({ exception: err, properties })
try {
Comment thread
JamieMagee marked this conversation as resolved.
const properties = buildProperties(info)
if (info.level === 'error') {
if (info.stack) {
const err = new Error(info.message)
err.stack = info.stack
this.aiClient.trackException({ exception: err, properties })
} else {
this.aiClient.trackTrace({
message: info.message,
severity: appInsights.KnownSeverityLevel.Error,
properties
})
}
} else {
this.aiClient.trackTrace({
message: info.message,
severity: appInsights.KnownSeverityLevel.Error,
severity: mapLevel(info.level),
properties
})
}
} else {
this.aiClient.trackTrace({
message: info.message,
severity: mapLevel(info.level),
properties
})
} catch (err) {
console.error('ApplicationInsights telemetry failed', err)
} finally {
Comment thread
JamieMagee marked this conversation as resolved.
callback()
}

callback()
}
}

Expand Down
28 changes: 28 additions & 0 deletions test/unit/providers/logging/loggerTests.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -63,4 +63,32 @@ describe('logger', function () {
expect(trackTrace.firstCall.args[0].message).to.contain('plain error without stack')
expect(trackTrace.firstCall.args[0].severity).to.equal('Error')
})

it('still calls callback if trackTrace throws', done => {
const consoleError = sinon.stub(console, 'error')
trackTrace.throws(new Error('AI unavailable'))
const logger = factory({ aiClient })
logger.info('test message')
clock.runAll()
setImmediate(() => {
expect(trackTrace.callCount).to.equal(1)

@JamieMagee JamieMagee Jun 28, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This checks that trackTrace was called once, but it never checks that the Winston callback ran, which is the whole point of the PR. The done() on line 76 comes from the test's own setImmediate on line 73, so it isn't wired to the transport's callback at all.

I tried breaking the fix to see what these catch. If you skip callback() but don't throw synchronously (the actual hang this PR is about), the test still passes. The only reason it fails today when you revert the fix is that the throw escapes out of logger.info() under fake timers, which is a different failure from the one you care about.

ApplicationInsightsTransport isn't exported, so the cleanest way to assert the real guarantee is to export it and call it directly with a spy:

const cb = sinon.spy()
new ApplicationInsightsTransport({ aiClient }).log({ level: 'info', message: 'x' }, cb)
clock.runAll()
expect(cb.calledOnce).to.equal(true)

Then the test fails if the callback ever stops running. Same idea for the trackException test below.

consoleError.restore()

@JamieMagee JamieMagee Jun 28, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

consoleError.restore() runs after the expect on line 74, inside the faked setImmediate. If that assertion ever fails, it throws out of clock.runAll(), restore() never runs, and done() never fires. afterEach only restores the clock, so console.error stays stubbed as a no-op for the rest of the suite and later tests go quiet.

Putting the stub in a sinon sandbox and resetting it in afterEach keeps cleanup off the assertion's happy path.

done()
})
clock.runAll()
})

it('still calls callback if trackException throws', done => {
const consoleError = sinon.stub(console, 'error')
trackException.throws(new Error('AI unavailable'))
const logger = factory({ aiClient })
logger.log({ level: 'error', message: 'boom', stack: 'Error: boom\n at test:1:1' })
clock.runAll()
setImmediate(() => {
expect(trackException.callCount).to.equal(1)

@JamieMagee JamieMagee Jun 28, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same as above.

consoleError.restore()

@JamieMagee JamieMagee Jun 28, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same as above.

done()
})
clock.runAll()
})
})