Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
59 changes: 52 additions & 7 deletions channels/1ds-post-js/src/PostChannel.ts
Original file line number Diff line number Diff line change
Expand Up @@ -805,16 +805,53 @@ export class PostChannel extends BaseTelemetryPlugin implements IChannelControls
}

function _performAutoFlush(isAsync: boolean, doFlush?: boolean) {
// Only perform the auto flush check if the httpManager has an idle connection and we are not in a backoff situation
if (_httpManager.canSendRequest() && !_currentBackoffCount) {
if (_autoFlushEventsLimit > 0 && _queueSize > _autoFlushEventsLimit) {
// Force flushing
doFlush = true;
}

if (doFlush && _flushCallbackTimer == null) {
// Auto flush the queue, adding a callback to avoid the creation of a promise
_self.flush(isAsync, () => {}, SendRequestReason.MaxQueuedEvents);
// Auto flush is fire-and-forget (the callback is a no-op). Historically it
// called flush(), whose async path defers the send via a 0ms timer and then
// calls _waitForIdleManager(), which re-arms _flushCallbackTimer and polls
// (every FlushCheckTimer) until the HttpManager reports it is "completely idle"
// (no outstanding requests AND an empty send queue). While _flushCallbackTimer
// is non-null BOTH the normal scheduled timer (_scheduleTimer) and any further
// auto flush are suppressed. Under sustained intermittent failures (e.g. a load
// balancer recycling connections) there is almost always a retry in-flight or a
// re-queued batch, so the manager is rarely completely idle at the polling
// instant: the wait never completes, _flushCallbackTimer stays set and the
// channel stops draining permanently (the in-memory queue then saturates and
// telemetry is silently dropped as QueueFull) until the process is restarted.
//
// We keep the original deferred fire-and-forget behaviour (so the queue/discard
// semantics are unchanged) but tell _flushImpl NOT to wait for the manager to
// become idle: after the send it just resumes the normal schedule, so a
// busy/non-idle manager can no longer wedge draining.
if (isAsync) {
// Clear the normal schedule timer as we are going to try and flush ASAP
_clearScheduledTimer();

// Move all queued events to the HttpManager so that we don't discard new events (Auto flush scenario)
_queueBatches(EventLatencyValue.Normal, EventSendType.Batched, SendRequestReason.MaxQueuedEvents);
Comment on lines +832 to +837

_flushCallbackTimer = _createTimer(() => {
_flushCallbackTimer = null;
// waitForIdle = false -> fire-and-forget: do not park the scheduler
_flushImpl(() => { /* no-op */ }, SendRequestReason.MaxQueuedEvents, false);
}, 0);
} else {
let cleared = _clearScheduledTimer();

// Now cause all queued events to be sent synchronously
_sendEventsForLatencyAndAbove(EventLatencyValue.Normal, EventSendType.Synchronous, SendRequestReason.MaxQueuedEvents);

if (cleared) {
// restart the normal event timer if it was cleared
_scheduleTimer();
}
}
}
}
}
Expand Down Expand Up @@ -961,15 +998,17 @@ export class PostChannel extends BaseTelemetryPlugin implements IChannelControls
* @param callback - The callback method to call after the flush is complete
* @param sendReason - The reason why the flush is being called
*/
function _flushImpl(callback: () => void, sendReason: SendRequestReason) {
function _flushImpl(callback: () => void, sendReason: SendRequestReason, waitForIdle?: boolean) {
// Add any additional queued events and cause all queued events to be sent asynchronously
_sendEventsForLatencyAndAbove(EventLatencyValue.Normal, EventSendType.Batched, sendReason);

// All events (should) have been queue -- lets just make sure the queue counts are correct to avoid queue exhaustion (previous bug #9685112)
_resetQueueCounts();

_waitForIdleManager(() => {
// Only called AFTER the httpManager does not have any outstanding requests
let onFlushComplete = () => {
// Only called AFTER the httpManager does not have any outstanding requests, or
// immediately for a fire-and-forget auto flush (waitForIdle === false), which must
// not park the scheduler waiting for a manager that may never become idle.
if (callback) {
callback();
}
Expand All @@ -986,7 +1025,13 @@ export class PostChannel extends BaseTelemetryPlugin implements IChannelControls
// Restart the normal timer schedule
_scheduleTimer();
}
});
};

if (waitForIdle === false) {
onFlushComplete();
} else {
_waitForIdleManager(onFlushComplete);
}
}

