Skip to content

500 error accessing dashboard after upgrade to 1.16.1 from 1.15.10, caused by mismatched SQLite colmun type #18650

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
nicorac opened this issue Feb 7, 2022 · 29 comments · Fixed by #19656
Labels
issue/workaround it is or has a workaround

Comments

@nicorac
Copy link

nicorac commented Feb 7, 2022

Gitea Version

1.16.1

Git Version

2.25.1

Operating System

Ubuntu Server 20.04 LTS

How are you running Gitea?

Running as service with binaries (gitea-1.16.1-linux-amd64).

Database

SQLite

Can you reproduce the bug on the Gitea demo site?

No

Description

After upgrading from 1.15.10 to 1.16.1 I get a 500 error when accessing the dashboard.
Other pages seem to work correctly if I open them directly (repos, issues, ...).

(the same issue happened a week ago when I tried to upgrade from 1.15.10 to 1.16.0 but I haven't opened an issue at that time due to lack of time, sorry)

Log contains only this relevant line:

.../web/feed/profile.go:22:RetrieveFeeds() [E] GetFeeds: Find: converting driver.Value type string to a int64: invalid syntax

Database version before update was 189, after first run it was 209.

I've reverted back to 1.15.10 (both binaries and DB).

@lunny
Copy link
Member

lunny commented Feb 7, 2022

Could you paste more logs before this log and after?

@lunny
Copy link
Member

lunny commented Feb 7, 2022

And could you paste your database table action's structure?

@nicorac
Copy link
Author

nicorac commented Feb 7, 2022

This is the first log line in gitea.log as of today, repeated more times (I hit F5 morte than once).
Then another appeared, maybe related.
The last line is my attempt to get back to 1.15.10 before restoring the DB:

2022/02/07 08:22:41 .../web/feed/profile.go:22:RetrieveFeeds() [E] GetFeeds: Find: converting driver.Value type string to a int64: invalid syntax
2022/02/07 08:22:43 .../web/feed/profile.go:22:RetrieveFeeds() [E] GetFeeds: Find: converting driver.Value type string to a int64: invalid syntax
2022/02/07 08:22:44 .../web/feed/profile.go:22:RetrieveFeeds() [E] GetFeeds: Find: converting driver.Value type string to a int64: invalid syntax
2022/02/07 08:22:54 .../web/feed/profile.go:22:RetrieveFeeds() [E] GetFeeds: Find: converting driver.Value type string to a int64: invalid syntax
2022/02/07 08:23:47 ...s/context/context.go:290:PlainTextBytes() [E] PlainTextBytes: Not found.
2022/02/07 08:23:47 ...s/context/context.go:290:PlainTextBytes() [E] PlainTextBytes: Not found.
2022/02/07 08:25:22 .../web/feed/profile.go:22:RetrieveFeeds() [E] GetFeeds: Find: converting driver.Value type string to a int64: invalid syntax
2022/02/07 08:25:43 .../web/feed/profile.go:22:RetrieveFeeds() [E] GetFeeds: Find: converting driver.Value type string to a int64: invalid syntax
2022/02/07 08:26:48 ...ations/migrations.go:414:Migrate() [F] Downgrading database version from '209' to '189' is not supported and may result in loss of data integrity.
        If you really know what you're doing, execute `UPDATE version SET version=189 WHERE id=1;`

This is the requested table structure (in v1.15.10 DB):

CREATE TABLE [action] (
    id           INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL,
    user_id      INTEGER,
    op_type      INTEGER,
    act_user_id  INTEGER,
    repo_id      INTEGER,
    comment_id   INTEGER,
    is_deleted   INTEGER DEFAULT 0 NOT NULL,
    ref_name     TEXT,
    is_private   INTEGER DEFAULT 0 NOT NULL,
    content      TEXT,
    created_unix INTEGER
);
CREATE INDEX IDX_action_user_id ON [action] (user_id);
CREATE INDEX IDX_action_act_user_id ON [action] (act_user_id);
CREATE INDEX IDX_action_repo_id ON [action] (repo_id);
CREATE INDEX IDX_action_comment_id ON [action] (comment_id);
CREATE INDEX IDX_action_is_deleted ON [action] (is_deleted);
CREATE INDEX IDX_action_is_private ON [action] (is_private);
CREATE INDEX IDX_action_created_unix ON [action] (created_unix);

@zeripath
Copy link
Contributor

zeripath commented Feb 8, 2022

The error is coming from the sqlite DB itself and it indicates that one or more of the rows of action has a string value in one of its integer columns.

How this has happened I do not know. Gitea shouldn't have done this directly. Have you restored from a cross db backup previously?

The problem is that this cannot be automatically fixed. You're going to have to look at the sqlite DB yourself using sqlitebrowser or sqlite3. My suspicion is going to be that one of the is_ prefixed columns contains "true" and/or "false" when they should be 1 or 0.

@wxiaoguang
Copy link
Contributor

Maybe related to

The SQLite database was corrupted

@nicorac
Copy link
Author

nicorac commented Feb 8, 2022

The database worked correctly up to 1.15.10.

Have you restored from a cross db backup previously?

My steps:

  • stopped 1.15.10
  • backed up the DB file
  • downloaded 1.16.1 binary and started it
  • got 500 error
  • reverted to 1.15.10 and restored DB
  • restarted 1.15.10... it still works

My suspicion is going to be that one of the is_ prefixed columns contains "true" and/or "false" when they should be 1 or 0.

This is a good starting point, thanks.
I'll check it out as soon as I can stop the service 👍

@zeripath
Copy link
Contributor

zeripath commented Feb 8, 2022

There should be no need to stop the service to just read the data - sqlite will not take a lock unless you start writing to the db and once you write the lock will be released.

The issue would come if you start editing data but don't write it immediately as that will lock the table and gitea will hold-up until you release that lock.

@nicorac
Copy link
Author

nicorac commented Feb 9, 2022

I've checked actions table content and none of the is_* columns contain text, only 0 and 1.

The first 5 records in the table (id 118 ->122) have some differences with all the others:

  • they are the only one with is_private == 0
  • 4 of them they have repo_id == 0
  • ref_name contains a number instead of branch/tag names like "master", "integration", ...
  • created_unix column is empty
  • next id after these 5 rows is 359 (no IDs from 123 to 358...)
id user_id op_type act_user_id repo_id comment_id is_deleted ref_name is_private content created_unix
118 2 2 22 0 0 0 0 0
119 0 2 19 0 0 0 0 0
120 2 2 19 0 0 0 0 0
121 9 2 29 0 0 0 2 0
122 7 2 29 17 0 0 0 0
359 4 1 4 11 0 0 1 1549289674
360 1 1 4 11 0 0 1 1549289674
361 4 1 4 12 0 0 1 1549292689
362 1 1 4 12 0 0 1 1549292689
...(other 14000+ similar records, with consecutive IDs)

Could it be that those 5 leading records are causing the issue?

@lunny
Copy link
Member

lunny commented Feb 9, 2022

You can try to deleting them after you have a backup.

@nicorac
Copy link
Author

nicorac commented Feb 9, 2022

You can try to deleting them after you have a backup.

It worked: after deleting those 5 records I can now access toe dashboard without errors, thanks!

Just wondering what I've lost by deleting them and if there's a way to fix and re-adding them back...

@wxiaoguang
Copy link
Contributor

wxiaoguang commented Feb 10, 2022

These records are not important, they are used used to show user activities, so you can safely delete them (I even truncated the action table before, Gitea still works correctly).

It seems that empty created_unix causes the bug. SQLite doesn't have data type inside.

Is your database created by a very old Gitea?

@nicorac
Copy link
Author

nicorac commented Feb 10, 2022

These records are not important, they are used used to show user activities, so you can safely delete them

Ok, I've suspected that... can live without them 😉

Is your database created by a very old Gitea?

Yes it is.
I don't remember the version, but it surely was one of the very first ones...

@lunny
Copy link
Member

lunny commented Feb 10, 2022

But I think the created_unix should be there when action table created.

@nicorac
Copy link
Author

nicorac commented Feb 10, 2022

But I think the created_unix should be there when action table created.

I think so, but it didn't cause any issue till 1.15.10.
I hope this thread will help any other one lucky as me 😄

@wxiaoguang
Copy link
Contributor

But I think the created_unix should be there when action table created.

No, I have reviewed the whole history, it changed a lot.

@lunny
Copy link
Member

lunny commented Feb 10, 2022

But I think the created_unix should be there when action table created.

No, I have reviewed the whole history, it changed a lot.

Even if v1.0.0 the field has been there. https://github.com/go-gitea/gitea/blob/v1.0.0/models/action.go#L86

@wxiaoguang
Copy link
Contributor

The previous commit of v1.0.0 doesn't have that field. https://github.com/go-gitea/gitea/blame/0c9a616326ba096a2ff6c058cc96950f68c0fa6e/models/action.go

And I am not sure whether there are something wrong occurs during SQLite migrations since the field type/index all changed a lot. Well, this is just a guess.

@nicorac can you help to check what's the earliest created_unix in your action table?

@nicorac
Copy link
Author

nicorac commented Feb 10, 2022

what's the earliest created_unix in your action table?

It's 1549289674, which means GMT: Monday 4 February 2019 14:14:34

@wxiaoguang
Copy link
Contributor

what's the earliest created_unix in your action table?

It's 1549289674, which means GMT: Monday 4 February 2019 14:14:34

Well, not that early 😂 I have no idea

@wxiaoguang wxiaoguang changed the title 500 error accessing dashboard after upgrade to 1.16.1 from 1.15.10 500 error accessing dashboard after upgrade to 1.16.1 from 1.15.10, caused by mismatched SQLite colmun type Apr 6, 2022
@6543 6543 added this to the 1.16.8 milestone May 7, 2022
@6543
Copy link
Member

6543 commented May 7, 2022

should be fixed at #19629 ?

@singuliere
Copy link
Contributor

Yes, #19629 will fix the problem of the rows that have a repo_id of 0 but not the one with repo_id = 17 if the root cause of this particular error was indeed the empty created_unix field.

@singuliere
Copy link
Contributor

A null created_unix field cannot explain the error

2022/02/07 08:22:41 .../web/feed/profile.go:22:RetrieveFeeds() [E] GetFeeds: Find: converting driver.Value type string to a int64: invalid syntax

Figuring out the root cause would require more information:

  • A copy of the database to repeat the problem, or
  • An error message from XORM that provides a copy of the row that caused the error

What is puzzling is that there are no fields in Action that Find would need to convert from string to int64...

@wxiaoguang
Copy link
Contributor

wxiaoguang commented May 8, 2022

should be fixed at #19629 ?

I do not think they are the same problem. The problem in this issue is caused by incorrect database value, it might be caused by incorrect SQLite database operations (eg: incorrect upgrade/downgrade, incorrect dump/restore, etc) or unknown bugs (eg: during migration).

There is a chance that #19629 could bypass the problem, but the data in SQLite database is still incorrect.

I would propose to close this issue since there is no clue. Other databases won't be affected by this problem either.

And this problem can be bypassed manually (easily) by truncating action table or deleting the incorrect data in action table.

@wxiaoguang wxiaoguang added the issue/workaround it is or has a workaround label May 8, 2022
@wxiaoguang wxiaoguang removed this from the 1.16.8 milestone May 8, 2022
@singuliere
Copy link
Contributor

Other databases won't be affected by this problem either.

Why ?

@wxiaoguang
Copy link
Contributor

Log: converting driver.Value type string to a int64: invalid syntax

image

image

@singuliere
Copy link
Contributor

SQLite doesn't have data type inside.

I do not understand this sentence. How does that explain why other databases won't be affected by this problem?

@wxiaoguang
Copy link
Contributor

SQLite doesn't have data type inside.

I do not understand this sentence. How does that explain why other databases won't be affected by this problem?

In SQLite, you can have created_unix='' or created_unix=null or created_unix=123
In others, you can only have created_unix=null or created_unix=123

created_unix='' will cause the converting driver.Value type string to a int64 error, others won't.

@singuliere
Copy link
Contributor

I did not know that, thanks for explaining. Since this problem can still exist for Gitea instances that run on SQLite, I propose this issue is left open.

@singuliere
Copy link
Contributor

singuliere commented May 8, 2022

With these improvements to gitea doctor that replace created_unix='' with created_unix=0 this issue can be closed.

@go-gitea go-gitea locked and limited conversation to collaborators May 3, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
issue/workaround it is or has a workaround
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants