Kavita Docker (Unraid) container stops with no errors on library scan

[SanchoBlaze]

Describe the bug Fresh install of Kavita Nightly on unraid, containers stops with no errors during library scan.

To Reproduce Install nightly docker build on unraid

Expected behavior Scans library and adds comics

Desktop (please complete the following information):

• OS: Docker Unraid
• Browser Edge
• Version 113.0.1774.57 (Official build) (64-bit)

Additional context Add any other context about the problem here. kavita20230531.log

[SanchoBlaze]

Log after restarting container: kavita20230531 (1).log

Screenshot of Library after restart:

[SanchoBlaze]

Also does the same on latest docker image, however I can't save settings on that build due to a different (and fixed in nightly) bug

[majora2007]

I looked at your logs and from what I can see only, it scanned and saw multiple files. It processed Dragon Ball then it looks like the app was stopped (maybe crashed?) and restarted again.

Perhaps memory but it didn't look like there was many files. Does the docker have a limit on the memory?

[SanchoBlaze]

Hi, the container stopped again during the night. I restarted it this morning and did a library scan, monitoring the memory usage. it never got above 300mb. The screenshot is the usage at the point the container stopped:

Attached is also the log file for today kavita20230601.log

It's really strange, I don't have any limits in place that I can see and it's not just scanning the library, the below log is the log above, but after I again started the container and then tried to read something using the web reader which causes the container to stop almost immediately:

kavita20230601 (1).log

[majora2007]

Sorry for being so late to reply. That is actually hard disk space and not memory. When you read something, it unarchives the content and puts it in the mounted config. Please share your docker compose.

[SanchoBlaze]

No worries, I've included the docker run command that Unraid uses: docker run -d --name='Kavita' --net='br0' --ip='192.168.1.16' -e TZ="Europe/London" -e HOST_OS="Unraid" -e HOST_HOSTNAME="Nymeria" -e HOST_CONTAINERNAME="Kavita" -e 'TCP_PORT_5000'='5000' -l net.unraid.docker.managed=dockerman -l net.unraid.docker.webui='http://[IP]:[PORT:5000]' -l net.unraid.docker.icon='https://raw.githubusercontent.com/Kareadita/Kavita/develop/UI/Web/src/assets/icons/android-chrome-192x192.png' -v '/mnt/user/appdata/kavita':'/kavita/config':'rw' -v '/mnt/user/':'/library':'rw' --user 99:100 'kizaing/kavita'

[majora2007]

Can you please give me permissions and owner info for /mnt/user/appdata/kavita?

[SanchoBlaze]

drwxr-xr-x 1 nobody users 148 Jul 11 10:29 kavita/

[majora2007]

A user from chat is saying your permissions are incorrect and for their setup, they have: drwxrwxrwx 1 nobody users 148 Jul 11 09:35 kavita/

[majora2007]

Please see their comment:

from the logs:

[Kavita] [2023-06-01 00:00:11.495 +01:00 121] [Information] API.Services.Tasks.CleanupService All expired backups are older than 30 days. Removing all but last backup [Kavita] [2023-06-01 00:00:11.465 +01:00 44] [Error] API.Services.DirectoryService Unable to copy /kavita/config/appsettings.json to /kavita/config/temp/05_31_2023_23_00_11 System.IO.DirectoryNotFoundException: Could not find a part of the path '/kavita/config/temp/05_31_2023_23_00_11/appsettings.json'.

was getting the same thing when I was still using a migrated db and appsettings from the early days. was fixed when I did a clean config and rebuilt the db.

generally though, you don't wanna mess with the perms on the appsettings dir, and if you do, want to use the

Tools/New Perms for appdata changes (and it takes forever to do with docker running x.x) https://cdn.discordapp.com/attachments/840693141082341406/1128362346897740046/image.png

[SanchoBlaze]

So I've tried the suggestion of making it 777:

And it still dies when scanning library, log below: kavita20230712.log

Thanks

[majora2007]

So strange. I do see cover gen is working. Can you share the RAM you have allocated for the Kavita instance? I really believe you're hitting the limits. @scare376 would you happen to have any ideas for UnRaid?

[SanchoBlaze]

From docker stats:

[scare376]

I'm not sure. I spun up a fresh nightly container in unraid and it scanned fine. Maybe its hardware related?

[BU2B]

