search

go-gitea / gitea

Git with a cup of tea! Painless self-hosted all-in-one software development service, including Git hosting, code review, team collaboration, package registry and CI/CD
https://gitea.com
MIT License
45.02k stars 5.49k forks source link

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

Closed TheBinaryLoop closed 3 years ago

TheBinaryLoop commented 3 years ago

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 commented 3 years ago

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?

TheBinaryLoop commented 3 years ago

Yes. I added the key to my Gitea account. Next time I make an commit, I'll try to catch the logs.

Get Outlook for Androidhttps://aka.ms/AAb9ysg

From: Norwin @.> Sent: Saturday, July 10, 2021 11:02:46 AM To: go-gitea/gitea @.> Cc: Lukas Eßmann @.>; Mention @.> Subject: Re: [go-gitea/gitea] WARNING! Although there is a key with this ID in the database it does not verify this commit! This commit is SUSPICIOUS. (#16344)

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. @TheBinaryLoophttps://github.com/TheBinaryLoop do you still have logs from when this happened?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHubhttps://github.com/go-gitea/gitea/issues/16344#issuecomment-877601356, or unsubscribehttps://github.com/notifications/unsubscribe-auth/ADGS77FSVM7JRRBGZKMGBCDTXAEDNANCNFSM473NIIYA.

prologic commented 3 years ago

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

prologic commented 3 years ago

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

TheBinaryLoop commented 3 years ago

@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 commented 3 years ago

@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 commented 3 years ago

@prologic That's my problem as well

prologic commented 3 years ago

@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 commented 3 years ago

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 commented 3 years ago

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:

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

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

gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:20 Started GET / for 10.0.0.109:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:20 ...s/context/context.go:675:1() [D] Session ID: 6d03db7dfd07c5f6
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:20 ...s/context/context.go:676:1() [D] CSRF Token: eAqGixP7cPlfhj4cnUl62vnbHSc6MTYyNjE1MjEwNzY4MDQ0MDQxNQ
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:20 ...s/context/context.go:184:HTML() [D] Template: user/dashboard/dashboard
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:20 Completed GET / 200 OK in 28.240785ms
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 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
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 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
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 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
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 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
gitea_server.1.2nll4kd7alox@dm6.mills.io    | kex_exchange_identification: Connection closed by remote host
gitea_server.1.2nll4kd7alox@dm6.mills.io    | Connection closed by 10.255.0.2 port 60060
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:23 Started GET /prologic/opsfiles for 10.0.0.109:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:23 ...s/context/context.go:675:1() [D] Session ID: 6d03db7dfd07c5f6
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:23 ...s/context/context.go:676:1() [D] CSRF Token: eAqGixP7cPlfhj4cnUl62vnbHSc6MTYyNjE1MjEwNzY4MDQ0MDQxNQ
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:23 routers/repo/view.go:181:renderDirectory() [D] README.md
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:23 routers/repo/view.go:192:renderDirectory() [D] false
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:23 ...s/charset/charset.go:122:DetectEncoding() [D] Detected encoding: utf-8 (fast)
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:23 ...s/context/context.go:184:HTML() [D] Template: repo/home
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:23 Completed GET /prologic/opsfiles 200 OK in 87.290886ms
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:28 Started GET /prologic/golinks/src/commit/be9688571ce2c24380d743b87edf9ffe5e9e6e2f/Makefile for 192.99.4.163:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:28 ...s/context/context.go:675:1() [D] Session ID: 2d316a6cb9086a5b
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:28 ...s/context/context.go:676:1() [D] CSRF Token: LtX7qeP_nRAkVg9pR-tm--BKlHQ6MTYyNjE2MjIwODA4MzAyNTcxMA
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:28 ...s/charset/charset.go:122:DetectEncoding() [D] Detected encoding: utf-8 (fast)
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:28 ...s/charset/charset.go:122:DetectEncoding() [D] Detected encoding: utf-8 (fast)
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:28 ...s/context/context.go:184:HTML() [D] Template: repo/home
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:28 Completed GET /prologic/golinks/src/commit/be9688571ce2c24380d743b87edf9ffe5e9e6e2f/Makefile 200 OK in 27.997322ms
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:30 Started GET /prologic/opsfiles/commits/branch/master for 10.0.0.109:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:30 ...s/context/context.go:675:1() [D] Session ID: 6d03db7dfd07c5f6
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:30 ...s/context/context.go:676:1() [D] CSRF Token: eAqGixP7cPlfhj4cnUl62vnbHSc6MTYyNjE1MjEwNzY4MDQ0MDQxNQ
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:30 ...s/context/context.go:184:HTML() [D] Template: repo/commits
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:30 Completed GET /prologic/opsfiles/commits/branch/master 200 OK in 182.825366ms
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Started GET /prologic/opsfiles/commit/b96eead316175831e8ce92a47759850ad277217e for 10.0.0.109:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...s/context/context.go:675:1() [D] Session ID: 6d03db7dfd07c5f6
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...s/context/context.go:676:1() [D] CSRF Token: eAqGixP7cPlfhj4cnUl62vnbHSc6MTYyNjE1MjEwNzY4MDQ0MDQxNQ
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...s/charset/charset.go:122:DetectEncoding() [D] Detected encoding: utf-8 (fast)
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...s/charset/charset.go:122:DetectEncoding() [D] Detected encoding: utf-8 (fast)
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...s/context/context.go:184:HTML() [D] Template: repo/commit_page
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Completed GET /prologic/opsfiles/commit/b96eead316175831e8ce92a47759850ad277217e 200 OK in 119.141243ms
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Started GET /css/easymde.css?v=83c2a6bc19fdcfafbeb2f9ae6b3a3073 for 10.0.0.109:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /css/easymde.css
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Completed GET /css/easymde.css?v=83c2a6bc19fdcfafbeb2f9ae6b3a3073 304 Not Modified in 497.816µs
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Started GET /vendor/plugins/codemirror/addon/mode/loadmode.js for 10.0.0.109:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Started GET /js/easymde.js?v=83c2a6bc19fdcfafbeb2f9ae6b3a3073 for 10.0.0.109:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /js/easymde.js
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Completed GET /js/easymde.js?v=83c2a6bc19fdcfafbeb2f9ae6b3a3073 304 Not Modified in 554.283µs
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Started GET /vendor/plugins/codemirror/mode/meta.js for 10.0.0.109:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /vendor/plugins/codemirror/addon/mode/loadmode.js
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Completed GET /vendor/plugins/codemirror/addon/mode/loadmode.js 304 Not Modified in 3.836689ms
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /vendor/plugins/codemirror/mode/meta.js
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Completed GET /vendor/plugins/codemirror/mode/meta.js 304 Not Modified in 6.509941ms
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Started GET /fonts/icons.woff2 for 10.0.0.109:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /fonts/icons.woff2
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Completed GET /fonts/icons.woff2 304 Not Modified in 408.763µs
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Started GET /js/tribute.js for 10.0.0.109:0
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 ...les/public/public.go:165:handle() [I] [Static] Serving /js/tribute.js
gitea_server.1.2nll4kd7alox@dm6.mills.io    | 2021/07/13 07:43:34 Completed GET /js/tribute.js 304 Not Modified in 472.372µs
gitea_server.1.2nll4kd7alox@dm6.mills.io    | kex_exchange_identification: Connection closed by remote host
gitea_server.1.2nll4kd7alox@dm6.mills.io    | Connection closed by 10.255.0.2 port 60110
prologic commented 3 years ago

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) <prologic@shortcircuit.net.au>" [ultimate]
Author: James Mills <prologic@shortcircuit.net.au>
Date:   Tue Jul 13 17:43:06 2021 +1000

    Reconfigure Drone CI to connect to Gitea
...
noerw commented 3 years ago

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:

prologic commented 3 years ago
  • 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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

Bingo!

AC4C014F1440EBD6                    1         [{"ID":1,"UID":1,"Email":"prologic@shortcircuit.net.au","IsActivated":false,"IsPrimary":false}]
prologic commented 3 years ago

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 commented 3 years ago

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

zeripath commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

@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 commented 3 years ago

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 commented 3 years ago

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!