"Export your Vikunja Data" not working

gian · 8 September 2021 21:47

Hi there,

When I try to export my user data from the user settings, all seems to be working. I get the following notification:
grafik

Unfortunately, there is no e-mail. The log contains an ERROR:

2021-09-08T23:33:53.375748954+02:00: ERROR      ▶ events/func1 bd8d Error while handling message 5eefc5be-abed-4b50-958c-79662afd42df, topic_poisoned=user.export.requested, handler_poisoned=user.export.requested.handle.user.data.export, subscriber_poisoned=gochannel.GoChannel, reason_poisoned=1 error occurred:
        * panic occurred: "invalid memory address or nil pointer dereference", stacktrace:
goroutine 1176 [running]:
runtime/debug.Stack()
        /usr/local/go/src/runtime/debug/stack.go:24 +0x65
github.com/ThreeDotsLabs/watermill/message/router/middleware.Recoverer.func1.1()
        /srv/app/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router/middleware/recoverer.go:27 +0x58
panic({0x1192120, 0x1fc13d0})
        /usr/local/go/src/runtime/panic.go:1038 +0x215
code.vikunja.io/api/pkg/models.exportListsAndTasks(0xc000518750, 0x3c, 0x242)
        /go/src/code.vikunja.io/api/pkg/models/export.go:188 +0x6ef
code.vikunja.io/api/pkg/models.ExportUserData(0xc000518750, 0xc00044d0e0)
        /go/src/code.vikunja.io/api/pkg/models/export.go:60 +0x3d0
code.vikunja.io/api/pkg/models.(*HandleUserDataExport).Handle(0xc00042c1c0, 0xc00042c360)
        /go/src/code.vikunja.io/api/pkg/models/listeners.go:593 +0x191
github.com/ThreeDotsLabs/watermill/message.(*Router).AddNoPublisherHandler.func1(0xc0003f3bc0)
        /srv/app/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router.go:284 +0x1d
github.com/ThreeDotsLabs/watermill/message/router/middleware.Recoverer.func1(0xc0005f9d50)
        /srv/app/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router/middleware/recoverer.go:32 +0x72
github.com/ThreeDotsLabs/watermill/message/router/middleware.Retry.Middleware.func1(0xc00042c360)
        /srv/app/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router/middleware/retry.go:71 +0x303
github.com/ThreeDotsLabs/watermill/message/router/middleware.poisonQueue.Middleware.func1(0x11a3420)
        /srv/app/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router/middleware/poison.go:99 +0xbc
github.com/ThreeDotsLabs/watermill/components/metrics.HandlerPrometheusMetricsMiddleware.Middleware.func1(0xc00042c360)
        /srv/app/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/components/metrics/handler.go:57 +0x1d2
github.com/ThreeDotsLabs/watermill/message.(*handler).handleMessage(0xc0004177c0, 0xc00042c360, 0xc00020e930)
        /srv/app/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router.go:601 +0x17a
created by github.com/ThreeDotsLabs/watermill/message.(*handler).run
        /srv/app/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router.go:472 +0x270


,  payload={"User":{"id":4,"name":"Gian","username":"gian","created":"0001-01-01T00:00:00Z","updated":"2021-09-07T22:39:32+02:00"}}

Does anybody know what could cause this behavior and how to fix it?
I could imagine it is caused by some sort of mysql error, as I’m having other issues with the db as well (Duplicate entry for key).

I’m running vikunja versions 0.18.0 on Debian 10. The frontend runs on Server A which also acts as a proxy to Server B. Server B then hosts the backend and the database.

Gian

kolaente · 8 September 2021 21:58

Please try 0.18.1 (just released).

gian · 9 September 2021 17:54

Same behavior with version 0.18.1, the LOG is different tough:

2021-09-09T19:53:21.972723258+02:00: ERROR      ▶ events/func1 1a684 Error while handling message 69148d54-f3cc-4548-8ebe-29d8c3421c11, handler_poisoned=user.export.requested.handle.user.data.export, subscriber_poisoned=gochannel.GoChannel, reason_poisoned=open ./files/1: no such file or directory, topic_poisoned=user.export.requested,  payload={"User":{"id":4,"name":"Gian","username":"gian","created":"0001-01-01T00:00:00Z","updated":"2021-09-07T22:39:32+02:00"}}

kolaente · 9 September 2021 18:08

That looks like an attachment file does not exist. Can you enable debug logging and try again?

gian · 9 September 2021 18:47

Thats all that gets logged:

