Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[Bug]: server crash after starting playback in browser #2157

Closed
Alistair1231 opened this issue Sep 28, 2023 · 11 comments
Closed

[Bug]: server crash after starting playback in browser #2157

Alistair1231 opened this issue Sep 28, 2023 · 11 comments
Labels
bug Something isn't working

Comments

@Alistair1231
Copy link
Contributor

Describe the issue

I switched from my phone to the PC, after I pressed play, the server crashed. Local and Direct playback both work on Android v0.9.66-beta

Here is my docker-compose.yml 
version: "3.7"
services:
  audiobookshelf:
    user: "1000:1000"
    image: ghcr.io/advplyr/audiobookshelf:latest
    container_name: abs-container
      #environment:
      #- AUDIOBOOKSHELF_UID=1000
      #- AUDIOBOOKSHELF_GID=100
    ports:
      - 13378:80
    volumes:
      - ./audiobooks:/audiobooks
      - ./ebooks:/ebooks
      - ./podcasts:/podcasts
      - ./config:/config
      - ./metadata:/metadata
        #      - ./client:/client
  watchtower:
    image: containrrr/watchtower
    container_name: watchtower
    volumes:
      - /var/run/docker.sock:/var/run/docker.sock
    # 21600s == 6hr
    command: --interval 21600 abs-container
Here is the ffprobe result of the file that caused it 
ffprobe version 5.1.3-1 Copyright (c) 2007-2022 the FFmpeg developers
  built with gcc 12 (Debian 12.2.0-14)
  configuration: --prefix=/usr --extra-version=1 --toolchain=hardened --libdir=/usr/lib/x86_64-linux-gnu --incdir=/usr/include/x86_64-linux-gnu --arch=amd64 --enable-gpl --disable-stripping --enable-gnutls --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libcodec2 --enable-libdav1d --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libglslang --enable-libgme --enable-libgsm --enable-libjack --enable-libmp3lame --enable-libmysofa --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librabbitmq --enable-librist --enable-librubberband --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libsrt --enable-libssh --enable-libsvtav1 --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzimg --enable-libzmq --enable-libzvbi --enable-lv2 --enable-omx --enable-openal --enable-opencl --enable-opengl --enable-sdl2 --disable-sndio --enable-libjxl --enable-pocketsphinx --enable-librsvg --enable-libmfx --enable-libdc1394 --enable-libdrm --enable-libiec61883 --enable-chromaprint --enable-frei0r --enable-libx264 --enable-libplacebo --enable-librav1e --enable-shared
  libavutil      57. 28.100 / 57. 28.100
  libavcodec     59. 37.100 / 59. 37.100
  libavformat    59. 27.100 / 59. 27.100
  libavdevice    59.  7.100 / 59.  7.100
  libavfilter     8. 44.100 /  8. 44.100
  libswscale      6.  7.100 /  6.  7.100
  libswresample   4.  7.100 /  4.  7.100
  libpostproc    56.  6.100 / 56.  6.100
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x55cd4215b5c0] stream 0, timescale not set
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'audiobooks/J M Clarke/Mark of the Fool/Mark of the Fool 03 - Mark of the Fool 3/Mark of the Fool 3.m4b':
  Metadata:
    major_brand     : M4A
    minor_version   : 512
    compatible_brands: isomiso2
    title           : Mark of the Fool 3
    artist          : J.M. Clarke
    genre           : Audiobook
    copyright       : ©2023 Aethon Books (P)2023 Aethon Audio
    album           : Mark of the Fool 3
    track           : 1/1
    disc            : 1/1
    date            : 2023-01-01
    encoder         : Lavf58.29.100
  Duration: 22:51:32.41, start: 0.000000, bitrate: 126 kb/s
  Chapters:
    Chapter #0:0: start 0.000000, end 15.836000
      Metadata:
        title           : Chapter 1
    Chapter #0:1: start 15.836000, end 1094.473000
      Metadata:
        title           : Chapter 2
    Chapter #0:2: start 1094.473000, end 1765.111000
      Metadata:
        title           : Chapter 3
    Chapter #0:3: start 1765.111000, end 2609.575000
      Metadata:
        title           : Chapter 4
    Chapter #0:4: start 2609.575000, end 3355.191000
      Metadata:
        title           : Chapter 5
    Chapter #0:5: start 3355.191000, end 4171.488000
      Metadata:
        title           : Chapter 6
    Chapter #0:6: start 4171.488000, end 5065.410000
      Metadata:
        title           : Chapter 7
    Chapter #0:7: start 5065.410000, end 5869.819000
      Metadata:
        title           : Chapter 8
    Chapter #0:8: start 5869.819000, end 6607.702000
      Metadata:
        title           : Chapter 9
    Chapter #0:9: start 6607.702000, end 7476.756000
      Metadata:
        title           : Chapter 10
    Chapter #0:10: start 7476.756000, end 8274.245000
      Metadata:
        title           : Chapter 11
    Chapter #0:11: start 8274.245000, end 9049.536000
      Metadata:
        title           : Chapter 12
    Chapter #0:12: start 9049.536000, end 9940.045000
      Metadata:
        title           : Chapter 13
    Chapter #0:13: start 9940.045000, end 10655.521000
      Metadata:
        title           : Chapter 14
    Chapter #0:14: start 10655.521000, end 11402.043000
      Metadata:
        title           : Chapter 15
    Chapter #0:15: start 11402.043000, end 12264.641000
      Metadata:
        title           : Chapter 16
    Chapter #0:16: start 12264.641000, end 12992.493000
      Metadata:
        title           : Chapter 17
    Chapter #0:17: start 12992.493000, end 13718.535000
      Metadata:
        title           : Chapter 18
    Chapter #0:18: start 13718.535000, end 14556.566000
      Metadata:
        title           : Chapter 19
    Chapter #0:19: start 14556.566000, end 15306.966000
      Metadata:
        title           : Chapter 20
    Chapter #0:20: start 15306.966000, end 16336.794000
      Metadata:
        title           : Chapter 21
    Chapter #0:21: start 16336.794000, end 17228.696000
      Metadata:
        title           : Chapter 22
    Chapter #0:22: start 17228.696000, end 17959.822000
      Metadata:
        title           : Chapter 23
    Chapter #0:23: start 17959.822000, end 18849.286000
      Metadata:
        title           : Chapter 24
    Chapter #0:24: start 18849.286000, end 19789.044000
      Metadata:
        title           : Chapter 25
    Chapter #0:25: start 19789.044000, end 20702.726000
      Metadata:
        title           : Chapter 26
    Chapter #0:26: start 20702.726000, end 21674.156000
      Metadata:
        title           : Chapter 27
    Chapter #0:27: start 21674.156000, end 22580.059000
      Metadata:
        title           : Chapter 28
    Chapter #0:28: start 22580.059000, end 23451.759000
      Metadata:
        title           : Chapter 29
    Chapter #0:29: start 23451.759000, end 24287.678000
      Metadata:
        title           : Chapter 30
    Chapter #0:30: start 24287.678000, end 25256.972000
      Metadata:
        title           : Chapter 31
    Chapter #0:31: start 25256.972000, end 26280.600000
      Metadata:
        title           : Chapter 32
    Chapter #0:32: start 26280.600000, end 27068.592000
      Metadata:
        title           : Chapter 33
    Chapter #0:33: start 27068.592000, end 27723.511000
      Metadata:
        title           : Chapter 34
    Chapter #0:34: start 27723.511000, end 28438.779000
      Metadata:
        title           : Chapter 35
    Chapter #0:35: start 28438.779000, end 29436.285000
      Metadata:
        title           : Chapter 36
    Chapter #0:36: start 29436.285000, end 30189.424000
      Metadata:
        title           : Chapter 37
    Chapter #0:37: start 30189.424000, end 31011.852000
      Metadata:
        title           : Chapter 38
    Chapter #0:38: start 31011.852000, end 31679.774000
      Metadata:
        title           : Chapter 39
    Chapter #0:39: start 31679.774000, end 32537.310000
      Metadata:
        title           : Chapter 40
    Chapter #0:40: start 32537.310000, end 33244.450000
      Metadata:
        title           : Chapter 41
    Chapter #0:41: start 33244.450000, end 34257.514000
      Metadata:
        title           : Chapter 42
    Chapter #0:42: start 34257.514000, end 34921.442000
      Metadata:
        title           : Chapter 43
    Chapter #0:43: start 34921.442000, end 35766.091000
      Metadata:
        title           : Chapter 44
    Chapter #0:44: start 35766.091000, end 36579.881000
      Metadata:
        title           : Chapter 45
    Chapter #0:45: start 36579.881000, end 37451.488000
      Metadata:
        title           : Chapter 46
    Chapter #0:46: start 37451.488000, end 38149.619000
      Metadata:
        title           : Chapter 47
    Chapter #0:47: start 38149.619000, end 38952.054000
      Metadata:
        title           : Chapter 48
    Chapter #0:48: start 38952.054000, end 39835.550000
      Metadata:
        title           : Chapter 49
    Chapter #0:49: start 39835.550000, end 40826.741000
      Metadata:
        title           : Chapter 50
    Chapter #0:50: start 40826.741000, end 41587.542000
      Metadata:
        title           : Chapter 51
    Chapter #0:51: start 41587.542000, end 42549.034000
      Metadata:
        title           : Chapter 52
    Chapter #0:52: start 42549.034000, end 43410.959000
      Metadata:
        title           : Chapter 53
    Chapter #0:53: start 43410.959000, end 44465.563000
      Metadata:
        title           : Chapter 54
    Chapter #0:54: start 44465.563000, end 45294.097000
      Metadata:
        title           : Chapter 55
    Chapter #0:55: start 45294.097000, end 46043.684000
      Metadata:
        title           : Chapter 56
    Chapter #0:56: start 46043.684000, end 46891.607000
      Metadata:
        title           : Chapter 57
    Chapter #0:57: start 46891.607000, end 47660.536000
      Metadata:
        title           : Chapter 58
    Chapter #0:58: start 47660.536000, end 48673.669000
      Metadata:
        title           : Chapter 59
    Chapter #0:59: start 48673.669000, end 49603.048000
      Metadata:
        title           : Chapter 60
    Chapter #0:60: start 49603.048000, end 50461.420000
      Metadata:
        title           : Chapter 61
    Chapter #0:61: start 50461.420000, end 51271.448000
      Metadata:
        title           : Chapter 62
    Chapter #0:62: start 51271.448000, end 52051.754000
      Metadata:
        title           : Chapter 63
    Chapter #0:63: start 52051.754000, end 52837.634000
      Metadata:
        title           : Chapter 64
    Chapter #0:64: start 52837.634000, end 53630.920000
      Metadata:
        title           : Chapter 65
    Chapter #0:65: start 53630.920000, end 54420.677000
      Metadata:
        title           : Chapter 66
    Chapter #0:66: start 54420.677000, end 55340.327000
      Metadata:
        title           : Chapter 67
    Chapter #0:67: start 55340.327000, end 56182.677000
      Metadata:
        title           : Chapter 68
    Chapter #0:68: start 56182.677000, end 57012.419000
      Metadata:
        title           : Chapter 69
    Chapter #0:69: start 57012.419000, end 57779.931000
      Metadata:
        title           : Chapter 70
    Chapter #0:70: start 57779.931000, end 58670.208000
      Metadata:
        title           : Chapter 71
    Chapter #0:71: start 58670.208000, end 59483.371000
      Metadata:
        title           : Chapter 72
    Chapter #0:72: start 59483.371000, end 60374.924000
      Metadata:
        title           : Chapter 73
    Chapter #0:73: start 60374.924000, end 61294.364000
      Metadata:
        title           : Chapter 74
    Chapter #0:74: start 61294.364000, end 62121.506000
      Metadata:
        title           : Chapter 75
    Chapter #0:75: start 62121.506000, end 62963.786000
      Metadata:
        title           : Chapter 76
    Chapter #0:76: start 62963.786000, end 63826.779000
      Metadata:
        title           : Chapter 77
    Chapter #0:77: start 63826.779000, end 64837.358000
      Metadata:
        title           : Chapter 78
    Chapter #0:78: start 64837.358000, end 65673.857000
      Metadata:
        title           : Chapter 79
    Chapter #0:79: start 65673.857000, end 66466.958000
      Metadata:
        title           : Chapter 80
    Chapter #0:80: start 66466.958000, end 67408.457000
      Metadata:
        title           : Chapter 81
    Chapter #0:81: start 67408.457000, end 68415.205000
      Metadata:
        title           : Chapter 82
    Chapter #0:82: start 68415.205000, end 69310.288000
      Metadata:
        title           : Chapter 83
    Chapter #0:83: start 69310.288000, end 70111.213000
      Metadata:
        title           : Chapter 84
    Chapter #0:84: start 70111.213000, end 70861.868000
      Metadata:
        title           : Chapter 85
    Chapter #0:85: start 70861.868000, end 71754.791000
      Metadata:
        title           : Chapter 86
    Chapter #0:86: start 71754.791000, end 72500.059000
      Metadata:
        title           : Chapter 87
    Chapter #0:87: start 72500.059000, end 73299.708000
      Metadata:
        title           : Chapter 88
    Chapter #0:88: start 73299.708000, end 74102.863000
      Metadata:
        title           : Chapter 89
    Chapter #0:89: start 74102.863000, end 74886.002000
      Metadata:
        title           : Chapter 90
    Chapter #0:90: start 74886.002000, end 75765.296000
      Metadata:
        title           : Chapter 91
    Chapter #0:91: start 75765.296000, end 76534.666000
      Metadata:
        title           : Chapter 92
    Chapter #0:92: start 76534.666000, end 77329.624000
      Metadata:
        title           : Chapter 93
    Chapter #0:93: start 77329.624000, end 78104.892000
      Metadata:
        title           : Chapter 94
    Chapter #0:94: start 78104.892000, end 78947.265000
      Metadata:
        title           : Chapter 95
    Chapter #0:95: start 78947.265000, end 79648.717000
      Metadata:
        title           : Chapter 96
    Chapter #0:96: start 79648.717000, end 80458.931000
      Metadata:
        title           : Chapter 97
    Chapter #0:97: start 80458.931000, end 81356.800000
      Metadata:
        title           : Chapter 98
    Chapter #0:98: start 81356.800000, end 82260.822000
      Metadata:
        title           : Chapter 99
    Chapter #0:99: start 82260.822000, end 82292.000000
      Metadata:
        title           : Chapter 100
  Stream #0:0[0x1](und): Audio: aac (LC) (mp4a / 0x6134706D), 44100 Hz, stereo, fltp, 125 kb/s (default)
    Metadata:
      handler_name    : SoundHandler
      vendor_id       : [0][0][0][0]
  Stream #0:1[0x2](und): Data: bin_data (text / 0x74786574) (default)
    Metadata:
      creation_time   : 2023-04-12T10:09:18.000000Z
      handler_name    : Chapter titles
  Stream #0:2[0x0]: Video: mjpeg (Baseline), yuvj420p(pc, bt470bg/unknown/unknown), 500x500 [SAR 1:1 DAR 1:1], 90k tbr, 90k tbn (attached pic)
