400 Bad Request on first namespace creation / Error 500 on /api/v1/info

Hi, thanks for the help.
Changing frontend made it worse as now I cant get past the login page.
I turned on verbose logging of everything and I’m not get anything in the logs.
Seems like I messed the install up as the frontend now returns 'Could not find or use Vikunja installation at “todo.domain.com:3456” ’

KR
EpicShelter

Is the API reachable from the outside, aka from the browser?

Could you share your configuration?

Can you reach the /API/v1/info endpoint? If that doesn’t work, you won’t be able to change the API URL in the frontend.

The API is reachable from the browser. calling /api/v1 returns {"message":"missing or malformed jwt"} which is to be expected.

calling the /api/v1/info endpoint with a browser or postman with headers returns a 500 Internal Server Error, but as I said no sign of anything in the logs.
I can upload my configs if you like, but they are very close to the default config/ configs shown in the docs.

Thanks for the help

/etc/vikunja/config.yml → service: # This token is used to verify issued JWT tokens. # Default is a - Pastebin.com

/etc/vikunja-front/index.html → <!DOCTYPE html><html lang="en"><head><title>Vikunja</title><meta charset="utf-8" - Pastebin.com

Looks like you’re hitting this: #767 - `500` on `/info` with deafult config - api - Gitea

To fix it, you have two options: Either set openid > providers > name/authurl/clientid/clientsecret to "" in the config or upgrade the frontend and the API to unstable which contains a fix.

Hi, I think there is something even funkier going on.

Neither changing to unstable nor setting the openid provider variables to “” changed anything.
I tried accessing the site with a different device too, but the results are always the same. 500 when calling /info.

I’m at a complete loss haha

Thanks
Epic

Nothing in the logs? Even with debug logging enabled for everything? There should be at least some sign of the logs working, if the log files are completely empty you may want to change that to stdout instead. What exact version are you using? (Run vikunja version and paste the output)

I set the logs to stdout and debug but still nothing useable.

The version is Vikunja api version v0.16.0+83-4880a0265b

But you do see the 500 in the logs? (just to confirm the logs are working)

Hi, sorry for the delay. I re-checked the log config and it’s all set to the most verbose. I tried logging to stdout and to a file but there’s no sign of the 500 anywhere

Then there should be something in the nginx logs. At least some sign of a 500 somewhere.

OK i found this in the nginx logs:

Hmm that looks like nginx got an error from the proxy upstream which is Vikunja in this case. So the error does occur somewhere in Vikunja and not in the proxy.

Could you provide all config and its setup so I can recreate and hopefully reproduce it? It definitely looks like a weird bug.

Oh and I guess you’ve already checked the basic things like the server itself is working properly etc?

I was debugging this in the Cloudron package. A call to /api/v1/info seems to result in some sort of crash (not a Go expert). Let me know if I can provide you with any more information. Note that the app itself works fine, frontend is fine etc. It’s only when I do curl https://vikunja.cloudron.com/api/v1/info, I get this backtrace.

I am using Vikunja 0.16.0

