Todoist Migration fails after 51 iterations / 19 minutes

JaCoB1123 · 5 February 2023 21:08

Hi,

I just wanted to import my tasks from Todoist and after numerous tries enabled debug logging and got the following after 51 iterations and 19 minutes. I’m using the current unstable image, as the regular image failed because of the posted_uid attribute. Here are the last log entries:

2023-02-05T21:02:39.391888931Z: DEBUG     ▶ todoist/Migrate 15fd [Todoist Migration] Retrieved full task data for done task 274431714
2023-02-05T21:02:39.552537787Z: DEBUG     ▶ todoist/Migrate 15fe [Todoist Migration] Retrieved full task data for done task 274426453
2023-02-05T21:02:39.754493386Z: DEBUG     ▶ todoist/Migrate 15ff [Todoist Migration] Retrieved full task data for done task 274421004
2023-02-05T21:02:40.096718929Z: DEBUG     ▶ todoist/Migrate 1600 [Todoist Migration] Retrieved full task data for done task 274380594
2023-02-05T21:02:40.277204191Z: DEBUG     ▶ todoist/Migrate 1601 [Todoist Migration] Retrieved full task data for done task 274380591
2023-02-05T21:02:40.470920619Z: DEBUG     ▶ todoist/Migrate 1602 [Todoist Migration] Retrieved full task data for done task 274379567
2023-02-05T21:02:40.836485755Z: DEBUG     ▶ todoist/Migrate 1603 [Todoist Migration] Retrieved full task data for done task 274349400
2023-02-05T21:02:41.019550266Z: DEBUG     ▶ todoist/Migrate 1604 [Todoist Migration] Retrieved full task data for done task 273735308
2023-02-05T21:02:41.195536134Z: DEBUG     ▶ todoist/Migrate 1605 [Todoist Migration] Retrieved full task data for done task 273594363
2023-02-05T21:02:41.381041033Z: DEBUG     ▶ todoist/Migrate 1606 [Todoist Migration] Retrieved full task data for done task 273553515
2023-02-05T21:02:41.381125412Z: DEBUG     ▶ todoist/Migrate 1607 [Todoist Migration] Got 5587 done items for user 1
2023-02-05T21:02:41.381143167Z: DEBUG     ▶ todoist/Migrate 1608 [Todoist Migration] Getting archived projects for user 1
2023-02-05T21:02:41.695633276Z: DEBUG     ▶ todoist/Migrate 1609 [Todoist Migration] Got 44 archived projects for user 1
2023-02-05T21:02:41.695699441Z: DEBUG     ▶ todoist/Migrate 160a [Todoist Migration] Getting data for archived projects for user 1
2023-02-05T21:02:50.491244197Z: DEBUG     ▶ todoist/Migrate 160b [Todoist Migration] Got all todoist user data for user 1
2023-02-05T21:02:50.491369936Z: DEBUG     ▶ todoist/Migrate 160c [Todoist Migration] Start converting data for user 1
2023-02-05T21:02:50.511167717Z: DEBUG     ▶ todoist/convertTodoistToVikunja 160d [Todoist Migration] Could not find task 4031409177 in tasks map while trying to get resolve subtasks for task 4031409335
2023-02-05T21:02:50.511340143Z: DEBUG     ▶ todoist/convertTodoistToVikunja 160e [Todoist Migration] Could not find task 4031409497 in tasks map while trying to get resolve subtasks for task 4031409573
2023-02-05T21:02:50.511369469Z: DEBUG     ▶ todoist/convertTodoistToVikunja 160f [Todoist Migration] Could not find task 4031409497 in tasks map while trying to get resolve subtasks for task 4031409614
2023-02-05T21:02:50.51142299Z: DEBUG      ▶ todoist/convertTodoistToVikunja 1610 [Todoist Migration] Could not find task 4031422986 in tasks map while trying to get resolve subtasks for task 4031423228
2023-02-05T21:02:50.511437538Z: DEBUG     ▶ todoist/convertTodoistToVikunja 1611 [Todoist Migration] Could not find task 4031422986 in tasks map while trying to get resolve subtasks for task 4031423555
2023-02-05T21:02:50.511472995Z: DEBUG     ▶ todoist/convertTodoistToVikunja 1612 [Todoist Migration] Could not find task 4031409177 in tasks map while trying to get resolve subtasks for task 4031426410
2023-02-05T21:02:50.511543358Z: DEBUG     ▶ todoist/convertTodoistToVikunja 1613 [Todoist Migration] Could not find task 4031426916 in tasks map while trying to get resolve subtasks for task 4031428931
2023-02-05T21:02:50.511557405Z: DEBUG     ▶ todoist/convertTodoistToVikunja 1614 [Todoist Migration] Could not find task 4031426916 in tasks map while trying to get resolve subtasks for task 4031429318
2023-02-05T21:02:50.51157067Z: DEBUG      ▶ todoist/convertTodoistToVikunja 1615 [Todoist Migration] Could not find task 4031422986 in tasks map while trying to get resolve subtasks for task 4031501640
2023-02-05T21:02:50.511581059Z: DEBUG     ▶ todoist/convertTodoistToVikunja 1616 [Todoist Migration] Could not find task 4031409497 in tasks map while trying to get resolve subtasks for task 4031502656
2023-02-05T21:02:50.523158897Z: -         ▶ echo recover.go:113 [PANIC RECOVER] runtime error: invalid memory address or nil pointerdereference goroutine 9 [running]:
github.com/labstack/echo/v4/middleware.RecoverWithConfig.func1.1.1()
  /go/pkg/mod/github.com/labstack/echo/v4@v4.10.0/middleware/recover.go:93 +0x14e
