bugs

I had a look at my profile today and noticed my play time is abit out of wack..

136years 35 days 3 hours and 14minutes. That's more then a life time :P

Happened to me too: http://bots4.net/profile/60839/Stop

Other known cases:

http://bots4.net/profile/31913/sirop5 http://bots4.net/profile/53943/Mister-Fantastic http://bots4.net/profile/53429/malix6

The "136 year club" as I like to call it :P

Hmm, this is a strange one. I'm kind of stumped. Let me walk through my understanding of the problem to see if this spurs any theories from the community.

As others have noted in another thread, 2^32 is 4294967296 which when interpreted as seconds, is a little over 136 years. In fact, 3 of the 6 affected bots have exactly this "played" value in the database (and the other 3 aren't far off):

mysql> select id, username, played from bots order by played desc limit 10;
+-------+----------------------+------------+
| id    | username             | played     |
+-------+----------------------+------------+
| 31913 | sirop5               | 4294967295 |
| 53429 | malix6               | 4294967295 |
| 53943 | Mister Fantastic     | 4294967295 |
| 44560 | pmmk                 | 4294961282 |
| 29634 | Cosmic               | 4294872423 |
| 53970 | Mrsmith1987          | 4294404011 |
|   174 | Lyrad                |   45123063 |
|   499 | Xerex                |   38604349 |
|   142 | TheCause             |   35537127 |
|  1542 | Eucliwood Hellscythe |   33967368 |
+-------+----------------------+------------+

Here's how "played" currently gets calculated:

• On every page load where you're logged in, a user bookkeeping routine gets executed.
• Among other things, this bookkeeping routine is responsible for incrementing the "played" time for your bot in the database.
• The amount the value is incremented is determined by a function, getIncrementalPlaytimeSeconds().
• getIncrementalPlaytimeSeconds() simply queries the database for your bot's "lastactive" value, then returns "$now - $lastactive".
• "lastactive" is updated by the same bookkeeping routine, always setting its value to "$now".

Also worth noting that getIncrementalPlaytimeSeconds() was introduced on June 12, 2016 as part of a major refactoring of some of the oldest code in the game related to login and authentication. It caused enough subtle problems that about a month later, I made an announcement explaining what I'd done and the context in an effort to encourage folks to be on the lookout for oddities. Given that we're over 6 years into this game's lifetime and this issue just cropped up relatively recently, I'd be willing to bet kudos that the bug was introduced with that June 12, 2016 update. Before that update, most of the logic was effectively the same, with the major exception being that "lastactive" was passed around in the PHP session data instead of read from the database.

Also, my interpretation of "some values are 2^32 exactly, some are just close" is that the bug results in a very large, but not necessarily 2^32, value being returned by getIncrementalPlaytimeSeconds(). So when the bug hits, your "played" value skyrockets. When the bug doesn't hit, your value still creeps upwards like normal, eventually hitting the 2^32 cap.

So based on all this information, I think there are a few possibilities, but none of them seem likely at all, hence me being stumped. Let me know if you have any ideas!

If you have a look at Sicrop5's profile he actually has a photo of his play time and in that photo it says the bot was built 72days ago. Now I'm saying that it was actually built back in 2013 so the bug has been around before the 2016 updates

Oh yeah, that's a great point. I agree that pretty definitively rules out the June 12, 2016 as the source of the problem. Thanks for noticing that!

Good news and bad news...

Good news: This bug is "fixed".

Bad news: This bug isn't really fixed. I just put a hacky solution in where the game won't increment your played time by more than 1 hour (the idle logout period) at a time. It also checks for negative increments in case that was somehow happening too. So that should in theory prevent people from somehow getting 2^32 played time seconds (i.e. ~136.2 years), but I'm not calling this bug truly "fixed" because I still don't understand what causes it - I've only (I hope) mitigated it.

Unfortunately for the 34 affected bots (the list has grown since 2017), the only thing I could really do with their played time was to reset it to 0, so this has been done now. Even if I were to sift through daily backups and get their played times from before the bug impacted them, it would be only a partial estimate since their played time hasn't been tracked properly since then. Here are the affected bots:

mysql> select id, username, played from bots order by played desc limit 100;
+-------+----------------------+------------+
| id    | username             | played     |
+-------+----------------------+------------+
|    17 | Arkuden              | 4294967295 |
| 57686 | Bolt of Zeus         | 4294967295 |
| 53943 | Mister Fantastic     | 4294967295 |
| 31913 | sirop5               | 4294967295 |
| 75898 | Heath The Lion       | 4294967295 |
| 29634 | Cosmic               | 4294967295 |
| 65350 | Bolt of zeusV2       | 4294967295 |
| 51720 | adlolhitlol3         | 4294967295 |
| 60839 | Stop                 | 4294967295 |
| 54463 | Negan                | 4294967295 |
| 53429 | malix6               | 4294967295 |
| 44560 | pmmk                 | 4294967070 |
| 11327 | Mensur               | 4294964593 |
| 52148 | Vic Vinegar          | 4294946086 |
| 61488 | WDK1                 | 4294925533 |
| 69848 | Reaper 17            | 4294925335 |
| 56192 | Scarlett 02          | 4294912585 |
| 52137 | RatSlayer            | 4294911125 |
| 61201 | Mana II              | 4294910927 |
|  5758 | Apex                 | 4294888676 |
| 65233 | Roboto 01            | 4294865880 |
| 61223 | Mana IV              | 4294856388 |
| 63370 | Negan 18             | 4294853208 |
| 61227 | Mana VII             | 4294844739 |
| 61224 | Mana V               | 4294842798 |
| 61226 | Mana VI              | 4294810120 |
| 53472 | Asset 11             | 4294753680 |
| 54607 | Negan 13             | 4294737574 |
| 53505 | Asset 32             | 4294730530 |
| 54465 | Negan 02             | 4294690517 |
| 60870 | ShadowOfDeath 13     | 4294612766 |
| 66308 | ramohj               | 4294478327 |
| 53970 | Mrsmith1987          | 4294404011 |
| 64103 | avalance             | 4293915966 |
|  1542 | Eucliwood Hellscythe |   70714971 |
(snip)