Merge branch 'master' into fixHangingTest

Author: Hweinstock

packages/core/src/amazonq/messages/chatMessageDuration.ts

@@ -83,16 +83,28 @@ export class AmazonQChatMessageDuration {
 
             // TODO: handle onContextCommand round trip time
             if (metrics.trigger !== 'onContextCommand') {
+                const editorReceivedMessage = durationFrom('chatMessageSent', 'editorReceivedMessage')
+                const featureReceivedMessage = durationFrom('editorReceivedMessage', 'featureReceivedMessage')
+                const messageDisplayed = durationFrom('featureReceivedMessage', 'messageDisplayed')
+                let reasonDesc = undefined
+
+                /**
+                 * Temporary include more information about outliers so that we can find out if the messages
+                 * aren't being sent or the user is actually doing a different chat flow
+                 */
+                if ([editorReceivedMessage, featureReceivedMessage].some((val) => val > 30000 || val < -30000)) {
+                    reasonDesc = JSON.stringify(metrics.events)
+                }
                 telemetry.amazonq_chatRoundTrip.emit({
                     amazonqChatMessageSentTime: metrics.events.chatMessageSent ?? -1,
-                    amazonqEditorReceivedMessageMs: durationFrom('chatMessageSent', 'editorReceivedMessage') ?? -1,
-                    amazonqFeatureReceivedMessageMs:
-                        durationFrom('editorReceivedMessage', 'featureReceivedMessage') ?? -1,
-                    amazonqMessageDisplayedMs: durationFrom('featureReceivedMessage', 'messageDisplayed') ?? -1,
+                    amazonqEditorReceivedMessageMs: editorReceivedMessage ?? -1,
+                    amazonqFeatureReceivedMessageMs: featureReceivedMessage ?? -1,
+                    amazonqMessageDisplayedMs: messageDisplayed ?? -1,
                     source: metrics.trigger,
                     duration: totalDuration,
                     result: 'Succeeded',
                     traceId: metrics.traceId,
+                    ...(reasonDesc !== undefined ? { reasonDesc } : {}),
                 })
             }
 

packages/core/src/shared/crashMonitoring.ts

@@ -179,7 +179,7 @@ class Heartbeat {
 
     public async start() {
         // Send an initial heartbeat immediately
-        await withFailCtx('initialSendHeartbeat', () => this.state.sendHeartbeat())
+        await withFailCtx('sendHeartbeatInitial', () => this.state.sendHeartbeat())
 
         // Send a heartbeat every interval
         this.intervalRef = globals.clock.setInterval(async () => {
@@ -200,6 +200,10 @@ class Heartbeat {
                 this._onFailure.fire()
             }
         }, this.heartbeatInterval)
+
+        // We will know the first heartbeat, and can infer the next ones starting from this timestamp.
+        // In case of heartbeat failure we have a separate failure metric.
+        telemetry.ide_heartbeat.emit({ timestamp: globals.clock.Date.now(), id: className, result: 'Succeeded' })
     }
 
     /** Stops everything, signifying a graceful shutdown */
@@ -455,38 +459,40 @@ export class FileSystemState {
             })
         }
 
