Habitica: Clicking tasks rapidly gives you drops then removes them. Are drops being awarded client-side?

[Alys]

_Players who experience this bug do NOT need to comment on this issue. We know it happens for everyone and so we do not need to know which players have noticed it._

---

If you rapidly mark many tasks as complete or hit + many times quickly on a Habit, you appear to be given more drops than you are actually given -- dropped items are removed after a sync.

This implies that drops are being awarded by the client as well as the server, which isn't supposed to happen any more, and which is confusing for those users who don't realise that clicking too quickly results in some clicks not being permanently recorded.

Players can avoid this bug by not clicking tasks too quickly (that also ensures that all clicks are correctly recorded) however we might want to check to see how drops are being awarded.

How to duplicate this (requires write access to a Habitica database):

1. Set a test account to have no dropped items (for easy comparison after testing), a huge perception (for easy gathering of drops) and a zero drop count for the day. For example: "stats.buffs.per":100000,"items.lastDrop": { "count": 0, "date": "2016-07-01T00:00:00.000Z" }, "items.food": {}, "items.hatchingPotions": {}, "items.eggs": {},
2. Sync the browser and confirm that there are no dropped items in the Inventory.
3. Create a Habit (+ or +/-).
4. Spam-click the Habit rapidly until you've seen many drops.
5. Go to the Inventory and note how many dropped items of each kind there are.
6. Click the sync button. Dropped items will disappear.

If you count the drops seen in the notifications (which is possible to do accurately after spam-clicking using the Show All Notifications bookmarklet), you notice that the number of notifications you see is the same as the initial number of items seen in the Inventory (as expected). After a sync, the number of items in the Inventory decreases to match the database's value of items.lastDrop.count.

[SabreCat]

Interesting. Could it be an overload on database writes per time? I.e., does anything _other_ than drops also roll back when you perform this flow?

[Alys]

Yes, it does the usual thing of rolling back gold and XP when you sync, as typical for sync errors. The reason drops are notable is that they're meant to be assigned server-side now.

Although interestingly, I've just checked the history on the Habit and it does record one value for every rapid click, even when gold and drops are rolled back. I haven't noticed that before from sync errors, although of course before API v3, Habits didn't keep a record of every click.

[SabreCat]

Aren't Gold and XP also assigned server side, though? So it could still be both things affected by the same problem.

In the past, it was a case of the server data and the client data conflicting. It could now be a case of the server data and the database data conflicting. If the server doesn't wait for the database round-trip before returning its response to the client, the client could be updated with information the server expects to be saved, but which doesn't actually get written. So the trouble occurs without drops being assigned on the client at all.

[paglias]

XPs and Gold are awarded both on the client and the server with the server being the only source of truth for what goes in the database, so if there's any difference the server value overrides the one on the client.

Drops are definitely awarded only on the server, also because the code has been moved from shared to the server directtory. Not sure what's going on with the notifications, I'll try to investigate tomorrow

[sebastienplat]

I would love to have a look at this, if it's ok ?

[Alys]

@paulwasit You're most welcome to look into this, but it might not be simple to find the cause. Ask here if you run into problems!

[sebastienplat]

OK so I was able to update my profile in mongo.exe to boost my perception, and to locate the API call in the taskServices.js. As @SabreCat said, the notifications occur in userServices.js after the API call is resolved, so I think the issue is server-side. I will keep investigating further.

I had troubles to recreate the bug though: I had to click like a madman for drops to disappear.

I was not able to locate the attribution of coins/XP: I figured it occur by calling $window.habitrpgShared.ops.scoreTask({user: user, task: data.params.task, direction: data.params.direction}, data.params), but where does it lead ?

[khipkin]

The Shared.ops.scoreTask logic is here: https://github.com/HabitRPG/habitrpg/blob/develop/website/common/script/ops/scoreTask.js

[sebastienplat]

I think I know what could cause the issue.

In api-v3/task.js, there is a call to user.fns.randomDrop({task, delta}, req); that links to common/script/fns/randomDrop.

The dropped item is set and added in two places of the user object:

• _tmp.drop
• items.xxx

The user object is then saved to the db and _tmp is included in the returned object resJsonData for the notification.

But what happens when two API calls occur at the same time, for the same category of items (ie. the second one occur before the user object is saved at the end of the first one) ? One will override the other, because instead of pushing the new item to the db, the entire field is updated.

But _tmp.drop will still be added to resJsonData for both calls, hence two notifications.

I have been able to confirm by ensuring a drop for each task completion & ensuring it is always the same item. After syncing, a number of drops is always reduced.

So I will now try to update the save method, to push the new drop instead of overwritting the entire field.

[sebastienplat]

thanks @khipkin !

[SabreCat]

Nice investigation!

[Alys]

@TheHollidayInn is working on concurrency fixes that should help with this and other issues so I'm closing this.