template error in issues list when poster_id is -1

[ashimokawa]

• Gitea version (or commit ref): 1.10.0+14-gc01afd584
• Git version: 2.20.1
• Operating system: Debian 10
• Database:
  • PostgreSQL
  • MySQL
  • MSSQL
  • SQLite
• Can you reproduce the bug at https://try.gitea.io:
  • Yes (provide example URL)
  • No
  • Not relevant
• Log gist:

template: repo/issue/list:236:26: executing "repo/issue/list" at <.Poster.ID>: nil pointer evaluating *models.User.ID

Description

Deleted owners issues sometimes get poster_id=-1 in issue table, leading to a template error in ./templates/repo/issue/list.tmpl in the issue list

This happened for 5 issues on codeberg.org, in an organization where users create one-time accounts for one single interaction, then delete it (I won't comment on that, not my idea), but that fluctuation seems to make the error much more likely.

I am willing to fix the template IF you tell me that -1 is expected, if it is not then we have to find out why poster_id gets set to -1. Or is it rather a bug that deleted users poster_id do NOT get to -1?

[ashimokawa]

I have a hunch:

I could happen when issues, which were created by deleted users get closed by someone in the same organization.

that's not the case 😑

[ashimokawa]

can't reproduce but happens.
Best is probably to clarify how expected behavior for deleted users is regarding -1 vs dangeling user ID.

An admin on try could also query the issue table...

select count(*) from issue where poster_id=-1

[lunny]

If users' id <= 0, then it will be replaced as a ghost user.

[ashimokawa]

@lunny
No if poster_id is -1 the above error will occur in the template

[ashimokawa]

Also dangeling ids will be replaced by ghost, only problem is -1, which keeps occuring.

When I change all -1 to 100000000 the template works

[lunny]

So this should be a bug.

[ashimokawa]

@lunny

Yes, but what is the bug?

1. The template should work with -1 as poster_id, it does not. that's the bug.

If that is true, why does poster_id of deleted users stays intact in issue table except for rare cases where it is set to -1.

OR

2. The bug is that poster_id becomes -1, that should not happen

[techknowlogick]

The poster_id should not be < 0, as template is just saying that it received nil as a user which means that what is being supplied to the template is incorrect. As when ghost is provided that is technically a valid user, so template is ok assuming everything passed to it won’t be nil. If I’m a bit rambly, the -1 id is the bug, not the template.

[ashimokawa]

@techknowlogick
This was exactly my question. I would have provided a PR to make the template work with -1, but now I know better. Thanks 👍 .

It does not happen often but it happens that poster_ids become -1, after a user deletes himself.
I had a look at the code but I did not find the cause. As I said earlier we have users on codeberg who - no kidding - create an account for every single issue, then delete it seconds after opening the issue. I also looked for -1 in the comments table but there was none - only in the issue table.

EDIT:
If you are an admin on try.gitea.io would be cool if you could query the database for -1

[techknowlogick]

@ashimokawa both options work for a solution, just one is better as with template it would just hide the underlying problem.

I just searched gitea.com and try.gitea.io DB and couldn't find any poster_id of -1.

[ashimokawa]

@techknowlogick
Thanks for doing the query!

I also did not change the template locally to be able to see if the problem re-occurs. My workaround to to set the id to some very high magic value for those five entries.

[ashimokawa]

Damn, this just happened again (the same repo from the "I delete my account for every singe interaction" guys).

https://codeberg.org/crimeflare/cloudflare-tor/issues?q=&type=all&sort=&state=closed&labels=0&milestone=0&assignee=0

`
MariaDB [gitea]> select count(*) from issue where poster_id=-1;
+----------+
| count(*) |
+----------+
| 2 |
+----------+
1 row in set (0.001 sec)

`

[mrsdizzie]

OK so the problem here is that .Poster.ID is nil. There might be some confusion over the issue value of poster_id (would be PosterID in template) with the .ID field of the pointer to a *user model contained in Poster value of the issue (or .Poster.ID in the template).

So in your error what is happening is that the ID of the Poster is nil (looks like Poster itself is nil). The template itself doesn't care (or even check) what poster_id of the issue is, however when creating a list of issues Poster ends up nil if the poster_id is <= 0 :

gitea/models/issue_list.go

Lines 98 to 105 in e80fe20

	for _, issue := range issues {
	if issue.PosterID <= 0 {
	continue
	}
	var ok bool
	if issue.Poster, ok = posterMaps[issue.PosterID]; !ok {
	issue.Poster = NewGhostUser()
	}

So you can't really change the template to "deal with -1" because it doesn't have a problem with that directly. The template expects Poster to be a valid pointer to a User model (regular or ghost) as it uses several fields from that *User model directly and if it is nil will fail.

As suggested, poster_id of an issue shouldn't get set to -1 when somebody deletes their account.

I'm unable to reproduce that happening, and it sounds like you are also unable to reproduce but are seeing it happen on the live site somehow.

Do you happen to have any combination of Gitea and SQL logs that suggest if the poster_id was changed from something valid to -1 based on a certain action?

Or if perhaps the issue itself was somehow created with a poster_id of -1 initially?

If not if you could enable that type of logging it should at least be possible to see what sets the poster_id of a particular issue to -1 and hopefully that provides more insight into where to look 👀

[lunny]

OK. Maybe we should

ghostUser := NewGhostUser() 
for _, issue := range issues { 
 	if issue.PosterID <= 0 {
+               issue.Poster = ghostUser
 		continue 
 	} 
 	var ok bool 
 	if issue.Poster, ok = posterMaps[issue.PosterID]; !ok { 
- 		issue.Poster = NewGhostUser() 
+ 		issue.Poster = ghostUser 
 	} 

[mrsdizzie]

@lunny I think that it being set to -1 is a bug that shouldn't happen (maybe it happens in cases where not a ghost user also). The blame for that section says it specifically is written like that to fix a bug:

#1913

But I'm not familiar with it otherwise. I can't see why poster_id should be -1 in the database ever though since deleting a user doesn't seem to change it.

[ashimokawa]

@mrsdizzie

You are right, I cannot reproduce the issue but I see it happening on our instance.
As I said multiple times, it is triggered by a group of people creating throwaway accounts for every single issue comment(!). I guess it makes it more likely to occur. And yes, I am sure that the poster_id changes to -1. To see that I have to enable logging, you are right!

And yes, normally that does not happen! We have many deleted users, I deleted multiple test users myself, normally the poster_id stays an intact, and does not change to -1. But there are these rare cases where it DOES happen. Maybe even the same person triggers it every time, he/she is using tor and creates a new account for every interaction.

I did test a workaround in codeberg-test.org and "fixed" the template by checking if Poster is non-nil, that works, not exactly "allowing -1" but checking for nil.

It is a mystery.

[ashimokawa]

Only occurrence where PosterID is set to -1 implicitly is loadPoster(), any chance that the issue is updated in the database after loadPoster() is called?

gitea/models/issue.go

Lines 156 to 170 in 6e81eaf

	func (issue *Issue) loadPoster(e Engine) (err error) {
	if issue.Poster == nil {
	issue.Poster, err = getUserByID(e, issue.PosterID)
	if err != nil {
	issue.PosterID = -1
	issue.Poster = NewGhostUser()
	if !IsErrUserNotExist(err) {
	return fmt.Errorf("getUserByID.(poster) [%d]: %v", issue.PosterID, err)
	}
	err = nil
	return
	}
	}
	return
	}

[mrsdizzie]

@mrsdizzie

You are right, I cannot reproduce the issue but I see it happening on our instance.
As I said multiple times, it is triggered by a group of people creating throwaway accounts for every single issue comment(!). I guess it makes it more likely to occur. And yes, I am sure that the poster_id changes to -1. To see that I have to enable logging, you are right!

I guess without specific logs and not being able to reproduce with the assumed cause it doesn't seem possible to be sure of anything.

And yes, normally that does not happen! We have many deleted users, I deleted multiple test users myself, normally the poster_id stays an intact, and does not change to -1. But there are these rare cases where it DOES happen. Maybe even the same person triggers it every time, he/she is using tor and creates a new account for every interaction.

It is a mystery.

It should be possible to get specific logs of what is happening and figure it out from there. Anything going into or being changed in the database should have a detailed record and hopefully matching gitea/web logs can provide more information as well.

So there should be some SQL log of the poster_id either being modified or created with -1, and that timestamp should match some sort of Gitea log suggesting an action that triggered it (deleting user, creating issue, something else all together??)

Because there is no code for modifying the poster_id in the delete user function (and nowhere else that I see though certainly possible I am missing it) I'm just as inclined to believe that these issues are somehow being created with a poster_id of -1 rather than the database being modified afterwards -- though again logs should say exactly where this is happening with no need to assume otherwise.

Would be interested to try and get to the bottom of it with those logs if possible

[mrsdizzie]

Only occurrence where PosterID is set to -1 implicitly is loadPoster(), any chance that the issue is updated in the database after loadPoster() is called?

gitea/models/issue.go

Lines 156 to 170 in 6e81eaf

	func (issue *Issue) loadPoster(e Engine) (err error) {
	if issue.Poster == nil {
	issue.Poster, err = getUserByID(e, issue.PosterID)
	if err != nil {
	issue.PosterID = -1
	issue.Poster = NewGhostUser()
	if !IsErrUserNotExist(err) {
	return fmt.Errorf("getUserByID.(poster) [%d]: %v", issue.PosterID, err)
	}
	err = nil
	return
	}
	}
	return
	}

Nothing here directly modifies the database. There is a chance that anything is happening since none of us can reproduce or 100% say why just looking at the code, but the logs will say for sure what does/did happen.

[ashimokawa]

@mrsdizzie

The reason why I believe that it happens afterwards is that it happend after issues got closed, and the time between opening and closing were 3 months for some issues. If it had been -1 upon creation the bug would have been triggered much earlier.

Enough said, we have to do more logging

[ashimokawa]

They did it again. Seems they are using the API:

Here is the howto they wrote:

https://codeberg.org/TESTER/debugyou/issues/16

[ashimokawa]

They closed 10 issues of a deleted user via api, and all poster_ids of these issues became -1.

I did not yet have time to reproduce it, but I assume the bug is

"closing issues opened by now deleted users via API causes poster id to become -1"

[ashimokawa]

@mrsdizzie
@lunny
@techknowlogick
CONFIRMED!
I can reproduce the issue easily, and yes poster_id becomes -1.
Via API (I used gitnex from my phone), close an issue that was opened by a deleted user. That's all.

[ashimokawa]

@mrsdizzie

Here is the log when closing the issue via API.
loadPoster() patches poster id to -1 (see code I pasted above)

Then the issue gets updated (all fields) and then it is set to closed (the two lines below from the xorm log)

This probably also happens when changing the issue in another way via API (not only closing)

2019/12/05 08:48:10 .../xorm/session_raw.go:178:exec() [I] [SQL] UPDATE `issue` SET `repo_id` = ?, `index` = ?, `poster_id` = ?, `original_author` = ?, `original_author_id` = ?, `name` = ?, `content` = ?, `milestone_id` = ?, `priority` = ?, `is_closed` = ?, `is_pull` = ?, `num_comments` = ?, `ref` = ?, `deadline_unix` = ?, `closed_unix` = ?, `is_locked` = ?, `updated_unix` = ? WHERE `id`=? []interface {}{45, 2, -1, "", 0, "sddddsdfdsddddd", "sdfsdfdddd", 0, 0, false, false, 2, "", 0, 0, false, 1575532090, 4408} - took: 321.335µs
2019/12/05 08:48:10 .../xorm/session_raw.go:178:exec() [I] [SQL] UPDATE `issue` SET `is_closed` = ?, `closed_unix` = ?, `updated_unix` = ? WHERE `id`=? []interface {}{true, 1575532090, 1575532090, 4408} - took: 267.86µs

[lunny]

Because loadPoster changed the posterID to -1 if found poster is not there. And when closeing issue, it should not only update issue's status column but not all columns.

[lunny]

@ashimokawa Thanks for your effort!

[ashimokawa]

Keep in mind that closing the issue is only an example, it seems the same happens when changing the issue title (via API)

[6543]

how and why this bug happen in simple terms

1. issue.LoadAttributes() andles deleted users by change some data so UI and is working
2. API issue edit (wich open/close and edit an issue) use this function to load the issue complete into ram
3. at api routine issue values are changed based on json <- the -1 from loadAttributes is now in the object
4. the api safe the in memory issue back to DB -> now we have a wrong falue

solutions

• before write back to DB check if -1 is in poseterID if so load old value into ram ( PR [Backport] [Fix] use default avatar for ghost user (fix 500 error) (#9536) #9537 )
• change how API update an Issue need new function's in model .... (upstream PR Fix #9189 - API Allow only specific Colums to be updated on Issue #9539)
• let the system habdle -1 as ghost user (we need to change some more functions)