UpdatePublicKey: Failed to update public key: public key does not exist #843

@ethantkoenig commented on GitHub (Jun 26, 2017):

@gsantner The INSERT command you posted isn't valid; the column count doesn't match the value count, and created and updated are not columns in the public_key table.

Are you sure there is a key with id 20 in the database (i.e. SELECT * FROM public_key WHERE id=20 returns something)?

If for some reason you're not able to directly run the SELECT command, you could instead use the GET /api/v1/users/:username/keys API endpoint to double-check that the key does in fact exist in the database.

@ethantkoenig commented on GitHub (Jun 26, 2017): @gsantner The `INSERT` command you posted isn't valid; the column count doesn't match the value count, and `created` and `updated` are not columns in the public_key table. Are you sure there is a key with id 20 in the database (i.e. `SELECT * FROM public_key WHERE id=20` returns something)? If for some reason you're not able to directly run the `SELECT` command, you could instead use the `GET /api/v1/users/:username/keys` API endpoint to double-check that the key does in fact exist in the database.

GiteaMirror commented

@gsantner commented on GitHub (Jun 26, 2017):

Sorry maybe I accidentally removed one during pasting to github. below is the export again.
Yes, the query gets exactly this line, so I'm sure theres ID 20 in there.

API: tried https://DOMAIN/gitea/api/v1/users/gregor/keys and it just shows me a white page without any error (accessed via browser). Theres also no error or other message in the log from this api query.
Did tail -f *.log inside code.gitea.io/gitea/log

in fact exist in the database.

It does, I directly accessed the database gitea is using.

As said above, I can access/clone/push. But sometimes (multiple times a day, and often at CI) it just gives this error. The keys are correctly setted up at my clients.

--
-- Tabellenstruktur für Tabelle `public_key`
--

