sharp icon indicating copy to clipboard operation
sharp copied to clipboard

Custom libvips, NixOS, require('sharp') taking between 5 and 20 seconds

Open tim-kos opened this issue 3 years ago • 5 comments

Possible install-time or require-time problem

  • [x] I have read the documentation relating to installation.
  • [x] I have ensured that the architecture and platform of Node.js used for npm install is the same as the architecture and platform of Node.js used at runtime.

Are you using the latest version of sharp?

No, but the issue is unrelated to that.

  • [ ] I am using the latest version of sharp as reported by npm view sharp dist-tags.latest.

I am using 0.30.2.

[email protected]
├─ color@^4.2.1
├─ detect-libc@^2.0.1
├─ node-addon-api@^4.3.0
├─ prebuild-install@^7.0.1
├─ semver@^7.3.5
├─ [email protected]
│  └─ lru-cache@^6.0.0
├─ simple-get@^4.0.1
├─ tar-fs@^2.1.1
└─ tunnel-agent@^0.6.0

Is this a problem with filesystem permissions?

If you are using npm v6 or earlier and installing as a root or sudo user, have you tried with the npm install --unsafe-perm flag?

If you are using npm v7 or later, does the user running npm install own the directory it is run in?

If you are using the ignore-scripts feature of npm, have you tried with the npm install --ignore-scripts=false flag?

What is the complete output of running npm install --verbose --foreground-scripts sharp in an empty directory?

