Skip to content

WARNING! Although there is a key with this ID in the database it does not verify this commit! This commit is SUSPICIOUS. #16344

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
2 of 6 tasks
TheBinaryLoop opened this issue Jul 5, 2021 · 24 comments
Labels

Comments

@TheBinaryLoop
Copy link

TheBinaryLoop commented Jul 5, 2021

  • Gitea version (or commit ref): 1.14.3
  • Git version: git version 2.31.1.windows.1
  • Operating system: Linux/Docker
  • Database (use [x]):
    • PostgreSQL
    • MySQL
    • MSSQL
    • SQLite
  • Can you reproduce the bug at https://try.gitea.io:
    • Yes (provide example URL)
    • No
  • Log gist:
    I don't know how logs would help with this issue but if its necessary i will provide logs.

Description

I added my gpg key and signed a commit with it. Localy i can verify the commit with git verify-commit HEAD but in the webinterface it shows as "WARNING! Although there is a key with this ID in the database it does not verify this commit! This commit is SUSPICIOUS.".

Screenshots

Screenshot 2021-07-06 at 00-19-19
Screenshot 2

@noerw
Copy link
Member

noerw commented Jul 10, 2021

Did you add that GPG key to your Gitea account?

But I can confirm with 1.14.3, that commits correctly signed are marked as invalid signed occasionally.
The key is added to the account, locally the commit signature is still valid.
I didn't catch the logs the last time this happened, but will do in the future.
@TheBinaryLoop do you still have logs from when this happened?

@noerw noerw added the type/bug label Jul 10, 2021
@TheBinaryLoop
Copy link
Author

TheBinaryLoop commented Jul 10, 2021 via email

@prologic
Copy link

@TheBinaryLoop I"m seeing the same issue here. I haven't managed to capture any logs though. Have you?

@prologic
Copy link

@techknowlogick Appreicate you closing my issue so promptly, but I'd like to help resolve this. I'm a bit puzzled myself 🤣

@TheBinaryLoop
Copy link
Author

@prologic No. Do I need to enable some flag or something? I just get the default log. I can try and capture the log while I push a commit. Or do I need to capture the log at some other point?

@prologic
Copy link

@prologic No. Do I need to enable some flag or something? I just get the default log. I can try and capture the log while I push a commit. Or do I need to capture the log at some other point?

What's not clear to ms is whether the Gitea backend needs to be setup with debug logging or not? I would have thought if something bad happened you'd get a warning or error level log entry, but I can't seem to find one.

@TheBinaryLoop
Copy link
Author

@prologic That's my problem as well

@prologic
Copy link

@techknowlogick We could really use some help here, as I'm unfamiliar with the project's codebase it's hard for me to work out why this is happening to us.

@noerw
Copy link
Member

noerw commented Jul 13, 2021

I'm not sure if more verbose logging is needed for this, but I'd enable it just in case:
@prologic @TheBinaryLoop Learn here how to enable more verbose debug logging.
Enable it now, so you have the logs the next time it happens.
Depending on the amount of traffic your instance receives you'll need to be quick to tail the log after the incident to find the right segment.

edit: Looking at the failing code section, I'm wondering if the key you used for those "bad" commits is a subkey?

@prologic
Copy link

I just reconfigured my instance with debug logging turned on, did a commit to one of my private repos and pushed.

This is what I got:

[email protected]    | 2021/07/13 07:42:57 ...s/context/context.go:675:1() [D] Session ID: 9cc471b0b3edca10
[email protected]    | 2021/07/13 07:42:57 ...s/context/context.go:676:1() [D] CSRF Token: L6yxrhlagBnGcVh4KNdg4MkZIUs6MTYyNjE2MjE3NzQwNjM1NDA2Ng
[email protected]    | 2021/07/13 07:42:57 Completed GET /prologic/golinks/src/be9688571ce2c24380d743b87edf9ffe5e9e6e2f/Makefile 302 Found in 22.461248ms