panic({0x12d5300, 0x213f620})
  /usr/local/go/src/runtime/panic.go:884 +0x213
code.vikunja.io/api/pkg/modules/migration/todoist.convertTodoistToVikunja(0xc000164370, 0x5?)
  /go/src/code.vikunja.io/api/pkg/modules/migration/todoist/todoist.go:388 +0x10d5
code.vikunja.io/api/pkg/modules/migration/todoist.(*Migration).Migrate(0xc0004661f0, 0xc000274840)
  /go/src/code.vikunja.io/api/pkg/modules/migration/todoist/todoist.go:658 +0x1f5a
code.vikunja.io/api/pkg/modules/migration/handler.(*MigrationWeb).Migrate(0xa0b820?, {0x17c5590, 0xc000395180})
  /go/src/code.vikunja.io/api/pkg/modules/migration/handler/handler.go:70 +0xa7
github.com/labstack/echo-jwt/v4.Config.ToMiddleware.func2.1({0x17c5590, 0xc000395180})
  /go/pkg/mod/github.com/labstack/echo-jwt/v4@v4.1.0/jwt.go:237 +0x41d
code.vikunja.io/api/pkg/routes.registerAPIRoutes.func1.1({0x17c5590, 0xc000395180})
  /go/src/code.vikunja.io/api/pkg/routes/routes.go:225 +0x1cb
github.com/labstack/echo/v4.(*Echo).add.func1({0x17c5590, 0xc000395180})
  /go/pkg/mod/github.com/labstack/echo/v4@v4.10.0/echo.go:546 +0x51
github.com/labstack/echo/v4/middleware.CORSWithConfig.func1.1({0x17c5590, 0xc000395180})
  /go/pkg/mod/github.com/labstack/echo/v4@v4.10.0/middleware/cors.go:255 +0x8b8
github.com/labstack/echo/v4/middleware.RecoverWithConfig.func1.1({0x17c5590, 0xc000395180})
  /go/pkg/mod/github.com/labstack/echo/v4@v4.10.0/middleware/recover.go:119 +0xfe
github.com/labstack/echo/v4/middleware.LoggerWithConfig.func2.1({0x17c5590, 0xc000395180})
  /go/pkg/mod/github.com/labstack/echo/v4@v4.10.0/middleware/logger.go:126 +0xe2
github.com/labstack/echo/v4.(*Echo).ServeHTTP(0xc000022fc0, {0x17b1100?, 0xc0006580e0}, 0xc00013c100)
  /go/pkg/mod/github.com/labstack/echo/v4@v4.10.0/echo.go:633 +0x3d1
net/http.serverHandler.ServeHTTP({0x17ad788?}, {0x17b1100, 0xc0006580e0}, 0xc00013c100)
  /usr/local/go/src/net/http/server.go:2936 +0x316
net/http.(*conn).serve(0xc000198360, {0x17b1a90, 0xc0002e2210})
  /usr/local/go/src/net/http/server.go:1995 +0x612
created by net/http.(*Server).Serve
  /usr/local/go/src/net/http/server.go:3089 +0x5ed
goroutine 1 [chan receive, 20 minutes]:
code.vikunja.io/api/pkg/cmd.glob..func25(0x2152380?, {0x142361b?, 0x0?, 0x0?})
  /go/src/code.vikunja.io/api/pkg/cmd/web.go:102 +0x19e
github.com/spf13/cobra.(*Command).execute(0x2152380, {0xc000040050, 0x0, 0x0})
  /go/pkg/mod/github.com/spf13/cobra@v1.6.1/command.go:920 +0x847
github.com/spf13/cobra.(*Command).ExecuteC(0x2152380)
  /go/pkg/mod/github.com/spf13/cobra@v1.6.1/command.go:1044 +0x3bd
github.com/spf13/cobra.(*Command).Execute(...)
  /go/pkg/mod/github.com/spf13/cobra@v1.6.1/command.go:968
code.vikunja.io/api/pkg/cmd.Execute()
  /go/src/code.vikunja.io/api/pkg/cmd/cmd.go:44 +0x25
main.main()
  /go/src/code.vikunja.io/api/main.go:22 +0x17
goroutine 24 [select, 20 minutes]:
database/sql.(*DB).connectionOpener(0xc000533790, {0x17b19e8, 0xc0000a68c0})
  /usr/local/go/src/database/sql/sql.go:1218 +0x8d
created by database/sql.OpenDB
  /usr/local/go/src/database/sql/sql.go:791 +0x18d
goroutine 40 [chan receive, 20 minutes]:
github.com/ThreeDotsLabs/watermill/message.(*handler).handleClose(0xc00056cdc0)
  /go/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router.go:573 +0x2e
created by github.com/ThreeDotsLabs/watermill/message.(*handler).run
  /go/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router.go:468 +0x245
goroutine 8 [chan receive, 20 minutes]:
github.com/ThreeDotsLabs/watermill/message.(*handler).handleClose(0xc00056d180)
  /go/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router.go:573 +0x2e
created by github.com/ThreeDotsLabs/watermill/message.(*handler).run
  /go/pkg/mod/github.com/!three!dots!labs/watermill@v1.1.1/message/router.go:468 +0x245
goroutine 28 [select, 3 minutes]:
github.com/robfig/cron/v3.(*Cron).run(0xc00012f9a0)
  /go/pkg/mod/github.com/robfig/cron/v3@v3.0.1/cron.go:263 +0xab9
created by github.co
2023-02-05T21:02:50.523221755Z: WEB       ▶ 10.0.0.100  POST 500 /api/v1/migration/todoist/migrate 19m57.996664138s - Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/109.0

kolaente · 7 February 2023 11:07

Which version are you using? (From the “about” dialoge in the frontend)

JaCoB1123 · 7 February 2023 15:26

Here’s what the about page shows me:

Frontend Version: 0.20.3

API Version: v0.20.1+99-aa25ccdc91

kolaente · 7 February 2023 16:08

I’ve pushed a potential fix in 58da38adb6. Please check with the next unstable build (in ~45min) if the error is gone. If the migration runs through without problems please also check if all tasks with sub tasks were correctly imported (as that’s where the error came from).

JaCoB1123 · 7 February 2023 22:06

Awesome, thank. It’s looking good so far.

Edit: I did find some nested tasks, that did not get created correctly.

Case 1: Subtasks have been created correctly. Parent-Task (recurring) is done though, although it’s actually open.
Case 2: Only one subtask has been created. Parent-Task was recurring as well and was incorrectly marked done also.

Edit2: Searching my logs for “subtask” shows the following warnings:

[Todoist Migration] Could not find task 4031409177 in tasks map while trying to resolve subtasks for task 4031409335
[Todoist Migration] Could not find task 4031409497 in tasks map while trying to resolve subtasks for task 4031409573
[Todoist Migration] Could not find task 4031409497 in tasks map while trying to resolve subtasks for task 4031409614
[Todoist Migration] Could not find task 4031422986 in tasks map while trying to resolve subtasks for task 4031423228
[Todoist Migration] Could not find task 4031422986 in tasks map while trying to resolve subtasks for task 4031423555
[Todoist Migration] Could not find task 4031409177 in tasks map while trying to resolve subtasks for task 4031426410
[Todoist Migration] Could not find task 4031426916 in tasks map while trying to resolve subtasks for task 4031428931
[Todoist Migration] Could not find task 4031426916 in tasks map while trying to resolve subtasks for task 4031429318
[Todoist Migration] Could not find task 4031422986 in tasks map while trying to resolve subtasks for task 4031501640
[Todoist Migration] Could not find task 4031409497 in tasks map while trying to resolve subtasks for task 4031502656
[Todoist Migration] Could not find task 3881461069 in tasks map while trying to add it as subtask
[Todoist Migration] Could not find task 469484171 in tasks map while trying to add it as subtask
[Todoist Migration] Could not find task 2780011345 in tasks map while trying to add it as subtask
[Todoist Migration] Could not find task 2685939061 in tasks map while trying to resolve subtasks for task 2685939173