ssh operations refrain to work since d409d3

[agaida]

• Gitea version (or commit ref): d409d3a
• Git version: 2.11.0
• Operating system: Ubuntu zesty
• Database (use [x]):
  • PostgreSQL
  • MySQL
  • MSSQL
  • [ x] SQLite
• Can you reproduce the bug at https://try.gitea.io:
  • Yes (provide example URL)
  • No
  • [x ] Not relevant
• Log gist:

Description

since commit d409d3a Sanitation fix ssh actions hangs

Log

agaida@vmd18926:~$ git clone git@gitea:Test/pyfll p-10
Cloning into 'p-10'...
remote: Counting objects: 7528, done.
remote: Compressing objects: 100% (2441/2441), done.
remote: Total 7528 (delta 5067), reused 7517 (delta 5060)
Receiving objects: 100% (7528/7528), 3.07 MiB | 0 bytes/s, done.
Resolving deltas: 100% (5067/5067), done.
agaida@vmd18926:~$ git clone git@gitea:Test/pyfll p-6 
Cloning into 'p-6'...
remote: Counting objects: 7528, done.
remote: Compressing objects: 100% (2441/2441), done.
remote: Total 7528 (delta 5067), reused 7517 (delta 5060)
Receiving objects: 100% (7528/7528), 3.07 MiB | 0 bytes/s, done.
Resolving deltas: 100% (5067/5067), done.
agaida@vmd18926:~$ git clone git@gitea:Test/pyfll p-4
Cloning into 'p-4'...
remote: Counting objects: 7528, done.
remote: Compressing objects: 100% (2441/2441), done.
remote: Total 7528 (delta 5067), reused 7517 (delta 5060)
Receiving objects: 100% (7528/7528), 3.07 MiB | 0 bytes/s, done.
Resolving deltas: 100% (5067/5067), done.
agaida@vmd18926:~$ git clone git@gitea:Test/pyfll p-2
Cloning into 'p-2'...
^C
agaida@vmd18926:~$ git clone git@gitea:Test/pyfll p-3
Cloning into 'p-3'...
^C
agaida@vmd18926:~$ git clone git@gitea:Test/pyfll p-4again
Cloning into 'p-4again'...
remote: Counting objects: 7528, done.
remote: Compressing objects: 100% (2441/2441), done.
remote: Total 7528 (delta 5067), reused 7517 (delta 5060)
Receiving objects: 100% (7528/7528), 3.07 MiB | 0 bytes/s, done.
Resolving deltas: 100% (5067/5067), done.

This behaviour is reproducible - just branch the current master and hard reset it to some commits before.

[lunny]

@bkcsoft maybe you can take a look this.

[kubatyszko]

Interesting report, I reviewed the sanitization commit and there doesn't seem to be anything that could affect SSH at all, most if not all changes are template/HTML related.

I might be able to upgrade one of my environments to the HEAD and see if I see any SSH issues.

Thanks.

[agaida]

models/repo.go

seems to be worth a look - ok, wild guess, i don't speek go.

[gsantner]

I also couldn't use ssh on current HEAD. Went back to 21290d4 , the problem doesn't exist there.

I turned on SSH/GIT verbose log, and it was hanging at pre-receive.
Maybe useful: 21290d4...master

[kubatyszko]

I just built gitea based on 21290d4 and I'm seeing this error:

Counting objects: 3, done.
Writing objects: 100% (3/3), 202 bytes | 0 bytes/s, done.
Total 3 (delta 0), reused 0 (delta 0)
Gitea: Internal error
UpdatePublicKey: near "WHERE": syntax error
To ssh://localhost:2222/kuba/test.git
 * [new branch]      master -> master
error: failed to push some refs to 'ssh://kt@localhost:2222/kuba/test.git'

I am precisely on Gitea Version: 1.1.0+118-g21290d4

This might be some hint to whover has clue what broke with SSH recently.

Other than the warning (and seemingly failing operations) - push/pull actually works.

[kubatyszko]