[email protected]    | kex_exchange_identification: Connection closed by remote host
[email protected]    | Connection closed by 10.255.0.2 port 59992
[email protected]    | Accepted publickey for git from 10.255.0.2 port 49512 ssh2: RSA SHA256:7KKqaOSBTmR+kMz8D4ULVKLgy4Kgufm/XQxiZK+UBtw
[email protected]    | 2021/07/13 07:43:08 Started GET /api/internal/serv/command/2/prologic/opsfiles?mode=2&verb=git-receive-pack for 127.0.0.1:54824
[email protected]    | 2021/07/13 07:43:08 ...ters/private/serv.go:404:ServCommand() [D] Serv Results:
[email protected]    | 	IsWiki: false
[email protected]    | 	IsDeployKey: false
[email protected]    | 	KeyID: 2	KeyName: Personal
[email protected]    | 	UserName: prologic
[email protected]    | 	UserID: 1
[email protected]    | 	OwnerName: prologic
[email protected]    | 	RepoName: opsfiles
[email protected]    | 	RepoID: 1
[email protected]    | 2021/07/13 07:43:08 Completed GET /api/internal/serv/command/2/prologic/opsfiles?mode=2&verb=git-receive-pack 200 OK in 2.214691ms
[email protected]    | 2021/07/13 07:43:09 Started POST /api/internal/hook/pre-receive/prologic/opsfiles for 127.0.0.1:54826
[email protected]    | 2021/07/13 07:43:09 Completed POST /api/internal/hook/pre-receive/prologic/opsfiles 200 OK in 970.197µs
[email protected]    | 2021/07/13 07:43:09 Started POST /api/internal/hook/post-receive/prologic/opsfiles for 127.0.0.1:54830
[email protected]    | 2021/07/13 07:43:09 Completed POST /api/internal/hook/post-receive/prologic/opsfiles 200 OK in 1.593536ms
[email protected]    | 2021/07/13 07:43:09 Started POST /api/internal/ssh/2/update/1 for 127.0.0.1:54832
[email protected]    | 2021/07/13 07:43:09 Completed POST /api/internal/ssh/2/update/1 200 OK in 29.021846ms
[email protected]    | Received disconnect from 10.255.0.2 port 49512:11: disconnected by user
[email protected]    | Disconnected from user git 10.255.0.2 port 49512
[email protected]    | 2021/07/13 07:43:10 Started GET /user/login for 10.0.0.12:0
[email protected]    | 2021/07/13 07:43:10 ...s/context/context.go:675:1() [D] Session ID: c07e0149664ad27e
[email protected]    | 2021/07/13 07:43:10 ...s/context/context.go:676:1() [D] CSRF Token: vE9anTXDAt3mzmDkfrCUifMsvqM6MTYyNjE2MjE5MDE3ODcxNjEzMA
[email protected]    | 2021/07/13 07:43:10 ...s/context/context.go:184:HTML() [D] Template: user/auth/signin
[email protected]    | 2021/07/13 07:43:10 Completed GET /user/login 200 OK in 8.868747ms





