Full user progress wiped

[Lefro1]

What happened?

At 01:00 PDT while doing reading, I had all my progress and everything was fine.

At 21:00 PDT when opening Kavita again, all my user progress was gone. All files were still present, covers present, even my account specific collections and bookmarks were present. But all series that had been read now showed as unread, whether fully complete or partially complete.

Of note, I do not have my server auto-updating so it is not technically on the most recent release. However, no action was taken to update so at least that shouldn't contribute:

Version
0.8.2.0
Install ID
2e534f70
First Install Version
0.8.2.0
First Install Date
8/14/24

I am using the jvmilazz0/kavita image.

What did you expect?

To not have my user progress wiped.

Kavita Version Number - If you don not see your version number listed, please update Kavita and see if your issue still persists.

0.8.3 - Stable

What operating system is Kavita being hosted from?

Docker (Dockerhub Container)

If the issue is being seen on Desktop, what OS are you running where you see the issue?

None

If the issue is being seen in the UI, what browsers are you seeing the problem on?

No response

If the issue is being seen on Mobile, what OS are you running where you see the issue?

None

If the issue is being seen on the Mobile UI, what browsers are you seeing the problem on?

No response

Relevant log output

No response

Additional Notes

I have the full docker logs exported when the issue was noticed but no action had been taken. I also have full "server images" (everything in /config/) for:

1. The instance noticed at 9 PM
2. An automated backup taken at 4 AM where the same issue is present
   1. I had restored to this instance, and progress was still missing.
3. An automated backup taken 1 week ago at 4 AM on 2024-09-15 (which I fell back to).
   1. I had restored to this instance and all progress had return.

Because of the ability to restore from backup, this is not urgent for me and I do not need the issue resolved, but am happy to provide any and all information in case this could be some bigger thing.

[majora2007]

You're saying all progress was wiped but the series themselves were still there? Kavita only has one way to override reading progress and that is manually through the UI (or via API).

I'm going to assume you didn't trigger it manually. Is your instance public? Do you use any apps with Kavita that perform any syncing? Can you attach logs during the timeframe of having to not having progress?

[Lefro1]

You're saying all progress was wiped but the series themselves were still there?

Yes.

I'm going to assume you didn't trigger it manually.

I did not.

Is your instance public?

It is not.

Do you use any apps with Kavita that perform any syncing?

I...don't know. Over a year ago I set up paperback so I could download chapter locally. Other than that, no.

---

kavita20240922.log

Here is the log file for the day the incident happened. Of note, a full server backup occurred at 4 AM where the container goes offline, is backed up, and goes back online.

From my time reading (~1 AM), to the restart (~4 AM) to the time I checked and saw progress wiped (~9 PM) I couldn't see anything of note.

[therobbiedavis]

@Lefro1 What happened around 4AM to cause the restart?

[Lefro1]

I have a weekly backup of all containers on the server hosting kavita - the flow of which being

1. Shut down the container (issued via. stop command)
2. Copy all files for that application
3. Start the container again.

[DieselTech]

There is 2 things that stand out to me as abnormal in the logs.

1 - The frequency of progress update events is very high. Sometimes 70 in under a minute.

2 - The processing speed of the update events is very erratic.

[Kavita] [2024-09-22 00:41:50.209 -07:00  214] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 1.8194 ms
[Kavita] [2024-09-22 00:41:50.221 -07:00  198] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 1.4487 ms
[Kavita] [2024-09-22 00:41:57.104 -07:00  214] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 3.8715 ms
[Kavita] [2024-09-22 00:41:58.698 -07:00  103] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 1574.5302 ms
[Kavita] [2024-09-22 00:41:58.711 -07:00  214] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 1053.5614 ms
[Kavita] [2024-09-22 00:41:58.789 -07:00  489] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 304.0187 ms
[Kavita] [2024-09-22 00:41:58.819 -07:00  198] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 753.8266 ms
[Kavita] [2024-09-22 00:41:58.941 -07:00  214] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 153.5059 ms
[Kavita] [2024-09-22 00:41:59.415 -07:00  214] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 3.9207 ms
[Kavita] [2024-09-22 00:42:05.792 -07:00  214] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 4.3790 ms
[Kavita] [2024-09-22 00:42:10.195 -07:00  198] [Information] Serilog.AspNetCore.RequestLoggingMiddleware HTTP POST /api/reader/progress responded 200 in 4.0625 ms