$ npm install --verbose --foreground-scripts sharp
npm verb cli /nix/store/lbsd10sv0bc53x7apqgm5drl0pmbc7h8-nodejs-16.15.1/bin/node /srv/recent/2923918988/api2/software/bin/npm
npm info using [email protected]
npm info using [email protected]
npm timing npm:load:whichnode Completed in 0ms
npm timing config:load:defaults Completed in 1ms
npm timing config:load:file:/nix/store/lbsd10sv0bc53x7apqgm5drl0pmbc7h8-nodejs-16.15.1/lib/node_modules/npm/npmrc Completed in 0ms
npm timing config:load:builtin Completed in 0ms
npm timing config:load:cli Completed in 2ms
npm timing config:load:env Completed in 2ms
npm timing config:load:file:/srv/recent/2923918988/foo/.npmrc Completed in 0ms
npm timing config:load:project Completed in 8ms
npm timing config:load:file:/home/ubuntu/.npmrc Completed in 0ms
npm timing config:load:user Completed in 0ms
npm timing config:load:file:/nix/store/lbsd10sv0bc53x7apqgm5drl0pmbc7h8-nodejs-16.15.1/etc/npmrc Completed in 1ms
npm timing config:load:global Completed in 1ms
npm timing config:load:validate Completed in 0ms
npm timing config:load:credentials Completed in 1ms
npm timing config:load:setEnvs Completed in 0ms
npm timing config:load Completed in 17ms
npm timing npm:load:configload Completed in 17ms
npm timing npm:load:mkdirpcache Completed in 0ms
npm timing npm:load:mkdirplogs Completed in 0ms
npm verb title npm install sharp
npm verb argv "install" "--loglevel" "verbose" "--foreground-scripts" "sharp"
npm timing npm:load:setTitle Completed in 1ms
npm timing config:load:flatten Completed in 2ms
npm timing npm:load:display Completed in 7ms
npm verb logfile logs-max:10 dir:/srv/shared/npm/_logs
npm verb logfile /srv/shared/npm/_logs/2022-08-25T10_22_38_758Z-debug-0.log
npm timing npm:load:logFile Completed in 4ms
npm timing npm:load:timers Completed in 0ms
npm timing npm:load:configScope Completed in 0ms
npm timing npm:load Completed in 32ms
npm timing arborist:ctor Completed in 0ms
npm timing arborist:ctor Completed in 1ms
npm timing idealTree:init Completed in 10ms
npm timing idealTree:userRequests Completed in 2ms
npm http fetch GET 200 https://registry.npmjs.org/sharp 13ms (cache hit)
npm http fetch GET 200 https://registry.npmjs.org/tunnel-agent 30ms (cache hit)
npm http fetch GET 200 https://registry.npmjs.org/detect-libc 96ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/color 102ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/simple-get 106ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/node-addon-api 112ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/prebuild-install 113ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/semver 113ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/tar-fs 114ms (cache miss)
npm timing idealTree:#root Completed in 144ms
npm http fetch GET 200 https://registry.npmjs.org/color-convert 51ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/expand-template 52ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/color-string 56ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/napi-build-utils 62ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/minimist 69ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/mkdirp-classic 71ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/pump 82ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/github-from-package 85ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/chownr 82ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/once 89ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/safe-buffer 87ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/simple-concat 93ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/decompress-response 95ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/tar-stream 94ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/node-abi 104ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/lru-cache 103ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/mkdirp-classic 105ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/rc 270ms (cache miss)
npm timing idealTree:node_modules/sharp Completed in 293ms
npm http fetch GET 200 https://registry.npmjs.org/color-name 33ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/simple-swizzle 34ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/color-name 39ms (cache miss)
npm timing idealTree:node_modules/color Completed in 43ms
npm timing idealTree:node_modules/color-convert Completed in 2ms
npm timing idealTree:node_modules/color-name Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/is-arrayish 32ms (cache miss)
npm timing idealTree:node_modules/color-string Completed in 34ms
npm timing idealTree:node_modules/detect-libc Completed in 0ms
npm timing idealTree:node_modules/node-addon-api Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/ini 6ms (cache hit)
npm http fetch GET 200 https://registry.npmjs.org/strip-json-comments 31ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/deep-extend 34ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/end-of-stream 35ms (cache miss)
npm timing idealTree:node_modules/prebuild-install Completed in 45ms
npm timing idealTree:node_modules/expand-template Completed in 0ms
npm timing idealTree:node_modules/github-from-package Completed in 0ms
npm timing idealTree:node_modules/minimist Completed in 0ms
npm timing idealTree:node_modules/mkdirp-classic Completed in 0ms
npm timing idealTree:node_modules/napi-build-utils Completed in 0ms
npm timing idealTree:node_modules/node-abi Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/wrappy 28ms (cache miss)
npm timing idealTree:node_modules/pump Completed in 31ms
npm timing idealTree:node_modules/end-of-stream Completed in 0ms
npm timing idealTree:node_modules/once Completed in 1ms
npm timing idealTree:node_modules/rc Completed in 4ms
npm timing idealTree:node_modules/deep-extend Completed in 0ms
npm timing idealTree:node_modules/ini Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/yallist 35ms (cache miss)
npm timing idealTree:node_modules/semver Completed in 39ms
npm timing idealTree:node_modules/lru-cache Completed in 1ms
npm http fetch GET 200 https://registry.npmjs.org/mimic-response 28ms (cache miss)
npm timing idealTree:node_modules/simple-get Completed in 30ms
npm timing idealTree:node_modules/decompress-response Completed in 1ms
npm timing idealTree:node_modules/mimic-response Completed in 0ms
npm timing idealTree:node_modules/simple-concat Completed in 0ms
npm timing idealTree:node_modules/simple-swizzle Completed in 1ms
npm timing idealTree:node_modules/is-arrayish Completed in 0ms
npm timing idealTree:node_modules/strip-json-comments Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/bl 27ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/inherits 34ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/fs-constants 37ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/readable-stream 39ms (cache miss)
npm timing idealTree:node_modules/tar-fs Completed in 45ms
npm timing idealTree:node_modules/chownr Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/util-deprecate 38ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/buffer 42ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/string_decoder 46ms (cache miss)
npm timing idealTree:node_modules/tar-stream Completed in 52ms
npm http fetch GET 200 https://registry.npmjs.org/base64-js 29ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/ieee754 36ms (cache miss)
npm timing idealTree:node_modules/bl Completed in 40ms
npm timing idealTree:node_modules/buffer Completed in 2ms
npm timing idealTree:node_modules/base64-js Completed in 0ms
npm timing idealTree:node_modules/fs-constants Completed in 0ms
npm timing idealTree:node_modules/ieee754 Completed in 0ms
npm timing idealTree:node_modules/inherits Completed in 0ms
npm timing idealTree:node_modules/readable-stream Completed in 2ms
npm timing idealTree:node_modules/string_decoder Completed in 1ms
npm timing idealTree:node_modules/safe-buffer Completed in 0ms
npm timing idealTree:node_modules/tunnel-agent Completed in 0ms
npm timing idealTree:node_modules/util-deprecate Completed in 0ms
npm timing idealTree:node_modules/wrappy Completed in 0ms
npm timing idealTree:node_modules/yallist Completed in 0ms
npm timing idealTree:buildDeps Completed in 817ms
npm timing idealTree:fixDepFlags Completed in 1ms
npm timing idealTree Completed in 831ms
npm timing reify:loadTrees Completed in 831ms
npm timing reify:diffTrees Completed in 1ms
npm timing reify:retireShallow Completed in 1ms
npm timing reify:createSparse Completed in 6ms
npm timing reify:trashOmits Completed in 0ms
npm timing reify:loadBundles Completed in 0ms
npm http fetch POST 200 https://registry.npmjs.org/-/npm/v1/security/advisories/bulk 287ms
npm timing auditReport:getReport Completed in 291ms
npm timing auditReport:init Completed in 0ms
npm timing reify:audit Completed in 293ms
npm http fetch GET 200 https://registry.npmjs.org/base64-js/-/base64-js-1.5.1.tgz 416ms (cache miss)
npm timing reifyNode:node_modules/base64-js Completed in 451ms
npm http fetch GET 200 https://registry.npmjs.org/inherits/-/inherits-2.0.4.tgz 412ms (cache miss)
npm timing reifyNode:node_modules/inherits Completed in 466ms
npm http fetch GET 200 https://registry.npmjs.org/fs-constants/-/fs-constants-1.0.0.tgz 413ms (cache miss)
npm timing reifyNode:node_modules/fs-constants Completed in 469ms
npm http fetch GET 200 https://registry.npmjs.org/mkdirp-classic/-/mkdirp-classic-0.5.3.tgz 343ms (cache miss)
npm timing reifyNode:node_modules/mkdirp-classic Completed in 475ms
npm http fetch GET 200 https://registry.npmjs.org/util-deprecate/-/util-deprecate-1.0.2.tgz 456ms (cache miss)
npm timing reifyNode:node_modules/util-deprecate Completed in 484ms
npm http fetch GET 200 https://registry.npmjs.org/chownr/-/chownr-1.1.4.tgz 418ms (cache miss)
npm timing reifyNode:node_modules/chownr Completed in 489ms
npm http fetch GET 200 https://registry.npmjs.org/string_decoder/-/string_decoder-1.3.0.tgz 451ms (cache miss)
npm timing reifyNode:node_modules/string_decoder Completed in 493ms
npm http fetch GET 200 https://registry.npmjs.org/strip-json-comments/-/strip-json-comments-2.0.1.tgz 406ms (cache miss)
npm timing reifyNode:node_modules/strip-json-comments Completed in 500ms
npm http fetch GET 200 https://registry.npmjs.org/ieee754/-/ieee754-1.2.1.tgz 475ms (cache miss)
npm timing reifyNode:node_modules/ieee754 Completed in 506ms
npm http fetch GET 200 https://registry.npmjs.org/once/-/once-1.4.0.tgz 401ms (cache miss)
npm timing reifyNode:node_modules/once Completed in 508ms
npm http fetch GET 200 https://registry.npmjs.org/end-of-stream/-/end-of-stream-1.4.4.tgz 398ms (cache miss)
npm timing reifyNode:node_modules/end-of-stream Completed in 511ms
npm http fetch GET 200 https://registry.npmjs.org/safe-buffer/-/safe-buffer-5.2.1.tgz 498ms (cache miss)
npm timing reifyNode:node_modules/safe-buffer Completed in 521ms
npm http fetch GET 200 https://registry.npmjs.org/yallist/-/yallist-4.0.0.tgz 447ms (cache miss)
npm timing reifyNode:node_modules/yallist Completed in 524ms
npm http fetch GET 200 https://registry.npmjs.org/decompress-response/-/decompress-response-6.0.0.tgz 447ms (cache miss)
npm timing reifyNode:node_modules/decompress-response Completed in 527ms
npm http fetch GET 200 https://registry.npmjs.org/wrappy/-/wrappy-1.0.2.tgz 430ms (cache miss)
npm timing reifyNode:node_modules/wrappy Completed in 529ms
npm http fetch GET 200 https://registry.npmjs.org/pump/-/pump-3.0.0.tgz 419ms (cache miss)
npm timing reifyNode:node_modules/pump Completed in 535ms
npm http fetch GET 200 https://registry.npmjs.org/github-from-package/-/github-from-package-0.0.0.tgz 397ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/color-name/-/color-name-1.1.4.tgz 387ms (cache miss)
npm timing reifyNode:node_modules/color-name Completed in 541ms
npm http fetch GET 200 https://registry.npmjs.org/mimic-response/-/mimic-response-3.1.0.tgz 342ms (cache miss)
npm timing reifyNode:node_modules/mimic-response Completed in 545ms
npm http fetch GET 200 https://registry.npmjs.org/lru-cache/-/lru-cache-6.0.0.tgz 473ms (cache miss)
npm timing reifyNode:node_modules/lru-cache Completed in 555ms
npm http fetch GET 200 https://registry.npmjs.org/napi-build-utils/-/napi-build-utils-1.0.2.tgz 429ms (cache miss)
npm timing reifyNode:node_modules/napi-build-utils Completed in 558ms
npm http fetch GET 200 https://registry.npmjs.org/expand-template/-/expand-template-2.0.3.tgz 414ms (cache miss)
npm timing reifyNode:node_modules/expand-template Completed in 561ms
npm http fetch GET 200 https://registry.npmjs.org/ini/-/ini-1.3.8.tgz 476ms (cache miss)
npm timing reifyNode:node_modules/ini Completed in 567ms
npm http fetch GET 200 https://registry.npmjs.org/deep-extend/-/deep-extend-0.6.0.tgz 474ms (cache miss)
npm timing reifyNode:node_modules/deep-extend Completed in 569ms
npm http fetch GET 200 https://registry.npmjs.org/color-string/-/color-string-1.9.1.tgz 418ms (cache miss)
npm timing reifyNode:node_modules/color-string Completed in 580ms
npm timing reifyNode:node_modules/github-from-package Completed in 582ms
npm http fetch GET 200 https://registry.npmjs.org/tunnel-agent/-/tunnel-agent-0.6.0.tgz 418ms (cache miss)
npm timing reifyNode:node_modules/tunnel-agent Completed in 585ms
npm http fetch GET 200 https://registry.npmjs.org/simple-get/-/simple-get-4.0.1.tgz 410ms (cache miss)
npm timing reifyNode:node_modules/simple-get Completed in 588ms
npm http fetch GET 200 https://registry.npmjs.org/rc/-/rc-1.2.8.tgz 487ms (cache miss)
npm timing reifyNode:node_modules/rc Completed in 597ms
npm http fetch GET 200 https://registry.npmjs.org/simple-concat/-/simple-concat-1.0.1.tgz 473ms (cache miss)
npm timing reifyNode:node_modules/simple-concat Completed in 601ms
npm http fetch GET 200 https://registry.npmjs.org/detect-libc/-/detect-libc-2.0.1.tgz 410ms (cache miss)
npm timing reifyNode:node_modules/detect-libc Completed in 603ms
npm http fetch GET 200 https://registry.npmjs.org/tar-stream/-/tar-stream-2.2.0.tgz 546ms (cache miss)
npm timing reifyNode:node_modules/tar-stream Completed in 608ms
npm http fetch GET 200 https://registry.npmjs.org/node-abi/-/node-abi-3.24.0.tgz 486ms (cache miss)
npm timing reifyNode:node_modules/node-abi Completed in 610ms
npm http fetch GET 200 https://registry.npmjs.org/simple-swizzle/-/simple-swizzle-0.2.2.tgz 468ms (cache miss)
npm timing reifyNode:node_modules/simple-swizzle Completed in 618ms
npm http fetch GET 200 https://registry.npmjs.org/prebuild-install/-/prebuild-install-7.1.1.tgz 438ms (cache miss)
npm timing reifyNode:node_modules/prebuild-install Completed in 622ms
npm http fetch GET 200 https://registry.npmjs.org/color/-/color-4.2.3.tgz 429ms (cache miss)
npm timing reifyNode:node_modules/color Completed in 625ms
npm http fetch GET 200 https://registry.npmjs.org/is-arrayish/-/is-arrayish-0.3.2.tgz 563ms (cache miss)
npm timing reifyNode:node_modules/is-arrayish Completed in 636ms
npm http fetch GET 200 https://registry.npmjs.org/color-convert/-/color-convert-2.0.1.tgz 487ms (cache miss)
npm timing reifyNode:node_modules/color-convert Completed in 650ms
npm http fetch GET 200 https://registry.npmjs.org/minimist/-/minimist-1.2.6.tgz 518ms (cache miss)
npm timing reifyNode:node_modules/minimist Completed in 666ms
npm http fetch GET 200 https://registry.npmjs.org/bl/-/bl-4.1.0.tgz 612ms (cache miss)
npm timing reifyNode:node_modules/bl Completed in 671ms
npm http fetch GET 200 https://registry.npmjs.org/buffer/-/buffer-5.7.1.tgz 636ms (cache miss)
npm timing reifyNode:node_modules/buffer Completed in 674ms
npm http fetch GET 200 https://registry.npmjs.org/readable-stream/-/readable-stream-3.6.0.tgz 642ms (cache miss)
npm timing reifyNode:node_modules/readable-stream Completed in 687ms
npm http fetch GET 200 https://registry.npmjs.org/node-addon-api/-/node-addon-api-5.0.0.tgz 510ms (cache miss)
npm http fetch GET 200 https://registry.npmjs.org/tar-fs/-/tar-fs-2.1.1.tgz 529ms (cache miss)
npm timing reifyNode:node_modules/node-addon-api Completed in 701ms
npm timing reifyNode:node_modules/tar-fs Completed in 702ms
npm http fetch GET 200 https://registry.npmjs.org/semver/-/semver-7.3.7.tgz 531ms (cache miss)
npm timing reifyNode:node_modules/semver Completed in 711ms
npm http fetch GET 200 https://registry.npmjs.org/sharp/-/sharp-0.30.7.tgz 523ms (cache miss)
npm timing reifyNode:node_modules/sharp Completed in 722ms
npm timing reify:unpack Completed in 725ms
npm timing reify:unretire Completed in 0ms
npm timing build:queue Completed in 3ms
npm timing build:link:node_modules/prebuild-install Completed in 2ms
npm timing build:link:node_modules/rc Completed in 1ms
npm timing build:link:node_modules/semver Completed in 2ms
npm timing build:link Completed in 3ms
npm info run [email protected] install node_modules/sharp (node install/libvips && node install/dll-copy && prebuild-install) || (node install/can-compile && node-gyp rebuild && node install/dll-copy)

