Internal server Error

[Aviortheking]

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

Description

While trying to push on try.gitea.io OR my own server I get this result AND in the frontend there is nothing changed on new repos

https://git.delta-wings.net

❯ git push -u origin master -v
Pushing to git@git.delta-wings.net:tcgdex/website.git
Locking support detected on remote "origin". Consider enabling it with:
  $ git config lfs.https://git.delta-wings.net/tcgdex/website.git/info/lfs.locksverify true
Enumerating objects: 10, done.
Counting objects: 100% (10/10), done.
Delta compression using up to 4 threads
Compressing objects: 100% (6/6), done.
Writing objects: 100% (6/6), 21.38 KiB | 10.69 MiB/s, done.
Total 6 (delta 1), reused 0 (delta 0)
remote: . Processing 1 references
remote: Gitea: Internal Server Error
remote: Unable to contact gitea: Post http://localhost:3000/api/internal/hook/post-receive/tcgdex/website: read tcp 127.0.0.1:55080->127.0.0.1:3000: i/o timeout
To git.delta-wings.net:tcgdex/website.git
   d3cce2e..3e255c2  master -> master
Branch 'master' set up to track remote branch 'master' from 'origin'.
updating local tracking ref 'refs/remotes/origin/master'

https://try.gitea.io

❯ git push -u test master -v
Pushing to https://try.gitea.io/Avior/t.git
Username for 'https://try.gitea.io': Avior
Password for 'https://Avior@try.gitea.io': 
Enumerating objects: 42, done.
Counting objects: 100% (42/42), done.
Delta compression using up to 4 threads
Compressing objects: 100% (38/38), done.
Writing objects: 100% (42/42), 153.31 KiB | 5.90 MiB/s, done.
Total 42 (delta 2), reused 0 (delta 0)
POST git-receive-pack (157142 bytes)
remote: . Processing 1 references
remote: Gitea: Internal Server Error
remote: Unable to contact gitea: Post http://localhost:3000/api/internal/hook/post-receive/Avior/t: read tcp 127.0.0.1:47514->127.0.0.1:3000: i/o timeout
To https://try.gitea.io/Avior/t.git
 * [new branch]      master -> master
Branch 'master' set up to track remote branch 'master' from 'test'.
updating local tracking ref 'refs/remotes/test/master'

...

Screenshots

[guillep2k]

We were having issues on try.gitea.io today. Can you try again now?

[Aviortheking]

Same thing happens https://try.gitea.io/Avior/g

❯ git push -u test master -v
Pushing to https://try.gitea.io/Avior/g.git
Username for 'https://try.gitea.io': Avior
Password for 'https://Avior@try.gitea.io': 
Enumerating objects: 42, done.
Counting objects: 100% (42/42), done.
Delta compression using up to 4 threads
Compressing objects: 100% (38/38), done.
Writing objects: 100% (42/42), 153.31 KiB | 8.07 MiB/s, done.
Total 42 (delta 2), reused 0 (delta 0)
POST git-receive-pack (157143 bytes)
remote: . Processing 1 references
remote: Gitea: Internal Server Error
remote: Unable to contact gitea: Post http://localhost:3000/api/internal/hook/post-receive/Avior/g: read tcp 127.0.0.1:56480->127.0.0.1:3000: i/o timeout
To https://try.gitea.io/Avior/g.git
 * [new branch]      master -> master
Branch 'master' set up to track remote branch 'master' from 'test'.
updating local tracking ref 'refs/remotes/test/master'

[bobemoe]

I'm getting this on my instance too. Just updated to the latest: 1.12.0+dev-295-gea7ad382e

remote: Unable to contact gitea: Post http://localhost:3000/api/internal/hook/post-receive/myuser/myrepo: read tcp 127.0.0.1:44488->127.0.0.1:3000: i/o timeout

The actual git repo seems to be updated from the failed push, I can pull elsewhere and another push reports "Already up to date" its just Gitea fronted hasn't noticed.

I can't see any clues in the logs.

[bobemoe]

The push does hang for about 20 secs before the timeout, and I did notice about 10 instances threads of gitea web sitting at the top of htop for memory usage during this. Not sure if that's normal?

I couldn't see them in ps but there were these:

git       9788 93.4 22.9 1529132 469828 ?      Sl   09:26   0:55 /home/git/gitea web
git       9820  0.0  0.1  25728  2116 ?        Sl   09:26   0:00 /usr/bin/git receive-pack --stateless-rpc /home/git/gitea-repositories/myuser/myrepo.git
git       9853  0.0  0.1  19628  3120 ?        S    09:26   0:00 bash ./hooks/post-receive.d/gitea
git       9854  0.2  1.8 616676 38284 ?        Sl   09:26   0:00 /home/git/gitea hook --config=/home/git/custom/conf/app.ini post-receive

The bottom 3 then disappeared after the timeout leaving just the normal single instance of /home/git/gitea web

I've just rolled back to 1.12.0+dev-145-gad3a9577a and everything is working fine again. (Probably not the latest build before the bug, just I've not updated in a while.)

[zeripath]

10 instances of Gitea web? There should only be on.