[email protected]    | 2021/07/13 07:43:20 Started GET / for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:20 ...s/context/context.go:675:1() [D] Session ID: 6d03db7dfd07c5f6
[email protected]    | 2021/07/13 07:43:20 ...s/context/context.go:676:1() [D] CSRF Token: eAqGixP7cPlfhj4cnUl62vnbHSc6MTYyNjE1MjEwNzY4MDQ0MDQxNQ
[email protected]    | 2021/07/13 07:43:20 ...s/context/context.go:184:HTML() [D] Template: user/dashboard/dashboard
[email protected]    | 2021/07/13 07:43:20 Completed GET / 200 OK in 28.240785ms
[email protected]    | 2021/07/13 07:43:20 Started GET /api/v1/repos/search?sort=updated&order=desc&uid=1&team_id=0&q=&page=1&mode= for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:20 Started GET /api/v1/repos/search?sort=updated&order=desc&uid=1&team_id=0&q=&page=1&limit=15&mode=&archived=false for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:20 Completed GET /api/v1/repos/search?sort=updated&order=desc&uid=1&team_id=0&q=&page=1&limit=15&mode=&archived=false 200 OK in 13.725996ms
[email protected]    | 2021/07/13 07:43:20 Completed GET /api/v1/repos/search?sort=updated&order=desc&uid=1&team_id=0&q=&page=1&mode= 200 OK in 22.951707ms
[email protected]    | kex_exchange_identification: Connection closed by remote host
[email protected]    | Connection closed by 10.255.0.2 port 60060
[email protected]    | 2021/07/13 07:43:23 Started GET /prologic/opsfiles for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:23 ...s/context/context.go:675:1() [D] Session ID: 6d03db7dfd07c5f6
[email protected]    | 2021/07/13 07:43:23 ...s/context/context.go:676:1() [D] CSRF Token: eAqGixP7cPlfhj4cnUl62vnbHSc6MTYyNjE1MjEwNzY4MDQ0MDQxNQ
[email protected]    | 2021/07/13 07:43:23 routers/repo/view.go:181:renderDirectory() [D] README.md
[email protected]    | 2021/07/13 07:43:23 routers/repo/view.go:192:renderDirectory() [D] false
[email protected]    | 2021/07/13 07:43:23 ...s/charset/charset.go:122:DetectEncoding() [D] Detected encoding: utf-8 (fast)
[email protected]    | 2021/07/13 07:43:23 ...s/context/context.go:184:HTML() [D] Template: repo/home
[email protected]    | 2021/07/13 07:43:23 Completed GET /prologic/opsfiles 200 OK in 87.290886ms
[email protected]    | 2021/07/13 07:43:28 Started GET /prologic/golinks/src/commit/be9688571ce2c24380d743b87edf9ffe5e9e6e2f/Makefile for 192.99.4.163:0
[email protected]    | 2021/07/13 07:43:28 ...s/context/context.go:675:1() [D] Session ID: 2d316a6cb9086a5b
[email protected]    | 2021/07/13 07:43:28 ...s/context/context.go:676:1() [D] CSRF Token: LtX7qeP_nRAkVg9pR-tm--BKlHQ6MTYyNjE2MjIwODA4MzAyNTcxMA
[email protected]    | 2021/07/13 07:43:28 ...s/charset/charset.go:122:DetectEncoding() [D] Detected encoding: utf-8 (fast)
[email protected]    | 2021/07/13 07:43:28 ...s/charset/charset.go:122:DetectEncoding() [D] Detected encoding: utf-8 (fast)
[email protected]    | 2021/07/13 07:43:28 ...s/context/context.go:184:HTML() [D] Template: repo/home
[email protected]    | 2021/07/13 07:43:28 Completed GET /prologic/golinks/src/commit/be9688571ce2c24380d743b87edf9ffe5e9e6e2f/Makefile 200 OK in 27.997322ms
[email protected]    | 2021/07/13 07:43:30 Started GET /prologic/opsfiles/commits/branch/master for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:30 ...s/context/context.go:675:1() [D] Session ID: 6d03db7dfd07c5f6
[email protected]    | 2021/07/13 07:43:30 ...s/context/context.go:676:1() [D] CSRF Token: eAqGixP7cPlfhj4cnUl62vnbHSc6MTYyNjE1MjEwNzY4MDQ0MDQxNQ
[email protected]    | 2021/07/13 07:43:30 ...s/context/context.go:184:HTML() [D] Template: repo/commits
[email protected]    | 2021/07/13 07:43:30 Completed GET /prologic/opsfiles/commits/branch/master 200 OK in 182.825366ms
[email protected]    | 2021/07/13 07:43:34 Started GET /prologic/opsfiles/commit/b96eead316175831e8ce92a47759850ad277217e for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:34 ...s/context/context.go:675:1() [D] Session ID: 6d03db7dfd07c5f6
[email protected]    | 2021/07/13 07:43:34 ...s/context/context.go:676:1() [D] CSRF Token: eAqGixP7cPlfhj4cnUl62vnbHSc6MTYyNjE1MjEwNzY4MDQ0MDQxNQ
[email protected]    | 2021/07/13 07:43:34 ...s/charset/charset.go:122:DetectEncoding() [D] Detected encoding: utf-8 (fast)
[email protected]    | 2021/07/13 07:43:34 ...s/charset/charset.go:122:DetectEncoding() [D] Detected encoding: utf-8 (fast)
[email protected]    | 2021/07/13 07:43:34 ...s/context/context.go:184:HTML() [D] Template: repo/commit_page
[email protected]    | 2021/07/13 07:43:34 Completed GET /prologic/opsfiles/commit/b96eead316175831e8ce92a47759850ad277217e 200 OK in 119.141243ms
[email protected]    | 2021/07/13 07:43:34 Started GET /css/easymde.css?v=83c2a6bc19fdcfafbeb2f9ae6b3a3073 for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /css/easymde.css
[email protected]    | 2021/07/13 07:43:34 Completed GET /css/easymde.css?v=83c2a6bc19fdcfafbeb2f9ae6b3a3073 304 Not Modified in 497.816µs
[email protected]    | 2021/07/13 07:43:34 Started GET /vendor/plugins/codemirror/addon/mode/loadmode.js for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:34 Started GET /js/easymde.js?v=83c2a6bc19fdcfafbeb2f9ae6b3a3073 for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /js/easymde.js
[email protected]    | 2021/07/13 07:43:34 Completed GET /js/easymde.js?v=83c2a6bc19fdcfafbeb2f9ae6b3a3073 304 Not Modified in 554.283µs
[email protected]    | 2021/07/13 07:43:34 Started GET /vendor/plugins/codemirror/mode/meta.js for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /vendor/plugins/codemirror/addon/mode/loadmode.js
[email protected]    | 2021/07/13 07:43:34 Completed GET /vendor/plugins/codemirror/addon/mode/loadmode.js 304 Not Modified in 3.836689ms
[email protected]    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /vendor/plugins/codemirror/mode/meta.js
[email protected]    | 2021/07/13 07:43:34 Completed GET /vendor/plugins/codemirror/mode/meta.js 304 Not Modified in 6.509941ms
[email protected]    | 2021/07/13 07:43:34 Started GET /fonts/icons.woff2 for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /fonts/icons.woff2
[email protected]    | 2021/07/13 07:43:34 Completed GET /fonts/icons.woff2 304 Not Modified in 408.763µs
[email protected]    | 2021/07/13 07:43:34 Started GET /js/tribute.js for 10.0.0.109:0
[email protected]    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /js/tribute.js
[email protected]    | 2021/07/13 07:43:34 Completed GET /js/tribute.js 304 Not Modified in 472.372µs
[email protected]    | kex_exchange_identification: Connection closed by remote host
[email protected]    | Connection closed by 10.255.0.2 port 60110

