Account deletion never actually occurs #1021

Open
opened 1 month ago by Sabinno · 8 comments
Sabinno commented 1 month ago

I kept receiving emails from Vikunja and found that my account was supposed to be deleted 5 days ago. I could log in just fine, all data was there, etc. My logs do not go far back enough to determine what might have happened there, so unfortunately I can't provide any logs. The warning still exists at the top of the homepage, too.

I kept receiving emails from Vikunja and found that my account was supposed to be deleted 5 days ago. I could log in just fine, all data was there, etc. My logs do not go far back enough to determine what might have happened there, so unfortunately I can't provide any logs. The warning still exists at the top of the homepage, too.
konrad added the
kind/bug
label 1 month ago
Owner

What version are you using?

What version are you using?
Owner

It should still try to delete the user, is there anything in the logs from the past hour about that?

It should still try to delete the user, is there anything in the logs from the past hour about that?
Poster

0.18.1, sorry for not posting that. Here's my api/v1/info:

{"version":"v0.18.1","frontend_url":"https://vikunja.argonaut.network/","motd":"","link_sharing_enabled":true,"max_file_size":"20MB","registration_enabled":false,"available_migrators":["vikunja-file"],"task_attachments_enabled":true,"enabled_background_providers":null,"totp_enabled":true,"legal":{"imprint_url":"","privacy_policy_url":""},"caldav_enabled":true,"auth":{"local":{"enabled":true},"openid_connect":{"enabled":true,"redirect_url":"https://vikunja.argonaut.network/auth/openid/","providers":[{"name":"Argonaut Network","key":"argonautnetwork","auth_url":"https://keycloak.argonaut.network/auth/realms/argonaut-network/protocol/openid-connect/auth","client_id":"vikunja"}]}},"email_reminders_enabled":true,"user_deletion_enabled":true}

There are no logs in the api container regarding account deletion; just requests to the API for normal stuff. Last related log items were several days ago, actually, when I went to request and then confirm the deletion, which resulted in POST 204 codes.

So I inadvertently lied -- I guess I do have logs from that long ago. Hah.

0.18.1, sorry for not posting that. Here's my api/v1/info: ``` {"version":"v0.18.1","frontend_url":"https://vikunja.argonaut.network/","motd":"","link_sharing_enabled":true,"max_file_size":"20MB","registration_enabled":false,"available_migrators":["vikunja-file"],"task_attachments_enabled":true,"enabled_background_providers":null,"totp_enabled":true,"legal":{"imprint_url":"","privacy_policy_url":""},"caldav_enabled":true,"auth":{"local":{"enabled":true},"openid_connect":{"enabled":true,"redirect_url":"https://vikunja.argonaut.network/auth/openid/","providers":[{"name":"Argonaut Network","key":"argonautnetwork","auth_url":"https://keycloak.argonaut.network/auth/realms/argonaut-network/protocol/openid-connect/auth","client_id":"vikunja"}]}},"email_reminders_enabled":true,"user_deletion_enabled":true} ``` There are no logs in the api container regarding account deletion; just requests to the API for normal stuff. Last related log items were several days ago, actually, when I went to request and then confirm the deletion, which resulted in POST 204 codes. So I inadvertently lied -- I guess I do have logs from that long ago. Hah.
Owner

Could you enable debug logging, wait for the next full hour and check if there's anything meaningful in the logs?

https://vikunja.io/docs/config-options/#level

Could you enable debug logging, wait for the next full hour and check if there's anything meaningful in the logs? https://vikunja.io/docs/config-options/#level
Poster

This appears to be related.