I'm adding my +1 to this issue as I have a similar problem with Kavita crashing overnight. It seems like when does go down, I have to restart the docker engine otherwise it won't launch. I suspect it has something to do with the overnight scan or corrupted files, but it seems to manually scan without any issues

[BU2B]

Changing perms on the Kavita folder in app data from 755 to 777 and OU from root/root to nobody/users. Also changing the kavita.db perms from 644 to 777 along with the OU to see if helps. I have no idea why they would have be set like they were.

[BU2B]

Overnight, Kavita crashed again, so changing the perms and ownership as outlined above did not fix the issue.

[majora2007]

If you run a separate instance of this and just have a small set of files can you validate if it crashes overnight?

[BU2B]

I'll try that and get back with you. About how many would you say is a small set that would be a valid test... like no more than 12 perhaps?

[majora2007]

Yeah, something 20 under would be extremely light. It will rule out any sort of memory issue.

The thing is, Kavita doesn't do any work if the file/folder hasn't changed since last scan, so you shouldn't have those types of issues.

Also on the new instance, set the logger to Trace.

[BU2B]

I'll remove all the folders from the library folder and put under 20 in a folder called test. But I didn't see a way to set options for the logger in Kavita, the docker config, or the wiki. Please advise, thank you.

[majora2007]

First, you cannot have 20 loose leaf files in the library root. You need to still follow the scanner requirements.

Second, the logger level is in admin panel:

[BU2B]

Understood. The plan is to have them like this:

Header	Header	Header	Header
Library	[Root Folder]
┖──	test		[folder inside library root folder]
	┖──	eBook 1.epub	[inside test folder]
	┖──	...	[inside test folder]
	┖──	epub 16.epub	[inside test folder]

Is that correct?

[majora2007]

Yes that technically works for books.

[BU2B]

please see attached.

kavita20230716.log

[majora2007]

Did it crash for your test run? I do see an error for something that has been fixed in the nightly, but it shouldn't crash the whole process, just make that api fail.

[BU2B]

yes, sorry... this was the test run. 17 ePubs and 1 pdf in the structure outlined above. Kavita crashed just like it has been doing since it was installed. Other docker containers were still running fine and I was able to launch another container, but not Kavita. The only way to start it again was to stop and start the docker service.

[majora2007]

Would you be able to try on our nightly? It's :nightly tag.

[BU2B]

installing now... will keep you posted.

PS. (and this might be cosmetic) on the nightly, the cache size was 0, with a message in red "You must have at least 50 MB." The (i) said the default is 75MB. I manually gave it 100MB and the message went away. I have no idea what it was set to in the previous release, but if it's not cosmetic, I wonder if this could have been part of the problem.

[BU2B]

test run using :nightly version & cache @ 100MB resulted in the same problem. I've attached the log, but unfortunately, the log wasn't set to trace, so I'll let it run overnight again and let you know results tomorrow.

kavita20230717.log

[majora2007]

I don't see any crash point, the service in the latest logs ran consistently throughout the night. There are no breaks in the logs or the service starting again.

[BU2B]

interesting... it was stopped this morning and wouldn't launch without restarting the docker service. fwiw, there's a break in the log starting around 3:02a until I got it going again around 6:45a. I suspect around 3:02a is when it went down. Is it possible it's the docker version (v20.10.21) or an issue with the config files that's causing the problem?

[Kavita] [2023-07-17 03:02:24.993 -05:00  650] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP GET /api/device responded 200 in 2.5727 ms

[Kavita] [2023-07-17 06:45:56.131 -05:00  1] [Fatal] API.Program Running MigrateSeriesRelationsExport migration - Please be patient, this may take some time. This is not an error

[majora2007]

It's unlikely there is a config issue. That is not an error. It's just Fatal to make sure it's always in the logs as it's important. You can put your config here if you'd like.

When you say it wouldn't launch again, what does that mean? Like the browser wouldn't respond when you navigated to the url?

[BU2B]

see attached for what is hopefully a better, more detailed explanation. If it's still not clear, I can do a screen recording for you in the morning so you can see what it takes make Kavita work after a 'crash' or whatnot.

[majora2007]

@scare376 any idea on this? Do you know of other logs we might check for these users?

[scare376]

https://docs.docker.com/config/daemon/logs/ could check the daemon logs to see if there's anything? Oh and also what unRAID version are you running

[BU2B]

Same problem again with Kavita running overnight. I'm not sure how to proceed next with troubleshooting unRaid system / docker issues if this isn't an issue with Kavita.

