focalboard icon indicating copy to clipboard operation
focalboard copied to clipboard

Published 20 hours ago • verified publisher icon mattermost

Bug: Personal server > Log errors after dropping db

Open ogi-m opened this issue 2 years ago • 4 comments

Steps to reproduce the behavior

  1. Have an active session on personal server
  2. With the session open, drop the database with tables
  3. Restart systemctl focalboard.service
  4. Observe the log errors:
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.691 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.691 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.693 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.693 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.695 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.794 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.795 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.821 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.823 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.823 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.825 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.834 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.835 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.839 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.840 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.937 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.938 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.959 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.960 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.961 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.962 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.979 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.980 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.995 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 20 18:47:31 ip-172-25-53-236 focalboard-server[2510471]: debug [2022-04-20 18:47:31.997 Z] API DEBUG                                caller="api/api.go:4113" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards

Edition and Platform

  • Edition: Personal Server
  • Version: v0.16.0
  • Browser and OS: Chrome on Windows

ogi-m avatar Apr 21 '22 19:04 ogi-m

After creating a new user:

Apr 21 19:13:07 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:13:07.136 Z] Block change event                       caller="notifylogger/logger_backend.go:48" action=add board="Meeting Agenda " card="Social Media Strategy" block_id=aqb6f4xrzwb8fzbr9bwmkhdsyeo
Apr 21 19:14:34 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:14:34.305 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 21 19:14:34 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:14:34.311 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.296 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.302 Z] API DEBUG                                caller="api/api.go:4135" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/users/me
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.361 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.367 Z] API DEBUG                                caller="api/api.go:4135" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/users/me
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.370 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.371 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.378 Z] API DEBUG                                caller="api/api.go:4135" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.378 Z] API DEBUG                                caller="api/api.go:4135" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.420 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.431 Z] API DEBUG                                caller="api/api.go:4135" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/boards
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.488 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.493 Z] API DEBUG                                caller="api/api.go:4135" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/users/me/memberships
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.593 Z] attachSession                            caller="api/auth.go:459" single_user=false
Apr 21 19:31:02 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:02.595 Z] API DEBUG                                caller="api/api.go:4135" code=401 error="unable to get the session for the token: sql: no rows in result set" msg= api=/api/v2/teams/0/templates
Apr 21 19:31:03 ip-172-25-53-236 focalboard-server[2524068]: error [2022-04-21 19:31:03.186 Z] ERROR WebSocket                          caller="ws/server.go:136" client="127.0.0.1:42652" error="websocket: close 1001 (going away)"
Apr 21 19:31:03 ip-172-25-53-236 focalboard-server[2524068]: debug [2022-04-21 19:31:03.186 Z] DISCONNECT WebSocket                     caller="ws/server.go:125" client="127.0.0.1:42652"

ogi-m avatar Apr 21 '22 19:04 ogi-m

@ogi-m What is the impact on test? If no impact, then we can probably leave as is. cc @chenilim @sbishel

wuwinson avatar Apr 25 '22 18:04 wuwinson

@wuwinson There's a log spam whenever there's an active session on the server, so it's a continuous problem. It doesn't have to be a code fix, but if someone has a solution to make it stop that's fine too. cc @chenilim @sbishel @metanerd

ogi-m avatar Apr 27 '22 14:04 ogi-m

Hello @wuwinson @ogi-m, I have encountered something similar while developing and testing using the personal server.

In particular I use the following scenario:

  • build server and webapp
  • start server via npm run runserver-test (it starts the server with configuration used for Cypress tests)
  • open browser at http://localhost:8088 and see the login page
  • register the first user
  • test something

Sometimes I restart the server and in-memory SQLite db is dropped so the server starts with fresh database. But I still have auth information (token) stored in the browser and this leads to the behavior described in this bug (constant spam in logs).

For my development scenario I can either go to register page directly or remove the token from browser local storage to prevent this. But still this is some inconvenience during the development process.

Looks like this in browser:

https://user-images.githubusercontent.com/5587620/183243744-7b90db0b-28f5-42c5-bbed-c16d48ce8211.mov

@chenilim @mgdelacroix looks like this is some server side issue, can we fix this?

kamre avatar Aug 06 '22 09:08 kamre