11:23:20 - 172.18.0.1 - - [08/Mar/2021:19:23:20 +0000] "GET /api/v1/info HTTP/1.1" 500 36 "-" "curl/7.68.0"
11:23:20 - 2021-03-08T19:23:20.191721378Z: - 	▶ echo recover.go:92 [PANIC RECOVER] interface conversion: interface {} is nil, not string goroutine 44 [running]:
11:23:20 - github.com/labstack/echo/v4/middleware.RecoverWithConfig.func1.1.1(0x152df38, 0x1000, 0x0, 0x16850c0, 0xc000236fa0)
11:23:20 - 	/srv/app/pkg/mod/github.com/labstack/echo/v4@v4.1.17/middleware/recover.go:77 +0x105
11:23:20 - panic(0x1275340, 0xc0002db080)
11:23:20 - 	/usr/local/go/src/runtime/panic.go:969 +0x1b9
11:23:20 - code.vikunja.io/api/pkg/modules/auth/openid.getProviderFromMap(0xc0001ff650, 0x13d4426, 0x15, 0x11efd80)
11:23:20 - 	/go/src/code.vikunja.io/api/pkg/modules/auth/openid/providers.go:95 +0x86d
11:23:20 - code.vikunja.io/api/pkg/modules/auth/openid.GetAllProviders(0xc0000ac6c0, 0x13d75b9, 0x17, 0xc0004b2700, 0xe)
11:23:20 - 	/go/src/code.vikunja.io/api/pkg/modules/auth/openid/providers.go:46 +0x1a5
11:23:20 - code.vikunja.io/api/pkg/routes/api/v1.Info(0x16850c0, 0xc000236fa0, 0x0, 0x0)
11:23:20 - 	/go/src/code.vikunja.io/api/pkg/routes/api/v1/info.go:107 +0x477
11:23:20 - github.com/labstack/echo/v4.(*Echo).add.func1(0x16850c0, 0xc000236fa0, 0x13dde75, 0x1b)
11:23:20 - 	/srv/app/pkg/mod/github.com/labstack/echo/v4@v4.1.17/echo.go:522 +0x62
11:23:20 - github.com/labstack/echo/v4/middleware.CORSWithConfig.func1.1(0x16850c0, 0xc000236fa0, 0x203000, 0x203000)
11:23:20 - 	/srv/app/pkg/mod/github.com/labstack/echo/v4@v4.1.17/middleware/cors.go:121 +0x483
11:23:20 - github.com/labstack/echo/v4/middleware.RecoverWithConfig.func1.1(0x16850c0, 0xc000236fa0, 0x0, 0x0)
11:23:20 - 	/srv/app/pkg/mod/github.com/labstack/echo/v4@v4.1.17/middleware/recover.go:98 +0x142
11:23:20 - github.com/labstack/echo/v4/middleware.LoggerWithConfig.func2.1(0x16850c0, 0xc000236fa0, 0x0, 0x0)
11:23:20 - 	/srv/app/pkg/mod/github.com/labstack/echo/v4@v4.1.17/middleware/logger.go:117 +0x130
11:23:20 - github.com/labstack/echo/v4.(*Echo).ServeHTTP(0xc00000c3c0, 0x1663ca0, 0xc0001cc700, 0xc0000ab500)
11:23:20 - 	/srv/app/pkg/mod/github.com/labstack/echo/v4@v4.1.17/echo.go:633 +0x182
11:23:20 - net/http.serverHandler.ServeHTTP(0xc0001cc0e0, 0x1663ca0, 0xc0001cc700, 0xc0000ab500)
11:23:20 - 	/usr/local/go/src/net/http/server.go:2843 +0xa3
11:23:20 - net/http.(*conn).serve(0xc00028f720, 0x1667de0, 0xc00052f240)
11:23:20 - 	/usr/local/go/src/net/http/server.go:1925 +0x8ad
11:23:20 - created by net/http.(*Server).Serve
11:23:20 - 	/usr/local/go/src/net/http/server.go:2969 +0x36c
11:23:20 - 
11:23:20 - goroutine 1 [chan receive]:
11:23:20 - code.vikunja.io/api/pkg/cmd.glob..func2(0x1fc6ec0, 0x209e430, 0x0, 0x0)
11:23:20 - 	/go/src/code.vikunja.io/api/pkg/cmd/web.go:68 +0x1dd
11:23:20 - github.com/spf13/cobra.(*Command).execute(0x1fc6ec0, 0xc0000321d0, 0x0, 0x0, 0x1fc6ec0, 0xc0000321d0)
11:23:20 - 	/srv/app/pkg/mod/github.com/spf13/cobra@v1.1.1/command.go:854 +0x2c2
11:23:20 - github.com/spf13/cobra.(*Command).ExecuteC(0x1fc6ec0, 0x44dfca, 0x1fe3f60, 0xc000000180)
11:23:20 - 	/srv/app/pkg/mod/github.com/spf13/cobra@v1.1.1/command.go:958 +0x375
11:23:20 - github.com/spf13/cobra.(*Command).Execute(...)
11:23:20 - 	/srv/app/pkg/mod/github.com/spf13/cobra@v1.1.1/command.go:895
11:23:20 - code.vikunja.io/api/pkg/cmd.Execute()
11:23:20 - 	/go/src/code.vikunja.io/api/pkg/cmd/cmd.go:44 +0x31
11:23:20 - main.main()
11:23:20 - 	/go/src/code.vikunja.io/api/main.go:22 +0x25
11:23:20 - 
11:23:20 - goroutine 10 [select]:
11:23:20 - github.com/go-redis/redis/v8/internal/pool.(*ConnPool).reaper(0xc00025fb80, 0xdf8475800)
11:23:20 - 	/srv/app/pkg/mod/github.com/go-redis/redis/v8@v8.4.8/internal/pool/pool.go:453 +0xfe
11:23:20 - created by github.com/go-redis/redis/v8/internal/pool.NewConnPool
11:23:20 - 	/srv/app/pkg/mod/github.com/go-redis/redis/v8@v8.4.8/internal/pool/pool.go:107 +0x1fc
11:23:20 - 
11:23:20 - goroutine 15 [select]:
11:23:20 - database/sql.(*DB).connectionOpener(0xc00025b860, 0x1667de0, 0xc00023f1c0)
11:23:20 - 	/usr/local/go/src/database/sql/sql.go:1126 +0xf5
11:23:20 - created by database/sql.OpenDB
11:23:20 - 	/usr/local/go/src/database/sql/sql.go:740 +0x12a
11:23:20 - 
11:23:20 - goroutine 45 [runnable]:
11:23:20 - net/http.(*connReader).backgroundRead(0xc0002da000)
11:23:20 - 	/usr/local/go/src/net/http/server.go:689
11:23:20 - created by net/http.(*connReader).startBackgroundRead
11:23:20 - 	/usr/local/go/src/net/http/server.go:686 +0xd5
11:23:20 - 
11:23:20 - goroutine 24 [select]:
11:23:20 - code.vikunja.io/api/pkg/mail.StartMailDaemon.func1()
11:23:20 - 	/go/src/code.vikunja.io/api/pkg/mail/mail.go:62 +0x13b
11:23:20 - created by code.vikunja.io/api/pkg/mail.StartMailDaemon
11:23:20 - 	/go/src/code.vikunja.io/api/pkg/mail/mail.go:55 +0x167
11:23:20 - 
11:23:20 - goroutine 25 [select]:
11:23:20 - github.com/robfig/cron/v3.(*Cron).run(0xc0002363c0)
11:23:20 - 	/srv/app/pkg/mod/github.com/robfig/cron/v3@v3.0.1/cron.go:263 +0x545
11:23:20 - created by github.com/robfig/cron/v3.(*Cron).Start
11:23:20 - 	/srv/app/pkg/mod/github.com/robfig/cron/v3@v3.0.1/cron.go:222 
11:23:20 - 

Ah so, I was wrong about this back trace appearing only for /api/v1/info. When I register a new user, I get the same trace again. But it doesn’t seem to stop the backend/frontend from working. I can register a user, login, creates namespaces/lists/tasks etc just fine.

Yeah that’s 400 Bad Request on first namespace creation / Error 500 on /api/v1/info - #7 by kolaente

(In hindsight I really should’ve published a fix release…)

1 Like

Sorry, I thought it was already in the latest release! I guess we will wait for the next release then, thanks.

1 Like

Unstable has the fix but is, well, unstable.

@kolaente thanks, I wanted to ask if this issue is indeed the root cause for Can't log in to desktop app (W10) or is the issue something else? edit: you already replied that this might be root cause in Can't log in to desktop app (W10) - #5 by kolaente .

I am actually OK with using the unstable binary in the Cloudron package (it’s unstable package in Cloudron as well). We will get more testing that way on the latest unstable :slight_smile:

1 Like

I’m running unstable on my installation as well so it is in general usable since I’ll just fix stuff if I break something severely.
I also plan on getting a release ready some time in april, so not too far away from now. I thought about making releases more often with less features, but then again I’m lazy and doing a proper release is some effort…