If you would like, I can at least stop and restart the docker service to get to the Kavita trace logs and post them here; but it sounds like there's not much else we can glean. :-/

Note: fwiw, I was able to get to the docker logs via ssh. Here's the one from yesterday kavita20230718.log

[scare376]

https://cybertalk.io/en/unraid-execution-error-403-docker-engine/ I found this. Everything I see points to an issue with unRAID/docker. You can try what they recommend in that article or I would look through and/or create a post in the unRAID docker forums. If everything there falls through it could be an edge case Kavita docker image issue imo.

[SanchoBlaze]

I don't have the same issue with restarting Kavita, after is stops I just click start again.

I've created a new nightly container:

With a restricted library size:

Settings in Kavita:

and is still crashed without any errors (includes restart at end):

kavita20230719.log

I'm on the latest version of unRaid 6.12.3

Docker log doesn't seem to contain anything useful:

time="2023-07-19T10:32:45.065461090+01:00" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 time="2023-07-19T10:32:45.065586879+01:00" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 time="2023-07-19T10:32:45.065629292+01:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 time="2023-07-19T10:32:45.065826627+01:00" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/18a8fa954a8b6ba2cb809531e2fcf1b0e782e7c124153cd0c9667ebae9e7212a pid=8355 runtime=io.containerd.runc.v2 time="2023-07-19T10:59:48.621151739+01:00" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 time="2023-07-19T10:59:48.621321073+01:00" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 time="2023-07-19T10:59:48.621341910+01:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 time="2023-07-19T10:59:48.621619686+01:00" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/9359a36e8dd82fa0b0924350b72a9ad3b2ecdf532643fbb46a2b8fd6c5030428 pid=31235 runtime=io.containerd.runc.v2 time="2023-07-19T11:02:40.809337738+01:00" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 time="2023-07-19T11:02:40.809533308+01:00" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 time="2023-07-19T11:02:40.809575542+01:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 time="2023-07-19T11:02:40.809860683+01:00" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/dea45a30da4185db7777946a65d16416e51f58db4d6933542c799df0def4190a pid=29739 runtime=io.containerd.runc.v2 time="2023-07-19T12:31:11.494836147+01:00" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 time="2023-07-19T12:31:11.495026068+01:00" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 time="2023-07-19T12:31:11.495067555+01:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 time="2023-07-19T12:31:11.495554915+01:00" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/1a4e458f3129a6de00458965f4aa137a92e9a4186d3daf9d1e2e90d7af0615d7 pid=6068 runtime=io.containerd.runc.v2 time="2023-07-19T12:34:52.935537491+01:00" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1 time="2023-07-19T12:34:52.935687516+01:00" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1 time="2023-07-19T12:34:52.935711352+01:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1 time="2023-07-19T12:34:52.936131164+01:00" level=info msg="starting signal loop" namespace=moby path=/run/docker/containerd/daemon/io.containerd.runtime.v2.task/moby/1a4e458f3129a6de00458965f4aa137a92e9a4186d3daf9d1e2e90d7af0615d7 pid=22329 runtime=io.containerd.runc.v2

[BU2B]

TIL: from docker "endpoint with name Kavita already exists in network bridge". I found a few commands that suggests once the container goes down, it exits with a bad status code (e.g. non-zero) that holds the network open; which might be why it won't start. That said, I'm updating unRaid to the latest version 6.12.3 (docker v20.10.24) and will delete Kavita and start over to see if it helps.

https://stackoverflow.com/questions/43743169/error-response-from-daemon-service-endpoint-with-name

update: it did not make a difference. Disabling overnight scan and db backup to see if that solves the issue.

[BU2B]

Eureka! From what I can tell, the culprit was Plex... a temporary folder used for metadata (scraping?) was filling up the docker image overnight. Kavita would take a dive about the same time the docker image hit 100%; the weird thing is, other dockers did not, including Plex.

There may be other workarounds, but the solution seems to be: create a path and point the temporary folder outside the Plex container. Kavita remained running overnight and I can stop and start the docker normally. I've attached an image below.

I'm going to look at doing something similar for all space hog containers... hope this helps.

[SanchoBlaze]

Unfortunately, this does not fix the issue I'm having. Manually running the scan will crash Kavita regardless of if any other containers are running (also docker.img is 100GB and is using less than 20GB).

[SanchoBlaze]

I've moved my unraid to new hardware and whatever was causing Kavita to stop is no longer a problem.

Thanks for your help.