I wonder if you might have been seeing a temporary load spike from the new code stats indexer or if there's a lock up somewhere in the pull checks code - it would be good if you could git bisect the issue or perhaps try the latest but with the stats indexer disabled to see if it really is that.

An option to get Gitea started then send a flush with the new Gitea manager command.

[Aviortheking]

tried the latest it still do it
BUT i got this in the logs

server_1  | 2020/02/13 08:02:58 ...dexer/stats/queue.go:24:handle() [E] stats queue idexer.Index(24) failed: Error 1093: You can't specify target table 'language_stat' for update in FROM clause

and when trying to go to this page : https://git.delta-wings.net/admin/monitor I get a 504 error (idk if it's related)

[bobemoe]

@zirpath, ah they are not instances, they are threads.. that's why I couldn't see them in ps but still looks like they still may be a clue to what's happening?

Just researching how to flush, bisect or disable stats and I may give it a shot...

EDIT: Bisecting now...

[bobemoe]

ad2642a8aac9facb217a8471df1d3e00f1214e92 is the first bad commit
commit ad2642a8aac9facb217a8471df1d3e00f1214e92
Author: Lauris BH <lauris@nix.lv>
Date:   Tue Feb 11 11:34:17 2020 +0200

    Language statistics bar for repositories (#8037)
    
    * Implementation for calculating language statistics
    
    Impement saving code language statistics to database
    
    Implement rendering langauge stats
    
    Add primary laguage to show in repository list
    
    Implement repository stats indexer queue
    
    Add indexer test
    
    Refactor to use queue module
    
    * Do not timeout for queues

:100644 100644 de67f582dace3d56349f8fc227b2875a0aa46d55 f28b199f0dc573d1fe79504af19499a22b3abeb4 M	go.mod
:100644 100644 ff5c52bc23410a2ca94d17c62d2999e1d9d0b62c 30109a24e4096c12e90ea26b546fa60a52665cbf M	go.sum
:040000 040000 b408357c4e006b5c664505059253be06f51b11ce cb8928a1136870ffba1f6b14671d2a39878b830f M	integrations
:040000 040000 21ff0601109bb967510e8055385b13e736324883 3e0ba85f1c120133ee6bc440523c5ccaaa85f2b6 M	models
:040000 040000 ff070690f23865c7b93aa083e9353b21a2fa86aa 3dbed83837acee11a482a175f5bc9eed5c0190cc M	modules
:040000 040000 0c43d298548debe91342c57f8d9148aa0f46c526 5348c1b25fba5fdd2bff763510cfabd22386462f M	options
:040000 040000 380ecce01ba358b353e2b6fcf0e20a89581d8517 bfb4adb881cc02ffd1259a09677873406feeaab7 M	routers
:040000 040000 55d4de3f39b9a3d00d8e38c678452fb7329045c3 76f89f38f0cb1060a2a0a657df15752e2210ea54 M	templates
:040000 040000 c52ed5b8a90753e95a73367d794ba3aa7ea7205e c45bd337f9cbcc4980c07e35a80c1f6575402dad M	vendor
:040000 040000 e17f853d41c417d19fd011c74806b7c3fc2d7d45 27a93037bcc1766a2744958ea912291c40bab1e8 M	web_src

[lafriks]

Problem is with old MySQL server versions only

[bobemoe]

What's old? I'm running:
mysql Ver 14.14 Distrib 5.7.28, for Linux (x86_64) using EditLine wrapper still pretty common I think, after that its v8?

[mqudsi]

This isn't fixed for me, I'm running a self-hosted instance on a97fe76950bf69ca71c9b790e8d0e76d5e870235 (which is after #10251).

I'm using MariaDB, if it makes a difference:

> mysql --version
mysql  Ver 15.1 Distrib 10.3.22-MariaDB, for FreeBSD12.0 (amd64) using readline 5.1

and this is what I get:

mqudsi@ZBOOK /m/c/U/m/g/o/crdb> git push -f
Enumerating objects: 15, done.
Counting objects: 100% (15/15), done.
Delta compression using up to 8 threads
Compressing objects: 100% (13/13), done.
Writing objects: 100% (15/15), 2.79 KiB | 407.00 KiB/s, done.
Total 15 (delta 0), reused 0 (delta 0)
remote: . Processing 1 references
remote: Gitea: Internal Server Error
remote: Unable to contact gitea: Post http://0.0.0.0:3000/api/internal/hook/post-receive/mqudsi/crdb.odo: read tcp 127.0.0.1:30909->127.0.0.1:3000: i/o timeout
To git.neosmart.net:mqudsi/crdb.odo.git
 + c6f2f7f...0ab88af master -> master (forced update)

I've attached the log, but something must be wrong with my configuration because it's mostly just SQL.

gitea.pushfail.log

[mqudsi]

Now that I'm reading the PR that was intended to fix this, I believe the specific context might be relevant. This issue either caused the hang that led to my #10276 or my specific case in #10276 caused the subsequent push to trigger this bug.

I ran into the issue described in #10276 which resulted in a git repo with a commit but the gitea db being unaware of it. To rectify, I ran git commit --amend then git push -f in an attempt to get gitea to reindex.

---

Update: I deleted the repository and pushed again and that worked fine.

[zeripath]

I suspect that the deadlock fixed in #10283 is related