Internal Server Error when viewing project as "List" or "Table"

Bug
1

Hello!

I recently migrated my boards from Trello using the migrator tool. All files seem intact and I was notified that migration is successful. I just have one issue with a specific board. It throws an “Internal Server Error” when I try to view it as “List” or “Table”. I can view it in Kanban without any issues though since I can view, add, edit, and remove tasks.

This is the exact error I am getting when I looked through the docker logs:

2024-04-23T11:18:11.221495731Z: ERROR ▶ handler/ReadAllWeb 1c62 disk I/O error: permission denied

I am not sure why it is throwing permission denied errors when I can view all the other boards without any issues. I have set proper permissions on the db/ and files/ directory from the beginning.

image
image301×131 1.48 KB

In this specific board, there are 23 buckets (or list in Trello). My first thought was there might be an issue with one (or more) bucket or the cards inside them. To test this out, I tried migrating 3 buckets at a time (archive the other 20, migrate the 3, then repeat) to identify if there is any corrupted or problematic bucket. Interestingly, I can view it as “List” or “Table” when I used this approach and I got no errors.

I am using:

  • Version: v0.23.0+525-ecbefdb921
  • Database: sqlite
  • Installed using docker compose

Maybe I overlooked something or is this a bug? This board is quite large so I’m thinking that it has something to do with the data size and Vikunja is unable to load it as List or Table. Any help or advise would be appreciated. Thanks in advance!

2

Were you able to identify a specific bucket as being the root cause with this approach?

3

It turns out all of the buckets seems good. During this time, I was able to view the project as List and Table without any problems. But when I try to migrate them again all at once, the error pops back again.

4

Can you enable database logging so that we can narrow it down to where the problem happens?

5

Hello, here’s the logs that I have captured:

STANDARD LOGS:
2024-04-23T14:52:28.287257896Z: ERROR ▶ handler/ReadAllWeb 2d66 disk I/O error: permission denied

DATABASE LOGS:

2024-04-23T14:52:28.200405478Z: INFO    ▶ [DATABASE] 2d60 [SQL] SELECT `id`, `title`, `description`, `identifier`, `hex_color`, `owner_id`, `parent_project_id`, `is_archived`, `background_file_id`, `background_blur_hash`, `position`, `created`, `updated` FROM `projects` WHERE (id = ?) ORDER BY position LIMIT 1 [170] - 25.741µs
2024-04-23T14:52:28.200547179Z: INFO    ▶ [DATABASE] 2d61 [SQL] SELECT `entity_id`, `user_id`, `kind` FROM `favorites` WHERE (entity_id = ? AND user_id = ? AND kind = ?) LIMIT 1 [173 4 2] - 30.67µs
2024-04-23T14:52:28.20062964Z: INFO     ▶ [DATABASE] 2d62 [SQL] SELECT `id`, `title`, `description`, `identifier`, `hex_color`, `owner_id`, `parent_project_id`, `is_archived`, `background_file_id`, `background_blur_hash`, `position`, `created`, `updated` FROM `projects` WHERE `id` IN (?) [173] - 22.721µs
2024-04-23T14:52:28.201338766Z: INFO    ▶ [DATABASE] 2d63 [SQL] WITH RECURSIVE all_projects AS (
                    SELECT
                        p.*
                    FROM
                        projects p
                    WHERE
                        p.id = ?
                    UNION ALL
                    SELECT
                        p.*
                    FROM
                        projects p
                            INNER JOIN all_projects pc ON p.ID = pc.parent_project_id
                )
                SELECT DISTINCT * FROM all_projects [173] - 606.095µs