I reverted to d9db188 and that fixed it (that's one commit before #1466 (I didn't do a full bisect, simply reverted the commit that seemed like it could be causing issues when a SSH key is being used, the error message with the "WHERE" description clearly indicates it's related to some UPDATE operation when using SSH key...

[strk]

What database are you using @kubatyszko ? Can you enable statement logging and check the exact statement being sent ?

[kubatyszko]

sqlite in this case, the statement is:

2017/04/18 16:40:00 [I] [SQL] UPDATE `public_key` SET  WHERE `id`=? [1]

It seems to missing a thing to set between SET and WHERE...

Also, there is no specific field in the table that would store last-used of the key:

sqlite> .schema public_key
CREATE TABLE `public_key` (`id` INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, `owner_id` INTEGER NOT NULL, `name` TEXT NOT NULL, `fingerprint` TEXT NOT NULL, `content` TEXT NOT NULL, `mode` INTEGER NOT NULL DEFAULT 2, `type` INTEGER NOT NULL DEFAULT 1, `created_unix` INTEGER NULL, `updated_unix` INTEGER NULL);
CREATE INDEX `IDX_public_key_owner_id` ON `public_key` (`owner_id`);
sqlite>

The only field that could fit the purpose would be updated_unix...

[lunny]

^ Wrong reference.

[tbaschak]

I actually migrated from sqlite to mysql (in a very very manual way) b/c I thought it was an error in the sqlite backend on my end. The error happens in both sqlite and mysql backends. Like @kubatyszko said above theres something missing after SET in the UPDATE query in both.

I did not realize however that push/pull operations actually were successful despite this.

[lunny]

@kubatyszko and @tbaschak I think both your issue has been reported via #1471 and has been fixed by #1474 and merged to master. Your issue is not related with this one.

[ncwgf]

not sure is it same issue but I also face the ssh hang up like @gsantner reported
and it is no way to success
Gitea Version: 1.1.0+125-g2eeae84c (Docker image)
turn on ssh verbose log ssh -v, full log here of git fetch origin

$ git fetch origin
OpenSSH_7.3p1, OpenSSL 1.0.2k  26 Jan 2017
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Connecting to <host> [<host>] port <port>.
debug1: Connection established.
debug1: identity file /c/Users/<User>/.ssh/id_rsa type 1
debug1: key_load_public: No such file or directory
debug1: identity file /c/Users/<User>/.ssh/id_rsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/Users/<User>/.ssh/id_dsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/Users/<User>/.ssh/id_dsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/Users/<User>/.ssh/id_ecdsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/Users/<User>/.ssh/id_ecdsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/Users/<User>/.ssh/id_ed25519 type -1
debug1: key_load_public: No such file or directory
debug1: identity file /c/Users/<User>/.ssh/id_ed25519-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_7.3
debug1: Remote protocol version 2.0, remote software version Go
debug1: no match: Go
debug1: Authenticating to <host>:<port> as 'git'
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: algorithm: curve25519-sha256@libssh.org
debug1: kex: host key algorithm: ssh-rsa
debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha2-256 compression: none
debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha2-256 compression: none
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ssh-rsa SHA256:<key>
debug1: Host '[<host>]:<port>' is known and matches the RSA host key.
debug1: Found key in /c/Users/<User>/.ssh/known_hosts:4
debug1: rekey after 4294967296 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: rekey after 4294967296 blocks
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey
debug1: Next authentication method: publickey
debug1: Offering RSA public key: /c/Users/<User>/.ssh/id_rsa
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug1: Authentication succeeded (publickey).
Authenticated to <host> ([<host>]:<port>).
debug1: channel 0: new [client-session]
debug1: Entering interactive session.
debug1: pledge: network
debug1: Sending command: git-upload-pack '/<org>/<xxx>.git'  <--- hang up here

detail log ssh -vvv

...cut
debug3: send packet: type 50
debug3: receive packet: type 52
debug1: Authentication succeeded (publickey).
Authenticated to <host> ([<host>]:<port>).
debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug3: send packet: type 90
debug1: Entering interactive session.
debug1: pledge: network
debug3: receive packet: type 91
debug2: callback start
debug2: fd 3 setting TCP_NODELAY
debug3: ssh_packet_set_tos: set IP_TOS 0x08
debug2: client_session2_setup: id 0
debug1: Sending command: git-upload-pack '/<org>/<repo>.git'   <--- hang up point on debug1
debug2: channel 0: request exec confirm 1
debug3: send packet: type 98
debug2: callback done
debug2: channel 0: open confirm rwindow 2097152 rmax 32768
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0  <---- hang 

here is the log if it work (use older version of docker image e.g. tag 1.1)

...cut
debug1: Sending command: git-upload-pack '/<org>/<repo>.git' <--- hang up point on debug1 if fail
debug2: channel 0: request exec confirm 1
debug3: send packet: type 98
debug2: callback done
debug2: channel 0: open confirm rwindow 2097152 rmax 32768
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0 <---- hang here if fail
debug2: channel 0: read<=0 rfd 4 len 0
debug2: channel 0: read failed
debug2: channel 0: close_read
debug2: channel 0: input open -> drain
debug2: channel 0: ibuf empty
debug2: channel 0: send eof
debug3: send packet: type 96
debug2: channel 0: input drain -> closed
debug2: channel 0: rcvd adjust 4
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug2: channel 0: output open -> drain
debug3: channel 0: will not send data after close
debug2: channel 0: obuf empty
debug2: channel 0: close_write
debug2: channel 0: output drain -> closed
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug3: send packet: type 97
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
  #0 client-session (t4 r0 i3/0 o3/0 fd -1/-1 cc -1)

debug3: send packet: type 1
debug3: fd 0 is not O_NONBLOCK
debug3: fd 1 is not O_NONBLOCK
Transferred: sent 2792, received 1968 bytes, in 0.2 seconds
Bytes per second: sent 17104.6, received 12056.5
debug1: Exit status 0