fix: FileNotFound error during SSO token refresh (#5392)

* refactor: increase scrubNames() file ext limit Problem: scrubNames() removes PII from a file path. There is also a limit to the file extension length of 4 characters. If the length is greater, the file ext is fully excluded. We have some scenarios in telemetry where the file has no file ext but we want to see it. A guess is that there are some cases where the file ext is longer than 4 chars. Solution: Show the file ext regardless of its length. Signed-off-by: Nikolas Komonen <[email protected]> * bug: rename() fails causing FileNotFoundError Problem: In our aws_refreshCredentials telemetry we saw a spike in FileNotFound errors when writing the refreshed token to our filesystem. This is caused by something in the vscode.workspace.fs.rename() implementation that is not obvious and does not seem like an obvious error on our end. Most of the time things work, so most users are not running in to this problem. Originally, to fix some errors happening during writing to the filesystem we created an "atomic" write, but there are edge cases where this did not work. So there are different implementations of writing a file that we used to rememdy this. Solution: Try the next fallback methods for saving the file to the file system when one fails. See the comment in the code for the explanation of the implementation. We also report telemetry on the specific failed cases to hopefully get a better understanding of the specific failures. We can use this Signed-off-by: Nikolas Komonen <[email protected]> * changelog items Signed-off-by: Nikolas Komonen <[email protected]> * add tests + logging Signed-off-by: Nikolas Komonen <[email protected]> --------- Signed-off-by: Nikolas Komonen <[email protected]>
aws · Jul 29, 2024 · 3eb168d · 3eb168d
1 parent 9b8f4d0
commit 3eb168d
Show file tree

Hide file tree

Showing 6 changed files with 116 additions and 14 deletions.
diff --git a/packages/amazonq/.changes/next-release/Bug Fix-ceb237af-1d58-4560-9939-c07074eb3eee.json b/packages/amazonq/.changes/next-release/Bug Fix-ceb237af-1d58-4560-9939-c07074eb3eee.json
@@ -0,0 +1,4 @@
+{
+	"type": "Bug Fix",
+	"description": "FileNotFound error causing early SSO expiration"
+}
diff --git a/packages/core/src/shared/errors.ts b/packages/core/src/shared/errors.ts
@@ -345,7 +345,7 @@ export function getTelemetryResult(error: unknown | undefined): Result {
  */
 export function scrubNames(s: string, username?: string) {
     let r = ''
-    const fileExtRe = /\.[^.\/]{1,4}$/
+    const fileExtRe = /\.[^.\/]+$/
     const slashdot = /^[~.]*[\/\\]*/
 
     /** Allowlisted filepath segments. */

diff --git a/packages/core/src/shared/fs/fs.ts b/packages/core/src/shared/fs/fs.ts
@@ -2,7 +2,7 @@
  * Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
  * SPDX-License-Identifier: Apache-2.0
  */
-import * as vscode from 'vscode'
+import vscode from 'vscode'
 import os from 'os'
 import { promises as nodefs, constants as nodeConstants, WriteFileOptions } from 'fs'
 import { isCloud9 } from '../extensionUtilities'
@@ -11,6 +11,7 @@ import {
     PermissionsError,
     PermissionsTriplet,
     ToolkitError,
+    getTelemetryReasonDesc,
     isFileNotFoundError,
     isPermissionsError,
     scrubNames,
@@ -21,6 +22,7 @@ import { resolvePath } from '../utilities/pathUtils'
 import crypto from 'crypto'
 import { waitUntil } from '../utilities/timeoutUtils'
 import { telemetry } from '../telemetry/telemetry'
+import { getLogger } from '../logger/logger'
 
 const vfs = vscode.workspace.fs
 type Uri = vscode.Uri
@@ -236,13 +238,55 @@ export class FileSystem {
         await fs.mkdir(_path.dirname(uri.fsPath))
 
         if (opts?.atomic) {
+            // Background: As part of an "atomic write" we write to a temp file, then rename
+            // to the target file. The problem was that each `rename()` implementation doesn't always
+            // work. The solution is to try each implementation and then fallback to a regular write if none of them work.
+            // 1. Atomic write with VSC rename(), but may throw `FileNotFound` errors
+            //    - Looks to be this error from what we see in telemetry: https://github.com/microsoft/vscode/blob/09d5f4efc5089ce2fc5c8f6aeb51d728d7f4e758/src/vs/platform/files/common/fileService.ts#L1029-L1030
+            // 2. Atomic write with Node rename(), but may throw `EPERM` errors on Windows
+            //    - This is explained in https://github.com/aws/aws-toolkit-vscode/pull/5335
+            //    - Step 1 is supposed to address the EPERM issue
+            // 3. Finally, do a regular file write, but may result in invalid file content
+            //
+            // For telemetry, we will only report failures as to not overload with succeed events.
             const tempFile = this.#toUri(`${uri.fsPath}.${crypto.randomBytes(8).toString('hex')}.tmp`)
-            await write(tempFile)
-            await fs.rename(tempFile, uri)
-            return
-        } else {
-            await write(uri)
+            try {
+                await write(tempFile)
+                await fs.rename(tempFile, uri)
+                return
+            } catch (e) {
+                telemetry.ide_fileSystem.emit({
+                    action: 'writeFile',
+                    result: 'Failed',
+                    reason: 'writeFileAtomicVscRename',
+                    reasonDesc: getTelemetryReasonDesc(e),
+                })
+                getLogger().warn(`writeFile atomic VSC failed for, ${uri.fsPath}, with %O`, e)
+                // Atomic write with VSC rename() failed, so try with Node rename()
+                try {
+                    await write(tempFile)
+                    await nodefs.rename(tempFile.fsPath, uri.fsPath)
+                    return
+                } catch (e) {
+                    telemetry.ide_fileSystem.emit({
+                        action: 'writeFile',
+                        result: 'Failed',
+                        reason: 'writeFileAtomicNodeRename',
+                        reasonDesc: getTelemetryReasonDesc(e),
+                    })
+                    getLogger().warn(`writeFile atomic Node failed for, ${uri.fsPath}, with %O`, e)
+                    // The atomic rename techniques were not successful, so we will
+                    // just resort to regular a non-atomic write
+                }
+            } finally {
+                // clean up temp file since it possibly remains
+                if (await fs.exists(tempFile)) {
+                    await fs.delete(tempFile)
+                }
+            }
         }
+
+        await write(uri)
     }
 
     async rename(oldPath: vscode.Uri | string, newPath: vscode.Uri | string) {

diff --git a/packages/core/src/test/shared/errors.test.ts b/packages/core/src/test/shared/errors.test.ts
@@ -518,12 +518,17 @@ describe('util', function () {
             scrubNames('user: jdoe123 file: C:/Users/user1/.aws/sso/cache/abc123.json (regex: /foo/)', fakeUser),
             'user: x file: C:/Users/x/.aws/sso/cache/x.json (regex: /x/)'
         )
-        assert.deepStrictEqual(scrubNames('/Users/user1/foo.jso (?)', fakeUser), '/Users/x/x.jso (?)')
-        assert.deepStrictEqual(scrubNames('/Users/user1/foo.js (?)', fakeUser), '/Users/x/x.js (?)')
-        assert.deepStrictEqual(scrubNames('/Users/user1/foo.longextension (?)', fakeUser), '/Users/x/x (?)')
-        assert.deepStrictEqual(scrubNames('/Users/user1/foo.ext1.ext2.ext3', fakeUser), '/Users/x/x.ext3')
-        assert.deepStrictEqual(scrubNames('/Users/user1/extMaxLength.1234', fakeUser), '/Users/x/x.1234')
-        assert.deepStrictEqual(scrubNames('/Users/user1/extExceedsMaxLength.12345', fakeUser), '/Users/x/x')
+        assert.deepStrictEqual(scrubNames('/Users/user1/foo.jso', fakeUser), '/Users/x/x.jso')
+        assert.deepStrictEqual(scrubNames('/Users/user1/foo.js', fakeUser), '/Users/x/x.js')
+        assert.deepStrictEqual(scrubNames('/Users/user1/noFileExtension', fakeUser), '/Users/x/x')
+        assert.deepStrictEqual(scrubNames('/Users/user1/minExtLength.a', fakeUser), '/Users/x/x.a')
+        assert.deepStrictEqual(scrubNames('/Users/user1/extIsNum.123456', fakeUser), '/Users/x/x.123456')
+        assert.deepStrictEqual(
+            scrubNames('/Users/user1/foo.looooooooongextension', fakeUser),
+            '/Users/x/x.looooooooongextension'
+        )
+        assert.deepStrictEqual(scrubNames('/Users/user1/multipleExts.ext1.ext2.ext3', fakeUser), '/Users/x/x.ext3')
+
         assert.deepStrictEqual(scrubNames('c:\\fooß\\bar\\baz.txt', fakeUser), 'c:/xß/x/x.txt')
         assert.deepStrictEqual(
             scrubNames('uhh c:\\path with\\ spaces \\baz.. hmm...', fakeUser),

diff --git a/packages/core/src/test/shared/fs/fs.test.ts b/packages/core/src/test/shared/fs/fs.test.ts
@@ -4,10 +4,11 @@
  */
 
 import assert from 'assert'
-import * as vscode from 'vscode'
+import vscode from 'vscode'
 import * as path from 'path'
 import * as utils from 'util'
 import { existsSync, mkdirSync, promises as nodefs, readFileSync, rmSync } from 'fs'
+import nodeFs from 'fs'
 import { FakeExtensionContext } from '../../fakeExtensionContext'
 import fs, { FileSystem } from '../../../shared/fs/fs'
 import * as os from 'os'
@@ -19,6 +20,7 @@ import { EnvironmentVariables } from '../../../shared/environmentVariables'
 import * as testutil from '../../testUtil'
 import globals from '../../../shared/extensionGlobals'
 import { driveLetterRegex } from '../../../shared/utilities/pathUtils'
+import { IdeFileSystem } from '../../../shared/telemetry/telemetry.gen'
 
 describe('FileSystem', function () {
     let fakeContext: vscode.ExtensionContext
@@ -93,6 +95,49 @@ describe('FileSystem', function () {
             assert.strictEqual(readFileSync(filePath, 'utf-8'), 'MyContent')
         })
 
+        // We try multiple methods to do an atomic write, but if one fails we want to fallback
+        // to the next method. The following are the different combinations of this when a method throws.
+        const throwCombinations = [
+            { vsc: false, node: false },
+            { vsc: true, node: false },
+            { vsc: true, node: true },
+        ]
+        throwCombinations.forEach((throws) => {
+            it(`still writes a file if one of the atomic write methods fails: ${JSON.stringify(throws)}`, async function () {
+                if (throws.vsc) {
+                    sandbox.stub(fs, 'rename').throws(new Error('Test Error Message VSC'))
+                }
+                if (throws.node) {
+                    sandbox.stub(nodeFs.promises, 'rename').throws(new Error('Test Error Message Node'))
+                }
+                const filePath = createTestPath('myFileName')
+
+                await fs.writeFile(filePath, 'MyContent', { atomic: true })
+
+                assert.strictEqual(readFileSync(filePath, 'utf-8'), 'MyContent')
+                const expectedTelemetry: IdeFileSystem[] = []
+                if (throws.vsc) {
+                    expectedTelemetry.push({
+                        action: 'writeFile',
+                        result: 'Failed',
+                        reason: 'writeFileAtomicVscRename',
+                        reasonDesc: 'Test Error Message VSC',
+                    })
+                }
+                if (throws.node) {
+                    expectedTelemetry.push({
+                        action: 'writeFile',
+                        result: 'Failed',
+                        reason: 'writeFileAtomicNodeRename',
+                        reasonDesc: 'Test Error Message Node',
+                    })
+                }
+                if (expectedTelemetry.length > 0) {
+                    testutil.assertTelemetry('ide_fileSystem', expectedTelemetry)
+                }
+            })
+        })
+
         it('throws when existing file + no permission', async function () {
             if (isWin()) {
                 console.log('Skipping since windows does not support mode permissions')

diff --git a/packages/toolkit/.changes/next-release/Bug Fix-04a6bfcb-9d56-4388-aadd-50e6c7db9670.json b/packages/toolkit/.changes/next-release/Bug Fix-04a6bfcb-9d56-4388-aadd-50e6c7db9670.json
@@ -0,0 +1,4 @@
+{
+	"type": "Bug Fix",
+	"description": "FileNotFound error causing early SSO expiration"
+}