2021-09-09T20:39:00.000413815+02:00: DEBUG      ▶ models/getTasksWithRemindersInTheNextMinute c5e6 [Task Reminder Cron] Looking for reminders between 2021-09-09 20:39:00 +0200 CEST and 2021-09-09 20:40:00 +0200 CEST to send...
2021-09-09T20:39:00.008200443+02:00: DEBUG      ▶ models/getTasksWithRemindersInTheNextMinute c5e8 [Task Reminder Cron] Found 0 reminders
2021-09-09T20:39:11.150374652+02:00: INFO       ▶ migration/Migrate 048 Ran all migrations successfully.
2021-09-09T20:39:11.150524404+02:00: DEBUG      ▶ models/RegisterReminderCron 049 [Task Reminder Cron] Timezone is CET
2021-09-09T20:39:11.150680278+02:00: INFO       ▶ cmd/func2 04a Vikunja version v0.18.1
2021-09-09T20:39:22.07840843+02:00: DEBUG       ▶ models/Handle 119 Starting to export user data for user 4...
2021-09-09T20:39:22.475384504+02:00: DEBUG      ▶ models/Handle 1173 Starting to export user data for user 4...
2021-09-09T20:39:23.066746737+02:00: DEBUG      ▶ models/Handle 21ce Starting to export user data for user 4...
2021-09-09T20:39:23.31994546+02:00: DEBUG       ▶ models/Handle 3229 Starting to export user data for user 4...
2021-09-09T20:39:23.618978683+02:00: DEBUG      ▶ models/Handle 4284 Starting to export user data for user 4...
2021-09-09T20:39:25.654899416+02:00: DEBUG      ▶ models/Handle 52e1 Starting to export user data for user 4...
2021-09-09T20:39:25.912472463+02:00: ERROR      ▶ events/func1 6341 Error while handling message d41a2c6c-c012-4a2a-a7df-2d238de128f6, topic_poisoned=user.export.requested, handler_poisoned=user.export.requested.handle.user.data.export, subscriber_poisoned=gochannel.GoChannel, reason_poisoned=open ./files/1: no such file or directory,  payload={"User":{"id":4,"name":"Gian","username":"gian","created":"0001-01-01T00:00:00Z","updated":"2021-09-07T22:39:32+02:00"}}

Logging-Configuration is set to:

log:
  # A folder where all the logfiles should go.
  path: /gin/vikunja/logs
  # Whether to show any logging at all or none
  enabled: true
  # Where the normal log should go. Possible values are stdout, stderr, file or off to disable standard logging.
  standard: "file"
  # Change the log level. Possible values (case-insensitive) are CRITICAL, ERROR, WARNING, NOTICE, INFO, DEBUG.
  level: "DEBUG"
  # Whether or not to log database queries. Useful for debugging. Possible values are stdout, stderr, file or off to disable database logging.
  database: "file"
  # The log level for database log messages. Possible values (case-insensitive) are CRITICAL, ERROR, WARNING, NOTICE, INFO, DEBUG.
  databaselevel: "DEBUG"
  # Whether to log http requests or not. Possible values are stdout, stderr, file or off to disable http logging.
  http: "file"
  # Echo has its own logging which usually is unnessecary, which is why it is disabled by default. Possible values are stdout, stderr, file or off to disable standard logging.
  echo: "file"
  # Whether or not to log events. Useful for debugging. Possible values are stdout, stderr, file or off to disable events logging.
  events: "file"
  # The log level for event log messages. Possible values (case-insensitive) are ERROR, INFO, DEBUG.
  eventslevel: "DEBUG"

Do you think deleting the files in my database could solve the error? There are four files listed in the database at the moment:

mysql> select * from files;
+----+--------------------------------+-----------+---------+---------------+---------------------+
| id | name                           | mime      | size    | created_by_id | created             |
+----+--------------------------------+-----------+---------+---------------+---------------------+
|  1 | 2018-12-18 11_49_14-Window.png |           |  315537 |             4 | 2020-05-13 18:04:01 |
|  2 | avatar.jpg                     | image/png | 9477210 |             4 | 2020-09-20 14:10:25 |
|  3 | avatar.jpg                     | image/png | 9477210 |             4 | 2020-09-20 14:11:09 |
|  4 | avatar.jpg                     | image/png | 7669166 |             4 | 2020-09-28 19:52:54 |
+----+--------------------------------+-----------+---------+---------------+---------------------+
4 rows in set (0.02 sec)

mysql>

kolaente · 10 September 2021 13:12

You would need to remove the attachment that the file 1 corresponds to. Does that file exist at ./files/1? (on whatever files folder you configured)

gian · 13 September 2021 13:25

That was it!
When I upgraded vikunja API I did not copy the files folder to the new location of the binary. Copying them solved this problem. You could mention the files folder in the upgrade section of the documentation. This might prevent others from making the same mistake.