2021-10-27T18:00:00.02421041Z: DEBUG	▶ models/getTasksWithRemindersInTheNextMinute 093 [Task Reminder Cron] Looking for reminders between 2021-10-27 14:00:00 -0400 EDT and 2021-10-27 14:01:00 -0400 EDT to send...,
2021-10-27T18:00:00.025364465Z: DEBUG	▶ user/notifyUsersScheduledForDeletion 099 Found 1 users scheduled for deletion,
2021-10-27T18:00:00.025556523Z: DEBUG	▶ models/getTasksWithRemindersInTheNextMinute 09b [Task Reminder Cron] Found 0 reminders,
2021-10-27T18:00:00.026368925Z: DEBUG	▶ models/deleteUsers 0a3 User 1 is not yet scheduled for deletion.
This appears to be related. ``` 2021-10-27T18:00:00.02421041Z: DEBUG ▶ models/getTasksWithRemindersInTheNextMinute 093 [Task Reminder Cron] Looking for reminders between 2021-10-27 14:00:00 -0400 EDT and 2021-10-27 14:01:00 -0400 EDT to send..., 2021-10-27T18:00:00.025364465Z: DEBUG ▶ user/notifyUsersScheduledForDeletion 099 Found 1 users scheduled for deletion, 2021-10-27T18:00:00.025556523Z: DEBUG ▶ models/getTasksWithRemindersInTheNextMinute 09b [Task Reminder Cron] Found 0 reminders, 2021-10-27T18:00:00.026368925Z: DEBUG ▶ models/deleteUsers 0a3 User 1 is not yet scheduled for deletion. ```
Owner

Yeah that looks like it is related.

What is the result of the following query in your Vikunja db?

select id, deletion_scheduled_at from users where deletion_scheduled_at is not null;

I've pushed an update which enabled more logging for user deletion in 8f55af07c9. Could you update to unstable once the CI released the new version (make a backup first or duplicate the instance entierly) and check if that gives us more useful output?

Yeah that looks like it is related. What is the result of the following query in your Vikunja db? ``` select id, deletion_scheduled_at from users where deletion_scheduled_at is not null; ``` I've pushed an update which enabled more logging for user deletion in 8f55af07c936218487ec94e65c6673fbddd0cdb5. Could you update to unstable once the CI released the new version (make a backup first or duplicate the instance entierly) and check if that gives us more useful output?
Poster

Results of select id, deletion_scheduled_at from users where deletion_scheduled_at is not null;:

MariaDB [vikunja]> select id, deletion_scheduled_at from users where deletion_scheduled_at is not null;
+----+-----------------------+
| id | deletion_scheduled_at |
+----+-----------------------+
|  1 | 2021-10-21 18:11:12   |
+----+-----------------------+
1 row in set (0.000 sec)

I'll upgrade shortly and let you know.

Results of `select id, deletion_scheduled_at from users where deletion_scheduled_at is not null;`: ``` MariaDB [vikunja]> select id, deletion_scheduled_at from users where deletion_scheduled_at is not null; +----+-----------------------+ | id | deletion_scheduled_at | +----+-----------------------+ | 1 | 2021-10-21 18:11:12 | +----+-----------------------+ 1 row in set (0.000 sec) ``` I'll upgrade shortly and let you know.
Poster

Perhaps this will assist.

2021-11-03T22:00:00.002325318Z: DEBUG	▶ user/notifyUsersScheduledForDeletion 294 Found 1 users scheduled for deletion to notify,
2021-11-03T22:00:00.002362003Z: DEBUG	▶ models/deleteUsers 299 Found 1 users scheduled for deletion,
2021-11-03T22:00:00.002381716Z: DEBUG	▶ models/deleteUsers 29b User 1 is not yet scheduled for deletion. Scheduled at 2021-10-21 14:11:12 -0400 EDT, now is 2021-11-03 22:00:00.002381113 +0000 UTC m=+5891.292068026
Perhaps this will assist. ``` 2021-11-03T22:00:00.002325318Z: DEBUG ▶ user/notifyUsersScheduledForDeletion 294 Found 1 users scheduled for deletion to notify, 2021-11-03T22:00:00.002362003Z: DEBUG ▶ models/deleteUsers 299 Found 1 users scheduled for deletion, 2021-11-03T22:00:00.002381716Z: DEBUG ▶ models/deleteUsers 29b User 1 is not yet scheduled for deletion. Scheduled at 2021-10-21 14:11:12 -0400 EDT, now is 2021-11-03 22:00:00.002381113 +0000 UTC m=+5891.292068026 ```
Sign in to join this conversation.
No Milestone
No Assignees
2 Participants
Notifications
Due Date

No due date set.

Dependencies

This issue currently doesn't have any dependencies.

Loading…
There is no content yet.