Error 500 on comment creation via API, with sudo #5871

jlecour · 2019-01-27T20:47:08Z

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

Description

I've been using the API to import projects and issues from Redmine/Gitolite to Gitea (it will be open sourced soon).
For a few days I've been using a Gitea instance with a version < 1.7 and it seemed to work really well. I could create issues and comments on repositories, with or without the Sudo header.
It seems that after the 1.7 upgrade I can't use Sudo anymore.
My request fail if I add the HTTP header. I get the same error with the query string parameter.

Examples :

# this one works
curl -v -X POST "https://my-gitea/api/v1/repos/jlecour/tests-redmine-to-gitea/issues/1/comments" -H "accept: application/json" -H "Authorization: token XXX" -H "Content-Type: application/json" -d "{ \"body\": \"comment body\"}"

# this one doesn't work (error 500)
curl -v -X POST "https://my-gitea/api/v1/repos/jlecour/tests-redmine-to-gitea/issues/1/comments" -H "accept: application/json" -H "Authorization: token XXX" -H "Content-Type: application/json" -d "{ \"body\": \"comment body\"}" -H "Sudo: other_user"

Obviously other_user exists and is a collaborator on the repository with Write permission.

In the logs, I only get SQL logs with a failed transaction (ROLLBACK). I've executed each request manually against my database and I get no error, so I guess the faulty request is not logged.

I'm not sure if it's a bug or if I did something wrong.
Is there a way to have more information about the error ?

The text was updated successfully, but these errors were encountered:

jlecour · 2019-01-27T20:54:20Z

I've tried this on try.gitea.org but I can't get to use sudo since I'm not an administrator.

jlecour · 2019-01-27T21:06:46Z

Another strange fact : I can create issues with Sudo (and the same user, on the same repository), but it fails for comments

zeripath · 2019-01-27T21:29:37Z

~~Oo that's interesting... Just tried this on master on my local machine.~~
I can get a 500 if I fail to log in correctly:

[Macaron] 2019-01-27 21:26:23: Started POST /api/v1/repos/administrator/private-with-collaborator/issues/1/comments for 127.0.0.1
[Macaron] PANIC: runtime error: invalid memory address or nil pointer dereference
/usr/lib/go-1.10/src/runtime/panic.go:502 (0x4388f8)
	gopanic: reflectcall(nil, unsafe.Pointer(d.fn), deferArgs(d), uint32(d.siz), uint32(d.siz))
/usr/lib/go-1.10/src/runtime/panic.go:63 (0x43796d)
	panicmem: panic(memoryError)
/usr/lib/go-1.10/src/runtime/signal_unix.go:388 (0x44e879)
	sigpanic: panicmem()
