pinojs / sonic-boom

Extremely fast utf8 only stream implementation
MIT License
266 stars 41 forks source link

shutdown error #189

Open ronag opened 10 months ago

ronag commented 10 months ago

Got the following error in production:

{"level":50,"time":1703841986253,"name":"render","err":{"type":"Error","message":"EINVAL: invalid argument, fsync","stack":"Error: EINVAL: invalid argument, fsync","errno":-22,"code":"EINVAL","syscall":"fsync"},"msg":"shutdown error"}

Did a grep of the source code for fsync and as far as I can see only sonic-boom calls it. Unless there is something in core. However, the only thing in core I can find is fs.createWriteStream with the flush option which is not used as far as I can tell.

grep -Rnw . -e "fsync"
./node_modules/@types/node/ts4.8/fs.d.ts:2325:     * Refer to the POSIX [`fsync(2)`](http://man7.org/linux/man-pages/man2/fsync.2.html) documentation for more detail. No arguments other
./node_modules/@types/node/ts4.8/fs.d.ts:2329:    export function fsync(fd: number, callback: NoParamCallback): void;
./node_modules/@types/node/ts4.8/fs.d.ts:2330:    export namespace fsync {
./node_modules/@types/node/ts4.8/fs.d.ts:2332:         * Asynchronous fsync(2) - synchronize a file's in-core state with the underlying storage device.
./node_modules/@types/node/ts4.8/fs.d.ts:2340:     * Refer to the POSIX [`fsync(2)`](http://man7.org/linux/man-pages/man2/fsync.2.html) documentation for more detail. Returns `undefined`.
./node_modules/@types/node/ts4.8/fs/promises.d.ts:214:         * Refer to the POSIX [`fsync(2)`](http://man7.org/linux/man-pages/man2/fsync.2.html) documentation for more detail.
./node_modules/@types/node/fs.d.ts:2325:     * Refer to the POSIX [`fsync(2)`](http://man7.org/linux/man-pages/man2/fsync.2.html) documentation for more detail. No arguments other
./node_modules/@types/node/fs.d.ts:2329:    export function fsync(fd: number, callback: NoParamCallback): void;
./node_modules/@types/node/fs.d.ts:2330:    export namespace fsync {
./node_modules/@types/node/fs.d.ts:2332:         * Asynchronous fsync(2) - synchronize a file's in-core state with the underlying storage device.
./node_modules/@types/node/fs.d.ts:2340:     * Refer to the POSIX [`fsync(2)`](http://man7.org/linux/man-pages/man2/fsync.2.html) documentation for more detail. Returns `undefined`.
./node_modules/@types/node/fs/promises.d.ts:214:         * Refer to the POSIX [`fsync(2)`](http://man7.org/linux/man-pages/man2/fsync.2.html) documentation for more detail.
./node_modules/sonic-boom/types/index.d.ts:16:    fsync?: boolean
./node_modules/sonic-boom/test/flush.test.js:125:  test('only call fsyncSync and not fsync when fsync: true', (t) => {
./node_modules/sonic-boom/test/flush.test.js:138:      fsync: true,
./node_modules/sonic-boom/test/flush.test.js:146:    fakeFs.fsync = function (fd, cb) {
./node_modules/sonic-boom/test/flush.test.js:147:      t.fail('fake fs.fsync called while should not')
./node_modules/sonic-boom/test/flush.test.js:174:        // to make sure fsync is not called as well
./node_modules/sonic-boom/test/flush.test.js:180:  test('call flush cb with error when fsync failed', (t) => {
./node_modules/sonic-boom/test/flush.test.js:215:    fakeFs.fsync = onFsyncOnFsyncSync(false, fs.fsync)
./node_modules/sonic-boom/test/fsync.test.js:8:test('fsync with sync', (t) => {
./node_modules/sonic-boom/test/fsync.test.js:22:  const stream = new SonicBoom({ fd, sync: true, fsync: true })
./node_modules/sonic-boom/test/fsync.test.js:33:test('fsync with async', (t) => {
./node_modules/sonic-boom/test/fsync.test.js:47:  const stream = new SonicBoom({ fd, fsync: true })
./node_modules/sonic-boom/index.js:94:  let { fd, dest, minLength, maxLength, maxWrite, sync, append = true, mkdir, retryEAGAIN, fsync, contentMode, mode } = opts || {}
./node_modules/sonic-boom/index.js:115:  this._fsync = fsync || false
./node_modules/sonic-boom/index.js:343:    // only if _fsync is false to avoid double fsync
./node_modules/sonic-boom/index.js:345:      fs.fsync(this.fd, (err) => {
./node_modules/sonic-boom/index.js:544:    // Skip the error. The fd might not support fsync.
./node_modules/sonic-boom/index.js:637:  fs.fsync(sonic.fd, closeWrapped)
./node_modules/sonic-boom/index.js:640:    // We skip errors in fsync
./node_modules/sonic-boom/README.md:66:* `fsync`: perform a [fsyncSync](https://nodejs.org/api/fs.html#fsfsyncsyncfd) every time a write is completed.

I suspect:

function actualClose (sonic) {
  if (sonic.fd === -1) {
    sonic.once('ready', actualClose.bind(null, sonic))
    return
  }

  sonic.destroyed = true
  sonic._bufs = []
  sonic._lens = []

  fs.fsync(sonic.fd, closeWrapped)

  function closeWrapped () {
    // We skip errors in fsync

    if (sonic.fd !== 1 && sonic.fd !== 2) {
      fs.close(sonic.fd, done)
    } else {
      done()
    }
  }

  function done (err) {
    if (err) {
      sonic.emit('error', err)
      return
    }

    if (sonic._ending && !sonic._writing) {
      sonic.emit('finish')
    }
    sonic.emit('close')
  }
}
mcollina commented 10 months ago

what's the kind of destination you are logging into? It looks like it doesn't support fsync, so we can really skip the error. Fancy a PR to ignore it?

ronag commented 10 months ago

Just regular stdout.

mcollina commented 10 months ago

stdout is connected to a tty, a file, a pipe, docker..?

ronag commented 10 months ago

docker

mcollina commented 10 months ago

Essentially if the callback error with EINVAL, it means the fd does not support fsync. It's not an error condition.

ronag commented 10 months ago

I don't think it's the callback. That would not cause a shutdown error. I suspect fsync throws invalid arguments synchronously if fd is invalid. How fd can be invalid is not something I've been able to figure out.