@prologic
Copy link

There is no mention of any problems with my GPG key. And this is what git log -v -p --show-signature shows:

commit b96eead316175831e8ce92a47759850ad277217e (HEAD -> master, origin/master)
gpg: Signature made Tue Jul 13 17:43:06 2021 AEST
gpg:                using RSA key C1F16643ADFF61B4A39EA3FEAC4C014F1440EBD6
gpg: Good signature from "James Mills (Public) <[email protected]>" [ultimate]
Author: James Mills <[email protected]>
Date:   Tue Jul 13 17:43:06 2021 +1000

    Reconfigure Drone CI to connect to Gitea
...

@noerw
Copy link
Member

noerw commented Jul 13, 2021

Hm, looks like logging is not especially verbose in that section of code. :/

@prologic This occurs for every commit you sign right? For me this just happened occasionally, seemlingly random.
So there may be something broken with your setup, not necessarily a bug. So to check up on your setup:

  • Is one of the emails in your gpg key also added to your account AND activated? otherwise the key won't give a valid signature
  • extremely unlikely, but: are there two keys with conflicting key-IDs registered in gitea?

@prologic
Copy link

  • Is one of the emails in your gpg key also added to your account AND activated? otherwise the key won't give a valid signature

Yes.

Screen Shot 2021-07-13 at 19 19 10

  • extremely unlikely, but: are there two keys with conflicting key-IDs registered in gitea?