> [email protected] install
> (node install/libvips && node install/dll-copy && prebuild-install) || (node install/can-compile && node-gyp rebuild && node install/dll-copy)

sharp: Downloading https://github.com/lovell/sharp-libvips/releases/download/v8.12.2/libvips-8.12.2-linux-x64.tar.brns
sharp: Integrity check passed for linux-x64n [email protected] install node_modules/sharp (node install/libvips && node ins
prebuild-install info begin Prebuild-install version 7.1.1install node_modules/sharp (node install/libvips && node ins
prebuild-install info looking for local prebuild @ prebuilds/sharp-v0.30.7-napi-v5-linux-x64.tar.gz
prebuild-install info looking for cached prebuild @ /home/ubuntu/.npm/_prebuilds/3c2afc-sharp-v0.30.7-napi-v5-linux-x64.tar.gz
prebuild-install http request GET https://github.com/lovell/sharp/releases/download/v0.30.7/sharp-v0.30.7-napi-v5-linux-x64.tar.gz
prebuild-install http 200 https://github.com/lovell/sharp/releases/download/v0.30.7/sharp-v0.30.7-napi-v5-linux-x64.tar.gz
prebuild-install info downloading to @ /home/ubuntu/.npm/_prebuilds/3c2afc-sharp-v0.30.7-napi-v5-linux-x64.tar.gz.3101638-90cd5ee1d863d.tmp
prebuild-install info renaming to @ /home/ubuntu/.npm/_prebuilds/3c2afc-sharp-v0.30.7-napi-v5-linux-x64.tar.gz
prebuild-install info unpacking @ /home/ubuntu/.npm/_prebuilds/3c2afc-sharp-v0.30.7-napi-v5-linux-x64.tar.gz
prebuild-install info unpack resolved to /srv/recent/2923918988/foo/node_modules/sharp/build/Release/sharp-linux-x64.node
prebuild-install info install Successfully installed prebuilt binary!
npm info run [email protected] install { code: 0, signal: null }
npm timing build:run:install:node_modules/sharp Completed in 1286ms
npm timing build:run:install Completed in 1286ms
npm timing build:deps Completed in 1292ms
npm timing build Completed in 1292ms
npm timing reify:build Completed in 1294ms
npm timing reify:trash Completed in 0ms
npm timing reify:save Completed in 13ms
npm timing reify Completed in 2893ms

added 45 packages, and audited 46 packages in 3s

9 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities
npm timing command:install Completed in 2899ms
npm verb exit 0
npm timing npm Completed in 2995ms
npm info ok

What is the output of running npx envinfo --binaries --system --npmPackages=sharp --npmGlobalPackages=sharp?

$ npx envinfo --binaries --system --npmPackages=sharp --npmGlobalPackages=sharp

  System:
    OS: Linux 5.11 Ubuntu 20.04.4 LTS (Focal Fossa)
    CPU: (4) x64 Intel(R) Xeon(R) Platinum 8124M CPU @ 3.00GHz
    Memory: 6.53 GB / 7.42 GB
    Container: Yes
    Shell: 5.0.17 - /bin/bash
  Binaries:
    Node: 16.15.1 - /srv/recent/2923918988/api2/software/bin/node
    Yarn: 1.22.0 - /srv/recent/2923918988/api2/software/bin/yarn
    npm: 8.11.0 - /srv/recent/2923918988/api2/software/bin/npm

Here is the problem in action, the require is taking 12 seconds:

2022-08-25 at 12 25

And here the code:

2022-08-25 at 12 26

What could be the reason for this? Thank you in advance!

tim-kos avatar Aug 25 '22 10:08 tim-kos

Is the installation environment running sharp v0.30.2 where the problem occurs using the standard prebuilt binaries (as the log provided for v0.30.7 might suggest) or is it possible you might be using a custom and/or globally-installed libvips?

What is the output of running ldd node_modules/sharp/build/Release/sharp-linux-x64.node in the affected environment?

lovell avatar Aug 25 '22 18:08 lovell

The output of the request command is the following

$ ldd node_modules/sharp/build/Release/sharp-linux-x64.node 
        linux-vdso.so.1 (0x00007ffe5232e000)
        libvips-cpp.so.42 => not found
        libvips.so.42 => not found
        libgobject-2.0.so.0 => /lib/x86_64-linux-gnu/libgobject-2.0.so.0 (0x00007fdc2db8a000)
        libglib-2.0.so.0 => /lib/x86_64-linux-gnu/libglib-2.0.so.0 (0x00007fdc2da61000)
        libstdc++.so.6 => /nix/store/x17b1wq871r4ycrxyy1n85ja09dxq3ih-gcc-10.3.0-lib/lib/libstdc++.so.6 (0x00007fdc2d88c000)
        libm.so.6 => /nix/store/saw6nkqqqfx5xm1h5cpk7gxnxmw9wk47-glibc-2.33-62/lib/libm.so.6 (0x00007fdc2d749000)
        libgcc_s.so.1 => /nix/store/saw6nkqqqfx5xm1h5cpk7gxnxmw9wk47-glibc-2.33-62/lib/libgcc_s.so.1 (0x00007fdc2d72f000)
        libpthread.so.0 => /nix/store/saw6nkqqqfx5xm1h5cpk7gxnxmw9wk47-glibc-2.33-62/lib/libpthread.so.0 (0x00007fdc2d70f000)
        libc.so.6 => /nix/store/saw6nkqqqfx5xm1h5cpk7gxnxmw9wk47-glibc-2.33-62/lib/libc.so.6 (0x00007fdc2d54a000)
        libffi.so.7 => /lib/x86_64-linux-gnu/libffi.so.7 (0x00007fdc2d53e000)
        libpcre.so.3 => /lib/x86_64-linux-gnu/libpcre.so.3 (0x00007fdc2d4cb000)
        /lib64/ld-linux-x86-64.so.2 (0x00007fdc2dc31000)

kiloreux avatar Aug 26 '22 08:08 kiloreux

This is not quite correct @kiloreux, the outout of a similar machine like where the issue arises, is the following

ldd node_modules/sharp/build/Release/sharp-linux-x64.node
	linux-vdso.so.1 (0x00007ffaa5e65000)
	libvips-cpp.so.42 => /nix/store/zfyfmxs99ji4mimyda95b0zdbkmi81mm-vips-8.12.2/lib/libvips-cpp.so.42 (0x00007ffaa5ddb000)
	libvips.so.42 => /nix/store/zfyfmxs99ji4mimyda95b0zdbkmi81mm-vips-8.12.2/lib/libvips.so.42 (0x00007ffaa595b000)
	libgobject-2.0.so.0 => /nix/store/sxzai36pf2sk7dxwpk9hn1gqn94k4646-glib-2.70.2/lib/libgobject-2.0.so.0 (0x00007ffaa5900000)
	libglib-2.0.so.0 => /nix/store/sxzai36pf2sk7dxwpk9hn1gqn94k4646-glib-2.70.2/lib/libglib-2.0.so.0 (0x00007ffaa57c8000)
	libstdc++.so.6 => /nix/store/ndnqiz3nnifj1blhg9q626xlmkqq1nmh-gcc-10.3.0-lib/lib/libstdc++.so.6 (0x00007ffaa55f1000)
	libm.so.6 => /nix/store/4s21k8k7p1mfik0b33r2spq5hq7774k1-glibc-2.33-108/lib/libm.so.6 (0x00007ffaa54b0000)
	libgcc_s.so.1 => /nix/store/4s21k8k7p1mfik0b33r2spq5hq7774k1-glibc-2.33-108/lib/libgcc_s.so.1 (0x00007ffaa5496000)
	libpthread.so.0 => /nix/store/4s21k8k7p1mfik0b33r2spq5hq7774k1-glibc-2.33-108/lib/libpthread.so.0 (0x00007ffaa5476000)
	libc.so.6 => /nix/store/4s21k8k7p1mfik0b33r2spq5hq7774k1-glibc-2.33-108/lib/libc.so.6 (0x00007ffaa52a0000)
	libexpat.so.1 => /nix/store/hwzah8ba3p9pwwv9zwdy5ysw8m7sljjw-expat-2.4.4/lib/libexpat.so.1 (0x00007ffaa526b000)
	libgsf-1.so.114 => /nix/store/vblhyfjfnq8shyi2m218lxvh238l5qa5-libgsf-1.14.48/lib/libgsf-1.so.114 (0x00007ffaa5221000)
	libxml2.so.2 => /nix/store/6apvrxx2qlxjsjg9cc07f2vnx3jg2cvq-libxml2-2.9.12/lib/libxml2.so.2 (0x00007ffaa50b3000)
	libfftw3.so.3 => /nix/store/069nq21mah3gshjyq34wc19siq00va75-fftw-double-3.3.10/lib/libfftw3.so.3 (0x00007ffaa4f0b000)
	liborc-0.4.so.0 => /nix/store/fkarwfgryqpjdkm4jlpscp1kgzbryyf2-orc-0.4.32/lib/liborc-0.4.so.0 (0x00007ffaa4e85000)
	liblcms2.so.2 => /nix/store/0sz652awsb7p1idpl53yvxmr60d17g1m-lcms2-2.12/lib/liblcms2.so.2 (0x00007ffaa4e21000)
	libIlmImf-2_5.so.25 => /nix/store/c1qr8a039il9krvvnn0vac7zgmvfynw3-openexr-2.5.7/lib/libIlmImf-2_5.so.25 (0x00007ffaa4b21000)
	libImath-2_5.so.25 => /nix/store/c1qr8a039il9krvvnn0vac7zgmvfynw3-openexr-2.5.7/lib/libImath-2_5.so.25 (0x00007ffaa4b06000)
	libHalf-2_5.so.25 => /nix/store/c1qr8a039il9krvvnn0vac7zgmvfynw3-openexr-2.5.7/lib/libHalf-2_5.so.25 (0x00007ffaa4ac1000)
	libIex-2_5.so.25 => /nix/store/c1qr8a039il9krvvnn0vac7zgmvfynw3-openexr-2.5.7/lib/libIex-2_5.so.25 (0x00007ffaa4a4c000)
	libIexMath-2_5.so.25 => /nix/store/c1qr8a039il9krvvnn0vac7zgmvfynw3-openexr-2.5.7/lib/libIexMath-2_5.so.25 (0x00007ffaa4a46000)
	libIlmThread-2_5.so.25 => /nix/store/c1qr8a039il9krvvnn0vac7zgmvfynw3-openexr-2.5.7/lib/libIlmThread-2_5.so.25 (0x00007ffaa4a3c000)
	libopenjp2.so.7 => /nix/store/kd73wm0xkfpkbnh31kbjcp4s642f26b1-openjpeg-2.4.0/lib/libopenjp2.so.7 (0x00007ffaa49db000)
	librsvg-2.so.2 => /nix/store/0ccn204v5kds9i08x7plf4x644l6wm87-librsvg-2.52.5/lib/librsvg-2.so.2 (0x00007ffaa3f2d000)
	libgdk_pixbuf-2.0.so.0 => /nix/store/2g610c5xqvikdixylipz01cymp1yb7j4-gdk-pixbuf-2.42.6/lib/libgdk_pixbuf-2.0.so.0 (0x00007ffaa3eff000)
	libmatio.so.11 => /nix/store/7b8vsrk7y80kvp7w81sl7hxxspjyf2dl-matio-1.5.21/lib/libmatio.so.11 (0x00007ffaa3ecf000)
	libcfitsio.so.9 => /nix/store/jn4cqrsa5wfrr67309bgddpmzajkssf4-cfitsio-4.0.0/lib/libcfitsio.so.9 (0x00007ffaa3bbe000)
	libwebpmux.so.3 => /nix/store/lir8r718z4ksjkgi1lawgrgi79z2ap03-libwebp-1.2.1/lib/libwebpmux.so.3 (0x00007ffaa3bb2000)
	libwebpdemux.so.2 => /nix/store/lir8r718z4ksjkgi1lawgrgi79z2ap03-libwebp-1.2.1/lib/libwebpdemux.so.2 (0x00007ffaa3bac000)
	libwebp.so.7 => /nix/store/lir8r718z4ksjkgi1lawgrgi79z2ap03-libwebp-1.2.1/lib/libwebp.so.7 (0x00007ffaa3b3d000)
	libpangocairo-1.0.so.0 => /nix/store/s4agfw48asi7n81ajh12l6ghqr7fm9ph-pango-1.50.3/lib/libpangocairo-1.0.so.0 (0x00007ffaa3b2c000)
	libpango-1.0.so.0 => /nix/store/s4agfw48asi7n81ajh12l6ghqr7fm9ph-pango-1.50.3/lib/libpango-1.0.so.0 (0x00007ffaa3ac2000)
	libharfbuzz.so.0 => /nix/store/nw2gv9l8lzi4scbddbg1vfvivzcpvag3-harfbuzz-3.2.0/lib/libharfbuzz.so.0 (0x00007ffaa39ca000)
	libcairo.so.2 => /nix/store/ybd7ni8vcg02k1w34l77c3axph8zx6yw-cairo-1.16.0/lib/libcairo.so.2 (0x00007ffaa388d000)
	libfontconfig.so.1 => /nix/store/wyf7am3d1xpzx6nagqq1j4ha07vlgrw8-fontconfig-2.13.94-lib/lib/libfontconfig.so.1 (0x00007ffaa3841000)
	libfreetype.so.6 => /nix/store/451fhyz2g9rgk7bd7nxgxjkx015ms0ms-freetype-2.11.1/lib/libfreetype.so.6 (0x00007ffaa377a000)
	libbz2.so.1 => /nix/store/nsgg55q1kh1ala68pas78hzfxsb3bnjk-bzip2-1.0.6.0.2/lib/libbz2.so.1 (0x00007ffaa3765000)
	libtiff.so.5 => /nix/store/qm6bwqqrzgv2yr9yclg6kjs8cz69ggjp-libtiff-4.3.0/lib/libtiff.so.5 (0x00007ffaa36e2000)
	libpng16.so.16 => /nix/store/vdcdfx068hmwqdd6wvsk5a6djlgrqfw4-libpng-apng-1.6.37/lib/libpng16.so.16 (0x00007ffaa36a8000)
	libz.so.1 => /nix/store/bqjh8dc6m5plswxrmmn9x4cpxrrw94lv-zlib-1.2.11/lib/libz.so.1 (0x00007ffaa368b000)
	libimagequant.so.0 => /nix/store/rrnmbz63cm57yzbb8nbd00zarg15m22r-libimagequant-2.17.0/lib/libimagequant.so.0 (0x00007ffaa3676000)
	libjpeg.so.62 => /nix/store/a6i6c7hkfn5s9bbgc1x6j1cnd5dppzkv-libjpeg-turbo-2.1.2/lib/libjpeg.so.62 (0x00007ffaa35bf000)
	libexif.so.12 => /nix/store/kgqbbhsj7d2km1g8hyrwigadqnfhlj7a-libexif-0.6.24/lib/libexif.so.12 (0x00007ffaa356d000)
	libgmodule-2.0.so.0 => /nix/store/sxzai36pf2sk7dxwpk9hn1gqn94k4646-glib-2.70.2/lib/libgmodule-2.0.so.0 (0x00007ffaa3566000)
	libgio-2.0.so.0 => /nix/store/sxzai36pf2sk7dxwpk9hn1gqn94k4646-glib-2.70.2/lib/libgio-2.0.so.0 (0x00007ffaa338a000)
	libffi.so.8 => /nix/store/5kmd81rnn4i8a9pd0z6hcv5skyd9hxfd-libffi-3.4.2/lib/libffi.so.8 (0x00007ffaa337d000)
	libpcre.so.1 => /nix/store/5w407jwmhxdd24xxzisv5nzmqlmvbxwb-pcre-8.45/lib/libpcre.so.1 (0x00007ffaa3302000)
	/lib64/ld-linux-x86-64.so.2 (0x00007ffaa5e67000)
	libdl.so.2 => /nix/store/4s21k8k7p1mfik0b33r2spq5hq7774k1-glibc-2.33-108/lib/libdl.so.2 (0x00007ffaa32fd000)
	libcairo-gobject.so.2 => /nix/store/ybd7ni8vcg02k1w34l77c3axph8zx6yw-cairo-1.16.0/lib/libcairo-gobject.so.2 (0x00007ffaa32f1000)
	libpangoft2-1.0.so.0 => /nix/store/s4agfw48asi7n81ajh12l6ghqr7fm9ph-pango-1.50.3/lib/libpangoft2-1.0.so.0 (0x00007ffaa32d4000)
	libfribidi.so.0 => /nix/store/ryj406gx09z7qxfyc1ahxy9vbdr9v1hm-fribidi-1.0.11/lib/libfribidi.so.0 (0x00007ffaa32b4000)
	libthai.so.0 => /nix/store/z0b0jqgvszaklfjl3dzdyvnhp2nn4v94-libthai-0.1.29/lib/libthai.so.0 (0x00007ffaa32a8000)
	libgraphite2.so.3 => /nix/store/s9drzb0i5hcqx5xdx6h15rvsk8g2li3q-graphite2-1.3.14/lib/libgraphite2.so.3 (0x00007ffaa327e000)
	libpixman-1.so.0 => /nix/store/c901n9lvwila9q77zwnif901i4l3f8hc-pixman-0.38.4/lib/libpixman-1.so.0 (0x00007ffaa31d2000)
	libEGL.so.1 => /nix/store/5lzlfgrc37wqj400b4qgpaa6kc9d2wr1-libglvnd-1.4.0/lib/libEGL.so.1 (0x00007ffaa31bc000)
	libxcb-shm.so.0 => /nix/store/n1h6395818hn30bi5dk31smjwvhwawax-libxcb-1.14/lib/libxcb-shm.so.0 (0x00007ffaa31b7000)
	libxcb.so.1 => /nix/store/n1h6395818hn30bi5dk31smjwvhwawax-libxcb-1.14/lib/libxcb.so.1 (0x00007ffaa318b000)
	libxcb-render.so.0 => /nix/store/n1h6395818hn30bi5dk31smjwvhwawax-libxcb-1.14/lib/libxcb-render.so.0 (0x00007ffaa3179000)
	libXrender.so.1 => /nix/store/cmnjdi9a0jnsxr1xn74c941j6kk8nldf-libXrender-0.9.10/lib/libXrender.so.1 (0x00007ffaa316c000)
	libX11.so.6 => /nix/store/6pdb0rz2w2hsfsy66kwrbz67jd424wv7-libX11-1.7.2/lib/libX11.so.6 (0x00007ffaa3027000)
	libXext.so.6 => /nix/store/a3yw11i2iskvr1zx2za4mwrj9sawq7hz-libXext-1.3.4/lib/libXext.so.6 (0x00007ffaa3012000)
	libGL.so.1 => /nix/store/5lzlfgrc37wqj400b4qgpaa6kc9d2wr1-libglvnd-1.4.0/lib/libGL.so.1 (0x00007ffaa2f84000)
	librt.so.1 => /nix/store/4s21k8k7p1mfik0b33r2spq5hq7774k1-glibc-2.33-108/lib/librt.so.1 (0x00007ffaa2f79000)
	liblzma.so.5 => /nix/store/ar8h49vw49k9w0n86jgvwx9abn527hbw-xz-5.2.5/lib/liblzma.so.5 (0x00007ffaa2f4d000)
	libdeflate.so.0 => /nix/store/ggf5pzjzf742yb24wqykx46jbhcmmbsf-libdeflate-1.8/lib/libdeflate.so.0 (0x00007ffaa2f3e000)
	libmount.so.1 => /nix/store/kx41yd3yyr9bwrsk85fhhx6qhavfwql6-util-linux-2.37.3-lib/lib/libmount.so.1 (0x00007ffaa2ede000)
	libselinux.so.1 => /nix/store/gck1cbz9hfqgw558139vjzmyg9r7bkmx-libselinux-3.3/lib/libselinux.so.1 (0x00007ffaa2eaf000)
	libresolv.so.2 => /nix/store/4s21k8k7p1mfik0b33r2spq5hq7774k1-glibc-2.33-108/lib/libresolv.so.2 (0x00007ffaa2e97000)
	libdatrie.so.1 => /nix/store/23jvypciz2yrfj9wd3hzhrqxyxp54mnd-libdatrie-2019-12-20-lib/lib/libdatrie.so.1 (0x00007ffaa2e8d000)
	libGLdispatch.so.0 => /nix/store/5lzlfgrc37wqj400b4qgpaa6kc9d2wr1-libglvnd-1.4.0/lib/libGLdispatch.so.0 (0x00007ffaa2dd4000)
	libXau.so.6 => /nix/store/x14h74lzrxk7j05pgqmba8yicb2bms6f-libXau-1.0.9/lib/libXau.so.6 (0x00007ffaa2dcd000)
	libXdmcp.so.6 => /nix/store/3ijd7iqmnwqvfyv4k8l5a8qw33agi1br-libXdmcp-1.1.3/lib/libXdmcp.so.6 (0x00007ffaa2dc5000)
	libGLX.so.0 => /nix/store/5lzlfgrc37wqj400b4qgpaa6kc9d2wr1-libglvnd-1.4.0/lib/libGLX.so.0 (0x00007ffaa2d90000)
	libblkid.so.1 => /nix/store/kx41yd3yyr9bwrsk85fhhx6qhavfwql6-util-linux-2.37.3-lib/lib/libblkid.so.1 (0x00007ffaa2d3a000)

Note, that there is a wrapped yarn script in place to allow us to reference libraries (libvips in this case) from pinned nix packages.

What it basically does, is setting environment variables for yarn to find the pinned native dependencies.

PREFIX_PATH = lib.makeBinPath (with pkgs; [
  pkg-config stdenv.cc nodejs nodejs.python nodePackages.node-gyp
]);

PREFIX_PKG_CONFIG_PATH = lib.makeSearchPathOutput "dev" "lib/pkgconfig" gypDependencies;

[...] makeWrapper "$out/libexec/yarn/bin/yarn.js" "$out/bin/.yarn-wrapped" \
    --prefix PATH : "${PREFIX_PATH}" \
    --prefix PKG_CONFIG_PATH : "${PREFIX_PKG_CONFIG_PATH}" \
    --set PKG_CONFIG pkg-config \
    --set YARN_NODE_LINKER node-modules \
    --set NPM_CONFIG_NODEDIR ${nodejs}

calbrecht avatar Aug 26 '22 09:08 calbrecht

Thanks, it looks like you're using a custom libvips with many dependencies, all of which have been packaged via NixOS.

When you require('sharp') all of these shared libraries will be dlopened, so you'll need to work out which of them is causing the slowdown. You can set the LD_DEBUG=libs environment variable to help with this.

lovell avatar Aug 26 '22 09:08 lovell

What a great advice, thank you very much. There are even several symbol lookup errors from several vips-modules, that cannot be good either.

calbrecht avatar Aug 26 '22 09:08 calbrecht

Were you able to make any progress with this?

lovell avatar Sep 27 '22 13:09 lovell

Beside the finding that the cgroup slice this is running in has total io.pressure stalls up to 15s, and that it is possible to speed up by inserting coins to EBS IOPS and throughput, not much unfortunately.

calbrecht avatar Oct 01 '22 19:10 calbrecht

Hey @lovell

We still couldn't get this below 8 seconds, on a c6id.4xlarge Amazon machine, which seems really weird. It should have enough disk power for this to be much faster, even under io.pressure. We do get it down if we add more disk iops and throughput, but that would mean increasing costs a lot.

Though there is still one thing we haven't tried yet and it is compiling all sharp native bindings and node as static libraries/binaries and that is because

  1. Is this possible with sharp?
  2. Would it really speed up things?

tim-kos avatar Oct 25 '22 13:10 tim-kos

My best guess would be that something in the chain of shared libraries must be opening/loading a lot of files, so switching to static linking might at least allow you to identify which one.

You can definitely compile libvips and its dependencies as a single, statically-linked shared library. Please see https://github.com/lovell/sharp-libvips/blob/8505258c86d6f28bcb4ee6f81e9b250ec97d31ef/build/lin.sh#L441-L468 for the build script that does exactly this.

I usually add a warning here about GPL licenced dependencies, but it looks like you're already using these (e.g. libfftw3, libimagequant) in the same process, so shared vs static won't change the situation as your code already falls under the terms of the GPL.

lovell avatar Oct 26 '22 13:10 lovell

Thank you @lovell , this is helpful. <3

tim-kos avatar Oct 27 '22 14:10 tim-kos

@tim-kos Were you able to make any progress with this?

lovell avatar Jan 24 '23 15:01 lovell

Closing due to inactivity but please feel free to reopen with more details if further help is required.

lovell avatar Apr 21 '23 08:04 lovell

It's still taking 6-8s here to require sharp on a fresh instance, so still far from ideal I am afraid. :/ Not sure what else we can try, do you have any ideas?

tim-kos avatar Apr 26 '23 10:04 tim-kos

Is this with all (or at least most) dependencies statically built? If so, what is the output of running:

LD_DEBUG=libs node -e "require('sharp')"

You might also be able to pipe the output through something like https://www.npmjs.com/package/gnomon to find out which line takes the longest to appear.

lovell avatar Apr 27 '23 08:04 lovell