2024-04-23T14:52:28.201691139Z: INFO    ▶ [DATABASE] 2d64 [SQL] SELECT `id`, `entity_type`, `entity_id`, `user_id`, `created` FROM `subscriptions` WHERE (user_id = ?) AND entity_id IN (?,?) AND entity_type=? [4 173 170 2] - 38.21µs
2024-04-23T14:52:28.20180044Z: INFO     ▶ [DATABASE] 2d65 [SQL] SELECT `id`, `title`, `project_id`, `view_kind`, `filter`, `position`, `bucket_configuration_mode`, `bucket_configuration`, `default_bucket_id`, `done_bucket_id`, `updated`, `created` FROM `project_views` WHERE (project_id = ?) [173] - 35.75µs
2024-04-23T14:52:29.622454836Z: INFO    ▶ [DATABASE] 2d67 [SQL] SELECT `id`, `notifiable_id`, `notification`, `name`, `subject_id`, `read_at`, `created` FROM `notifications` WHERE (notifiable_id = ?) ORDER BY id DESC LIMIT 50 [4] - 102.732µs
2024-04-23T14:52:39.72519836Z: INFOO    ▶ [DATABASE] 2d69 [SQL] SELECT `id`, `notifiable_id`, `notification`, `name`, `subject_id`, `read_at`, `created` FROM `notifications` WHERE (notifiable_id = ?) ORDER BY id DESC LIMIT 50 [4] - 110.81µs
2024-04-23T14:52:39.725495193Z: INFO    ▶ [DATABASE] 2d6a [SQL] SELECT count(*) FROM `notifications` WHERE (notifiable_id = ?) [4] - 30.1µs
2024-04-23T14:52:49.724177264Z: INFO    ▶ [DATABASE] 2d6b [SQL] SELECT `id`, `notifiable_id`, `notification`, `name`, `subject_id`, `read_at`, `created` FROM `notifications` WHERE (notifiable_id = ?) ORDER BY id DESC LIMIT 50 [4] - 346.153µs
6

What’s the output in the few lines before the error in the standard logs?

7

Here’s the other lines before the ERROR on the standard logs

2024-04-23T14:49:00.003200416Z: DEBUG   ▶ models/getTasksWithRemindersDueAndTheirUsers 2cdc [Task Reminder Cron] Found 0 reminders
2024-04-23T14:49:00.021034556Z: DEBUG   ▶ models/func1 2ce0 [Undone Overdue Tasks Reminder] Sending reminders to 0 users
2024-04-23T14:50:00.002156129Z: DEBUG   ▶ openid/RemoveEmptySSOTeams 2cef Deleting empty teams: []
2024-04-23T14:50:00.002713475Z: DEBUG   ▶ models/getTasksWithRemindersDueAndTheirUsers 2cf1 [Task Reminder Cron] Looking for reminders between 2024-04-24 00:50:00 +1000 AEST and 2024-04-24 00:51:00 +1000 AEST to send...
2024-04-23T14:50:00.0267225Z: DEBUG     ▶ models/getTasksWithRemindersDueAndTheirUsers 2cf4 [Task Reminder Cron] Found 0 reminders
2024-04-23T14:50:00.039586985Z: DEBUG   ▶ models/func1 2cf8 [Undone Overdue Tasks Reminder] Sending reminders to 0 users
2024-04-23T14:51:00.001304418Z: DEBUG   ▶ models/getTasksWithRemindersDueAndTheirUsers 2d06 [Task Reminder Cron] Looking for reminders between 2024-04-24 00:51:00 +1000 AEST and 2024-04-24 00:52:00 +1000 AEST to send...
2024-04-23T14:51:00.001780911Z: DEBUG   ▶ openid/RemoveEmptySSOTeams 2d08 Deleting empty teams: []
2024-04-23T14:51:00.002831012Z: DEBUG   ▶ models/getTasksWithRemindersDueAndTheirUsers 2d0c [Task Reminder Cron] Found 0 reminders
2024-04-23T14:51:00.022160905Z: DEBUG   ▶ models/func1 2d10 [Undone Overdue Tasks Reminder] Sending reminders to 0 users
2024-04-23T14:51:29.936966581Z: ERROR   ▶ handler/ReadAllWeb 2d23 disk I/O error: permission denied
2024-04-23T14:52:00.001236473Z: DEBUG   ▶ openid/RemoveEmptySSOTeams 2d2b Deleting empty teams: []
2024-04-23T14:52:00.001544756Z: DEBUG   ▶ models/getTasksWithRemindersDueAndTheirUsers 2d2d [Task Reminder Cron] Looking for reminders between 2024-04-24 00:52:00 +1000 AEST and 2024-04-24 00:53:00 +1000 AEST to send...
2024-04-23T14:52:00.002624666Z: DEBUG   ▶ models/getTasksWithRemindersDueAndTheirUsers 2d2f [Task Reminder Cron] Found 0 reminders
2024-04-23T14:52:00.018049974Z: DEBUG   ▶ models/func1 2d34 [Undone Overdue Tasks Reminder] Sending reminders to 0 users
2024-04-23T14:52:28.287257896Z: ERROR   ▶ handler/ReadAllWeb 2d66 disk I/O error: permission denied
8