CREATE TABLE `public_key` (
  `id` bigint(20) NOT NULL,
  `owner_id` bigint(20) NOT NULL,
  `name` varchar(255) NOT NULL,
  `fingerprint` varchar(255) NOT NULL,
  `content` text NOT NULL,
  `mode` int(11) NOT NULL DEFAULT '2',
  `type` int(11) NOT NULL DEFAULT '1',
  `created` datetime DEFAULT NULL,
  `updated` datetime DEFAULT NULL,
  `created_unix` bigint(20) DEFAULT NULL,
  `updated_unix` bigint(20) DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8;

--
-- Daten für Tabelle `public_key`
--

INSERT INTO `public_key` (`id`, `owner_id`, `name`, `fingerprint`, `content`, `mode`, `type`, `created`, `updated`, `created_unix`, `updated_unix`) VALUES
(20, 1, ' laptop gregor ', 'SHA256:arjdRrafsdfsdfadsfsd', 'ssh-rsa AAAasdfadsfadsfadsfadsfjr9F gregor@somewhere', 2, 1, NULL, NULL, 1498410219, 1498468069);

@gsantner commented on GitHub (Jun 26, 2017): Sorry maybe I accidentally removed one during pasting to github. below is the export again. Yes, the query gets exactly this line, so I'm sure theres ID 20 in there. API: tried `https://DOMAIN/gitea/api/v1/users/gregor/keys` and it just shows me a white page without any error (accessed via browser). Theres also no error or other message in the log from this api query. Did `tail -f *.log` inside `code.gitea.io/gitea/log` > in fact exist in the database. It does, I directly accessed the database gitea is using. As said above, I can access/clone/push. But sometimes (multiple times a day, and often at CI) it just gives this error. The keys are correctly setted up at my clients. ``` -- -- Tabellenstruktur für Tabelle `public_key` -- CREATE TABLE `public_key` ( `id` bigint(20) NOT NULL, `owner_id` bigint(20) NOT NULL, `name` varchar(255) NOT NULL, `fingerprint` varchar(255) NOT NULL, `content` text NOT NULL, `mode` int(11) NOT NULL DEFAULT '2', `type` int(11) NOT NULL DEFAULT '1', `created` datetime DEFAULT NULL, `updated` datetime DEFAULT NULL, `created_unix` bigint(20) DEFAULT NULL, `updated_unix` bigint(20) DEFAULT NULL ) ENGINE=InnoDB DEFAULT CHARSET=utf8; -- -- Daten für Tabelle `public_key` -- INSERT INTO `public_key` (`id`, `owner_id`, `name`, `fingerprint`, `content`, `mode`, `type`, `created`, `updated`, `created_unix`, `updated_unix`) VALUES (20, 1, ' laptop gregor ', 'SHA256:arjdRrafsdfsdfadsfsd', 'ssh-rsa AAAasdfadsfadsfadsfadsfjr9F gregor@somewhere', 2, 1, NULL, NULL, 1498410219, 1498468069); ```

GiteaMirror commented

@ethantkoenig commented on GitHub (Jun 29, 2017):

@gsantner What is the value of setting.LocalURL in your setup (specifically inside the serv subcommand)?

The request POST {setting.LocalURL}/api/internal/ssh/20/update (made here) is returning a 500, because whatever gitea instance is running at that URL is talking to a different database than the one that contains your key.

@ethantkoenig commented on GitHub (Jun 29, 2017): @gsantner What is the value of `setting.LocalURL` in your setup (specifically inside the `serv` subcommand)? The request `POST {setting.LocalURL}/api/internal/ssh/20/update` (made [here](https://github.com/go-gitea/gitea/blob/master/modules/private/internal.go#L40)) is returning a 500, because whatever gitea instance is running at that URL is talking to a different database than the one that contains your key.

GiteaMirror commented

@gsantner commented on GitHub (Jun 29, 2017):

I dont have any debugging tools or like that installed on the system. What shall I do, and where I can find the piece of information then?

@gsantner commented on GitHub (Jun 29, 2017): I dont have any debugging tools or like that installed on the system. What shall I do, and where I can find the piece of information then?

GiteaMirror commented

@gsantner commented on GitHub (Jun 29, 2017):

Btw: There is just one Gitea instance running on the system

@gsantner commented on GitHub (Jun 29, 2017): Btw: There is just one Gitea instance running on the system

GiteaMirror commented

@ethantkoenig commented on GitHub (Jun 29, 2017):

@gsantner From looking at the logs you've posted, setting.LocalURL is http://localhost:5642. Can do you the following:

Can you double-check that the gitea config (default location is custom/conf/app.ini) is correct? Specifically the database config?
Can you go to http://localhost:5642/user/settings/keys (authenticated as the user with id 1), and confirm that you see the key you inserted (SHA256:arjdRrafsdfsdfadsfsd)

If neither of these reveal anything, then I'm stuck 😕

@ethantkoenig commented on GitHub (Jun 29, 2017): @gsantner From looking at the logs you've posted, `setting.LocalURL` is `http://localhost:5642`. Can do you the following: 1. Can you double-check that the gitea config (default location is `custom/conf/app.ini`) is correct? Specifically the database config? 2. Can you go to `http://localhost:5642/user/settings/keys` (authenticated as the user with id 1), and confirm that you see the key you inserted (`SHA256:arjdRrafsdfsdfadsfsd`) If neither of these reveal anything, then I'm stuck :confused:

GiteaMirror commented

@gsantner commented on GitHub (Jun 29, 2017):

1 ) Well, it's localhost at a port yes, but apache is serving in front. (Which shouldn't matter anyway as I'm cloning via SSH)

[server]
SSH_DOMAIN   =  MY.DOMAIN.EXT
DOMAIN       = MY.DOMAIN.EXT
HTTP_PORT    = 5642    
ROOT_URL     = https://MY.DOMAIN.EXT/gitea
OFFLINE_MODE = false
ENABLE_GZIP  = false

[database]
DB_TYPE  = mysql
HOST     = 127.0.0.1:3306
NAME     = gitea
USER     = gitea
PASSWD   = PASS

Of course, yeah, the right key (hash) is there (I pasted some short random text in the issue). And in the database too. With the correct text and description.

@gsantner commented on GitHub (Jun 29, 2017): 1 ) Well, it's localhost at a port yes, but apache is serving in front. (Which shouldn't matter anyway as I'm cloning via SSH) ``` [server] SSH_DOMAIN = MY.DOMAIN.EXT DOMAIN = MY.DOMAIN.EXT HTTP_PORT = 5642 ROOT_URL = https://MY.DOMAIN.EXT/gitea OFFLINE_MODE = false ENABLE_GZIP = false [database] DB_TYPE = mysql HOST = 127.0.0.1:3306 NAME = gitea USER = gitea PASSWD = PASS ``` 2) Of course, yeah, the right key (hash) is there (I pasted some short random text in the issue). And in the database too. With the correct text and description.

GiteaMirror commented

@lafriks commented on GitHub (Jul 2, 2017):

Does in your app.ini config file has INTERNAL_TOKEN value?

@lafriks commented on GitHub (Jul 2, 2017): Does in your app.ini config file has `INTERNAL_TOKEN` value?

GiteaMirror commented

@gsantner commented on GitHub (Jul 3, 2017):

@lafriks Yep, under [security]

@gsantner commented on GitHub (Jul 3, 2017): @lafriks Yep, under `[security]`

GiteaMirror commented

@lafriks commented on GitHub (Jul 3, 2017):

and it is not empty, right? (do not post it here just confirm it is not empty)

@lafriks commented on GitHub (Jul 3, 2017): and it is not empty, right? (do **not** post it here just confirm it is not empty)

GiteaMirror commented

@gsantner commented on GitHub (Jul 3, 2017):

of course it is there

@gsantner commented on GitHub (Jul 3, 2017): of course it is there

GiteaMirror commented

@lunny commented on GitHub (Jul 13, 2017):

Could you reproduce that? Maybe take a look at the xorm.log?

@lunny commented on GitHub (Jul 13, 2017): Could you reproduce that? Maybe take a look at the xorm.log?

GiteaMirror commented

@gsantner commented on GitHub (Jul 13, 2017):

Yes, reproducible. serv.log.txt / xorm.log.txt. I deleted all logs before starting the script.

Maybe some kind of race condition? Maybe related to a timestamp?

#!/bin/bash
for i in `seq 1 100` ; do 
        git clone gogs@myhost:me/somerepo.git   CloneNr$i 2>&1 | grep "key" &
done
ls | wc -l

outputs: (59 clones out of 100 worked actually / loaded repo fully).

$
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
UpdatePublicKey: Failed to update public key: public key does not exist [id: 19]
59

@gsantner commented on GitHub (Jul 13, 2017): Yes, reproducible. [serv.log.txt](https://github.com/go-gitea/gitea/files/1144723/serv.log.txt) / [xorm.log.txt](https://github.com/go-gitea/gitea/files/1144724/xorm.log.txt). I deleted all logs before starting the script. Maybe some kind of race condition? Maybe related to a timestamp? ``` #!/bin/bash for i in `seq 1 100` ; do git clone gogs@myhost:me/somerepo.git CloneNr$i 2>&1 | grep "key" & done ls | wc -l ``` outputs: (59 clones out of 100 worked actually / loaded repo fully). ``` $ UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] UpdatePublicKey: Failed to update public key: public key does not exist [id: 19] 59 ```

GiteaMirror commented

@lafriks commented on GitHub (Jul 13, 2017):

Thanks for detailed info, I will look into this

@lafriks commented on GitHub (Jul 13, 2017): Thanks for detailed info, I will look into this

GiteaMirror commented

@gsantner commented on GitHub (Jul 20, 2017):

@lafriks
Thanks for your fixes! Tried the script above again, and there are no warnings/erorrs anymore now. But still about half of the clones do not work.

[gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone
83
[gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone
80
[gregor@gregor-desktop aatmp]$ 
[gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone
22
[gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone
30
[gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone
88
[gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone
50
[gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone
40
[gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone
67

In the Logs I can find
2017/07/20 16:15:08 [T] UpdatePublicKeyUpdated: http://localhost:PORT/api/internal/ssh/19/update lines, but no public key error anymore. I don't know where the problem lies now, but there is still a bug.
The problem may not occur so often when using it with one time push/pull for code updates, but if theres e.g. jenkins behind who does pull and make checks

@gsantner commented on GitHub (Jul 20, 2017): @lafriks Thanks for your fixes! Tried the script above again, and there are no warnings/erorrs anymore now. But still about half of the clones do not work. ``` [gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone 83 [gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone 80 [gregor@gregor-desktop aatmp]$ [gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone 22 [gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone 30 [gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone 88 [gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone 50 [gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone 40 [gregor@gregor-desktop aatmp]$ bash clonestuff.sh ; sleep 5 ; rmFolderWithGit clone 67 ``` In the Logs I can find `2017/07/20 16:15:08 [T] UpdatePublicKeyUpdated: http://localhost:PORT/api/internal/ssh/19/update` lines, but no public key error anymore. I don't know where the problem lies now, but there is still a bug. The problem may not occur so often when using it with one time push/pull for code updates, but if theres e.g. jenkins behind who does pull and make checks

GiteaMirror commented

@lafriks commented on GitHub (Jul 20, 2017):

@gsantner It works correctly wait before bash script finishes to execute and than check cloned repository count. Because at the end of git clone you have & so ls executes faster than git commands are finished cloning repositories that's way you get wrong count. If you will wait a bit longer and run ls manually you will see correct count

@lafriks commented on GitHub (Jul 20, 2017): @gsantner It works correctly wait before bash script finishes to execute and than check cloned repository count. Because at the end of git clone you have `&` so ls executes faster than git commands are finished cloning repositories that's way you get wrong count. If you will wait a bit longer and run ls manually you will see correct count

GiteaMirror commented

@gsantner commented on GitHub (Jul 20, 2017):

Thats what I tried too (before multiple script execution). fail2ban turned off. heres a log. I did check if some git is running too

log.txt

I tried the script too with 10 clones, that works. 100 may be a little heavy and unnatural, I'm just somewhat suprised it cannot be handled even if cloning is running from/to localhost. From the log: maybe an upstream bug in openssh?

@gsantner commented on GitHub (Jul 20, 2017): Thats what I tried too (before multiple script execution). fail2ban turned off. heres a log. I did check if some git is running too [log.txt](https://github.com/go-gitea/gitea/files/1163093/log.txt) I tried the script too with 10 clones, that works. 100 may be a little heavy and unnatural, I'm just somewhat suprised it cannot be handled even if cloning is running from/to localhost. From the log: maybe an upstream bug in openssh?

GiteaMirror commented

@lafriks commented on GitHub (Jul 20, 2017):

@gsantner try adding sleep before ls, might be that when scripts exits it child processes are also killed

@lafriks commented on GitHub (Jul 20, 2017): @gsantner try adding sleep before ls, might be that when scripts exits it child processes are also killed

GiteaMirror commented

@gsantner commented on GitHub (Jul 20, 2017):

I did execute the commands manually after some time. as said, I'm sure no git clone was running. (At the multi-test two above yes, but not in the manual clones where the log comes from.)

log.txt

Am 20. Juli 2017 18:18:31 MESZ schrieb Lauris BH notifications@github.com:

@gsantner try adding sleep before ls, might be that when scripts exits
it child processes are also killed

--
You are receiving this because you were mentioned.
Reply to this email directly or view it on GitHub:
https://github.com/go-gitea/gitea/issues/2060#issuecomment-316754767

--
Diese Nachricht wurde von meinem Android-Gerät mit K-9 Mail gesendet.

@gsantner commented on GitHub (Jul 20, 2017): I did execute the commands manually after some time. as said, I'm sure no git clone was running. (At the multi-test two above yes, but not in the manual clones where the log comes from.) [log.txt](https://github.com/go-gitea/gitea/files/1163090/log.txt) Am 20. Juli 2017 18:18:31 MESZ schrieb Lauris BH <notifications@github.com>: >@gsantner try adding sleep before ls, might be that when scripts exits >it child processes are also killed > >-- >You are receiving this because you were mentioned. >Reply to this email directly or view it on GitHub: >https://github.com/go-gitea/gitea/issues/2060#issuecomment-316754767 -- Diese Nachricht wurde von meinem Android-Gerät mit K-9 Mail gesendet.

GiteaMirror commented