debug hanging smoke test

smoke-tests/package.json

@@ -36,7 +36,7 @@
   },
   "tap": {
     "no-coverage": true,
-    "timeout": 1200,
+    "timeout": 600,
     "jobs": 1,
     "test-ignore": "fixtures/*",
     "nyc-arg": [

smoke-tests/test/fixtures/setup.js

@@ -158,7 +158,7 @@ module.exports = async (t, { testdir = {}, debug, mockRegistry = true, useProxy
     log(`${spawnCmd} ${spawnArgs.join(' ')}`)
     log('-'.repeat(40))
 
-    const { stderr, stdout } = await spawn(spawnCmd, spawnArgs, {
+    const p = spawn(spawnCmd, spawnArgs, {
       cwd,
       env: {
         ...getEnvPath(),
@@ -169,10 +169,20 @@ module.exports = async (t, { testdir = {}, debug, mockRegistry = true, useProxy
       ...opts,
     })
 
-    log(stderr)
-    log('-'.repeat(40))
-    log(stdout)
-    log('='.repeat(40))
+    // In debug mode, stream stdout and stderr to console so we can debug hanging processes
+    if (debug) {
+      p.process.stdout.on('data', (c) => log('STDOUT: ' + c.toString().trim()))
+      p.process.stderr.on('data', (c) => log('STDERR: ' + c.toString().trim()))
+    }
+
+    const { stdout, stderr } = await p
+    // If not in debug mode, print full stderr and stdout contents separately
+    if (!debug) {
+      log(stderr)
+      log('-'.repeat(40))
+      log(stdout)
+      log('='.repeat(40))
+    }
 
     return { stderr, stdout }
   }

smoke-tests/test/npm-replace-global.js

@@ -125,7 +125,7 @@ t.test('publish and replace global self', async t => {
     await npmPackage({
       manifest: { packuments: [publishedPackument] },
       tarballs: { [version]: tarball },
-      times: 2,
+      times: 3,
     })
     await fs.rm(cache, { recursive: true, force: true })
     await useNpm('install', 'npm@latest', '--global')

workspaces/arborist/lib/arborist/index.js

@@ -31,59 +31,10 @@ const { homedir } = require('os')
 const { depth } = require('treeverse')
 const mapWorkspaces = require('@npmcli/map-workspaces')
 const { log, time } = require('proc-log')
-
 const { saveTypeMap } = require('../add-rm-pkg-deps.js')
 const AuditReport = require('../audit-report.js')
 const relpath = require('../relpath.js')
-const { LRUCache } = require('lru-cache')
-
-class PackumentCache extends LRUCache {
-  static #heapLimit = require('node:v8').getHeapStatistics().heap_size_limit
-
-  #sizeKey
-  #disposed = new Set()
-
-  #log (...args) {
-    // It's all silly
-    log.silly('packumentCache', ...args)
-  }
-
-  constructor ({ heapFactor = 0.25, maxEntryFactor = 0.5, sizeKey = '_contentLength' } = {}) {
-    const maxSize = Math.floor(PackumentCache.#heapLimit * heapFactor)
-    const maxEntrySize = maxSize * maxEntryFactor
-    super({
-      maxSize,
-      maxEntrySize,
-      // Don't cache if we dont know the size
-      sizeCalculation: (p) => p[sizeKey] || maxEntrySize + 1,
-      dispose: (v, k) => {
-        this.#disposed.add(k)
-        this.#log(k, 'dispose')
-      },
-    })
-    this.#sizeKey = sizeKey
-    this.#log(`heap:${PackumentCache.#heapLimit} maxSize:${maxSize} maxEntrySize:${maxEntrySize}`)
-  }
-
-  set (k, v, ...args) {
-    // we use disposed only for a logging signal if we are setting packuments that
-    // have already been evicted from the cache previously. logging here could help
-    // us tune this in the future.
-    const disposed = this.#disposed.has(k)
-    /* istanbul ignore next - this doesnt happen consistently so hard to test without resorting to unit tests  */
-    if (disposed) {
-      this.#disposed.delete(k)
-    }
-    this.#log(k, 'set', `size:${v[this.#sizeKey]} disposed:${disposed}`)
-    return super.set(k, v, ...args)
-  }
-
-  has (k, ...args) {
-    const has = super.has(k, ...args)
-    this.#log(k, `cache-${has ? 'hit' : 'miss'}`)
-    return has
-  }
-}
+const PackumentCache = require('../packument-cache.js')
 
 const mixins = [
   require('../tracker.js'),

workspaces/arborist/lib/packument-cache.js

@@ -0,0 +1,57 @@
+const { LRUCache } = require('lru-cache')
+const { getHeapStatistics } = require('node:v8')
+const { log } = require('proc-log')
+
+class PackumentCache extends LRUCache {
+  static #heapLimit = Math.floor(getHeapStatistics().heap_size_limit)
+
+  #sizeKey
+  #disposed = new Set()
+
+  #log (...args) {
+    console.error('packumentCache', ...args)
+  }
+
+  constructor ({
+    heapFactor = 0.25,
+    maxEntryFactor = 0.5,
+    sizeKey = '_contentLength',
+  } = {}) {
+    const maxSize = Math.floor(PackumentCache.#heapLimit * heapFactor)
+    const maxEntrySize = Math.floor(maxSize * maxEntryFactor)
+    super({
+      maxSize,
+      maxEntrySize,
+      // Don't cache if we dont know the size
+      sizeCalculation: (p) => p[sizeKey] || maxEntrySize + 1,
+      dispose: (v, k) => {
+        this.#disposed.add(k)
+        this.#log(k, 'dispose')
+      },
+    })
+    this.#sizeKey = sizeKey
+    this.#log(`heap:${PackumentCache.#heapLimit} maxSize:${maxSize} maxEntrySize:${maxEntrySize}`)
+  }
+
+  set (k, v, ...args) {
+    // we use disposed only for a logging signal if we are setting packuments that
+    // have already been evicted from the cache previously. logging here could help
+    // us tune this in the future.
+    const disposed = this.#disposed.has(k)
+    /* istanbul ignore next - this doesnt happen consistently so hard to test without resorting to unit tests  */
+    if (disposed) {
+      this.#disposed.delete(k)
+    }
+    this.#log(k, 'set', `size:${v[this.#sizeKey]} disposed:${disposed}`)
+    return super.set(k, v, ...args)
+  }
+
+  has (k, ...args) {
+    const has = super.has(k, ...args)
+    this.#log(k, `cache-${has ? 'hit' : 'miss'}`)
+    return has
+  }
+}
+
+module.exports = PackumentCache
+// module.exports = Map