Since you’re using docker, can you send all logs to stdout? Having them separate makes them harder to correlate. The requests from the db log do not seem to belong to the request that’s made when accessing the list view.
Then please close all Vikunja tabs except one, switch to the kanban view and then back to the list view. Then send all log lines happening before one which looks similar to this: GET 500 /api/v1/projects/1/views/1/tasks

9

Hello,

Here’s the log that I have captured as soon as I switch from Kanban to List view.

2024-04-25T14:20:06.21510866Z: WEB      ▶ XXX.XXX.XX.XX  GET 200 /api/v1/notifications?page=1 1.198795ms - Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 OPR/107.0.0.0
2024-04-25T14:20:12.589315386Z: INFO    ▶ [DATABASE] 12295 [SQL] SELECT `id`, `title`, `project_id`, `view_kind`, `filter`, `position`, `bucket_configuration_mode`, `bucket_configuration`, `default_bucket_id`, `done_bucket_id`, `updated`, `created` FROM `project_views` WHERE (id = ? AND project_id = ?) LIMIT 1 [741 182] - 193.823µs
2024-04-25T14:20:12.590232007Z: INFO    ▶ [DATABASE] 12296 [SQL] SELECT `id`, `title`, `description`, `identifier`, `hex_color`, `owner_id`, `parent_project_id`, `is_archived`, `background_file_id`, `background_blur_hash`, `position`, `created`, `updated` FROM `projects` WHERE (id = ?) ORDER BY position LIMIT 1 [182] - 68.712µs
2024-04-25T14:20:12.590664623Z: INFO    ▶ [DATABASE] 12297 [SQL] SELECT DISTINCT `tasks`.*, `task_positions`.`position` FROM `tasks` LEFT JOIN `task_positions` ON task_positions.task_id = tasks.id AND task_positions.project_view_id = ? WHERE (project_id IN (?)) AND `done`=? ORDER BY task_positions.`position` asc NULLS LAST, `id` asc NULLS LAST LIMIT 50 [741 182 false] - 159.033µs
**2024-04-25T14:20:12.673788477Z: ERROR   ▶ handler/ReadAllWeb 12298 disk I/O error: permission denied**
**2024-04-25T14:20:12.674716369Z: WEB     ▶ XXX.XXX.XX.XX   GET 500 /api/v1/projects/182/views/741/tasks?**
sort_by[]=position&order_by[]=asc&filter=&filter_include_nulls=false&filter_timezone=Australia%2FSydney&s=&page=1 86.021942ms - Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 OPR/107.0.0.0
2024-04-25T14:20:13.036996458Z: WEB     ▶ XXX.XXX.XX.XX  GET 304 /favicon.ico 1.55167ms - Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 OPR/107.0.0.0
2024-04-25T14:20:16.190090533Z: INFO    ▶ [DATABASE] 12299 [SQL] SELECT `id`, `notifiable_id`, `notification`, `name`, `subject_id`, `read_at`, `created` FROM `notifications` WHERE (notifiable_id = ?) ORDER BY id DESC LIMIT 50 [4] - 121.301µs
2024-04-25T14:20:16.190337286Z: INFO    ▶ [DATABASE] 1229a [SQL] SELECT count(*) FROM `notifications` WHERE (notifiable_id = ?) [4] - 48.83µs
2024-04-25T14:20:16.190417587Z: WEB     ▶ XXX.XXX.XX.XX  GET 200 /api/v1/notifications?page=1 641.648µs - Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 OPR/107.0.0.0
2024-04-25T14:20:26.416999782Z: INFO    ▶ [DATABASE] 1229b [SQL] SELECT `id`, `notifiable_id`, `notification`, `name`, `subject_id`, `read_at`, `created` FROM `notifications` WHERE (notifiable_id = ?) ORDER BY id DESC LIMIT 50 [4] - 97.872µs
2024-04-25T14:20:26.417242375Z: INFO    ▶ [DATABASE] 1229c [SQL] SELECT count(*) FROM `notifications` WHERE (notifiable_id = ?) [4] - 24.971µs
2024-04-25T14:20:26.417305335Z: WEB     ▶ XXX.XXX.XX.XX  GET 200 /api/v1/notifications?page=1 571.627µs - Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 OPR/107.0.0.0
2024-04-25T14:20:36.19734851Z: INFO     ▶ [DATABASE] 1229d [SQL] SELECT `id`, `notifiable_id`, `notification`, `name`, `subject_id`, `read_at`, `created` FROM `notifications` WHERE (notifiable_id = ?) ORDER BY id DESC LIMIT 50 [4] - 99.241µs
2024-04-25T14:20:36.197557364Z: INFO    ▶ [DATABASE] 1229e [SQL] SELECT count(*) FROM `notifications` WHERE (notifiable_id = ?) [4] - 32.972µs
2024-04-25T14:20:36.197653474Z: WEB     ▶ XXX.XXX.XX.XX  GET 200 /api/v1/notifications?page=1 567.457µs - Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 OPR/107.0.0.0
2024-04-25T14:20:46.200055331Z: INFO    ▶ [DATABASE] 1229f [SQL] SELECT `id`, `notifiable_id`, `notification`, `name`, `subject_id`, `read_at`, `created` FROM `notifications` WHERE (notifiable_id = ?) ORDER BY id DESC LIMIT 50 [4] - 366.466µs
2024-04-25T14:20:46.200614748Z: INFO    ▶ [DATABASE] 122a0 [SQL] SELECT count(*) FROM `notifications` WHERE (notifiable_id = ?) [4] - 109.351µs
2024-04-25T14:20:46.201677791Z: WEB     ▶ XXX.XXX.XX.XX  GET 200 /api/v1/notifications?page=1 2.497861ms - Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 OPR/107.0.0.0
2024-04-25T14:20:56.221022571Z: INFO    ▶ [DATABASE] 122a1 [SQL] SELECT `id`, `notifiable_id`, `notification`, `name`, `subject_id`, `read_at`, `created` FROM `notifications` WHERE (notifiable_id = ?) ORDER BY id DESC LIMIT 50 [4] - 341.234µs
10

What are the permissions on the database file and the folder where the file is located? Did you mount the folder or the file only?

11

Hi,

Permission of .db file is -rwxrwxrw-, permission of the folder where the file is located (db/) is

drwxrwxr-x. Volumes are mounted as follows:

VIKUNJA_DATABASE_PATH: /db/vikunja.db

volumes:
  - ./files:/app/vikunja/files
  - ./db:/db
12

I don’t have a clue why this would be happening. Usually, when wrong permissions are the cause, it’s all or nothing - it either works or the App won’t start.