Unsupported codec with id 98314 for input stream 1
Here is the log with the crash 
abs-container  | [2023-09-27 06:37:28] INFO: [SocketAuthority] Socket Connected emoB7H_Z-8ZxVKOcAADp
abs-container  | [2023-09-27 06:37:50] INFO: [SocketAuthority] Socket aXHjcyNHsh44jKLkAADn disconnected from client "root" after 320863ms (Reason: ping timeout)
abs-container  | BadRequestError: request aborted
abs-container  |     at IncomingMessage.onAborted (/node_modules/raw-body/index.js:238:10)
abs-container  |     at IncomingMessage.emit (node:events:513:28)
abs-container  |     at IncomingMessage._destroy (node:_http_incoming:224:10)
abs-container  |     at _destroy (node:internal/streams/destroy:102:25)
abs-container  |     at IncomingMessage.destroy (node:internal/streams/destroy:64:5)
abs-container  |     at abortIncoming (node:_http_server:642:9)
abs-container  |     at socketOnClose (node:_http_server:636:3)
abs-container  |     at Socket.emit (node:events:525:35)
abs-container  |     at TCP.<anonymous> (node:net:301:12)
abs-container  | [2023-09-27 06:41:36] INFO: [SocketAuthority] Socket emoB7H_Z-8ZxVKOcAADp disconnected from client "root" after 247451ms (Reason: ping timeout)
abs-container  | BadRequestError: request aborted
abs-container  |     at IncomingMessage.onAborted (/node_modules/raw-body/index.js:238:10)
abs-container  |     at IncomingMessage.emit (node:events:513:28)
abs-container  |     at IncomingMessage._destroy (node:_http_incoming:224:10)
abs-container  |     at _destroy (node:internal/streams/destroy:102:25)
abs-container  |     at IncomingMessage.destroy (node:internal/streams/destroy:64:5)
abs-container  |     at abortIncoming (node:_http_server:642:9)
abs-container  |     at socketOnClose (node:_http_server:636:3)
abs-container  |     at Socket.emit (node:events:525:35)
abs-container  |     at TCP.<anonymous> (node:net:301:12)
abs-container  | BadRequestError: request aborted
abs-container  |     at IncomingMessage.onAborted (/node_modules/raw-body/index.js:238:10)
abs-container  |     at IncomingMessage.emit (node:events:513:28)
abs-container  |     at IncomingMessage._destroy (node:_http_incoming:224:10)
abs-container  |     at _destroy (node:internal/streams/destroy:102:25)
abs-container  |     at IncomingMessage.destroy (node:internal/streams/destroy:64:5)
abs-container  |     at abortIncoming (node:_http_server:642:9)
abs-container  |     at socketOnClose (node:_http_server:636:3)
abs-container  |     at Socket.emit (node:events:525:35)
abs-container  |     at TCP.<anonymous> (node:net:301:12)
abs-container  | BadRequestError: request aborted
abs-container  |     at IncomingMessage.onAborted (/node_modules/raw-body/index.js:238:10)
abs-container  |     at IncomingMessage.emit (node:events:513:28)
abs-container  |     at IncomingMessage._destroy (node:_http_incoming:224:10)
abs-container  |     at _destroy (node:internal/streams/destroy:102:25)
abs-container  |     at IncomingMessage.destroy (node:internal/streams/destroy:64:5)
abs-container  |     at abortIncoming (node:_http_server:642:9)
abs-container  |     at socketOnClose (node:_http_server:636:3)
abs-container  |     at Socket.emit (node:events:525:35)
abs-container  |     at TCP.<anonymous> (node:net:301:12)
abs-container  | BadRequestError: request aborted
abs-container  |     at IncomingMessage.onAborted (/node_modules/raw-body/index.js:238:10)
abs-container  |     at IncomingMessage.emit (node:events:513:28)
abs-container  |     at IncomingMessage._destroy (node:_http_incoming:224:10)
abs-container  |     at _destroy (node:internal/streams/destroy:102:25)
abs-container  |     at IncomingMessage.destroy (node:internal/streams/destroy:64:5)
abs-container  |     at abortIncoming (node:_http_server:642:9)
abs-container  |     at socketOnClose (node:_http_server:636:3)
abs-container  |     at Socket.emit (node:events:525:35)
abs-container  |     at TCP.<anonymous> (node:net:301:12)
abs-container  | BadRequestError: request aborted
abs-container  |     at IncomingMessage.onAborted (/node_modules/raw-body/index.js:238:10)
abs-container  |     at IncomingMessage.emit (node:events:513:28)
abs-container  |     at IncomingMessage._destroy (node:_http_incoming:224:10)
abs-container  |     at _destroy (node:internal/streams/destroy:102:25)
abs-container  |     at IncomingMessage.destroy (node:internal/streams/destroy:64:5)
abs-container  |     at abortIncoming (node:_http_server:642:9)
abs-container  |     at socketOnClose (node:_http_server:636:3)
abs-container  |     at Socket.emit (node:events:525:35)
abs-container  |     at TCP.<anonymous> (node:net:301:12)
abs-container  | [2023-09-27 08:57:09] INFO: [SocketAuthority] Socket Connected 4e5Zsdn8qYUfbZq6AADr
abs-container  | [2023-09-27 08:57:12] INFO: [PlaybackSessionManager] Syncing local session "Mark of the Fool 2" (play_local_f98a0bcc-8443-432d-b730-6d1ad164c331)
abs-container  | [2023-09-27 08:57:54] INFO: [SocketAuthority] Socket 4e5Zsdn8qYUfbZq6AADr disconnected from client "root" after 44864ms (Reason: ping timeout)
abs-container  | [2023-09-27 09:00:22] INFO: [SocketAuthority] Socket Connected cjlNa-Ij8D4-l9MZAADt
abs-container  | [2023-09-27 09:06:58] INFO: [SocketAuthority] Socket cjlNa-Ij8D4-l9MZAADt disconnected from client "root" after 396019ms (Reason: ping timeout)
abs-container  | [2023-09-27 09:13:37] INFO: [SocketAuthority] Socket Connected m0fyhbijRr5TmAHKAADv
abs-container  | [2023-09-27 09:19:03] INFO: [SocketAuthority] Socket m0fyhbijRr5TmAHKAADv disconnected from client "root" after 326604ms (Reason: ping timeout)
abs-container  | [2023-09-27 10:03:54] INFO: [SocketAuthority] Socket Connected Koeb_GBVsqaV9M4WAADx
abs-container  | [2023-09-27 10:32:28] INFO: [SocketAuthority] Socket Connected 55F91WyaabqYnqbcAADz
abs-container  | [2023-09-27 10:32:31] INFO: [SocketAuthority] Socket Koeb_GBVsqaV9M4WAADx disconnected from client "root" after 1717422ms (Reason: ping timeout)
abs-container  | [2023-09-27 10:42:02] INFO: [SocketAuthority] Socket 55F91WyaabqYnqbcAADz disconnected from client "root" after 574065ms (Reason: ping timeout)
abs-container  | [2023-09-27 10:47:10] INFO: [SocketAuthority] Socket Connected yuStQmGOeQ6ceCgAAAD1
abs-container  | [2023-09-27 10:52:31] INFO: [SocketAuthority] Socket yuStQmGOeQ6ceCgAAAD1 disconnected from client "root" after 320951ms (Reason: ping timeout)
abs-container  | [2023-09-27 12:00:00] INFO: [BackupManager] Running Backup
abs-container  | [2023-09-27 12:00:14] INFO: [BackupManager] 21820096 total bytes
abs-container  | [2023-09-27 12:00:14] INFO: [BackupManager] Backup successful 2023-09-27T1200
abs-container  | [2023-09-27 12:00:14] INFO: [BackupManager] Backup "2023-09-22T1200" Removed
abs-container  | [2023-09-27 12:11:38] INFO: [SocketAuthority] Socket Connected AQg-G1tzwmfuZKJBAAD3
abs-container  | [2023-09-27 12:17:24] INFO: [SocketAuthority] Socket AQg-G1tzwmfuZKJBAAD3 disconnected from client "root" after 346685ms (Reason: ping timeout)
abs-container  | BadRequestError: request aborted
abs-container  |     at IncomingMessage.onAborted (/node_modules/raw-body/index.js:238:10)
abs-container  |     at IncomingMessage.emit (node:events:513:28)
abs-container  |     at IncomingMessage._destroy (node:_http_incoming:224:10)
abs-container  |     at _destroy (node:internal/streams/destroy:102:25)
abs-container  |     at IncomingMessage.destroy (node:internal/streams/destroy:64:5)
abs-container  |     at abortIncoming (node:_http_server:642:9)
abs-container  |     at socketOnClose (node:_http_server:636:3)
abs-container  |     at Socket.emit (node:events:525:35)
abs-container  |     at TCP.<anonymous> (node:net:301:12)
abs-container  | [2023-09-27 18:00:00] INFO: [BackupManager] Running Backup
abs-container  | [2023-09-27 18:00:14] INFO: [BackupManager] 21820151 total bytes
abs-container  | [2023-09-27 18:00:14] INFO: [BackupManager] Backup successful 2023-09-27T1800
abs-container  | [2023-09-27 18:00:14] INFO: [BackupManager] Backup "2023-09-22T1800" Removed
abs-container  | [2023-09-27 18:29:17] INFO: [SocketAuthority] Socket Connected -NFW-mhSiwkrQt6uAAD5
abs-container  | [2023-09-27 18:29:19] INFO: Received ping
abs-container  | [2023-09-27 18:35:04] INFO: [SocketAuthority] Socket -NFW-mhSiwkrQt6uAAD5 disconnected from client "root" after 346552ms (Reason: ping timeout)
abs-container  | [2023-09-27 18:36:11] INFO: [SocketAuthority] Socket Connected PzCokYZNyHtXsZlrAAD7
abs-container  | [2023-09-27 18:36:32] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 2" for user "root" (Device: Windows 10 / Firefox)
abs-container  | [2023-09-27 18:36:32] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 2" for user "root" (Device: Windows 10 / Firefox)
abs-container  | [2023-09-27 19:59:39] INFO: [SocketAuthority] Socket Connected DzhZPvzFXVlVhM5dAAD9
abs-container  | [2023-09-27 20:01:43] INFO: [PlaybackSessionManager] startSession: Closing open session "Path of Daggers" for user "root" (Device: POCO F2 Pro SDK 33 / v13)
abs-container  | [2023-09-27 20:02:11] INFO: [SocketAuthority] Socket DzhZPvzFXVlVhM5dAAD9 disconnected from client "root" after 151212ms (Reason: transport close)
abs-container  | [2023-09-27 20:02:14] INFO: [SocketAuthority] Socket Connected kYp9ejRjFQDhM1j2AAD_
abs-container  | [2023-09-27 20:02:20] INFO: Received ping
abs-container  | [2023-09-27 20:02:50] INFO: [LibraryItemController] User "root" requested file download at "/audiobooks/J M Clarke/Mark of the Fool/Mark of the Fool 03 - Mark of the Fool 3/Mark of the Fool 3.m4b"
abs-container  | [2023-09-27 20:08:50] INFO: [SocketAuthority] Socket kYp9ejRjFQDhM1j2AAD_ disconnected from client "root" after 396533ms (Reason: ping timeout)
abs-container  | [2023-09-27 20:15:39] INFO: [SocketAuthority] Socket Connected cpCDw2462_hQy2iFAAEB
abs-container  | [2023-09-27 20:23:30] INFO: [SocketAuthority] Socket cpCDw2462_hQy2iFAAEB disconnected from client "root" after 471203ms (Reason: ping timeout)
abs-container  | [2023-09-27 21:10:53] INFO: [SocketAuthority] Socket Connected ztUmk6K2OvsqmqOQAAED
abs-container  | [2023-09-27 21:19:10] INFO: [SocketAuthority] Socket ztUmk6K2OvsqmqOQAAED disconnected from client "root" after 496658ms (Reason: ping timeout)
abs-container  | [2023-09-28 00:00:00] INFO: [BackupManager] Running Backup
abs-container  | [2023-09-28 00:00:14] INFO: [BackupManager] 21820488 total bytes
abs-container  | [2023-09-28 00:00:14] INFO: [BackupManager] Backup successful 2023-09-28T0000
abs-container  | [2023-09-28 00:00:14] INFO: [BackupManager] Backup "2023-09-23T0000" Removed
abs-container  | [2023-09-28 02:00:21] INFO: [SocketAuthority] Socket PzCokYZNyHtXsZlrAAD7 disconnected from client "root" after 26650137ms (Reason: transport close)
abs-container  | [2023-09-28 02:02:29] INFO: [SocketAuthority] Socket Connected 6126j-p4evuHnudjAAEF
abs-container  | [2023-09-28 06:00:00] INFO: [BackupManager] Running Backup
abs-container  | [2023-09-28 06:00:15] INFO: [BackupManager] 21820493 total bytes
abs-container  | [2023-09-28 06:00:15] INFO: [BackupManager] Backup successful 2023-09-28T0600
abs-container  | [2023-09-28 06:00:15] INFO: [BackupManager] Backup "2023-09-23T0600" Removed
abs-container  | [2023-09-28 07:25:29] INFO: [SocketAuthority] Socket Connected 1Mkc1fWnfG7ZLW8fAAEH
abs-container  | [2023-09-28 07:28:47] INFO: [SocketAuthority] Socket Connected exyWiS2k4CPmgnn8AAEJ
abs-container  | [2023-09-28 07:29:09] INFO: [SocketAuthority] Socket 1Mkc1fWnfG7ZLW8fAAEH disconnected from client "root" after 220619ms (Reason: ping timeout)
abs-container  | [2023-09-28 07:29:33] INFO: [SocketAuthority] Socket exyWiS2k4CPmgnn8AAEJ disconnected from client "root" after 45658ms (Reason: transport close)
abs-container  | BadRequestError: request aborted
abs-container  |     at IncomingMessage.onAborted (/node_modules/raw-body/index.js:238:10)
abs-container  |     at IncomingMessage.emit (node:events:513:28)
abs-container  |     at IncomingMessage._destroy (node:_http_incoming:224:10)
abs-container  |     at _destroy (node:internal/streams/destroy:102:25)
abs-container  |     at IncomingMessage.destroy (node:internal/streams/destroy:64:5)
abs-container  |     at abortIncoming (node:_http_server:642:9)
abs-container  |     at socketOnClose (node:_http_server:636:3)
abs-container  |     at Socket.emit (node:events:525:35)
abs-container  |     at TCP.<anonymous> (node:net:301:12)
abs-container  | [2023-09-28 07:29:39] INFO: [SocketAuthority] Socket Connected CPh6vb0OFajFt5A3AAEL
abs-container  | [2023-09-28 07:30:19] INFO: [SocketAuthority] Socket CPh6vb0OFajFt5A3AAEL disconnected from client "root" after 40588ms (Reason: transport close)
abs-container  | [2023-09-28 07:30:19] INFO: [SocketAuthority] Socket Connected W8JRAt0Gc6pDFaTSAAEN
abs-container  | [2023-09-28 07:30:49] INFO: [SocketAuthority] Socket W8JRAt0Gc6pDFaTSAAEN disconnected from client "root" after 29836ms (Reason: transport close)
abs-container  | [2023-09-28 07:31:53] INFO: [SocketAuthority] Socket Connected npCBOOSZXncaSR5TAAEP
abs-container  | [2023-09-28 07:38:30] INFO: [SocketAuthority] Socket npCBOOSZXncaSR5TAAEP disconnected from client "root" after 396555ms (Reason: ping timeout)
abs-container  | [2023-09-28 08:08:10] INFO: [SocketAuthority] Socket Connected 4smTjdzbBlV2eZDhAAER
abs-container  | [2023-09-28 08:13:56] INFO: [SocketAuthority] Socket 4smTjdzbBlV2eZDhAAER disconnected from client "root" after 346025ms (Reason: ping timeout)
abs-container  | [2023-09-28 08:37:48] INFO: [SocketAuthority] Socket Connected dvx6MgoyjTUl_lGpAAET
abs-container  | [2023-09-28 08:43:09] INFO: [SocketAuthority] Socket dvx6MgoyjTUl_lGpAAET disconnected from client "root" after 320949ms (Reason: ping timeout)
abs-container  | [2023-09-28 09:11:12] INFO: [SocketAuthority] Socket Connected ADhDn-GAeQACu8DKAAEV
abs-container  | [2023-09-28 09:16:34] INFO: [SocketAuthority] Socket ADhDn-GAeQACu8DKAAEV disconnected from client "root" after 321221ms (Reason: ping timeout)
abs-container  | [2023-09-28 11:01:18] INFO: [SocketAuthority] Socket Connected xyZo8Roneya_Scy9AAEX
abs-container  | [2023-09-28 11:07:04] INFO: [SocketAuthority] Socket xyZo8Roneya_Scy9AAEX disconnected from client "root" after 346220ms (Reason: ping timeout)
abs-container  | [2023-09-28 12:00:00] INFO: [BackupManager] Running Backup
abs-container  | [2023-09-28 12:00:13] INFO: [BackupManager] 21822184 total bytes
abs-container  | [2023-09-28 12:00:13] INFO: [BackupManager] Backup successful 2023-09-28T1200
abs-container  | [2023-09-28 12:00:13] INFO: [BackupManager] Backup "2023-09-23T1200" Removed
abs-container  | [2023-09-28 12:06:15] INFO: [SocketAuthority] Socket Connected Yj1dvQlK2OVT8im4AAEZ
abs-container  | [2023-09-28 12:12:01] INFO: [SocketAuthority] Socket Yj1dvQlK2OVT8im4AAEZ disconnected from client "root" after 345982ms (Reason: ping timeout)
abs-container  | [2023-09-28 16:19:05] INFO: [SocketAuthority] Socket Connected qxgiplwvXbuNvY2kAAEb
abs-container  | [2023-09-28 16:26:25] INFO: [SocketAuthority] Socket Connected 2HVqqFnCZkIJ9iyCAAEd
abs-container  | [2023-09-28 16:26:46] INFO: [SocketAuthority] Socket qxgiplwvXbuNvY2kAAEb disconnected from client "root" after 461119ms (Reason: ping timeout)
abs-container  | [2023-09-28 16:30:31] INFO: [SocketAuthority] Socket 2HVqqFnCZkIJ9iyCAAEd disconnected from client "root" after 246092ms (Reason: ping timeout)
abs-container  | [2023-09-28 17:15:24] INFO: [SocketAuthority] Socket 6126j-p4evuHnudjAAEF disconnected from client "root" after 54775387ms (Reason: transport close)
abs-container  | [2023-09-28 17:15:28] INFO: [SocketAuthority] Socket Connected -DSy89N47LdjPniLAAEf
abs-container  | [2023-09-28 17:47:06] INFO: [SocketAuthority] Socket Connected 7gBgICZltDeEdqVxAAEh
abs-container  | [2023-09-28 17:47:06] INFO: [SocketAuthority] Socket -DSy89N47LdjPniLAAEf disconnected from client "root" after 1898574ms (Reason: transport close)
abs-container  | [2023-09-28 17:52:07] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 2" for user "root" (Device: Windows 10 / Firefox)
abs-container  | [2023-09-28 17:52:07] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 2" for user "root" (Device: Windows 10 / Firefox)
abs-container  | [2023-09-28 17:52:21] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 3" for user "root" (Device: Windows 10 / Firefox)
abs-container  | [2023-09-28 17:52:22] INFO: [STREAM] START STREAM - Num Segments: 13716
abs-container  | [2023-09-28 17:52:22] INFO: [STREAM] Starting Stream at startTime 2:22:07.0 (User startTime 2:22:37.0) and Segment #1421
abs-container  | [2023-09-28 17:52:22] INFO: [INFO] FFMPEG transcoding started with command: ffmpeg -seek_timestamp 1 -f concat -safe 0 -ss 8527.1s -noaccurate_seek -i /metadata/streams/e91f3ffc-98a6-45ef-8a30-ba785c21997e/files.txt -y -loglevel error -map 0:a -c:a copy -f hls -copyts -avoid_negative_ts make_non_negative -max_delay 5000000 -max_muxing_queue_size 2048 -hls_time 6 -hls_segment_type mpegts -start_number 1421 -hls_playlist_type vod -hls_list_size 0 -hls_allow_cache 0 -hls_segment_filename /metadata/streams/e91f3ffc-98a6-45ef-8a30-ba785c21997e/output-%d.ts /metadata/streams/e91f3ffc-98a6-45ef-8a30-ba785c21997e/final-output.m3u8
abs-container  | [2023-09-28 17:52:22] INFO:
abs-container  | [2023-09-28 17:52:24] WARN: No Segments (Stream.js:183)
abs-container  | [2023-09-28 17:52:26] WARN: No Segments (Stream.js:183)
abs-container  | [2023-09-28 17:52:27] INFO: [adts @ 0x7fa9504ba900] Scalable configurations are not allowed in ADTS
abs-container  | [2023-09-28 17:52:27] INFO: [out#0/hls @ 0x7fa94f67f8c0] Could not write header (incorrect codec parameters ?): Invalid data found when processing input
abs-container  | [2023-09-28 17:52:27] INFO: [aost#0:0/copy @ 0x7fa94f645980] Error initializing output stream:
abs-container  | [2023-09-28 17:52:27] INFO:
abs-container  | [2023-09-28 17:52:28] INFO:
abs-container  | [2023-09-28 17:52:28] ERROR: Ffmpeg Err "ffmpeg exited with code 1:
abs-container  | " (Stream.js:340)
abs-container  | [2023-09-28 17:52:28] INFO: Closing Stream e91f3ffc-98a6-45ef-8a30-ba785c21997e
abs-container  | [2023-09-28 17:52:28] WARN: File path does not exist /metadata/streams/e91f3ffc-98a6-45ef-8a30-ba785c21997e/output-1426.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 17:52:28] WARN: [STREAM] Segment #1426 Request @2:22:36.0 is before start time (2:22:37.0) - Reset Transcode (Stream.js:146)
abs-container  | [2023-09-28 17:52:28] INFO: Deleted session data /metadata/streams/e91f3ffc-98a6-45ef-8a30-ba785c21997e
abs-container  | [2023-09-28 17:52:38] INFO: [SocketAuthority] Socket 7gBgICZltDeEdqVxAAEh disconnected from client "root" after 331709ms (Reason: transport close)
abs-container  | [2023-09-28 17:52:38] ERROR: [STREAM] Transcode never closed... (Stream.js:405)
abs-container  | [2023-09-28 17:52:38] INFO: Stream Reset New Start Time 2:22:24.0
abs-container  | [2023-09-28 17:52:38] INFO: [STREAM] START STREAM - Num Segments: 13716
abs-container  | [2023-09-28 17:52:38] INFO: [HlsRouter] Resetting Stream - notify client @8556s
abs-container  | node:internal/process/promises:279
abs-container  |             triggerUncaughtException(err, true /* fromPromise */);
abs-container  |             ^
abs-container  |
abs-container  |
abs-container  | [Error: ENOENT: no such file or directory, open '/metadata/streams/e91f3ffc-98a6-45ef-8a30-ba785c21997e/files.txt'] {
abs-container  |   errno: -2,
abs-container  |   code: 'ENOENT',
abs-container  |   syscall: 'open',
abs-container  |   path: '/metadata/streams/e91f3ffc-98a6-45ef-8a30-ba785c21997e/files.txt'
abs-container  | }
After a restart of the container, it still doesn't want to play but didn't crash 
abs-container  | [2023-09-28 17:55:15] INFO: === Starting Server ===
abs-container  | [2023-09-28 17:55:15] INFO: [Server] Init v2.4.3
abs-container  | [2023-09-28 17:55:15] INFO: [Database] Initializing db at "/config/absdatabase.sqlite"
abs-container  | [2023-09-28 17:55:16] INFO: [Database] Db connection was successful
abs-container  | [2023-09-28 17:55:17] INFO: [Database] Db initialized with models: user, library, libraryFolder, book, podcast, podcastEpisode, libraryItem, mediaProgress, series, bookSeries, author, bookAuthor, collection, collectionBook, playlist, playlistMediaItem, device, playbackSession, feed, feedEpisode, setting
abs-container  | [2023-09-28 17:55:18] ERROR: [BackupManager] Failed to unzip backup "/metadata/backups/2023-05-30T1800.audiobookshelf" Error: Bad archive
abs-container  |     at FsRead.readUntilFoundCallback [as callback] (/server/libs/nodeStreamZip/index.js:198:33)
abs-container  |     at FsRead.readCallback (/server/libs/nodeStreamZip/index.js:996:19)
abs-container  |     at FSReqCallback.wrapper [as oncomplete] (node:fs:671:5) (BackupManager.js:180)
abs-container  | [2023-09-28 17:55:18] ERROR: [BackupManager] Failed to load backups Error: Bad archive
abs-container  |     at FsRead.readUntilFoundCallback [as callback] (/server/libs/nodeStreamZip/index.js:198:33)
abs-container  |     at FsRead.readCallback (/server/libs/nodeStreamZip/index.js:996:19)
abs-container  |     at FSReqCallback.wrapper [as oncomplete] (node:fs:671:5) (BackupManager.js:209)
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Removed daily log: 2023-09-12.txt
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Removed daily log: 2023-09-13.txt
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Removed daily log: 2023-09-14.txt
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Removed daily log: 2023-09-15.txt
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Removed daily log: 2023-09-16.txt
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Removed daily log: 2023-09-17.txt
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Removed daily log: 2023-09-18.txt
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Removed daily log: 2023-09-19.txt
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Removed daily log: 2023-09-20.txt
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Removed daily log: 2023-09-21.txt
abs-container  | [2023-09-28 17:55:19] INFO: [LogManager] Init current daily log filename: 2023-09-28.txt
abs-container  | [2023-09-28 17:55:19] INFO: [Watcher] Initializing watcher for "Audiobooks".
abs-container  | [2023-09-28 17:55:19] INFO: [Watcher] Initializing watcher for "Ebooks".
abs-container  | [2023-09-28 17:55:19] INFO: Listening on port :80
abs-container  | [2023-09-28 17:55:19] INFO: [Watcher] "Ebooks" Ready
abs-container  | [2023-09-28 17:55:21] INFO: [Watcher] "Audiobooks" Ready
abs-container  | [2023-09-28 18:00:00] INFO: [BackupManager] Running Backup
abs-container  | [2023-09-28 18:00:04] INFO: [SocketAuthority] Socket Connected X4UDlGaHJl8OVsOzAAAB
abs-container  | [2023-09-28 18:00:36] INFO: [BackupManager] 21822463 total bytes
abs-container  | [2023-09-28 18:00:36] INFO: [BackupManager] Backup successful 2023-09-28T1800
abs-container  | [2023-09-28 18:00:47] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 3" for user "root" (Device: Windows 10 / Firefox)
abs-container  | [2023-09-28 18:00:48] INFO: [STREAM] START STREAM - Num Segments: 13716
abs-container  | [2023-09-28 18:00:48] INFO: [STREAM] Starting Stream at startTime 2:22:07.0 (User startTime 2:22:37.0) and Segment #1421
abs-container  | [2023-09-28 18:00:52] INFO: [INFO] FFMPEG transcoding started with command: ffmpeg -seek_timestamp 1 -f concat -safe 0 -ss 8527.1s -noaccurate_seek -i /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/files.txt -y -loglevel error -map 0:a -c:a copy -f hls -copyts -avoid_negative_ts make_non_negative -max_delay 5000000 -max_muxing_queue_size 2048 -hls_time 6 -hls_segment_type mpegts -start_number 1421 -hls_playlist_type vod -hls_list_size 0 -hls_allow_cache 0 -hls_segment_filename /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/output-%d.ts /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/final-output.m3u8
abs-container  | [2023-09-28 18:00:52] INFO:
abs-container  | [2023-09-28 18:00:53] WARN: File path does not exist /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/output-1426.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:00:53] WARN: [STREAM] Segment #1426 Request @2:22:36.0 is before start time (2:22:37.0) - Reset Transcode (Stream.js:146)
abs-container  | [2023-09-28 18:00:53] INFO: [FFMPEG] Transcode Killed
abs-container  | [2023-09-28 18:00:54] INFO: Stream Reset New Start Time 2:22:24.0
abs-container  | [2023-09-28 18:00:54] INFO: [STREAM] START STREAM - Num Segments: 13716
abs-container  | [2023-09-28 18:00:54] INFO: [HlsRouter] Resetting Stream - notify client @8556s
abs-container  | [2023-09-28 18:00:54] INFO: [STREAM] Starting Stream at startTime 2:21:54.0 (User startTime 2:22:24.0) and Segment #1419
abs-container  | [2023-09-28 18:00:54] INFO: [INFO] FFMPEG transcoding started with command: ffmpeg -seek_timestamp 1 -f concat -safe 0 -ss 8514s -noaccurate_seek -i /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/files.txt -y -loglevel error -map 0:a -c:a copy -f hls -copyts -avoid_negative_ts make_non_negative -max_delay 5000000 -max_muxing_queue_size 2048 -hls_time 6 -hls_segment_type mpegts -start_number 1419 -hls_playlist_type vod -hls_list_size 0 -hls_allow_cache 0 -hls_segment_filename /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/output-%d.ts /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/final-output.m3u8
abs-container  | [2023-09-28 18:00:54] INFO:
abs-container  | [2023-09-28 18:00:54] INFO: [STREAM] Clearing isResetting
abs-container  | [2023-09-28 18:00:56] INFO: [adts @ 0x7fdbe317c900] Scalable configurations are not allowed in ADTS
abs-container  | [2023-09-28 18:00:56] INFO: [out#0/hls @ 0x7fdbe23418c0] Could not write header (incorrect codec parameters ?): Invalid data found when processing input
abs-container  | [2023-09-28 18:00:56] INFO: [aost#0:0/copy @ 0x7fdbe2307980] Error initializing output stream:
abs-container  | [2023-09-28 18:00:56] INFO:
abs-container  | [2023-09-28 18:00:56] INFO:
abs-container  | [2023-09-28 18:00:56] ERROR: Ffmpeg Err "ffmpeg exited with code 1:
abs-container  | " (Stream.js:340)
abs-container  | [2023-09-28 18:00:56] INFO: Closing Stream a916cf93-4514-44bf-ac5f-ae28a973b1e1
abs-container  | [2023-09-28 18:00:56] INFO: Deleted session data /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1
abs-container  | [2023-09-28 18:00:57] WARN: File path does not exist /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/output-1426.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:00:57] ERROR: [HlsRouter] Stream a916cf93-4514-44bf-ac5f-ae28a973b1e1 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:01:00] WARN: File path does not exist /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/output-1426.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:01:00] ERROR: [HlsRouter] Stream a916cf93-4514-44bf-ac5f-ae28a973b1e1 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:01:04] WARN: File path does not exist /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/output-1426.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:01:04] ERROR: [HlsRouter] Stream a916cf93-4514-44bf-ac5f-ae28a973b1e1 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:01:10] WARN: File path does not exist /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/output-1426.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:01:10] ERROR: [HlsRouter] Stream a916cf93-4514-44bf-ac5f-ae28a973b1e1 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:01:20] WARN: File path does not exist /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/output-1426.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:01:20] ERROR: [HlsRouter] Stream a916cf93-4514-44bf-ac5f-ae28a973b1e1 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:01:38] WARN: File path does not exist /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/output-1426.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:01:38] ERROR: [HlsRouter] Stream a916cf93-4514-44bf-ac5f-ae28a973b1e1 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:02:12] WARN: File path does not exist /metadata/streams/a916cf93-4514-44bf-ac5f-ae28a973b1e1/output-1426.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:02:12] ERROR: [HlsRouter] Stream a916cf93-4514-44bf-ac5f-ae28a973b1e1 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:02:31] INFO: [SocketAuthority] Socket X4UDlGaHJl8OVsOzAAAB disconnected from client "root" after 146189ms (Reason: transport close)
abs-container  | [2023-09-28 18:02:33] INFO: [SocketAuthority] Socket Connected HrqYWQsJguUn0ZmzAAAD
This was my third try 
abs-container  | [2023-09-28 18:08:15] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 3" for user "root" (Device: Windows 10 / Firefox)
abs-container  | [2023-09-28 18:08:29] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 3" for user "root" (Device: Windows 10 / Firefox)
abs-container  | [2023-09-28 18:08:29] INFO: [STREAM] START STREAM - Num Segments: 13716
abs-container  | [2023-09-28 18:08:29] INFO: [STREAM] Starting Stream at startTime 2:23:45.0 (User startTime 2:24:15.0) and Segment #1437
abs-container  | [2023-09-28 18:08:30] INFO: [INFO] FFMPEG transcoding started with command: ffmpeg -seek_timestamp 1 -f concat -safe 0 -ss 8625.4s -noaccurate_seek -i /metadata/streams/67b5b9d0-ebb9-4a1e-a29b-08a06a64f058/files.txt -y -loglevel error -map 0:a -c:a copy -f hls -copyts -avoid_negative_ts make_non_negative -max_delay 5000000 -max_muxing_queue_size 2048 -hls_time 6 -hls_segment_type mpegts -start_number 1437 -hls_playlist_type vod -hls_list_size 0 -hls_allow_cache 0 -hls_segment_filename /metadata/streams/67b5b9d0-ebb9-4a1e-a29b-08a06a64f058/output-%d.ts /metadata/streams/67b5b9d0-ebb9-4a1e-a29b-08a06a64f058/final-output.m3u8
abs-container  | [2023-09-28 18:08:30] INFO:
abs-container  | [2023-09-28 18:08:32] WARN: No Segments (Stream.js:183)
abs-container  | [2023-09-28 18:08:33] INFO: [adts @ 0x7f60b4472900] Scalable configurations are not allowed in ADTS
abs-container  | [2023-09-28 18:08:33] INFO: [out#0/hls @ 0x7f60b36378c0] Could not write header (incorrect codec parameters ?): Invalid data found when processing input
abs-container  | [2023-09-28 18:08:33] INFO: [aost#0:0/copy @ 0x7f60b35fd980] Error initializing output stream:
abs-container  | [2023-09-28 18:08:33] INFO:
abs-container  | [2023-09-28 18:08:34] WARN: No Segments (Stream.js:183)
abs-container  | [2023-09-28 18:08:34] INFO:
abs-container  | [2023-09-28 18:08:34] ERROR: Ffmpeg Err "ffmpeg exited with code 1:
abs-container  | " (Stream.js:340)
abs-container  | [2023-09-28 18:08:34] INFO: Closing Stream 67b5b9d0-ebb9-4a1e-a29b-08a06a64f058
abs-container  | [2023-09-28 18:08:34] INFO: Deleted session data /metadata/streams/67b5b9d0-ebb9-4a1e-a29b-08a06a64f058
abs-container  | [2023-09-28 18:08:35] WARN: File path does not exist /metadata/streams/67b5b9d0-ebb9-4a1e-a29b-08a06a64f058/output-1442.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:08:35] ERROR: [HlsRouter] Stream 67b5b9d0-ebb9-4a1e-a29b-08a06a64f058 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:08:38] WARN: File path does not exist /metadata/streams/67b5b9d0-ebb9-4a1e-a29b-08a06a64f058/output-1442.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:08:38] ERROR: [HlsRouter] Stream 67b5b9d0-ebb9-4a1e-a29b-08a06a64f058 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:08:42] WARN: File path does not exist /metadata/streams/67b5b9d0-ebb9-4a1e-a29b-08a06a64f058/output-1442.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:08:42] ERROR: [HlsRouter] Stream 67b5b9d0-ebb9-4a1e-a29b-08a06a64f058 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:08:48] WARN: File path does not exist /metadata/streams/67b5b9d0-ebb9-4a1e-a29b-08a06a64f058/output-1442.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:08:48] ERROR: [HlsRouter] Stream 67b5b9d0-ebb9-4a1e-a29b-08a06a64f058 does not exist (HlsRouter.js:43)
abs-container  | [2023-09-28 18:08:57] WARN: File path does not exist /metadata/streams/67b5b9d0-ebb9-4a1e-a29b-08a06a64f058/output-1442.ts (HlsRouter.js:36)
abs-container  | [2023-09-28 18:08:57] ERROR: [HlsRouter] Stream 67b5b9d0-ebb9-4a1e-a29b-08a06a64f058 does not exist (HlsRouter.js:43)