No.

Screen Shot 2021-07-13 at 19 19 26


Does it matter that the email associated with that key is not marked as my primary email in Gitea?

@noerw
Copy link
Member

noerw commented Jul 13, 2021

Did you add the key before activating the email address? We might have a inconsistent DB here.
You can check the output of this SQL and see if it lists the email as not activated.

select key_id, primary_key_id, can_sign, emails from gpg_key;

Does it matter that the email associated with that key is not marked as my primary email in Gitea?

No, not to my knowledge

@prologic
Copy link

Did you add the key before activating the email address? We might have a inconsistent DB here.
You can check the output of this SQL and see if it lists the email as not activated.

Hahaha yes! I did indeed! It took awhile for me to "confirm" my secondary email as I hadn't setup email properly. Although it accepts the first email without verification for some reason :D

Can I just delete the GPG key and re-add it? Will that resolve this? If so, I claim this as a bug ;) A race!

@prologic
Copy link

Bingo!

AC4C014F1440EBD6                    1         [{"ID":1,"UID":1,"Email":"[email protected]","IsActivated":false,"IsPrimary":false}]

@prologic
Copy link

I fixed my database 🤣

Screen Shot 2021-07-13 at 20 13 52

Not something I'd recommend anyone do unless you really know your SQL and know what you're doing 😂

@noerw
Copy link
Member

noerw commented Jul 13, 2021

Nice. Readding the key would also have worked.
@TheBinaryLoop does that solve your problem too?

@zeripath
Copy link
Contributor

Once we finally have #14054 the key will show which addresses it validates for.

As an addtion we should probably also store all the email addresses that a key could validate even if they're not currently activated and just check that they're activated at the time of validation.

@prologic
Copy link

As an addtion we should probably also store all the email addresses that a key could validate even if they're not currently activated and just check that they're activated at the time of validation.

Yeah you need some kind of background job here to periodically check this, or a trigger off of validating en email. Doing this around the wrong way (unintentional stupid user) ends up in this weird situation that was rather hard to debug because of the obscure error 😄

@TheBinaryLoop
Copy link
Author

Nice. Readding the key would also have worked.
@TheBinaryLoop does that solve your problem too?

Yes. I manually updated the db via sql and now it shows correctly in the ui. Thanks guys 😄

@prologic
Copy link

@zeripath Why did you close this? This is not fixed. This is a bug in the code at best, at worst lacking documentation. Please reopen and let's get some code in to fix this. Thanks! 🙇‍♂️

@zeripath
Copy link
Contributor

Have you looked at 1.15 since #14054 has been merged?

The addresses that the key will validate for are now displayed and you can verify the key to make it work for any activated email address.

There's a smaller issue about storing all the addresses that a key could verify for - but actually just reimporting the key now it shows what it verifies is probably going to solve that.

@prologic
Copy link

Have you looked at 1.15 since #14054 has been merged?

The addresses that the key will validate for are now displayed and you can verify the key to make it work for any activated email address.

There's a smaller issue about storing all the addresses that a key could verify for - but actually just reimporting the key now it shows what it verifies is probably going to solve that.

Ahh! You could have said so with a comment and then closed :) All good! THanks!

@go-gitea go-gitea locked and limited conversation to collaborators Oct 19, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests

4 participants