You'll have a bunch of events responding back within 1-5ms (which is normal) and then you'll have a few that spike to over 500+ ms (not normal).

Also how is the /library mount created? Are you using local storage to the docker host or it is a remote mount (NAS / rclone)?

[Lefro1]

I don't really have a comment on the response times item - I do frequently get 500s when reading failing to save progress (which normally sorts itself out - in a worst case I mark the chapter as read when done).

Kavita runs on my home server in a docker container - and it mounts /library referencing directories in that server (so local for itself). Here is my full docker compose

services:
    kavita:
        image: jvmilazz0/kavita:latest
        container_name: kavita-portainer
        ports:
            - "5000:5000
        volumes:
            - /mnt/user/media/Books:/library:ro
            - /mnt/user/appdata/kavita-portainer/config:/kavita/config
        environment:
            TZ: 'America/Los_Angeles' 
        restart: unless-stopped

[Lefro1]

I still have all the dbs themselves if tools or guides exist to turn those into human readable formats.

One thing I've been wondering is if possibly the shutdown at restart for backup had problems and the user got corrupted?

[JlawsonEquine]

I've also experienced this since updating to the latest release, 0.8.3.2.

Kavita on an LXC container on Proxmox, library is mounted via NFS on a NAS. No downtime, No progress syncing apps. No issues prior to 8.3 despite everything else remaining the same. Kaizoku downloader for manga.

kavita20240929.zip

[DieselTech]

@Lefro1 Looks like the compose got borked, but I had a question about your setup. What filesystem is your setup using? (Ext4, btrfs?)

[kayhos]

Hello everyone, I was asked to post here to record the fact that another user has this experience.

On my side, it seems that my progress record was reset following the removal and readding of all the series/books in the library. I lost reviews and reading progress and covers that I had manually selected.

Here is what I posted in discord:

After further investigation, it seems like it dropped all the libraries content and readded, as I have lost the few reviews, the want to reads and the read stats I had... (this is my clue to saying everything was dropped and readded). I seem to have some DB locks happening on and off, but can't find one at the moment.

Before the question: My Kavita runs in a Docker and has a direct (hardware server to hardware server, no switch/router/telecom) mounted NFS drive in the Docker container. I also use KOMF in the same container. I can post my docker-compose on request.

[Lefro1]

@Lefro1 Looks like the compose got borked, but I had a question about your setup. What filesystem is your setup using? (Ext4, btrfs?)

I am using ZFS in Mirror mode (RAID 1)

And whoops on compose - was deleting unnecessary comments and ended up deleting the volumes marker. Fixed it.

[Lefro1]

Lost context: Shared db files outside of github directly.

@DieselTech Hopped back on and decided why not dig a little.

Again, I cannot say WHY this change occurred, but pointing to areas potentially to add more logging in:

The AppUserProgress table on my backup had 5,960 rows, but on the "lost progress" db has 142 rows.

Similarly, CreatedUtc on the backup goes back to early 2023 while the db that lost all progress has a single entry for 2023-01-22 19:43:24.8019202 and then ALL other entries are at 2024-09-22 01:20:37.8266509 which is about in line with when I had finished reading that night (and logs stop as I had put my tablet away).

Agreed on the logs aren't being helpful - but this points heavily to something happening that resulted in a full deletion of that table (or an unrecoverable corruption that results in what looks like that?)

[therobbiedavis]

@majora2007 Is there any migration that touched the progress table? I think there was one a few stable releases back but would that still be trying to run?

[majora2007]

v0.8.0 is the last release with any migrations that touch progress in any way. That was where due to the massive shift in how Kavita treats and organizes files internally, I had to write a ton of manual migrations that could result in data issues (but from testing, we didn't see much).

Once a migration runs, it never runs again. Each migration logs when it starts and completes in the logs as well, so doubtful.