Steps to reproduce the issue

  1. Start playback in Browser

Audiobookshelf version

v2.4.3

How are you running audiobookshelf?

Docker
@Alistair1231 Alistair1231 added the bug Something isn't working label Sep 28, 2023
@advplyr
Copy link
Owner

advplyr commented Sep 28, 2023

Thanks for the detailed info. If you have a chromium browser can you try playing on there? Firefox seems to have issues with some m4b but either way there is a bug here with the server crash.

@advplyr
Copy link
Owner

advplyr commented Sep 28, 2023

Can you enable debug logs? It looks like the crash you got was a race condition. Have you gotten the crash again after that?

@Alistair1231
Copy link
Contributor Author

Alistair1231 commented Sep 30, 2023 •
edited
Loading

Thanks for the detailed info. If you have a chromium browser can you try playing on there? Firefox seems to have issues with some m4b but either way there is a bug here with the server crash.

Can you enable debug logs? It looks like the crash you got was a race condition.

Oh, I totally missed that option. I enabled it now. Firefox seems to indeed be misbehaving. Edge works fine, here are the logs:

Playing from Edge (after successful playback, I enabled debug logs and refreshed to see if anything weird shows up) 
abs-container  | [2023-09-30 17:43:34] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 3" for user "root" (Device: Windows 10 / Edge)
abs-container  | [2023-09-30 17:43:49] INFO: [SocketAuthority] Socket 6t0YczC9Y1MtSiMrAAA5 disconnected from client "root" after 193990ms (Reason: transport close)
abs-container  | [2023-09-30 17:43:58] INFO: [SocketAuthority] Socket Gx33cLU3adLJNfXgAAA_ disconnected from client "root" after 47012ms (Reason: transport close)
abs-container  | [2023-09-30 17:44:00] INFO: [SocketAuthority] Socket Connected TZ7eRZkfw3aPmLgoAABB
abs-container  | [2023-09-30 17:44:09] DEBUG: Set Log Level to DEBUG (Logger.js:87)
abs-container  | [2023-09-30 17:44:18] DEBUG: Loaded 7 personalized shelves in 1.62s (LibraryItem.js:667)
abs-container  | [2023-09-30 17:44:28] DEBUG: [PlaybackSessionManager] startSessionRequest for device Windows 10 / Edge (PlaybackSessionManager.js:64)
abs-container  | [2023-09-30 17:44:28] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 3" for user "root" (Device: Windows 10 / Edge)
abs-container  | [2023-09-30 17:44:28] DEBUG: [PlaybackSessionManager] closeSession "2e2d5eb6-71d5-49ff-bd50-60df802b4bbe" (PlaybackSessionManager.js:306)
abs-container  | [2023-09-30 17:44:28] DEBUG: [PlaybackSessionManager] Removed session "2e2d5eb6-71d5-49ff-bd50-60df802b4bbe" (PlaybackSessionManager.js:330)
abs-container  | [2023-09-30 17:44:28] DEBUG: [PlaybackSessionManager] "root" starting direct play session for item "e04cb23a-3213-46e8-8cb4-0f4d291bdcdf" with id 424c4cc7-9106-4c5e-a22c-acaffca79a9f (Device: Windows 10 / Edge) (PlaybackSessionManager.js:240)
Playing from Firefox 
abs-container  | [2023-09-30 17:47:09] INFO: [SocketAuthority] Socket Connected 4e_HsIVvZwdWH778AABD
abs-container  | [2023-09-30 17:47:09] DEBUG: [SocketAuthority] User Online root (SocketAuthority.js:172)
abs-container  | [2023-09-30 17:47:11] DEBUG: Loaded 7 personalized shelves in 2.33s (LibraryItem.js:667)
abs-container  | [2023-09-30 17:47:22] DEBUG: [PlaybackSessionManager] startSessionRequest for device Windows 10 / Firefox (PlaybackSessionManager.js:64)
abs-container  | [2023-09-30 17:47:22] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 3" for user "root" (Device: Windows 10 / Firefox)
abs-container  | [2023-09-30 17:47:22] DEBUG: [PlaybackSessionManager] closeSession "3eea52fd-63e7-43c2-b10f-fd7cfe6c0956" (PlaybackSessionManager.js:306)
abs-container  | [2023-09-30 17:47:22] DEBUG: [PlaybackSessionManager] Removed session "3eea52fd-63e7-43c2-b10f-fd7cfe6c0956" (PlaybackSessionManager.js:330)
abs-container  | [2023-09-30 17:47:22] DEBUG: [PlaybackSessionManager] "root" starting direct play session for item "e04cb23a-3213-46e8-8cb4-0f4d291bdcdf" with id 4f2a5939-984c-41d4-9f7b-c06eb1f2d326 (Device: Windows 10 / Firefox) (PlaybackSessionManager.js:240)
abs-container  | [2023-09-30 17:47:31] DEBUG: [PlaybackSessionManager] startSessionRequest for device Windows 10 / Firefox (PlaybackSessionManager.js:64)
abs-container  | [2023-09-30 17:47:31] INFO: [PlaybackSessionManager] startSession: Closing open session "Mark of the Fool 3" for user "root" (Device: Windows 10 / Firefox)
abs-container  | [2023-09-30 17:47:31] DEBUG: [PlaybackSessionManager] closeSession "4f2a5939-984c-41d4-9f7b-c06eb1f2d326" (PlaybackSessionManager.js:306)
abs-container  | [2023-09-30 17:47:31] DEBUG: [PlaybackSessionManager] Removed session "4f2a5939-984c-41d4-9f7b-c06eb1f2d326" (PlaybackSessionManager.js:330)
abs-container  | [2023-09-30 17:47:31] DEBUG: [PlaybackSessionManager] "root" starting stream session for item "e04cb23a-3213-46e8-8cb4-0f4d291bdcdf" (Device: Windows 10 / Firefox) (PlaybackSessionManager.js:244)
abs-container  | [2023-09-30 17:47:31] INFO: [STREAM] START STREAM - Num Segments: 13716
abs-container  | [2023-09-30 17:47:31] INFO: [STREAM] Starting Stream at startTime 9:25:19.0 (User startTime 9:25:49.0) and Segment #5653
abs-container  | [2023-09-30 17:47:31] INFO: [INFO] FFMPEG transcoding started with command: ffmpeg -seek_timestamp 1 -f concat -safe 0 -ss 33919s -noaccurate_seek -i /metadata/streams/5c4446ce-e94f-4908-a6f4-56be466e45fc/files.txt -y -loglevel error -map 0:a -c:a copy -f hls -copyts -avoid_negative_ts make_non_negative -max_delay 5000000 -max_muxing_queue_size 2048 -hls_time 6 -hls_segment_type mpegts -start_number 5653 -hls_playlist_type vod -hls_list_size 0 -hls_allow_cache 0 -hls_segment_filename /metadata/streams/5c4446ce-e94f-4908-a6f4-56be466e45fc/output-%d.ts /metadata/streams/5c4446ce-e94f-4908-a6f4-56be466e45fc/final-output.m3u8
abs-container  | [2023-09-30 17:47:31] INFO:
abs-container  | [2023-09-30 17:47:33] INFO: [adts @ 0x7f7594d16900] Scalable configurations are not allowed in ADTS
abs-container  | [2023-09-30 17:47:33] INFO: [out#0/hls @ 0x7f7593edb8c0] Could not write header (incorrect codec parameters ?): Invalid data found when processing input
abs-container  | [2023-09-30 17:47:33] INFO: [aost#0:0/copy @ 0x7f7593ea1980] Error initializing output stream:
abs-container  | [2023-09-30 17:47:33] INFO:
abs-container  | [2023-09-30 17:47:33] INFO:
abs-container  | [2023-09-30 17:47:33] ERROR: Ffmpeg Err "ffmpeg exited with code 1:
abs-container  | " (Stream.js:340)
abs-container  | [2023-09-30 17:47:33] INFO: Closing Stream 5c4446ce-e94f-4908-a6f4-56be466e45fc
abs-container  | [2023-09-30 17:47:33] INFO: Deleted session data /metadata/streams/5c4446ce-e94f-4908-a6f4-56be466e45fc
abs-container  | [2023-09-30 17:47:33] DEBUG: [PlaybackSessionManager] Stream closed for session "5c4446ce-e94f-4908-a6f4-56be466e45fc" (Device: Windows 10 / Firefox) (PlaybackSessionManager.js:254)
abs-container  | [2023-09-30 17:47:33] WARN: File path does not exist /metadata/streams/5c4446ce-e94f-4908-a6f4-56be466e45fc/output-5658.ts (HlsRouter.js:36)
abs-container  | [2023-09-30 17:47:33] ERROR: [HlsRouter] Stream 5c4446ce-e94f-4908-a6f4-56be466e45fc does not exist (HlsRouter.js:43)
abs-container  | [2023-09-30 17:47:35] WARN: File path does not exist /metadata/streams/5c4446ce-e94f-4908-a6f4-56be466e45fc/output-5658.ts (HlsRouter.js:36)
abs-container  | [2023-09-30 17:47:35] ERROR: [HlsRouter] Stream 5c4446ce-e94f-4908-a6f4-56be466e45fc does not exist (HlsRouter.js:43)
abs-container  | [2023-09-30 17:47:37] WARN: File path does not exist /metadata/streams/5c4446ce-e94f-4908-a6f4-56be466e45fc/output-5658.ts (HlsRouter.js:36)
abs-container  | [2023-09-30 17:47:37] ERROR: [HlsRouter] Stream 5c4446ce-e94f-4908-a6f4-56be466e45fc does not exist (HlsRouter.js:43)
abs-container  | [2023-09-30 17:47:42] WARN: File path does not exist /metadata/streams/5c4446ce-e94f-4908-a6f4-56be466e45fc/output-5658.ts (HlsRouter.js:36)
abs-container  | [2023-09-30 17:47:42] ERROR: [HlsRouter] Stream 5c4446ce-e94f-4908-a6f4-56be466e45fc does not exist (HlsRouter.js:43)
abs-container  | [2023-09-30 17:47:50] WARN: File path does not exist /metadata/streams/5c4446ce-e94f-4908-a6f4-56be466e45fc/output-5658.ts (HlsRouter.js:36)
abs-container  | [2023-09-30 17:47:50] ERROR: [HlsRouter] Stream 5c4446ce-e94f-4908-a6f4-56be466e45fc does not exist (HlsRouter.js:43)

Have you gotten the crash again after that?

The crash only happened once so far. I will keep Debug logs enabled for now, in case it happens again. The playback issue happened every time I tried to start it. I used scrcpy to get my phone audio to my PC instead as a workaround.

@advplyr
Copy link
Owner

advplyr commented Sep 30, 2023

When I looked through your logs and the source code I could see this was a race condition so it may be rare that the crash occurs.

As a side note, you may be having this issue with firefox because of poorly encoded Audible audio files. This is described in #1872 (comment) and another related issue #172.

An in depth breakdown of this is here: https://rentry.co/n4ost

@Alistair1231
Copy link
Contributor Author

Alistair1231 commented Oct 1, 2023 •
edited
Loading

As a side note, you may be having this issue with firefox because of poorly encoded Audible audio files. This is described in #1872 (comment) and another related issue #172.

An in depth breakdown of this is here: https://rentry.co/n4ost

Mmh. The script on that rentry post did indeed seem to fix the issue. I can play the file now in Firefox. But if it is a malformed file, why would it only be an issue in Firefox and not Edge? Also, shouldn't the server fall back to transcoding if Direct Play fails?

When I looked through your logs and the source code I could see this was a race condition so it may be rare that the crash occurs.

Ok, I will keep the debug logging enabled for now.

@advplyr
Copy link
Owner

advplyr commented Oct 1, 2023

Something about the codec. Chromium based browsers like Edge have a better decoder then Firefox I guess.

If direct play fails it falls back to transcoding that's correct. However, the transcoder fails because of the bad file. I had written a specific edge case to catch this based on a specific error and then force re-encode it to AAC, but that specific error message is not the same every time I guess. You can see my attempt at force re-encoding this issue here https://github.com/advplyr/audiobookshelf/blob/master/server/objects/Stream.js#L343

I don't know how we would check for that issue with ffmpeg. It would be much better if audible didn't give these bad files

@Alistair1231
Copy link
Contributor Author

Alistair1231 commented Oct 1, 2023 •
edited
Loading

Something about the codec. Chromium based browsers like Edge have a better decoder then Firefox I guess.

Well now that I know that, I know I can try a chromium browser, when something like this happens again. I don't know if I will want to manually fix the file every time.

It would be much better if audible didn't give these bad files

Very true. 😄

If direct play fails it falls back to transcoding that's correct. However, the transcoder fails because of the bad file. I had written a specific edge case to catch this based on a specific error and then force re-encode it to AAC, but that specific error message is not the same every time I guess. You can see my attempt at force re-encoding this issue here https://github.com/advplyr/audiobookshelf/blob/master/server/objects/Stream.js#L343

I see. I tried that now. The error just says "Ffmpeg Err "ffmpeg exited with code 1:" instead of giving a proper error like in the other example.

But since I figured that any time ffmpeg just gives an Error 1, it might make sense to transcode, I simply removed the rest of the error in the check like this: 
// Temporary workaround for https://github.com/advplyr/audiobookshelf/issues/172
const aacErrorMsg = 'ffmpeg exited with code 1:'
if (audioCodec === 'copy' && this.isAACEncodable && err.message && err.message.startsWith(aacErrorMsg)) {
  Logger.info(`[Stream] Re-attempting stream with AAC encode`)
  this.transcodeOptions.forceAAC = true
  this.reset(this.startTime)
} else {
  // Close stream show error
  this.close(err.message)
}
then I simply mounted the file into the container in my docker-compose.yml 
...
 volumes:
      ...
      - ./Stream.js:/server/objects/Stream.js
...
After trying to play the file again this is the log. It did work, it took a bit, since the server is slow but it got there 
abs-container  | [2023-10-01 17:34:49] DEBUG: [PlaybackSessionManager] "root" starting stream session for item "e04cb23a-3213-46e8-8cb4-0f4d291bdcdf" (Device: Windows 10 / Firefox) (PlaybackSessionManager.js:244)
abs-container  | [2023-10-01 17:34:49] INFO: [STREAM] START STREAM - Num Segments: 13716
abs-container  | [2023-10-01 17:34:49] INFO: [STREAM] Starting Stream at startTime 13:47:43.0 (User startTime 13:48:13.0) and Segment #8277
abs-container  | [2023-10-01 17:34:51] INFO: [INFO] FFMPEG transcoding started with command: ffmpeg -seek_timestamp 1 -f concat -safe 0 -ss 49663s -noaccurate_seek -i /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/files.txt -y -loglevel error -map 0:a -c:a copy -f hls -copyts -avoid_negative_ts make_non_negative -max_delay 5000000 -max_muxing_queue_size 2048 -hls_time 6 -hls_segment_type mpegts -start_number 8277 -hls_playlist_type vod -hls_list_size 0 -hls_allow_cache 0 -hls_segment_filename /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-%d.ts /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/final-output.m3u8
abs-container  | [2023-10-01 17:34:51] INFO:
abs-container  | [2023-10-01 17:34:51] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8282.ts (HlsRouter.js:36)
abs-container  | [2023-10-01 17:34:51] WARN: [STREAM] Segment #8282 Request @13:48:12.0 is before start time (13:48:13.0) - Reset Transcode (Stream.js:146)
abs-container  | [2023-10-01 17:34:52] INFO: [FFMPEG] Transcode Killed
abs-container  | [2023-10-01 17:34:52] INFO: Stream Reset New Start Time 13:48:00.0
abs-container  | [2023-10-01 17:34:52] INFO: [STREAM] START STREAM - Num Segments: 13716
abs-container  | [2023-10-01 17:34:52] INFO: [HlsRouter] Resetting Stream - notify client @49692s
abs-container  | [2023-10-01 17:34:52] INFO: [STREAM] Starting Stream at startTime 13:47:30.0 (User startTime 13:48:00.0) and Segment #8275
abs-container  | [2023-10-01 17:34:52] INFO: [INFO] FFMPEG transcoding started with command: ffmpeg -seek_timestamp 1 -f concat -safe 0 -ss 49650s -noaccurate_seek -i /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/files.txt -y -loglevel error -map 0:a -c:a copy -f hls -copyts -avoid_negative_ts make_non_negative -max_delay 5000000 -max_muxing_queue_size 2048 -hls_time 6 -hls_segment_type mpegts -start_number 8275 -hls_playlist_type vod -hls_list_size 0 -hls_allow_cache 0 -hls_segment_filename /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-%d.ts /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/final-output.m3u8
abs-container  | [2023-10-01 17:34:52] INFO:
abs-container  | [2023-10-01 17:34:53] INFO: [STREAM] Clearing isResetting
abs-container  | [2023-10-01 17:34:54] INFO: [adts @ 0x7ffb7a17c900] Scalable configurations are not allowed in ADTS
abs-container  | [2023-10-01 17:34:54] INFO: [out#0/hls @ 0x7ffb793418c0] Could not write header (incorrect codec parameters ?): Invalid data found when processing input
abs-container  | [2023-10-01 17:34:54] INFO: [aost#0:0/copy @ 0x7ffb79307980] Error initializing output stream:
abs-container  | [2023-10-01 17:34:54] INFO:
abs-container  | [2023-10-01 17:34:54] INFO:
abs-container  | [2023-10-01 17:34:54] ERROR: Ffmpeg Err "ffmpeg exited with code 1:
abs-container  | " (Stream.js:340)
abs-container  | [2023-10-01 17:34:54] INFO: [Stream] Re-attempting stream with AAC encode
abs-container  | [2023-10-01 17:34:54] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8282.ts (HlsRouter.js:36)
abs-container  | [2023-10-01 17:34:54] INFO: [HlsRouter] Stream 6cdcc4b7-2c99-4324-9ee1-957857f0056e is currently resetting
abs-container  | [2023-10-01 17:34:56] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8282.ts (HlsRouter.js:36)
abs-container  | [2023-10-01 17:34:56] INFO: [HlsRouter] Stream 6cdcc4b7-2c99-4324-9ee1-957857f0056e is currently resetting
abs-container  | [2023-10-01 17:34:58] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8282.ts (HlsRouter.js:36)
abs-container  | [2023-10-01 17:34:58] INFO: [HlsRouter] Stream 6cdcc4b7-2c99-4324-9ee1-957857f0056e is currently resetting
abs-container  | [2023-10-01 17:35:03] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8282.ts (HlsRouter.js:36)
abs-container  | [2023-10-01 17:35:03] INFO: [HlsRouter] Stream 6cdcc4b7-2c99-4324-9ee1-957857f0056e is currently resetting
abs-container  | [2023-10-01 17:35:04] ERROR: [STREAM] Transcode never closed... (Stream.js:405)
abs-container  | [2023-10-01 17:35:04] INFO: Stream Reset New Start Time 13:48:00.0
abs-container  | [2023-10-01 17:35:04] INFO: [STREAM] START STREAM - Num Segments: 13716
abs-container  | [2023-10-01 17:35:04] INFO: [STREAM] Starting Stream at startTime 13:47:30.0 (User startTime 13:48:00.0) and Segment #8275
abs-container  | [2023-10-01 17:35:04] DEBUG: [Stream] Forcing AAC for tracks with mime type audio/mp4 and codec aac (Stream.js:280)
abs-container  | [2023-10-01 17:35:04] INFO: [INFO] FFMPEG transcoding started with command: ffmpeg -seek_timestamp 1 -f concat -safe 0 -ss 49650s -noaccurate_seek -i /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/files.txt -y -loglevel error -map 0:a -c:a aac -f hls -copyts -avoid_negative_ts make_non_negative -max_delay 5000000 -max_muxing_queue_size 2048 -hls_time 6 -hls_segment_type mpegts -start_number 8275 -hls_playlist_type vod -hls_list_size 0 -hls_allow_cache 0 -hls_segment_filename /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-%d.ts /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/final-output.m3u8
abs-container  | [2023-10-01 17:35:04] INFO:
abs-container  | [2023-10-01 17:35:07] INFO: [STREAM] Clearing isResetting
abs-container  | [2023-10-01 17:35:09] INFO: [STREAM-CHECK] Check Files 1 of 13716 0.01% Furthest Segment: 8275
abs-container  | [2023-10-01 17:35:11] INFO: [STREAM-CHECK] Check Files 1 of 13716 0.01% Furthest Segment: 8275
abs-container  | [2023-10-01 17:35:11] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8282.ts (HlsRouter.js:36)
abs-container  | Error: ENOENT: no such file or directory, stat '/metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8282.ts'
abs-container  | [2023-10-01 17:35:13] INFO: [STREAM-CHECK] Check Files 2 of 13716 0.01% Furthest Segment: 8276
abs-container  | [2023-10-01 17:35:15] INFO: [STREAM-CHECK] Check Files 3 of 13716 0.02% Furthest Segment: 8277
abs-container  | [2023-10-01 17:35:17] INFO: [STREAM-CHECK] Check Files 4 of 13716 0.03% Furthest Segment: 8278
abs-container  | [2023-10-01 17:35:19] INFO: [STREAM-CHECK] Check Files 4 of 13716 0.03% Furthest Segment: 8278
abs-container  | [2023-10-01 17:35:21] INFO: [STREAM-CHECK] Check Files 5 of 13716 0.04% Furthest Segment: 8279
abs-container  | [2023-10-01 17:35:23] INFO: [STREAM-CHECK] Check Files 6 of 13716 0.04% Furthest Segment: 8280
abs-container  | [2023-10-01 17:35:25] INFO: [STREAM-CHECK] Check Files 6 of 13716 0.04% Furthest Segment: 8280
abs-container  | [2023-10-01 17:35:27] INFO: [STREAM] 6cdcc4b7-2c99-4324-9ee1-957857f0056e notifying client that stream is ready
abs-container  | [2023-10-01 17:35:27] INFO: [STREAM-CHECK] Check Files 7 of 13716 0.05% Furthest Segment: 8281
abs-container  | [2023-10-01 17:35:28] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8283.ts (HlsRouter.js:36)
abs-container  | Error: ENOENT: no such file or directory, stat '/metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8283.ts'
abs-container  | [2023-10-01 17:35:29] INFO: [STREAM-CHECK] Check Files 8 of 13716 0.06% Furthest Segment: 8282
abs-container  | [2023-10-01 17:35:30] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8283.ts (HlsRouter.js:36)
abs-container  | Error: ENOENT: no such file or directory, stat '/metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8283.ts'
abs-container  | [2023-10-01 17:35:31] INFO: [STREAM-CHECK] Check Files 9 of 13716 0.07% Furthest Segment: 8283
abs-container  | [2023-10-01 17:35:33] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8284.ts (HlsRouter.js:36)
abs-container  | Error: ENOENT: no such file or directory, stat '/metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8284.ts'
abs-container  | [2023-10-01 17:35:33] INFO: [STREAM-CHECK] Check Files 9 of 13716 0.07% Furthest Segment: 8283
abs-container  | [2023-10-01 17:35:35] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8285.ts (HlsRouter.js:36)
abs-container  | Error: ENOENT: no such file or directory, stat '/metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8285.ts'
abs-container  | [2023-10-01 17:35:35] INFO: [STREAM-CHECK] Check Files 10 of 13716 0.07% Furthest Segment: 8284
abs-container  | [2023-10-01 17:35:36] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8286.ts (HlsRouter.js:36)
abs-container  | Error: ENOENT: no such file or directory, stat '/metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8286.ts'
abs-container  | [2023-10-01 17:35:37] INFO: [STREAM-CHECK] Check Files 11 of 13716 0.08% Furthest Segment: 8285
abs-container  | [2023-10-01 17:35:38] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8286.ts (HlsRouter.js:36)
abs-container  | Error: ENOENT: no such file or directory, stat '/metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8286.ts'
abs-container  | [2023-10-01 17:35:39] INFO: [STREAM-CHECK] Check Files 12 of 13716 0.09% Furthest Segment: 8286
abs-container  | [2023-10-01 17:35:41] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8287.ts (HlsRouter.js:36)
abs-container  | Error: ENOENT: no such file or directory, stat '/metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8287.ts'
abs-container  | [2023-10-01 17:35:41] INFO: [STREAM-CHECK] Check Files 12 of 13716 0.09% Furthest Segment: 8286
abs-container  | [2023-10-01 17:35:43] WARN: File path does not exist /metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8288.ts (HlsRouter.js:36)
abs-container  | Error: ENOENT: no such file or directory, stat '/metadata/streams/6cdcc4b7-2c99-4324-9ee1-957857f0056e/output-8288.ts'
abs-container  | [2023-10-01 17:35:43] INFO: [STREAM-CHECK] Check Files 13 of 13716 0.09% Furthest Segment: 8287
abs-container  | [2023-10-01 17:35:45] INFO: [STREAM-CHECK] Check Files 14 of 13716 0.10% Furthest Segment: 8288
abs-container  | [2023-10-01 17:35:47] INFO: [STREAM-CHECK] Check Files 14 of 13716 0.10% Furthest Segment: 8288
abs-container  | [2023-10-01 17:35:49] INFO: [STREAM-CHECK] Check Files 15 of 13716 0.11% Furthest Segment: 8289
abs-container  | [2023-10-01 17:35:51] INFO: [STREAM-CHECK] Check Files 16 of 13716 0.12% Furthest Segment: 8290
abs-container  | [2023-10-01 17:35:53] INFO: [STREAM-CHECK] Check Files 17 of 13716 0.12% Furthest Segment: 8291
abs-container  | [2023-10-01 17:35:55] INFO: [STREAM-CHECK] Check Files 18 of 13716 0.13% Furthest Segment: 8292

Is that a change that would make sense as a pull request? If this somehow interferes with something we can also just leave it as it is. This seems to be quite the rare issue. At least I only ever encountered it once so far. Maybe I was lucky.

@advplyr
Copy link
Owner

advplyr commented Oct 1, 2023

I think that makes sense to implement if you want to put in a PR. The more important check there is the isAACEncodable which would make sure we aren't trying to transcode an mp3 to AAC.
It will be quite a bit slower reencoding to AAC but at least it will play

@Alistair1231 Alistair1231 mentioned this issue Oct 2, 2023
Merged
@Alistair1231
Copy link
Contributor Author

Should this be closed then? The race condition crash wasn't found and fixed, but the issue that presumably caused it was.

@advplyr
Copy link
Owner

advplyr commented Oct 3, 2023

Yeah I think so. We can re-open if this crash surfaces again

@advplyr advplyr closed this as completed Oct 3, 2023
@advplyr advplyr mentioned this issue Oct 3, 2023
Closed
@advplyr advplyr added the awaiting release Issue is resolved and will be in the next release label Oct 13, 2023
@advplyr
Copy link
Owner

advplyr commented Oct 29, 2023

Fallback to forcing AAC is added in v2.5.0

@advplyr advplyr removed the awaiting release Issue is resolved and will be in the next release label Oct 29, 2023
@dmasice dmasice mentioned this issue Nov 20, 2023
Closed
@advplyr advplyr mentioned this issue Dec 9, 2023
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@Alistair1231 @advplyr