/home/andrew/go/src/code.gitea.io/gitea/routers/api/v1/api.go:88 (0x12a48a2)
	sudo.func1: if ctx.User.IsAdmin {
...

It's de-referencing null because ctx.User isn't actually set ~~anymore~~.

Nasty. ~~I don't understand how the tests didn't pick this up.~~

I've put in a PR to fix this.

zeripath · 2019-01-27T22:07:04Z

OK, I think I've spotted a different bug, because I wasn't actually properly logging in... So I was getting a null pointer - which is bad enough to require a patch in itself...

zeripath · 2019-01-27T22:13:42Z

I'm not able to completely replicate your issue on master. Let me check on 1.7.0

jlecour · 2019-01-27T22:18:00Z

Is there a special mode I can run my instance with to help you debug this ?

zeripath · 2019-01-27T22:24:22Z

Hmm... I can't replicate with a valid token. I can get a 500 if the token is invalid though and I've just put a PR in for that. Are you sure that your token is correct?

zeripath · 2019-01-27T22:27:24Z

Is there something special about that issue?

zeripath · 2019-01-27T22:28:28Z

I guess you aren't getting the above nil dereference error?

jlecour · 2019-01-27T22:30:13Z

As far as I can tell, my token is working.
I've been using it to create/delete repositories and issues (with Sudo), add collaborators to a repository…
I just can't post a comment with Sudo :/

zeripath · 2019-01-27T22:32:07Z

If you're getting a ROLLBACK then something is causing a conflict in the database - which is very odd.

jlecour · 2019-01-27T22:33:50Z

It's working perfectly with 1.6.3 but not with 1.7.0.

zeripath · 2019-01-27T22:36:24Z

I suspect its something to do with my fixing of deadlocks patches. There's a cascade of actions that come after the creation of an issue comment. I wonder if one of them isn't working within the session...

jlecour · 2019-01-27T22:37:23Z

It's also OK with 1.6.4.

zeripath · 2019-01-27T22:43:28Z

OK presumably the conflict is occurring in here: https://github.com/go-gitea/gitea/blob/master/models/issue_comment.go#L544

zeripath · 2019-01-27T22:44:17Z

Do you have watchers on your issue or have webhooks?

jlecour · 2019-01-27T22:47:21Z

No watchers on the comment.
Since it's an import job from another code hosting system, the issue is created and the comments are added right after that.

There is also no webhooks nor Git hooks.

zeripath · 2019-01-27T22:49:24Z

There's nothing trying to post at the same time is there? Maybe you're both trying to post at the same time although there really should be an error thrown back to you.

zeripath · 2019-01-27T22:50:00Z

Could you post your db log with the rollback in it? And what dB are you using?

jlecour · 2019-01-27T23:12:34Z

I don't think anything tries to post at the same time. It's a procedural script.

Here is the DB log :

2019/01/28 00:07:32 [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_bare`, `is_mirror`, `is_fork`, `fork_id`, `size`, `is_fsck_enabled`, `topics`, `created_unix`, `updated_unix` FROM `repository` WHERE `id`=? LIMIT 1 []interface {}{90}
2019/01/28 00:07:32 [I] [SQL] SELECT `name` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{11}
2019/01/28 00:07:32 [I] [SQL] SELECT * FROM `user` INNER JOIN issue_assignees ON assignee_id = `user`.id WHERE (issue_assignees.issue_id = ?) []interface {}{2559}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `uid`, `name`, `sha1`, `created_unix`, `updated_unix` FROM `access_token` WHERE `sha1`=? LIMIT 1 []interface {}{"MYTOKEN"}
2019/01/28 00:07:33 [I] [SQL] UPDATE `access_token` SET `uid` = ?, `name` = ?, `sha1` = ?, `updated_unix` = ? WHERE `id`=? []interface {}{11, "remine-to-gitea", "MYTOKEN", 1548630453, 2}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{11}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `lower_name`=? LIMIT 1 []interface {}{"redmine_importer"}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `lower_name`=? LIMIT 1 []interface {}{"jlecour"}
2019/01/28 00:07:33 [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_bare`, `is_mirror`, `is_fork`, `fork_id`, `size`, `is_fsck_enabled`, `topics`, `created_unix`, `updated_unix` FROM `repository` WHERE `owner_id`=? AND `lower_name`=? LIMIT 1 []interface {}{11, "tests-redmine-to-gitea"}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `repo_id`, `type`, `config`, `created_unix` FROM `repo_unit` WHERE (repo_id = ?) []interface {}{90}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `mode` FROM `access` WHERE `user_id`=? AND `repo_id`=? LIMIT 1 []interface {}{20, 90}
2019/01/28 00:07:33 [I] [SQL] BEGIN TRANSACTION
2019/01/28 00:07:33 [I] [SQL] INSERT INTO `issue` (`repo_id`,`index`,`poster_id`,`name`,`content`,`milestone_id`,`priority`,`is_closed`,`is_pull`,`num_comments`,`ref`,`deadline_unix`,`created_unix`,`updated_unix`,`closed_unix`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) []interface {}{90, 6, 20, "Page d'activité / historique", "MY ISSUE", 0, 0, false, false, 0, "", 0, 1548630453, 1548630453, 0}
2019/01/28 00:07:33 [I] [SQL] UPDATE `repository` SET num_issues = num_issues + 1 WHERE id = ? []interface {}{90}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `mode` FROM `access` WHERE (repo_id = ? AND mode >= ?) []interface {}{90, 2}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id` IN (?) []interface {}{20}
2019/01/28 00:07:33 [I] [SQL] INSERT INTO `issue_user` (`uid`, `issue_id`, `is_read`, `is_mentioned`) VALUES (?, ?, ?, ?),(?, ?, ?, ?) []interface {}{20, 2560, false, false, 11, 2560, false, false}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `label` LEFT JOIN issue_label ON issue_label.label_id = label.id WHERE (issue_label.issue_id = ?) ORDER BY `label`.`name` ASC []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `user` INNER JOIN issue_assignees ON assignee_id = `user`.id WHERE (issue_assignees.issue_id = ?) []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `uuid`, `issue_id`, `release_id`, `comment_id`, `name`, `download_count`, `size`, `created_unix` FROM `attachment` WHERE (issue_id = ? AND comment_id = 0) []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `type`, `poster_id`, `issue_id`, `label_id`, `old_milestone_id`, `milestone_id`, `assignee_id`, `removed_assignee`, `old_title`, `new_title`, `dependent_issue_id`, `commit_id`, `line`, `tree_path`, `content`, `patch`, `created_unix`, `updated_unix`, `commit_sha`, `review_id`, `invalidated` FROM `comment` WHERE comment.issue_id=? ORDER BY `comment`.`created_unix` ASC, `comment`.`id` ASC []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] SELECT COALESCE(sum(`time`),0) FROM `tracked_time` WHERE issue_id=? []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `type`, `issue_id`, `comment_id`, `user_id`, `created_unix` FROM `reaction` WHERE reaction.issue_id=? ORDER BY `reaction`.`issue_id` ASC, `reaction`.`comment_id` ASC, `reaction`.`created_unix` ASC, `reaction`.`id` ASC []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] COMMIT
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `watch` INNER JOIN `user` ON `user`.id = `watch`.user_id WHERE (`watch`.repo_id=?) AND (`user`.is_active=?) AND (`user`.prohibit_login=?) []interface {}{90, true, false}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `repo_id`, `index`, `poster_id`, `name`, `content`, `milestone_id`, `priority`, `is_closed`, `is_pull`, `num_comments`, `ref`, `deadline_unix`, `created_unix`, `updated_unix`, `closed_unix` FROM `issue` WHERE `id`=? LIMIT 1 []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] INSERT INTO `action` (`user_id`,`op_type`,`act_user_id`,`repo_id`,`comment_id`,`is_deleted`,`ref_name`,`is_private`,`content`,`created_unix`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) []interface {}{20, 6, 20, 90, 0, false, "", true, "6|Page d'activité / historique", 1548630453}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{11}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `repo_id`, `type`, `config`, `created_unix` FROM `repo_unit` WHERE (repo_id = ?) []interface {}{90}
2019/01/28 00:07:33 [I] [SQL] INSERT INTO `action` (`user_id`,`op_type`,`act_user_id`,`repo_id`,`comment_id`,`is_deleted`,`ref_name`,`is_private`,`content`,`created_unix`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) []interface {}{11, 6, 20, 90, 0, false, "", true, "6|Page d'activité / historique", 1548630453}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `watch` INNER JOIN `user` ON `user`.id = `watch`.user_id WHERE (`watch`.repo_id=?) AND (`user`.is_active=?) AND (`user`.prohibit_login=?) []interface {}{90, true, false}
2019/01/28 00:07:33 [I] [SQL] SELECT DISTINCT `poster_id` FROM `comment` INNER JOIN `user` ON `user`.id = `comment`.poster_id WHERE (`comment`.issue_id = ?) AND (`comment`.type = ?) AND (`user`.is_active = ?) AND (`user`.prohibit_login = ?) []interface {}{2560, 0, true, false}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{20}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `user` INNER JOIN issue_assignees ON assignee_id = `user`.id WHERE (issue_assignees.issue_id = ?) []interface {}{2560}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{11}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `mode` FROM `access` WHERE `user_id`=? AND `repo_id`=? LIMIT 1 []interface {}{20, 90}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `label` LEFT JOIN issue_label ON issue_label.label_id = label.id WHERE (issue_label.issue_id = ?) ORDER BY `label`.`name` ASC []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `user` INNER JOIN issue_assignees ON assignee_id = `user`.id WHERE (issue_assignees.issue_id = ?) []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `repo_id`, `org_id`, `url`, `content_type`, `secret`, `events`, `is_ssl`, `is_active`, `hook_task_type`, `meta`, `last_status`, `created_unix`, `updated_unix` FROM `webhook` WHERE (is_active=?) AND `repo_id`=? []interface {}{true, 90}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `repo_id`, `hook_id`, `uuid`, `type`, `url`, `payload_content`, `content_type`, `event_type`, `is_ssl`, `is_delivered`, `delivered`, `is_succeed`, `request_content`, `response_content` FROM `hook_task` WHERE (repo_id=? AND is_delivered=?) []interface {}{90, false}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `repo_id`, `index`, `poster_id`, `name`, `content`, `milestone_id`, `priority`, `is_closed`, `is_pull`, `num_comments`, `ref`, `deadline_unix`, `created_unix`, `updated_unix`, `closed_unix` FROM `issue` WHERE `id`=? LIMIT 1 []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `label` LEFT JOIN issue_label ON issue_label.label_id = label.id WHERE (issue_label.issue_id = ?) ORDER BY `label`.`name` ASC []interface {}{2560}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{20}
2019/01/28 00:07:33 [I] [SQL] BEGIN TRANSACTION
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `issue_watch` INNER JOIN `user` ON `user`.id = `issue_watch`.user_id WHERE (`issue_watch`.issue_id = ?) AND (`user`.is_active = ?) AND (`user`.prohibit_login = ?) []interface {}{2560, true, false}
2019/01/28 00:07:33 [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_bare`, `is_mirror`, `is_fork`, `fork_id`, `size`, `is_fsck_enabled`, `topics`, `created_unix`, `updated_unix` FROM `repository` WHERE `id`=? LIMIT 1 []interface {}{90}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `watch` INNER JOIN `user` ON `user`.id = `watch`.user_id WHERE (`watch`.repo_id=?) AND (`user`.is_active=?) AND (`user`.prohibit_login=?) []interface {}{90, true, false}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `status`, `source`, `issue_id`, `commit_id`, `updated_by`, `created_unix`, `updated_unix` FROM `notification` WHERE (issue_id = ?) []interface {}{2560}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{11}
2019/01/28 00:07:33 [I] [SQL] SELECT `name` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{11}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `repo_id`, `type`, `config`, `created_unix` FROM `repo_unit` WHERE (repo_id = ?) []interface {}{90}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `user` INNER JOIN issue_assignees ON assignee_id = `user`.id WHERE (issue_assignees.issue_id = ?) []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] INSERT INTO `notification` (`user_id`,`repo_id`,`status`,`source`,`issue_id`,`commit_id`,`updated_by`,`created_unix`,`updated_unix`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?) []interface {}{11, 90, 1, 1, 2560, "", 20, 1548630453, 1548630453}
2019/01/28 00:07:33 [I] [SQL] COMMIT
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `uid`, `name`, `sha1`, `created_unix`, `updated_unix` FROM `access_token` WHERE `sha1`=? LIMIT 1 []interface {}{"MYTOKEN"}
2019/01/28 00:07:33 [I] [SQL] UPDATE `access_token` SET `uid` = ?, `name` = ?, `sha1` = ?, `updated_unix` = ? WHERE `id`=? []interface {}{11, "remine-to-gitea", "MYTOKEN", 1548630453, 2}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{11}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `lower_name`=? LIMIT 1 []interface {}{"redmine_importer"}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `lower_name`=? LIMIT 1 []interface {}{"jlecour"}
2019/01/28 00:07:33 [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_bare`, `is_mirror`, `is_fork`, `fork_id`, `size`, `is_fsck_enabled`, `topics`, `created_unix`, `updated_unix` FROM `repository` WHERE `owner_id`=? AND `lower_name`=? LIMIT 1 []interface {}{11, "tests-redmine-to-gitea"}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `repo_id`, `type`, `config`, `created_unix` FROM `repo_unit` WHERE (repo_id = ?) []interface {}{90}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `mode` FROM `access` WHERE `user_id`=? AND `repo_id`=? LIMIT 1 []interface {}{20, 90}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `repo_id`, `index`, `poster_id`, `name`, `content`, `milestone_id`, `priority`, `is_closed`, `is_pull`, `num_comments`, `ref`, `deadline_unix`, `created_unix`, `updated_unix`, `closed_unix` FROM `issue` WHERE `repo_id`=? AND `index`=? LIMIT 1 []interface {}{90, 6}
2019/01/28 00:07:33 [I] [SQL] BEGIN TRANSACTION
2019/01/28 00:07:33 [I] [SQL] INSERT INTO `comment` (`type`,`poster_id`,`issue_id`,`label_id`,`old_milestone_id`,`milestone_id`,`assignee_id`,`removed_assignee`,`old_title`,`new_title`,`dependent_issue_id`,`commit_id`,`line`,`tree_path`,`content`,`patch`,`created_unix`,`updated_unix`,`commit_sha`,`review_id`,`invalidated`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) []interface {}{0, 20, 2560, 0, 0, 0, 0, false, "", "", 0, 0, 0, "", "MY COMMENT", "", 1548630453, 1548630453, "", 0, false}
2019/01/28 00:07:33 [I] [SQL] UPDATE `issue` SET num_comments=num_comments+1 WHERE id=? []interface {}{2560}
2019/01/28 00:07:33 [I] [SQL] UPDATE `issue` SET `updated_unix` = ? WHERE `id`=? []interface {}{1548630453, 2560}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `watch` INNER JOIN `user` ON `user`.id = `watch`.user_id WHERE (`watch`.repo_id=?) AND (`user`.is_active=?) AND (`user`.prohibit_login=?) []interface {}{90, true, false}
2019/01/28 00:07:33 [I] [SQL] INSERT INTO `action` (`user_id`,`op_type`,`act_user_id`,`repo_id`,`comment_id`,`is_deleted`,`ref_name`,`is_private`,`content`,`created_unix`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) []interface {}{20, 10, 20, 90, 3592, false, "", true, "6|MY COMMENT", 1548630453}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{11}
2019/01/28 00:07:33 [I] [SQL] SELECT `id`, `repo_id`, `type`, `config`, `created_unix` FROM `repo_unit` WHERE (repo_id = ?) []interface {}{90}
2019/01/28 00:07:33 [I] [SQL] INSERT INTO `action` (`user_id`,`op_type`,`act_user_id`,`repo_id`,`comment_id`,`is_deleted`,`ref_name`,`is_private`,`content`,`created_unix`) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) []interface {}{11, 10, 20, 90, 3592, false, "", true, "6|MY COMMENT", 1548630453}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `watch` INNER JOIN `user` ON `user`.id = `watch`.user_id WHERE (`watch`.repo_id=?) AND (`user`.is_active=?) AND (`user`.prohibit_login=?) []interface {}{90, true, false}
2019/01/28 00:07:33 [I] [SQL] SELECT DISTINCT `poster_id` FROM `comment` INNER JOIN `user` ON `user`.id = `comment`.poster_id WHERE (`comment`.issue_id = ?) AND (`comment`.type = ?) AND (`user`.is_active = ?) AND (`user`.prohibit_login = ?) []interface {}{2560, 0, true, false}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{20}
2019/01/28 00:07:33 [I] [SQL] SELECT * FROM `user` INNER JOIN issue_assignees ON assignee_id = `user`.id WHERE (issue_assignees.issue_id = ?) []interface {}{2560}
2019/01/28 00:07:33 [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`, `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`, `description`, `num_teams`, `num_members`, `diff_view_style` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{11}
2019/01/28 00:07:33 [I] [SQL] ROLL BACK

zeripath · 2019-01-27T23:29:27Z

~~Hmm I wonder I don't think this is necessary: https://github.com/go-gitea/gitea/blob/master/models/issue_comment.go#L533~~

~~Does commenting it out make your problem go away?~~

That's necessary

zeripath · 2019-01-27T23:37:17Z

No. It shouldn't be that.

It could be this

gitea/models/repo_watch.go

Line 90 in 6311e4c

act.loadRepo()

That loads the repository outside of the transaction.

jlecour · 2019-01-27T23:38:48Z

Are you asking me to download the source code, comment the If block, recompile and try again?

If so, I need instructions because I’ve never compiled a Go project yet.

zeripath · 2019-01-27T23:39:16Z

You probably have only just started noticing it because I might have missed it in my deadlock fixing set which probably moved the notifyWatchers bit into the transaction.

zeripath · 2019-01-27T23:50:46Z

If you want it fixed today, yes. I'm afraid it's almost midnight here and I'm going to bed. My day job is very different from coding so I won't be able to hack until the evening.

The act.loadRepo() function is defined here:

gitea/models/action.go

Line 117 in 7d65ddf

func (a *Action) loadRepo() {

Go isn't that hard - it's yet another imperative language with a garbage collector. If it helps, up until my first patch in August I had never written a line of it. There's some instructions on Gitea.io. See if you can recruit some help on discord too.

Otherwise I can fix it tomorrow. Hopefully I've identified the right bug so it should be quick to sort.

PS it's no longer a comment out the block btw, the act.loadrepo code needs to be pulled within the transaction by passing the session e in and using that. If no session is available then you can pass in x and it will work.

zeripath · 2019-01-27T23:54:41Z

https://docs.gitea.io/en-us/install-from-source/ is the basic build instructions.

jlecour · 2019-01-28T08:24:45Z

@zeripath Hey, I'm sorry if I was a bit blunt.

I did not expect anything, and certainly not to have it fixed and delivered for free the same day.
I'm very thankful for your quick response to my issue. You took from your limited personal time to help me and that's very appreciated.

I'm not sure that I'll be able to setup a test instance of gitea to try the proposed fix without impacting my production instance. I can stay on 1.6.4 until this is properly investigated and fixed. I will report if I can do more on my side.

Thanks again.

zeripath · 2019-01-28T19:27:34Z

OK, so looking at this again. The act.loadRepo() should be fine - we create it with that set.

What is interesting though is that your xorm.log appears to effectively call notifyWatchers twice.

zeripath · 2019-01-28T19:38:04Z

AHA! It's this https://github.com/go-gitea/gitea/blob/release/v1.7/models/issue_comment.go#L635 - which is not in master.

zeripath · 2019-01-28T19:43:32Z

So #5110 probably silently fixed this issue.

@lunny, do you think it would be reasonable to backport #5110 to v1.7.0 to fix this issue.

@jlecour could you try on latest to see if you can replicate your issue?

jlecour · 2019-01-28T20:45:32Z

@zeripath Good news !

Which commit/tag/branch should I try to compile and run ?

adelowo · 2019-01-28T21:21:53Z

@jlecour Master branch

jlecour · 2019-01-28T22:24:04Z

OK, compiling Gitea was really easy !

I've verified that master doesn't have the bug I've found anymore.

Thanks you @zeripath you've been amazing !

If by any chance you are at FOSDEM in Brussels next weekend, I'd be happy to thank your personally.

zeripath · 2019-01-28T22:30:20Z

No worries. Afraid I won't be at fosdem unfortunately, never been.

I'll have another think about this bug - I suspect that others were likely to be hit by it - it's likely to be in the mail creation scripts but I can't seem to replicate it. Tell me what dB are you using? I guess you've got email switched on too?

jlecour · 2019-01-28T22:34:40Z

I've been using MySQL and yes I have mail notifications enabled.

zeripath · 2019-01-29T21:21:21Z

This is probably actually the bug in #5891 - well when it's backported.

zeripath added the issue/confirmed Issue has been reviewed and confirmed to be present or accepted to be implemented label Jan 27, 2019

zeripath removed the issue/confirmed Issue has been reviewed and confirmed to be present or accepted to be implemented label Jan 27, 2019

jlecour closed this as completed Jan 28, 2019

go-gitea locked and limited conversation to collaborators Nov 24, 2020

Error 500 on comment creation via API, with sudo #5871

Error 500 on comment creation via API, with sudo #5871

Comments

jlecour commented Jan 27, 2019

Description

jlecour commented Jan 27, 2019

jlecour commented Jan 27, 2019

zeripath commented Jan 27, 2019 • edited Loading

zeripath commented Jan 27, 2019

zeripath commented Jan 27, 2019

jlecour commented Jan 27, 2019

zeripath commented Jan 27, 2019

zeripath commented Jan 27, 2019

zeripath commented Jan 27, 2019

jlecour commented Jan 27, 2019

zeripath commented Jan 27, 2019

jlecour commented Jan 27, 2019

zeripath commented Jan 27, 2019 • edited Loading

jlecour commented Jan 27, 2019

zeripath commented Jan 27, 2019

zeripath commented Jan 27, 2019 • edited Loading

jlecour commented Jan 27, 2019

zeripath commented Jan 27, 2019

zeripath commented Jan 27, 2019

jlecour commented Jan 27, 2019

zeripath commented Jan 27, 2019 • edited Loading

zeripath commented Jan 27, 2019

jlecour commented Jan 27, 2019 • edited Loading

zeripath commented Jan 27, 2019

zeripath commented Jan 27, 2019 • edited Loading

zeripath commented Jan 27, 2019

jlecour commented Jan 28, 2019

zeripath commented Jan 28, 2019

zeripath commented Jan 28, 2019

zeripath commented Jan 28, 2019 • edited Loading

jlecour commented Jan 28, 2019

adelowo commented Jan 28, 2019

jlecour commented Jan 28, 2019

zeripath commented Jan 28, 2019

jlecour commented Jan 28, 2019 • edited Loading

zeripath commented Jan 29, 2019

zeripath commented Jan 27, 2019 •

edited

Loading

zeripath commented Jan 27, 2019 •

edited

Loading

zeripath commented Jan 27, 2019 •

edited

Loading

zeripath commented Jan 27, 2019 •

edited

Loading

jlecour commented Jan 27, 2019 •

edited

Loading

zeripath commented Jan 27, 2019 •

edited

Loading

zeripath commented Jan 28, 2019 •

edited

Loading

jlecour commented Jan 28, 2019 •

edited

Loading