Gitea: Internal error retrieve protected branches information failed: EOF #3992

@randyesq commented on GitHub (Sep 20, 2019):

I also have run the admin Maintenance Operations task titled "Resynchronize pre-receive, update and post-receive hooks of all repositories." and this did not fix anything.

@randyesq commented on GitHub (Sep 20, 2019): I also have run the admin Maintenance Operations task titled "Resynchronize pre-receive, update and post-receive hooks of all repositories." and this did not fix anything.

GiteaMirror commented

@techknowlogick commented on GitHub (Sep 20, 2019):

This may have been fixed in a more recent version of Gitea (we just released 1.9.3). The newer versions also have patched some security vulns that are in 1.7.

1.9 also has improved logging to assist with debugging.

@techknowlogick commented on GitHub (Sep 20, 2019): This may have been fixed in a more recent version of Gitea (we just released 1.9.3). The newer versions also have patched some security vulns that are in 1.7. 1.9 also has improved logging to assist with debugging.

GiteaMirror commented

@randyesq commented on GitHub (Sep 20, 2019):

@techknowlogick is there something in the diff between 1.7 -> 1.9 that would suggest this would be fixed? From most of the issues that I referred to, it didn't seem like it was understood why this was even happening in the first place.

@randyesq commented on GitHub (Sep 20, 2019): @techknowlogick is there something in the diff between 1.7 -> 1.9 that would suggest this would be fixed? From most of the issues that I referred to, it didn't seem like it was understood why this was even happening in the first place.

GiteaMirror commented

@techknowlogick commented on GitHub (Sep 20, 2019):

Potentially there could be something that has been added as there has been hundreds of PRs since 1.7. It could be a timeout issue with the DB, and we've updated upstream dependencies, it could be an uncaught error that is now handled, it could be many things. We've also significantly refactored working with the underlying git repos which may be a factor. Please see the entire list of changes here: https://github.com/go-gitea/gitea/blob/master/CHANGELOG.md

I recommend updating and to see if this still happens, especially since there are several CVEs in the version you are currently using: https://cve.mitre.org/cgi-bin/cvekey.cgi?keyword=gitea Once you've updated the logging in v1.9.3 is really improved and can give a ton of details about what could be happening.

@techknowlogick commented on GitHub (Sep 20, 2019): Potentially there could be something that has been added as there has been hundreds of PRs since 1.7. It could be a timeout issue with the DB, and we've updated upstream dependencies, it could be an uncaught error that is now handled, it could be many things. We've also significantly refactored working with the underlying git repos which may be a factor. Please see the entire list of changes here: https://github.com/go-gitea/gitea/blob/master/CHANGELOG.md I recommend updating and to see if this still happens, especially since there are several CVEs in the version you are currently using: https://cve.mitre.org/cgi-bin/cvekey.cgi?keyword=gitea Once you've updated the logging in v1.9.3 is really improved and can give a ton of details about what could be happening.

GiteaMirror commented

@randyesq commented on GitHub (Sep 20, 2019):

Okay, we'll get on with upgrading this on our side and see if anything else comes up.

@randyesq commented on GitHub (Sep 20, 2019): Okay, we'll get on with upgrading this on our side and see if anything else comes up.

GiteaMirror commented

@devurandom commented on GitHub (Nov 1, 2019):

I also have run the admin Maintenance Operations task titled "Resynchronize pre-receive, update and post-receive hooks of all repositories." and this did not fix anything.

In my case it worked. I also pressed the ".ssh/authorized_keys" button, so maybe that had some effect, too.

@devurandom commented on GitHub (Nov 1, 2019): > I also have run the admin Maintenance Operations task titled "Resynchronize pre-receive, update and post-receive hooks of all repositories." and this did not fix anything. In my case it worked. I also pressed the ".ssh/authorized_keys" button, so maybe that had some effect, too.

GiteaMirror commented

@zeripath commented on GitHub (Nov 1, 2019):

yeah that would need changing too if you changed the path of the gitea binary.

To be clear Gitea has to write its real full path to:

gitea-repositories/*.git/hooks/pre-receive.d/gitea
gitea-repositories/*.git/hooks/update.d/gitea
gitea-repositories/*.git/hooks/post-receive.d/gitea
.ssh/authorized_keys (if you are not using the internal SSH or an AuthorizedKeysCommand)

These all have to be updated if you change the path of the Gitea binary.

If you are moving from Gogs you may have to remove any reference to Gogs within the gitea-repositories/*.git/hooks/*.d directories.

It really is simpler not to change the name of the binary.

@zeripath commented on GitHub (Nov 1, 2019): yeah that would need changing too if you changed the path of the gitea binary. To be clear Gitea has to write its real full path to: * `gitea-repositories/*.git/hooks/pre-receive.d/gitea` * `gitea-repositories/*.git/hooks/update.d/gitea` * `gitea-repositories/*.git/hooks/post-receive.d/gitea` * `.ssh/authorized_keys` (if you are not using the internal SSH or an AuthorizedKeysCommand) These all have to be updated if you change the path of the Gitea binary. If you are moving from Gogs you may have to remove any reference to Gogs within the `gitea-repositories/*.git/hooks/*.d` directories. It really is simpler not to change the name of the binary.

GiteaMirror commented

@randyesq commented on GitHub (Nov 1, 2019):

We encountered this issue in a K8S pod using v1.9.3 today.

@randyesq commented on GitHub (Nov 1, 2019): We encountered this issue in a K8S pod using v1.9.3 today.

GiteaMirror commented

@zeripath commented on GitHub (Nov 1, 2019):

@randyesq in order to diagnose I need to see what the message underlying that was and what your main Gitea logs show.

The problem here as originally stated cannot happen on 1.9 because those internal endpoints do not exist. I deleted them - (and now constantly regret doing so instead of coming up with an error saying you need to update although I remain uncertain how that helpful that would be as it could only be on the server.)

If your Gitea serv is requesting those end points e.g. /api/internal/branch/1/mfisch then you have got an old version of Gitea running somewhere and you need to do hunt it down.

Otherwise it's a different problem.

@zeripath commented on GitHub (Nov 1, 2019): @randyesq in order to diagnose I need to see what the message underlying that was and what your main Gitea logs show. The problem here as originally stated _cannot_ happen on 1.9 because those internal endpoints do not exist. I deleted them - (and now constantly regret doing so instead of coming up with an error saying you need to update although I remain uncertain how that helpful that would be as it could only be on the server.) If your Gitea serv is requesting those end points e.g. `/api/internal/branch/1/mfisch` then you have got an old version of Gitea running somewhere and you need to do hunt it down. Otherwise it's a different problem.

GiteaMirror commented

@randyesq commented on GitHub (Nov 2, 2019):

Here is the version of gitea that we are using:

ncn-w001:~/k8s # kubectl exec -it gitea-vcs-5df75f48f7-h8rx7 -n services bash
Defaulting container name to vcs.
Use 'kubectl describe pod/gitea-vcs-5df75f48f7-h8rx7 -n services' to see all of the containers in this pod.
bash-5.0# gitea --version
Gitea version 1.9.3 built with GNU Make 4.2.1, go1.12.9 : bindata, sqlite, sqlite_unlock_notify

Unfortunately, I don't have the server logs because they have rolled over since, but the output from the git client that was trying to force push the branch was:

    Total 12 (delta 2), reused 0 (delta 0)
    remote: Gitea: EOF
    To https://api-gw-service-nmn.local/vcs/cray/config-management.git
     ! [remote rejected] cray/cme-premium/1.1.0 -> cray/cme-premium/1.1.0 (pre-receive hook declined)
    error: failed to push some refs to 'https://api-gw-service-nmn.local/vcs/cray/config-management.git'

@randyesq commented on GitHub (Nov 2, 2019): Here is the version of gitea that we are using: ``` ncn-w001:~/k8s # kubectl exec -it gitea-vcs-5df75f48f7-h8rx7 -n services bash Defaulting container name to vcs. Use 'kubectl describe pod/gitea-vcs-5df75f48f7-h8rx7 -n services' to see all of the containers in this pod. bash-5.0# gitea --version Gitea version 1.9.3 built with GNU Make 4.2.1, go1.12.9 : bindata, sqlite, sqlite_unlock_notify ``` Unfortunately, I don't have the server logs because they have rolled over since, but the output from the git client that was trying to force push the branch was: ``` Total 12 (delta 2), reused 0 (delta 0) remote: Gitea: EOF To https://api-gw-service-nmn.local/vcs/cray/config-management.git ! [remote rejected] cray/cme-premium/1.1.0 -> cray/cme-premium/1.1.0 (pre-receive hook declined) error: failed to push some refs to 'https://api-gw-service-nmn.local/vcs/cray/config-management.git' ```

GiteaMirror commented

@zeripath commented on GitHub (Nov 2, 2019):

Without those logs we can't tell you anything.

All you can say is that there was a pre-receive decline - that could be because you were force pushing to a protected branch and that was disallowed although the EOF implies that's not.

It could be a bug in /api/internal/hook/pre-receive or it could be that you've got an old Gitea hanging around that's trying to get to the old endpoints.

This last is the most likely so double check there aren't some seriously old Giteas hanging around and:

Ensure that your .SSH/authorized_keys always refers to the correct version of Gitea if there are multiple versions available, and ensure that your hooks are all doing similarly.

If it happens again grab the logs. If you're getting requests to /api/internal/branch then there's an old Gitea around. If not you've found a bug and we need the logs.

@zeripath commented on GitHub (Nov 2, 2019): Without those logs we can't tell you anything. All you can say is that there was a pre-receive decline - that could be because you were force pushing to a protected branch and that was disallowed although the EOF implies that's not. It could be a bug in /api/internal/hook/pre-receive or it could be that you've got an old Gitea hanging around that's trying to get to the old endpoints. This last is the most likely so double check there aren't some seriously old Giteas hanging around and: Ensure that your .SSH/authorized_keys always refers to the correct version of Gitea if there are multiple versions available, and ensure that your hooks are all doing similarly. If it happens again grab the logs. If you're getting requests to /api/internal/branch then there's an old Gitea around. If not you've found a bug and we need the logs.

GiteaMirror commented

@randyesq commented on GitHub (Nov 4, 2019):

Ensure that your .SSH/authorized_keys always refers to the correct version of Gitea if there are multiple versions available, and ensure that your hooks are all doing similarly.

How do I ensure this?

@randyesq commented on GitHub (Nov 4, 2019): > Ensure that your .SSH/authorized_keys always refers to the correct version of Gitea if there are multiple versions available, and ensure that your hooks are all doing similarly. How do I ensure this?

GiteaMirror commented

@zeripath commented on GitHub (Nov 4, 2019):

The 2 admin tasks described above rewrite both of these things - however I can imagine a deployment style that would make those not work. It's your deployment - you tell me.

All I can say is to run those tasks, make sure there's not a rogue old version of Gitea in your container(s) or an old container still knocking around, and check those files.

If your Gitea serv is requesting /api/internal/branch that Gitea is not version 1.9 and it's out of date.

Further don't put multiple versions of Gitea in your containers. If you're using a script to wrap Gitea you should run Gitea with exec -a the_name_of_the_script as we use the $0 passed to Gitea as its path when writing hooks and authorized_keys.

@zeripath commented on GitHub (Nov 4, 2019): The 2 admin tasks described above rewrite both of these things - however I can imagine a deployment style that would make those not work. It's your deployment - you tell me. All I can say is to run those tasks, make sure there's not a rogue old version of Gitea in your container(s) or an old container still knocking around, and check those files. If your Gitea serv is requesting /api/internal/branch that Gitea is not version 1.9 and it's out of date. Further don't put multiple versions of Gitea in your containers. If you're using a script to wrap Gitea you should run Gitea with exec -a the_name_of_the_script as we use the $0 passed to Gitea as its path when writing hooks and authorized_keys.

GiteaMirror commented

@randyesq commented on GitHub (Nov 4, 2019):

Okay thanks, we only have one version of gitea, whatever is in the gitea/1.9.3 docker image from Docker hub, so I don't think it is a version issue.

@randyesq commented on GitHub (Nov 4, 2019): Okay thanks, we only have one version of gitea, whatever is in the gitea/1.9.3 docker image from Docker hub, so I don't think it is a version issue.

GiteaMirror commented

@lunny commented on GitHub (Nov 5, 2019):

It seems you have a subpath of your domain setting, maybe it's related. https://api-gw-service-nmn.local/vcs/cray/config-management.git.

@lunny commented on GitHub (Nov 5, 2019): It seems you have a subpath of your domain setting, maybe it's related. `https://api-gw-service-nmn.local/vcs/cray/config-management.git`.

GiteaMirror commented

@randyesq commented on GitHub (Nov 7, 2019):

Okay, I had this happen today. I am running v1.9.3 and logged in to the web UI, created an org, created a repo (initialized it with the checkbox), and attempted to create a file in the UI. Here is the server log:

[Macaron] 2019-11-07 20:19:31: Started POST /foo/bar/_new/master/ for 10.47.0.0
2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "passwd", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "diff_view_style", "theme" FROM "user" WHERE "id"=$1 LIMIT 1 []interface {}{1}
2019/11/07 20:19:31 ...s/context/context.go:328:func1() [D] Session ID: 84335f472022f1f8
2019/11/07 20:19:31 ...s/context/context.go:329:func1() [D] CSRF Token: 44JwSeHDqnv5UnglbneRrWs288M6MTU3MzE1Nzg2ODg4NjkxNjc0NA==
2019/11/07 20:19:31 .../xorm/session_raw.go:87:queryRow() [I] [SQL] SELECT count(*) FROM "notification" WHERE (user_id = $1) AND (status = $2) []interface {}{1, 0x1}
2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "passwd", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "diff_view_style", "theme" FROM "user" WHERE "lower_name"=$1 LIMIT 1 []interface {}{"foo"}
2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "owner_id", "lower_name", "name", "description", "website", "default_branch", "num_watches", "num_stars", "num_forks", "num_issues", "num_closed_issues", "num_pulls", "num_closed_pulls", "num_milestones", "num_closed_milestones", "is_private", "is_empty", "is_archived", "is_mirror", "is_fork", "fork_id", "size", "is_fsck_enabled", "close_issues_via_commit_in_any_branch", "topics", "avatar", "created_unix", "updated_unix" FROM "repository" WHERE "owner_id"=$1 AND "lower_name"=$2 LIMIT 1 []interface {}{2, "bar"}
2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "repo_id", "user_id", "mode" FROM "collaboration" WHERE "repo_id"=$1 AND "user_id"=$2 LIMIT 1 []interface {}{2, 1}
2019/11/07 20:19:31 ...xorm/session_find.go:199:noCacheFind() [I] [SQL] SELECT "id", "repo_id", "type", "config", "created_unix" FROM "repo_unit" WHERE (repo_id = $1) []interface {}{2}
2019/11/07 20:19:31 ...s/repo_permission.go:154:func1() [T] Permission Loaded for 824687817488:crayvcs in 824687817696:foo/bar:
	Permissions: AccessMode: 824687818880:owner, 5 Units, 0 UnitsMode(s): [
	Units[0]: ID: 824687817824 RepoID: 824687818160 Type: 824687818912:UnitTypeCode Config: {}
	Units[1]: ID: 824687818256 RepoID: 824687818352 Type: 824687818944:UnitTypeIssues Config: {"EnableTimetracker":true,"AllowOnlyContributorsToTrackTime":true,"EnableDependencies":true}
	Units[2]: ID: 824687818608 RepoID: 824687818640 Type: 824687818976:UnitTypePullRequests Config: {"IgnoreWhitespaceConflicts":false,"AllowMerge":true,"AllowRebase":true,"AllowRebaseMerge":true,"AllowSquash":true}
	Units[3]: ID: 824687818704 RepoID: 824687818736 Type: 824687819008:UnitTypeReleases Config: {}
	Units[4]: ID: 824687818800 RepoID: 824687818832 Type: 824687819040:UnitTypeWiki Config: {} ]
2019/11/07 20:19:31 .../xorm/session_raw.go:87:queryRow() [I] [SQL] SELECT count(*) FROM "release" WHERE repo_id=$1 AND is_draft=$2 []interface {}{2, false}
2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "owner_id", "lower_name", "name", "description", "website", "default_branch", "num_watches", "num_stars", "num_forks", "num_issues", "num_closed_issues", "num_pulls", "num_closed_pulls", "num_milestones", "num_closed_milestones", "is_private", "is_empty", "is_archived", "is_mirror", "is_fork", "fork_id", "size", "is_fsck_enabled", "close_issues_via_commit_in_any_branch", "topics", "avatar", "created_unix", "updated_unix" FROM "repository" WHERE (owner_id=$1 AND fork_id=$2) LIMIT 1 []interface {}{1, 2}
2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "user_id", "repo_id" FROM "watch" WHERE "user_id"=$1 AND "repo_id"=$2 LIMIT 1 []interface {}{1, 2}
2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "uid", "repo_id" FROM "star" WHERE "uid"=$1 AND "repo_id"=$2 LIMIT 1 []interface {}{1, 2}
2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "repo_id", "branch_name", "can_push", "enable_whitelist", "whitelist_user_i_ds", "whitelist_team_i_ds", "enable_merge_whitelist", "merge_whitelist_user_i_ds", "merge_whitelist_team_i_ds", "approvals_whitelist_user_i_ds", "approvals_whitelist_team_i_ds", "required_approvals", "created_unix", "updated_unix" FROM "protected_branch" WHERE "repo_id"=$1 AND "branch_name"=$2 LIMIT 1 []interface {}{2, "master"}
2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "repo_id", "branch_name", "can_push", "enable_whitelist", "whitelist_user_i_ds", "whitelist_team_i_ds", "enable_merge_whitelist", "merge_whitelist_user_i_ds", "merge_whitelist_team_i_ds", "approvals_whitelist_user_i_ds", "approvals_whitelist_team_i_ds", "required_approvals", "created_unix", "updated_unix" FROM "protected_branch" WHERE "repo_id"=$1 AND "branch_name"=$2 LIMIT 1 []interface {}{2, "master"}
[Macaron] 2019-11-07 20:19:31: Started GET / for 127.0.0.1
2019/11/07 20:19:31 ...s/context/context.go:328:func1() [D] Session ID: 9592bbb188ca9a45
2019/11/07 20:19:31 ...s/context/context.go:329:func1() [D] CSRF Token: 21NVKuOMVuEkabb1tuJWO-fXj4M6MTU3MzE1Nzk3MTU2Mjg1ODU1Mg==
2019/11/07 20:19:31 ...s/context/context.go:137:HTML() [D] Template: home
[Macaron] 2019-11-07 20:19:31: Completed GET / 200 OK in 3.384469ms
[Macaron] 2019-11-07 20:19:31: Started GET /api/internal/hook/pre-receive/foo/bar?old=84ae4ffb4f9f503ce796d345a676c800b675aacc&new=db46e075b33bac76664db835e728b2b34384e424&ref=refs%2Fheads%2Fmaster&userID=1&gitObjectDirectory=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&gitAlternativeObjectDirectories=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects&gitQuarantinePath=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&prID=0 for 127.0.0.1
2019/11/07 20:19:31 modules/auth/auth.go:97:CheckOAuthAccessToken() [T] ParseOAuth2Token: signature is invalid
2019/11/07 20:19:31 ...s/context/context.go:328:func1() [D] Session ID: 92c404aa8441d573
2019/11/07 20:19:31 ...s/context/context.go:329:func1() [D] CSRF Token: NMoCu5jvTAQNl_nD2qHisrnfQ9I6MTU3MzE1Nzk3MTc5MDgxMzM4MQ==
[Macaron] 2019-11-07 20:19:31: Completed GET /api/internal/hook/pre-receive/foo/bar?old=84ae4ffb4f9f503ce796d345a676c800b675aacc&new=db46e075b33bac76664db835e728b2b34384e424&ref=refs%2Fheads%2Fmaster&userID=1&gitObjectDirectory=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&gitAlternativeObjectDirectories=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects&gitQuarantinePath=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&prID=0 403 Forbidden in 911.132µs
2019/11/07 20:19:31 ...s/context/context.go:137:HTML() [D] Template: repo/editor/edit
[Macaron] 2019-11-07 20:19:31: Completed POST /foo/bar/_new/master/ 302 Found in 469.152703ms
2019/11/07 20:19:31 ...c/net/http/server.go:3012:logf() [I] http: superfluous response.WriteHeader call from gopkg.in/macaron%2ev1.(*responseWriter).WriteHeader (response_writer.go:59)
[Macaron] 2019-11-07 20:19:31: Started GET /vendor/plugins/simplemde/simplemde.min.css for 10.47.0.0
[Macaron] [Static] Serving /vendor/plugins/simplemde/simplemde.min.css
[Macaron] 2019-11-07 20:19:31: Completed GET /vendor/plugins/simplemde/simplemde.min.css 200 OK in 734.459µs
[Macaron] 2019-11-07 20:19:31: Started GET /vendor/plugins/highlight/github.css for 10.47.0.0
[Macaron] [Static] Serving /vendor/plugins/highlight/github.css
[Macaron] 2019-11-07 20:19:31: Completed GET /vendor/plugins/highlight/github.css 200 OK in 326.641µs
[Macaron] 2019-11-07 20:19:32: Started GET /vendor/plugins/codemirror/mode/yaml/yaml.js for 10.47.0.0
[Macaron] [Static] Serving /vendor/plugins/codemirror/mode/yaml/yaml.js
[Macaron] 2019-11-07 20:19:32: Completed GET /vendor/plugins/codemirror/mode/yaml/yaml.js 200 OK in 358.95µs
[Macaron] 2019-11-07 20:19:32: Started GET /foo/bar/_new/master/site.yml for 10.47.0.0
2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "passwd", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "diff_view_style", "theme" FROM "user" WHERE "id"=$1 LIMIT 1 []interface {}{1}
2019/11/07 20:19:32 ...s/context/context.go:328:func1() [D] Session ID: 84335f472022f1f8
2019/11/07 20:19:32 ...s/context/context.go:329:func1() [D] CSRF Token: 44JwSeHDqnv5UnglbneRrWs288M6MTU3MzE1Nzg2ODg4NjkxNjc0NA==
2019/11/07 20:19:32 .../xorm/session_raw.go:87:queryRow() [I] [SQL] SELECT count(*) FROM "notification" WHERE (user_id = $1) AND (status = $2) []interface {}{1, 0x1}
2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "passwd", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "diff_view_style", "theme" FROM "user" WHERE "lower_name"=$1 LIMIT 1 []interface {}{"foo"}
2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "owner_id", "lower_name", "name", "description", "website", "default_branch", "num_watches", "num_stars", "num_forks", "num_issues", "num_closed_issues", "num_pulls", "num_closed_pulls", "num_milestones", "num_closed_milestones", "is_private", "is_empty", "is_archived", "is_mirror", "is_fork", "fork_id", "size", "is_fsck_enabled", "close_issues_via_commit_in_any_branch", "topics", "avatar", "created_unix", "updated_unix" FROM "repository" WHERE "owner_id"=$1 AND "lower_name"=$2 LIMIT 1 []interface {}{2, "bar"}
2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "repo_id", "user_id", "mode" FROM "collaboration" WHERE "repo_id"=$1 AND "user_id"=$2 LIMIT 1 []interface {}{2, 1}
2019/11/07 20:19:32 ...xorm/session_find.go:199:noCacheFind() [I] [SQL] SELECT "id", "repo_id", "type", "config", "created_unix" FROM "repo_unit" WHERE (repo_id = $1) []interface {}{2}
2019/11/07 20:19:32 ...s/repo_permission.go:154:func1() [T] Permission Loaded for 824707920288:crayvcs in 824707920368:foo/bar:
	Permissions: AccessMode: 824707921584:owner, 5 Units, 0 UnitsMode(s): [
	Units[0]: ID: 824707920560 RepoID: 824707920608 Type: 824707921616:UnitTypeCode Config: {}
	Units[1]: ID: 824707920992 RepoID: 824707921040 Type: 824707921648:UnitTypeIssues Config: {"EnableTimetracker":true,"AllowOnlyContributorsToTrackTime":true,"EnableDependencies":true}
	Units[2]: ID: 824707921136 RepoID: 824707921184 Type: 824707921680:UnitTypePullRequests Config: {"IgnoreWhitespaceConflicts":false,"AllowMerge":true,"AllowRebase":true,"AllowRebaseMerge":true,"AllowSquash":true}
	Units[3]: ID: 824707921344 RepoID: 824707921376 Type: 824707921712:UnitTypeReleases Config: {}
	Units[4]: ID: 824707921440 RepoID: 824707921504 Type: 824707921744:UnitTypeWiki Config: {} ]
2019/11/07 20:19:32 .../xorm/session_raw.go:87:queryRow() [I] [SQL] SELECT count(*) FROM "release" WHERE repo_id=$1 AND is_draft=$2 []interface {}{2, false}
2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "owner_id", "lower_name", "name", "description", "website", "default_branch", "num_watches", "num_stars", "num_forks", "num_issues", "num_closed_issues", "num_pulls", "num_closed_pulls", "num_milestones", "num_closed_milestones", "is_private", "is_empty", "is_archived", "is_mirror", "is_fork", "fork_id", "size", "is_fsck_enabled", "close_issues_via_commit_in_any_branch", "topics", "avatar", "created_unix", "updated_unix" FROM "repository" WHERE (owner_id=$1 AND fork_id=$2) LIMIT 1 []interface {}{1, 2}
2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "user_id", "repo_id" FROM "watch" WHERE "user_id"=$1 AND "repo_id"=$2 LIMIT 1 []interface {}{1, 2}
2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "uid", "repo_id" FROM "star" WHERE "uid"=$1 AND "repo_id"=$2 LIMIT 1 []interface {}{1, 2}
2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "repo_id", "branch_name", "can_push", "enable_whitelist", "whitelist_user_i_ds", "whitelist_team_i_ds", "enable_merge_whitelist", "merge_whitelist_user_i_ds", "merge_whitelist_team_i_ds", "approvals_whitelist_user_i_ds", "approvals_whitelist_team_i_ds", "required_approvals", "created_unix", "updated_unix" FROM "protected_branch" WHERE "repo_id"=$1 AND "branch_name"=$2 LIMIT 1 []interface {}{2, "master"}
2019/11/07 20:19:32 ...s/context/context.go:137:HTML() [D] Template: repo/editor/edit
[Macaron] 2019-11-07 20:19:32: Completed GET /foo/bar/_new/master/site.yml 200 OK in 43.711104ms
[Macaron] 2019-11-07 20:19:32: Started GET /serviceworker.js for 10.47.0.0
2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "passwd", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "diff_view_style", "theme" FROM "user" WHERE "id"=$1 LIMIT 1 []interface {}{1}
2019/11/07 20:19:32 ...s/context/context.go:328:func1() [D] Session ID: 84335f472022f1f8
2019/11/07 20:19:32 ...s/context/context.go:329:func1() [D] CSRF Token: 44JwSeHDqnv5UnglbneRrWs288M6MTU3MzE1Nzg2ODg4NjkxNjc0NA==
2019/11/07 20:19:32 .../xorm/session_raw.go:87:queryRow() [I] [SQL] SELECT count(*) FROM "notification" WHERE (user_id = $1) AND (status = $2) []interface {}{1, 0x1}
[Macaron] 2019-11-07 20:19:32: Completed GET /serviceworker.js 200 OK in 7.783204ms

Looks like

[Macaron] 2019-11-07 20:19:31: Started GET /api/internal/hook/pre-receive/foo/bar?old=84ae4ffb4f9f503ce796d345a676c800b675aacc&new=db46e075b33bac76664db835e728b2b34384e424&ref=refs%2Fheads%2Fmaster&userID=1&gitObjectDirectory=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&gitAlternativeObjectDirectories=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects&gitQuarantinePath=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&prID=0 for 127.0.0.1
2019/11/07 20:19:31 modules/auth/auth.go:97:CheckOAuthAccessToken() [T] ParseOAuth2Token: signature is invalid

is the problem area.

Note, the user is created by the gitea admin CLI when gitea is brought up.

@randyesq commented on GitHub (Nov 7, 2019): Okay, I had this happen today. I am running v1.9.3 and logged in to the web UI, created an org, created a repo (initialized it with the checkbox), and attempted to create a file in the UI. Here is the server log: ``` [Macaron] 2019-11-07 20:19:31: Started POST /foo/bar/_new/master/ for 10.47.0.0 2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "passwd", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "diff_view_style", "theme" FROM "user" WHERE "id"=$1 LIMIT 1 []interface {}{1} 2019/11/07 20:19:31 ...s/context/context.go:328:func1() [D] Session ID: 84335f472022f1f8 2019/11/07 20:19:31 ...s/context/context.go:329:func1() [D] CSRF Token: 44JwSeHDqnv5UnglbneRrWs288M6MTU3MzE1Nzg2ODg4NjkxNjc0NA== 2019/11/07 20:19:31 .../xorm/session_raw.go:87:queryRow() [I] [SQL] SELECT count(*) FROM "notification" WHERE (user_id = $1) AND (status = $2) []interface {}{1, 0x1} 2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "passwd", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "diff_view_style", "theme" FROM "user" WHERE "lower_name"=$1 LIMIT 1 []interface {}{"foo"} 2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "owner_id", "lower_name", "name", "description", "website", "default_branch", "num_watches", "num_stars", "num_forks", "num_issues", "num_closed_issues", "num_pulls", "num_closed_pulls", "num_milestones", "num_closed_milestones", "is_private", "is_empty", "is_archived", "is_mirror", "is_fork", "fork_id", "size", "is_fsck_enabled", "close_issues_via_commit_in_any_branch", "topics", "avatar", "created_unix", "updated_unix" FROM "repository" WHERE "owner_id"=$1 AND "lower_name"=$2 LIMIT 1 []interface {}{2, "bar"} 2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "repo_id", "user_id", "mode" FROM "collaboration" WHERE "repo_id"=$1 AND "user_id"=$2 LIMIT 1 []interface {}{2, 1} 2019/11/07 20:19:31 ...xorm/session_find.go:199:noCacheFind() [I] [SQL] SELECT "id", "repo_id", "type", "config", "created_unix" FROM "repo_unit" WHERE (repo_id = $1) []interface {}{2} 2019/11/07 20:19:31 ...s/repo_permission.go:154:func1() [T] Permission Loaded for 824687817488:crayvcs in 824687817696:foo/bar: Permissions: AccessMode: 824687818880:owner, 5 Units, 0 UnitsMode(s): [ Units[0]: ID: 824687817824 RepoID: 824687818160 Type: 824687818912:UnitTypeCode Config: {} Units[1]: ID: 824687818256 RepoID: 824687818352 Type: 824687818944:UnitTypeIssues Config: {"EnableTimetracker":true,"AllowOnlyContributorsToTrackTime":true,"EnableDependencies":true} Units[2]: ID: 824687818608 RepoID: 824687818640 Type: 824687818976:UnitTypePullRequests Config: {"IgnoreWhitespaceConflicts":false,"AllowMerge":true,"AllowRebase":true,"AllowRebaseMerge":true,"AllowSquash":true} Units[3]: ID: 824687818704 RepoID: 824687818736 Type: 824687819008:UnitTypeReleases Config: {} Units[4]: ID: 824687818800 RepoID: 824687818832 Type: 824687819040:UnitTypeWiki Config: {} ] 2019/11/07 20:19:31 .../xorm/session_raw.go:87:queryRow() [I] [SQL] SELECT count(*) FROM "release" WHERE repo_id=$1 AND is_draft=$2 []interface {}{2, false} 2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "owner_id", "lower_name", "name", "description", "website", "default_branch", "num_watches", "num_stars", "num_forks", "num_issues", "num_closed_issues", "num_pulls", "num_closed_pulls", "num_milestones", "num_closed_milestones", "is_private", "is_empty", "is_archived", "is_mirror", "is_fork", "fork_id", "size", "is_fsck_enabled", "close_issues_via_commit_in_any_branch", "topics", "avatar", "created_unix", "updated_unix" FROM "repository" WHERE (owner_id=$1 AND fork_id=$2) LIMIT 1 []interface {}{1, 2} 2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "user_id", "repo_id" FROM "watch" WHERE "user_id"=$1 AND "repo_id"=$2 LIMIT 1 []interface {}{1, 2} 2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "uid", "repo_id" FROM "star" WHERE "uid"=$1 AND "repo_id"=$2 LIMIT 1 []interface {}{1, 2} 2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "repo_id", "branch_name", "can_push", "enable_whitelist", "whitelist_user_i_ds", "whitelist_team_i_ds", "enable_merge_whitelist", "merge_whitelist_user_i_ds", "merge_whitelist_team_i_ds", "approvals_whitelist_user_i_ds", "approvals_whitelist_team_i_ds", "required_approvals", "created_unix", "updated_unix" FROM "protected_branch" WHERE "repo_id"=$1 AND "branch_name"=$2 LIMIT 1 []interface {}{2, "master"} 2019/11/07 20:19:31 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "repo_id", "branch_name", "can_push", "enable_whitelist", "whitelist_user_i_ds", "whitelist_team_i_ds", "enable_merge_whitelist", "merge_whitelist_user_i_ds", "merge_whitelist_team_i_ds", "approvals_whitelist_user_i_ds", "approvals_whitelist_team_i_ds", "required_approvals", "created_unix", "updated_unix" FROM "protected_branch" WHERE "repo_id"=$1 AND "branch_name"=$2 LIMIT 1 []interface {}{2, "master"} [Macaron] 2019-11-07 20:19:31: Started GET / for 127.0.0.1 2019/11/07 20:19:31 ...s/context/context.go:328:func1() [D] Session ID: 9592bbb188ca9a45 2019/11/07 20:19:31 ...s/context/context.go:329:func1() [D] CSRF Token: 21NVKuOMVuEkabb1tuJWO-fXj4M6MTU3MzE1Nzk3MTU2Mjg1ODU1Mg== 2019/11/07 20:19:31 ...s/context/context.go:137:HTML() [D] Template: home [Macaron] 2019-11-07 20:19:31: Completed GET / 200 OK in 3.384469ms [Macaron] 2019-11-07 20:19:31: Started GET /api/internal/hook/pre-receive/foo/bar?old=84ae4ffb4f9f503ce796d345a676c800b675aacc&new=db46e075b33bac76664db835e728b2b34384e424&ref=refs%2Fheads%2Fmaster&userID=1&gitObjectDirectory=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&gitAlternativeObjectDirectories=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects&gitQuarantinePath=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&prID=0 for 127.0.0.1 2019/11/07 20:19:31 modules/auth/auth.go:97:CheckOAuthAccessToken() [T] ParseOAuth2Token: signature is invalid 2019/11/07 20:19:31 ...s/context/context.go:328:func1() [D] Session ID: 92c404aa8441d573 2019/11/07 20:19:31 ...s/context/context.go:329:func1() [D] CSRF Token: NMoCu5jvTAQNl_nD2qHisrnfQ9I6MTU3MzE1Nzk3MTc5MDgxMzM4MQ== [Macaron] 2019-11-07 20:19:31: Completed GET /api/internal/hook/pre-receive/foo/bar?old=84ae4ffb4f9f503ce796d345a676c800b675aacc&new=db46e075b33bac76664db835e728b2b34384e424&ref=refs%2Fheads%2Fmaster&userID=1&gitObjectDirectory=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&gitAlternativeObjectDirectories=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects&gitQuarantinePath=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&prID=0 403 Forbidden in 911.132µs 2019/11/07 20:19:31 ...s/context/context.go:137:HTML() [D] Template: repo/editor/edit [Macaron] 2019-11-07 20:19:31: Completed POST /foo/bar/_new/master/ 302 Found in 469.152703ms 2019/11/07 20:19:31 ...c/net/http/server.go:3012:logf() [I] http: superfluous response.WriteHeader call from gopkg.in/macaron%2ev1.(*responseWriter).WriteHeader (response_writer.go:59) [Macaron] 2019-11-07 20:19:31: Started GET /vendor/plugins/simplemde/simplemde.min.css for 10.47.0.0 [Macaron] [Static] Serving /vendor/plugins/simplemde/simplemde.min.css [Macaron] 2019-11-07 20:19:31: Completed GET /vendor/plugins/simplemde/simplemde.min.css 200 OK in 734.459µs [Macaron] 2019-11-07 20:19:31: Started GET /vendor/plugins/highlight/github.css for 10.47.0.0 [Macaron] [Static] Serving /vendor/plugins/highlight/github.css [Macaron] 2019-11-07 20:19:31: Completed GET /vendor/plugins/highlight/github.css 200 OK in 326.641µs [Macaron] 2019-11-07 20:19:32: Started GET /vendor/plugins/codemirror/mode/yaml/yaml.js for 10.47.0.0 [Macaron] [Static] Serving /vendor/plugins/codemirror/mode/yaml/yaml.js [Macaron] 2019-11-07 20:19:32: Completed GET /vendor/plugins/codemirror/mode/yaml/yaml.js 200 OK in 358.95µs [Macaron] 2019-11-07 20:19:32: Started GET /foo/bar/_new/master/site.yml for 10.47.0.0 2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "passwd", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "diff_view_style", "theme" FROM "user" WHERE "id"=$1 LIMIT 1 []interface {}{1} 2019/11/07 20:19:32 ...s/context/context.go:328:func1() [D] Session ID: 84335f472022f1f8 2019/11/07 20:19:32 ...s/context/context.go:329:func1() [D] CSRF Token: 44JwSeHDqnv5UnglbneRrWs288M6MTU3MzE1Nzg2ODg4NjkxNjc0NA== 2019/11/07 20:19:32 .../xorm/session_raw.go:87:queryRow() [I] [SQL] SELECT count(*) FROM "notification" WHERE (user_id = $1) AND (status = $2) []interface {}{1, 0x1} 2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "passwd", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "diff_view_style", "theme" FROM "user" WHERE "lower_name"=$1 LIMIT 1 []interface {}{"foo"} 2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "owner_id", "lower_name", "name", "description", "website", "default_branch", "num_watches", "num_stars", "num_forks", "num_issues", "num_closed_issues", "num_pulls", "num_closed_pulls", "num_milestones", "num_closed_milestones", "is_private", "is_empty", "is_archived", "is_mirror", "is_fork", "fork_id", "size", "is_fsck_enabled", "close_issues_via_commit_in_any_branch", "topics", "avatar", "created_unix", "updated_unix" FROM "repository" WHERE "owner_id"=$1 AND "lower_name"=$2 LIMIT 1 []interface {}{2, "bar"} 2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "repo_id", "user_id", "mode" FROM "collaboration" WHERE "repo_id"=$1 AND "user_id"=$2 LIMIT 1 []interface {}{2, 1} 2019/11/07 20:19:32 ...xorm/session_find.go:199:noCacheFind() [I] [SQL] SELECT "id", "repo_id", "type", "config", "created_unix" FROM "repo_unit" WHERE (repo_id = $1) []interface {}{2} 2019/11/07 20:19:32 ...s/repo_permission.go:154:func1() [T] Permission Loaded for 824707920288:crayvcs in 824707920368:foo/bar: Permissions: AccessMode: 824707921584:owner, 5 Units, 0 UnitsMode(s): [ Units[0]: ID: 824707920560 RepoID: 824707920608 Type: 824707921616:UnitTypeCode Config: {} Units[1]: ID: 824707920992 RepoID: 824707921040 Type: 824707921648:UnitTypeIssues Config: {"EnableTimetracker":true,"AllowOnlyContributorsToTrackTime":true,"EnableDependencies":true} Units[2]: ID: 824707921136 RepoID: 824707921184 Type: 824707921680:UnitTypePullRequests Config: {"IgnoreWhitespaceConflicts":false,"AllowMerge":true,"AllowRebase":true,"AllowRebaseMerge":true,"AllowSquash":true} Units[3]: ID: 824707921344 RepoID: 824707921376 Type: 824707921712:UnitTypeReleases Config: {} Units[4]: ID: 824707921440 RepoID: 824707921504 Type: 824707921744:UnitTypeWiki Config: {} ] 2019/11/07 20:19:32 .../xorm/session_raw.go:87:queryRow() [I] [SQL] SELECT count(*) FROM "release" WHERE repo_id=$1 AND is_draft=$2 []interface {}{2, false} 2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "owner_id", "lower_name", "name", "description", "website", "default_branch", "num_watches", "num_stars", "num_forks", "num_issues", "num_closed_issues", "num_pulls", "num_closed_pulls", "num_milestones", "num_closed_milestones", "is_private", "is_empty", "is_archived", "is_mirror", "is_fork", "fork_id", "size", "is_fsck_enabled", "close_issues_via_commit_in_any_branch", "topics", "avatar", "created_unix", "updated_unix" FROM "repository" WHERE (owner_id=$1 AND fork_id=$2) LIMIT 1 []interface {}{1, 2} 2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "user_id", "repo_id" FROM "watch" WHERE "user_id"=$1 AND "repo_id"=$2 LIMIT 1 []interface {}{1, 2} 2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "uid", "repo_id" FROM "star" WHERE "uid"=$1 AND "repo_id"=$2 LIMIT 1 []interface {}{1, 2} 2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "repo_id", "branch_name", "can_push", "enable_whitelist", "whitelist_user_i_ds", "whitelist_team_i_ds", "enable_merge_whitelist", "merge_whitelist_user_i_ds", "merge_whitelist_team_i_ds", "approvals_whitelist_user_i_ds", "approvals_whitelist_team_i_ds", "required_approvals", "created_unix", "updated_unix" FROM "protected_branch" WHERE "repo_id"=$1 AND "branch_name"=$2 LIMIT 1 []interface {}{2, "master"} 2019/11/07 20:19:32 ...s/context/context.go:137:HTML() [D] Template: repo/editor/edit [Macaron] 2019-11-07 20:19:32: Completed GET /foo/bar/_new/master/site.yml 200 OK in 43.711104ms [Macaron] 2019-11-07 20:19:32: Started GET /serviceworker.js for 10.47.0.0 2019/11/07 20:19:32 .../xorm/session_get.go:99:nocacheGet() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "passwd", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "diff_view_style", "theme" FROM "user" WHERE "id"=$1 LIMIT 1 []interface {}{1} 2019/11/07 20:19:32 ...s/context/context.go:328:func1() [D] Session ID: 84335f472022f1f8 2019/11/07 20:19:32 ...s/context/context.go:329:func1() [D] CSRF Token: 44JwSeHDqnv5UnglbneRrWs288M6MTU3MzE1Nzg2ODg4NjkxNjc0NA== 2019/11/07 20:19:32 .../xorm/session_raw.go:87:queryRow() [I] [SQL] SELECT count(*) FROM "notification" WHERE (user_id = $1) AND (status = $2) []interface {}{1, 0x1} [Macaron] 2019-11-07 20:19:32: Completed GET /serviceworker.js 200 OK in 7.783204ms ``` Looks like ``` [Macaron] 2019-11-07 20:19:31: Started GET /api/internal/hook/pre-receive/foo/bar?old=84ae4ffb4f9f503ce796d345a676c800b675aacc&new=db46e075b33bac76664db835e728b2b34384e424&ref=refs%2Fheads%2Fmaster&userID=1&gitObjectDirectory=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&gitAlternativeObjectDirectories=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects&gitQuarantinePath=%2Fdata%2Fgit%2Fgitea-repositories%2Ffoo%2Fbar.git%2F.%2Fobjects%2Fincoming-PfjpLI&prID=0 for 127.0.0.1 2019/11/07 20:19:31 modules/auth/auth.go:97:CheckOAuthAccessToken() [T] ParseOAuth2Token: signature is invalid ``` is the problem area. Note, the user is created by the gitea admin CLI when gitea is brought up.

GiteaMirror commented

4a08d574cf/routers/private/internal.go (L17-L24)

@zeripath commented on GitHub (Nov 8, 2019):

Ok a status forbidden in hook pre-receive code is preceded by a warning.

So the forbidden is happening at:

Meaning that the internal token being passed to the server from the running command is incorrect.

You have different internal tokens - they all have to be the same.

@zeripath commented on GitHub (Nov 8, 2019): Ok a status forbidden in hook pre-receive code is preceded by a warning. So the forbidden is happening at: https://github.com/go-gitea/gitea/blob/4a08d574cf496268b5ceae4fc605e103c870d204/routers/private/internal.go#L17-L24 Meaning that the internal token being passed to the server from the running command is incorrect. You have different internal tokens - they all have to be the same.

GiteaMirror commented

@randyesq commented on GitHub (Nov 11, 2019):

So this action was run from the UI from a logged in user. Are you saying that something that is being done with my configuration of gitea itself is wrong, or something in the UI is wrong?

@randyesq commented on GitHub (Nov 11, 2019): So this action was run from the UI from a logged in user. Are you saying that something that is being done with my configuration of gitea itself is wrong, or something in the UI is wrong?

GiteaMirror commented

4a08d574cf/routers/private/internal.go (L17-L24)

@zeripath commented on GitHub (Nov 11, 2019):

OK, I think it's time I stepped back down to what goes on when you do any git alterations in Gitea.

Say you edit a file to have new content from repo A
Gitea will do a temporary (extremely shallow) clone of the repo A lets call that B.
In B it will create a commit with the new content using git plumbing commands
It will then push to A from the temporary repo B.
It is during that push from B to A that gitea will then run the pre-receive, update and post-receive hooks.
The hooks are actually performed by git itself running a gitea subcommand, gitea hook which then transmits all of its data to the Gitea server.

Now if you go and take a look at one of your gitea-repositories you'll see that the hooks are something like:

❯ cat ~/gitea-repositories/administrator/nonempty.git/hooks/pre-receive.d/gitea                           [20:50:54]
#!/usr/bin/env bash
"/home/zeripath/go/src/code.gitea.io/gitea/gitea" hook --config='/home/zeripath/go/src/code.gitea.io/gitea/custom/conf/app.ini' pre-receive

Note the absolute path to the gitea application that run it, and a config file reference.

The config file reference is important because gitea will not be unlikely to find its config otherwise, in particular it needs the INTERNAL_TOKEN from that app.ini because, well that's the authorization token that gitea hook uses to talk to the server and it needs find the local address for the Gitea server to speak to (That's specifically LOCAL_ROOT_URL, but ROOT_URL, or whatever goes to make that if that's not set.)

Now as I state above, there is no place for a user to get Forbidden in hooks without some more logging except at:

So, when that push is happening the config that the hook files is finding is not correct - either because INTERNAL_TOKEN is not set or the server that hook speaks to over LOCAL_ROOT_URL has a different INTERNAL_TOKEN.

@zeripath commented on GitHub (Nov 11, 2019): OK, I think it's time I stepped back down to what goes on when you do any git alterations in Gitea. * Say you edit a file to have new content from repo A * Gitea will do a temporary (extremely shallow) clone of the repo A lets call that B. * In B it will create a commit with the new content using git plumbing commands * It will then push to A from the temporary repo B. * It is during that push from B to A that gitea will then run the pre-receive, update and post-receive hooks. * The hooks are actually performed by git itself running a gitea subcommand, `gitea hook` which then transmits all of its data to the Gitea server. Now if you go and take a look at one of your gitea-repositories you'll see that the hooks are something like: ``` ❯ cat ~/gitea-repositories/administrator/nonempty.git/hooks/pre-receive.d/gitea [20:50:54] #!/usr/bin/env bash "/home/zeripath/go/src/code.gitea.io/gitea/gitea" hook --config='/home/zeripath/go/src/code.gitea.io/gitea/custom/conf/app.ini' pre-receive ``` Note the absolute path to the gitea application that run it, and a config file reference. The config file reference is important because gitea will not be unlikely to find its config otherwise, in particular it needs the `INTERNAL_TOKEN` from that app.ini because, well that's the authorization token that gitea hook uses to talk to the server and it needs find the local address for the Gitea server to speak to (That's specifically LOCAL_ROOT_URL, but ROOT_URL, or whatever goes to make that if that's not set.) Now as I state above, there is no place for a user to get Forbidden in hooks without some more logging except at: https://github.com/go-gitea/gitea/blob/4a08d574cf496268b5ceae4fc605e103c870d204/routers/private/internal.go#L17-L24 So, when that push is happening the config that the hook files is finding is not correct - either because INTERNAL_TOKEN is not set or the server that hook speaks to over LOCAL_ROOT_URL has a different INTERNAL_TOKEN.

GiteaMirror commented

@randyesq commented on GitHub (Nov 11, 2019):

Is there a way I can modify the pre-receive.d/gitea bash script to print out the values of the INTERNAL_TOKEN that are in play?

@randyesq commented on GitHub (Nov 11, 2019): Is there a way I can modify the `pre-receive.d/gitea` bash script to print out the values of the INTERNAL_TOKEN that are in play?

GiteaMirror commented

@zeripath commented on GitHub (Nov 11, 2019):

A grep of the config file as a hook would do it as far as I can see.

@zeripath commented on GitHub (Nov 11, 2019): A grep of the config file as a hook would do it as far as I can see.

GiteaMirror commented

@randyesq commented on GitHub (Nov 11, 2019):

Where would the output of that hook script end up for me to review?

@randyesq commented on GitHub (Nov 11, 2019): Where would the output of that hook script end up for me to review?

GiteaMirror commented

@zeripath commented on GitHub (Nov 11, 2019):

Stdout from most git hooks is sent directly to the client. Certainly these would do so.

The issue is ensuring that you're getting exactly the same config file as the hook - you could grep/sed it out of the Gitea hook file.

However if you can do all that, I'm not certain just checking hook files and container confs would not work.

If you don't want it to go to the client - one trick is to do a wget to get it into a server log.

@zeripath commented on GitHub (Nov 11, 2019): Stdout from most git hooks is sent directly to the client. Certainly these would do so. The issue is ensuring that you're getting exactly the same config file as the hook - you could grep/sed it out of the Gitea hook file. However if you can do all that, I'm not certain just checking hook files and container confs would not work. If you don't want it to go to the client - one trick is to do a wget to get it into a server log.

GiteaMirror commented

@randyesq commented on GitHub (Nov 11, 2019):

Okay, well the instance for the server logs that I found was running in a VM that I have up that has the same configuration as our regular setup, here is the content of the hook and shows that the app.ini and gitea executable are where I expect them to be:

bash-5.0# cat /data/git/gitea-repositories/foo/bar.git/hooks/pre-receive.d/gitea
#!/usr/bin/env bash
"/app/gitea/gitea" hook --config='/data/gitea/conf/app.ini' pre-receive
bash-5.0# ls -l /app/gitea/gitea
-rwxr-xr-x    1 git      git       62985080 Sep  7 18:02 /app/gitea/gitea
bash-5.0# ls -l /data/gitea/conf/app.ini
-rwxr-xr-x    1 git      git           5793 Nov  7 20:30 /data/gitea/conf/app.ini

My app.ini does not include an INTERNAL_TOKEN when Gitea first starts up, but it looks like Gitea is creating one properly

bash-5.0# grep INTERNAL_TOKEN /data/gitea/conf/app.ini
INTERNAL_TOKEN = eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJuYmYiOjE1NzMxNTg2MDB9.dhqm5QaQFItK3--HV69oW8D3j_8UKkLoN0hn4tqg0pM

LOCAL_ROOT_URL and ROOT_URL are defined as such in the server section of app.ini:

[server]
PROTOCOL                        = http
DOMAIN                          = git-service.local
ROOT_URL                        = https://%(DOMAIN)s/vcs/
HTTP_ADDR                       = 0.0.0.0
HTTP_PORT                       = 3000
LOCAL_ROOT_URL                  = http://localhost:3000/
DISABLE_SSH                     = true
START_SSH_SERVER                = false
SSH_CREATE_AUTHORIZED_KEYS_FILE = false
OFFLINE_MODE                    = true
DISABLE_ROUTER_LOG              = false
APP_DATA_PATH                   = data

Anything you see here look incorrect?

@randyesq commented on GitHub (Nov 11, 2019): Okay, well the instance for the server logs that I found was running in a VM that I have up that has the same configuration as our regular setup, here is the content of the hook and shows that the `app.ini` and `gitea` executable are where I expect them to be: ``` bash-5.0# cat /data/git/gitea-repositories/foo/bar.git/hooks/pre-receive.d/gitea #!/usr/bin/env bash "/app/gitea/gitea" hook --config='/data/gitea/conf/app.ini' pre-receive bash-5.0# ls -l /app/gitea/gitea -rwxr-xr-x 1 git git 62985080 Sep 7 18:02 /app/gitea/gitea bash-5.0# ls -l /data/gitea/conf/app.ini -rwxr-xr-x 1 git git 5793 Nov 7 20:30 /data/gitea/conf/app.ini ``` My `app.ini` does not include an `INTERNAL_TOKEN` when Gitea first starts up, but it looks like Gitea is creating one properly ``` bash-5.0# grep INTERNAL_TOKEN /data/gitea/conf/app.ini INTERNAL_TOKEN = eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJuYmYiOjE1NzMxNTg2MDB9.dhqm5QaQFItK3--HV69oW8D3j_8UKkLoN0hn4tqg0pM ``` `LOCAL_ROOT_URL` and `ROOT_URL` are defined as such in the server section of `app.ini`: ``` [server] PROTOCOL = http DOMAIN = git-service.local ROOT_URL = https://%(DOMAIN)s/vcs/ HTTP_ADDR = 0.0.0.0 HTTP_PORT = 3000 LOCAL_ROOT_URL = http://localhost:3000/ DISABLE_SSH = true START_SSH_SERVER = false SSH_CREATE_AUTHORIZED_KEYS_FILE = false OFFLINE_MODE = true DISABLE_ROUTER_LOG = false APP_DATA_PATH = data ``` Anything you see here look incorrect?

GiteaMirror commented