-        await withFailCtx('init', () => fs.mkdir(this.stateDirPath))
+        await withFailCtx('init', () => nodeFs.mkdir(this.stateDirPath, { recursive: true }))
     }
 
     // ------------------ Heartbeat methods ------------------
     public async sendHeartbeat() {
         const extId = this.extId
+        const filePath = this.makeStateFilePath(extId)
+        const now = this.deps.now()
+
+        let fileHandle: nodeFs.FileHandle | undefined
         try {
-            const now = this.deps.now()
             const func = async () => {
-                const filePath = this.makeStateFilePath(extId)
-
-                // We were seeing weird behavior where we possibly read an old file, even though we overwrote it.
-                // So this is a sanity check.
-                await fs.delete(filePath, { force: true })
-
-                await fs.writeFile(filePath, JSON.stringify({ ...this.ext, lastHeartbeat: now }, undefined, 4))
-
-                // Sanity check to verify the write is accessible immediately after
-                const heartbeatData = JSON.parse(await fs.readFileText(filePath)) as ExtInstanceHeartbeat
+                fileHandle = await nodeFs.open(filePath, 'w')
+                await fileHandle.writeFile(JSON.stringify({ ...this.ext, lastHeartbeat: now }, undefined, 4))
+                // Noticing that some file reads are not immediately available after write. `fsync` is known to address this.
+                await fileHandle.sync()
+                await fileHandle.close()
+                fileHandle = undefined
+
+                // Sanity check to verify the latest write is accessible immediately
+                const heartbeatData = JSON.parse(await nodeFs.readFile(filePath, 'utf-8')) as ExtInstanceHeartbeat
                 if (heartbeatData.lastHeartbeat !== now) {
                     throw new CrashMonitoringError('Heartbeat write validation failed', { code: className })
                 }
+
+                this.deps.devLogger?.debug(`crashMonitoring: HEARTBEAT sent for ${truncateUuid(this.ext.sessionId)}`)
             }
             const funcWithCtx = () => withFailCtx('sendHeartbeatState', func)
             const funcWithRetries = withRetries(funcWithCtx, { maxRetries: 6, delay: 100, backoff: 2 })
-            const funcWithTelemetryRun = await telemetry.ide_heartbeat.run((span) => {
-                span.record({ id: className, timestamp: now })
-                return funcWithRetries
-            })
 
-            return funcWithTelemetryRun
+            return funcWithRetries
         } catch (e) {
+            await fileHandle?.close()
+
             // delete this ext from the state to avoid an incorrectly reported crash since we could not send a new heartbeat
             await this.deleteHeartbeatFile(extId, 'sendHeartbeatFailureCleanup')
             throw e
@@ -518,7 +524,21 @@ export class FileSystemState {
 
     private async deleteHeartbeatFile(ext: ExtInstanceId | ExtInstance, ctx: string) {
         // IMPORTANT: Must use NodeFs here since this is used during shutdown
-        const func = () => nodeFs.rm(this.makeStateFilePath(ext), { force: true })
+        const func = async () => {
+            const filePath = this.makeStateFilePath(ext)
+
+            // Even when deleting a file, if there is an open file handle it may still exist. This empties the
+            // contents, so that any following reads will get no data.
+            let fileHandle: nodeFs.FileHandle | undefined
+            try {
+                fileHandle = await nodeFs.open(filePath, 'w')
+                await fileHandle.sync()
+            } finally {
+                await fileHandle?.close()
+            }
+
+            await nodeFs.rm(filePath, { force: true })
+        }
         const funcWithCtx = () => withFailCtx(ctx, func)
         const funcWithRetries = withRetries(funcWithCtx, { maxRetries: 6, delay: 100, backoff: 2 })
         await funcWithRetries
@@ -553,7 +573,7 @@ export class FileSystemState {
     public async clearState(): Promise<void> {
         this.deps.devLogger?.debug('crashMonitoring: CLEAR_STATE: Started')
         await withFailCtx('clearState', async () => {
-            await fs.delete(this.stateDirPath, { force: true, recursive: true })
+            await nodeFs.rm(this.stateDirPath, { force: true, recursive: true })
             this.deps.devLogger?.debug('crashMonitoring: CLEAR_STATE: Succeeded')
         })
     }
@@ -576,7 +596,7 @@ export class FileSystemState {
                 // we will assume that other instance handled its termination appropriately.
                 // NOTE: On Windows we were failing on EBUSY, so we retry on failure.
                 const loadExtFromDisk = async () => {
-                    const text = await fs.readFileText(this.makeStateFilePath(extId))
+                    const text = await nodeFs.readFile(this.makeStateFilePath(extId), 'utf-8')
 
                     if (!text) {
                         return undefined

packages/core/src/shared/env/resolveEnv.ts

@@ -20,7 +20,7 @@ import { asEnvironmentVariables } from '../../auth/credentials/utils'
 import { getIAMConnection } from '../../auth/utils'
 import { ChildProcess } from '../utilities/processUtils'
 
-let unixShellEnvPromise: Promise<typeof process.env> | undefined = undefined
+let unixShellEnvPromise: Promise<typeof process.env | void> | undefined = undefined
 let envCacheExpireTime: number
 
 export interface IProcessEnvironment {
@@ -139,7 +139,7 @@ export async function mergeResolvedShellPath(env: IProcessEnvironment): Promise<
  * - we hit a timeout of `MAX_SHELL_RESOLVE_TIME`
  * - any other error from spawning a shell to figure out the environment
  */
-export async function getResolvedShellEnv(env?: IProcessEnvironment): Promise<typeof process.env | undefined> {
+export async function getResolvedShellEnv(env?: IProcessEnvironment): Promise<typeof process.env | void> {
     if (!env) {
         env = process.env
     }
@@ -176,7 +176,7 @@ export async function getResolvedShellEnv(env?: IProcessEnvironment): Promise<ty
         if (!unixShellEnvPromise || Date.now() > envCacheExpireTime) {
             // cache valid for 5 minutes
             envCacheExpireTime = Date.now() + 5 * 60 * 1000
-            unixShellEnvPromise = new Promise<NodeJS.ProcessEnv>(async (resolve, reject) => {
+            unixShellEnvPromise = new Promise<NodeJS.ProcessEnv | void>(async (resolve, reject) => {
                 const timeout = new Timeout(10000)
 
                 // Resolve shell env and handle errors
@@ -185,11 +185,11 @@ export async function getResolvedShellEnv(env?: IProcessEnvironment): Promise<ty
                     if (shellEnv && Object.keys(shellEnv).length > 0) {
                         resolve(shellEnv)
                     } else {
-                        return undefined
+                        resolve()
                     }
                 } catch {
                     // failed resolve should not affect other feature.
-                    return undefined
+                    resolve()
                 }
             })
         }

packages/core/src/test/shared/fs/node/fs.test.ts

@@ -0,0 +1,52 @@
+/*!
+ * Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
+ * SPDX-License-Identifier: Apache-2.0
+ */
+import nodeFs from 'fs/promises'
+import { TestFolder } from '../../../testUtil'
+import assert from 'assert'
+import { fs } from '../../../../shared'
+
+describe('Node FS', () => {
+    let testFolder: TestFolder
+
+    beforeEach(async function () {
+        testFolder = await TestFolder.create()
+    })
+
+    describe('open()', () => {
+        it('"w" flag clears file content', async () => {
+            const filePath = testFolder.pathFrom('file.txt')
+
+            // Make initial file with text
+            await nodeFs.writeFile(filePath, 'test')
+            assert.strictEqual(await fs.readFileText(filePath), 'test')
+
+            // Open file with "w"
+            const fileHandle = await nodeFs.open(filePath, 'w')
+            await fileHandle.close()
+
+            // file content was cleared
+            assert.strictEqual(await fs.readFileText(filePath), '')
+        })
+    })
+
+    describe('sync()', () => {
+        // we cannot accurately test if sync() works, so just assert nothing breaks when using it
+        it('runs without error', async () => {
+            const filePath = testFolder.pathFrom('file.txt')
+
+            // Make initial file with text
+            await nodeFs.writeFile(filePath, 'test')
+            assert.strictEqual(await fs.readFileText(filePath), 'test')
+
+            const fileHandle = await nodeFs.open(filePath, 'w')
+            await fileHandle.writeFile('updatedText')
+            await fileHandle.sync() // method under test
+            await fileHandle.close()
+
+            // file content was cleared
+            assert.strictEqual(await fs.readFileText(filePath), 'updatedText')
+        })
+    })
+})