function _waitForIdleManager(callback: () => void) {
Expand Down
64 changes: 64 additions & 0 deletions channels/1ds-post-js/test/Unit/src/PostChannelTest.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4004,6 +4004,70 @@ export class PostChannelTest extends AITestClass {
}
});

this.testCase({
name: "Regression (permanent stall): auto flush does not wedge behind the flush() wait-for-idle timer",
useFakeTimers: true,
test: () => {
// Fully controllable transport: record each request and let the test decide
// if/when it completes.
let sentRequests: Array<{ oncomplete: (status: number, headers: any) => void }> = [];
this.config.extensionConfig[this.postChannel.identifier] = {
httpXHROverride: {
sendPOST: (payload: IPayloadData, oncomplete: (status: number, headers: { [headerName: string]: string }) => void, sync?: boolean) => {
sentRequests.push({ oncomplete: oncomplete });
}
},
// Drive auto flush purely from the queued-event count (not the per-batch limit).
autoFlushEventsLimit: 5,
disableAutoBatchFlushLimit: true,
eventsLimitInMem: 1000
};

this.core.initialize(this.config, [this.postChannel]);
this.clock.tick(1);

let addEvents = (count: number) => {
for (let lp = 0; lp < count; lp++) {
this.postChannel.processTelemetry({
name: "stallEvt",
latency: EventLatency.Normal,
iKey: "testIkey"
} as IPostTransmissionTelemetryItem);
}
// Let any 0ms timer settle (the fix drains synchronously; this is defensive).
this.clock.tick(1);
};

// First burst crosses autoFlushEventsLimit -> auto flush triggers -> request #1 is sent.
addEvents(6);
QUnit.assert.equal(sentRequests.length, 1, "request #1 should have been sent, got " + sentRequests.length);

// Complete request #1. This clears the "first response" (clock-skew) gate so more
// requests are allowed to be sent again. Note we only advance the clock by 1ms, so any
// pending timer with a larger delay does NOT fire yet.
sentRequests[0].oncomplete(200, {});
this.clock.tick(1);

// A second burst crosses the auto flush limit again.
//
// Before the fix, the auto flush in the first burst routed through
// flush() -> _flushImpl -> _waitForIdleManager, which parked _flushCallbackTimer as a
// poll timer (fires on the FlushCheckTimer interval, not within our 1ms tick). While
// _flushCallbackTimer is non-null BOTH the scheduled timer and any further auto flush
// are suppressed, so this second burst would NOT be sent here (the channel is wedged
// waiting for the manager to become "completely idle"). With the fix, auto flush drains
// directly and never sets _flushCallbackTimer, so request #2 goes out immediately.
addEvents(6);
QUnit.assert.equal(sentRequests.length, 2, "request #2 must be sent - auto flush must not be wedged behind the flush() wait-for-idle timer (got " + sentRequests.length + ")");

// And it must keep working for subsequent bursts too.
sentRequests[1].oncomplete(200, {});
this.clock.tick(1);
addEvents(6);
QUnit.assert.equal(sentRequests.length, 3, "request #3 must be sent - the channel keeps draining (got " + sentRequests.length + ")");
}
});

}
}

Expand Down
2 changes: 1 addition & 1 deletion common/config/rush/pnpm-config.json
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@
"$schema": "https://developer.microsoft.com/json-schemas/rush/v5/pnpm-config.schema.json",
"globalOverrides": {
"minimatch": ">=3.1.5",
"tar": ">=7.5.13",
"tar": ">=7.5.16",
"glob": ">=7.2.3",
Comment on lines 4 to 6

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Is this a genuine concern?

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

Not really, tar is only used internally not even a direct dependency in any code in this project, it get dragged with npm

"lodash": ">=4.18.1",
"postcss": ">=8.5.14",
Expand Down
2 changes: 1 addition & 1 deletion package.json
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,7 @@
"overrides": {
"basic-ftp": ">=5.2.0",
"form-data": "^2.5.5",
"tar": "^7.5.13",
"tar": ">=7.5.16",
"glob": "^7.2.3",
"lodash": "^4.18.1",
Comment on lines 79 to 83
"minimatch": "^3.1.5"
Expand Down
Loading