ESOUI

ESOUI (https://www.esoui.com/forums/index.php)
-   Bug Reports (https://www.esoui.com/forums/forumdisplay.php?f=187)
-   -   [fixed] There's something terribly broken in saving and/or loading SavedVariables (https://www.esoui.com/forums/showthread.php?t=4933)

merlight 07/27/15 04:10 PM
[fixed] There's something terribly broken in saving and/or loading SavedVariables
 
Here's a sample of saved vars from a combat log add-on, section for character Sindari, i.e. below ["Default"]["@Account"]
Lua Code:
  1. ["Sindari"] = 
  2. {   
  3.     ["version"] = 2,
  4.     ["combatlog"] = 
  5.     {   
  6.         [20150720] = 
  7.         {   
  8.             [1] = "00:00:00.123 Queued 0 by Sindari to Reine Noir using Light Attack -- ok slot:Light_attack source:Self target:Enemy ptype:Invalid dtype:Flame",
  9.             [2] = "00:00:00.124 Heal 7 by <unknown> to Sindari using <unknown> -- ok slot:Ability source:Mob target:Self ptype:Magicka dtype:Generic",
  10.             [3] = "00:00:00.125 Heal 7 by <unknown> to Sindari using <unknown> -- ok slot:Ability source:Mob target:Self ptype:Magicka dtype:Generic",
  11.             [4] = "00:00:00.415 Hot_tick 594 by <unknown> to Sindari using <unknown> -- ok slot:Ability source:Mob target:Self ptype:Magicka dtype:Generic",
  12.             [5] = "00:00:01.939 Blocked_damage 320 by Sindari to Reine Noir using Crushing Shock -- ok slot:Ability source:Self target:Enemy ptype:Invalid dtype:Flame",
  13.             [6] = "00:00:01.943 Blocked_damage 64 by Sindari to Reine Noir using Befouled Weapon -- ok slot:Ability source:Self target:Enemy ptype:Invalid dtype:Disease",
  14.             [7] = "00:00:01.231 Blocked_damage 311 by Sindari to Reine Noir using Light Attack -- ok slot:Light_attack source:Self target:Enemy ptype:Invalid dtype:Flame",
  15.             [8] = "00:00:01.491 Critical_damage 1062 by Sindari to Reine Noir using Crushing Shock -- ok slot:Ability source:Self target:Enemy ptype:Magicka dtype:Shock",
  16.             [9] = "00:00:01.492 Damage 666 by Sindari to Reine Noir using Crushing Shock -- ok slot:Ability source:Self target:Enemy ptype:Magicka dtype:Cold",

When the log gets really long, more than 10k+ lines, it completely screws the saved vars structure. Here's a sample of the garbage from the same level of the table:
Lua Code:
  1. ["00:23:24.060 unit 'reticleoverplayer' is dead"] = 
  2. {   
  3.     ["version"] = 2,
  4.     ["combatlog"] = 
  5.     {   
  6.     },  
  7. },  
  8. ["00:21:49.585 Damage 237 by Sindari to Aoichan using Caltrops -- ok slot:Ability source:Self target:Enemy ptype:Magicka dtype:Physical"] = 
  9. {   
  10.     ["version"] = 2,
  11. },  
  12. [1385] = 
  13. {   
  14.     ["version"] = 2,
  15.     ["combatlog"] = 
  16.     {   
  17.     },  
  18. },
I don't have a character named 1385, or "00:23:24.060 unit 'reticleoverplayer' is dead". Either the saving or the loading code takes keys and data from deeper parts of the table and places them as keys on the character level. The original structure is not complex, it's a simple array of log messages shown above, nothing else; it's just huge.

Ayantir 07/27/15 04:26 PM
Yeah, I hitted it with pChat at the begenning of Chat restoration (I was dumping whole chat in saved vars).

You should look at mastermerchant way of managing this. I'm also working on a big project which will meet this limit, so i'll try to find a workaround.

Consider that if lua file is > 20MB , it has huge chance to be corrupted. After 32MB , it's 100% corrupted.

Maybe array indexes which can fail after some limit .. 4k or something.

sirinsidiator 07/28/15 01:47 AM
The serialization also fails to recognize recursive table structures and continues to write to your disk until the game crashes.

And I also happened upon a strange bug where my saved vars got cleared randomly when I used 2 separate ones in one file. I tried to find the reason for a long time, but gave up after a month or two.

Deleting an old var is also impossible, because setting it to nil leaves the old data unchanged. The best we get is setting it to an empty table and remove the unused var some versions later once we transferred data over to the new one.

ZOS_ChipHilseberg 07/28/15 05:51 AM
Hmm, that's worrisome. Is there anything I would have to do to repro this other than making a giant array in a saved var?

QuadroTony 07/28/15 06:03 AM
idk but this can be conencted

when you mouseover guild roster players one by one with Shissu guild tools installed your lua usage growing up very fast = memory leak

and you can reach limit fast(for me limit is 1024mb)

kerb9729 07/28/15 07:40 AM
Quote:
Originally Posted by QuadroTony (Post 22314)
idk but this can be conencted

when you mouseover guild roster players one by one with Shissu guild tools installed your lua usage growing up very fast = memory leak

and you can reach limit fast(for me limit is 1024mb)
I think this is a separate issue but -
You sure Shissu guild tools isn't just doing something silly?

What are you using to determine what lua's memory usage is? I've wondered how to do that.

QuadroTony 07/28/15 07:47 AM
Raetia info hub, Votans settings menu or CharInfo inspector can show you current lua usage

ZOS_ChipHilseberg 07/28/15 07:57 AM
I generated a 9MB Saved Vars file with 60000 strings in an array and did not see any corruption. Maybe there is something more to it?

kerb9729 07/28/15 08:30 AM
Something in the logged data that the save routine is interpreting as a table structure delineator maybe?

merlight 07/28/15 09:39 AM
Quote:
Originally Posted by ZOS_ChipHilseberg (Post 22320)
I generated a 9MB Saved Vars file with 60000 strings in an array and did not see any corruption. Maybe there is something more to it?
Yea it's weird. I don't check that file often, not unless I'm specifically looking for something or the add-on spits some error upon load. Right now my file is 19MB / 114k lines. It contains about 10 big arrays, the longest of which is yesterday's 30k lines (i.e. before I posted the above log with the file already corrupted). To me the most surprising thing is that the file is still valid Lua, although keys/data are scrambled.

It may be anything, a combination of array size, number of elements, depth, perhaps Lua memory setting. Or a bug I put in the add-on, that'd be stupid :D

A few years ago I had to patch Apache Flood because they were reading XML in fixed size chunks, and if you had a #text node crossing the read buffer boundary, it got split into two nodes, and the original code wasn't able to match such split nodes to keywords. This looks remotely similar, perhaps there's a point where the SavedVars reader/writer forgets the context and starts reading from the wrong offset / writing wrong data.

In the sample above I showed how data go "upwards", becoming keys in higher level. Here's a sample of the inverse, where a part of the root SavedVars table is flattened and written as values in the lowest level:
Lua Code:
  1. [4543] = "Jamila_SavedVariables",
  2. [4544] = "Default",
  3. [4545] = "@Merlight",
  4. [4546] = "21:32:46.030 Damage 207 by Sindari to Dominion Guard using Caltrops -- ok slot:Ability source:Self target:Mob ptype:Magicka dtype:Physical",
  5. [4547] = "combatlog",
  6. [4548] = "version",
  7. [4549] = 2,
  8. [4550] = 2305,
  9. [4551] = 210,
  10. [4552] = "00:21:49.585 Damage 237 by Sindari to Aoichan using Caltrops -- ok slot:Ability source:Self target:Enemy ptype:Magicka dtype:Physical",
  11. [4553] = "$AccountWide",
  12. [4554] = "00:21:06.574 Heal 767 by <unknown> to Sindari using <unknown> -- ok slot:Ability source:Mob target:Self ptype:Magicka dtype:Generic",
  13. [4555] = 20150724,
  14. [4556] = 1,

ZOS_ChipHilseberg 07/28/15 11:25 AM
Do your samples reflect the indentation of those pieces of code in the file?

merlight 07/28/15 11:43 AM
The 2 in the OP are with 12 leading spaces (3x indent) removed.

The 3rd one is with 24 leading spaces (6x indent) removed, it's the deepest level.

ZOS_ChipHilseberg 07/28/15 12:16 PM
If you could, would you email that saved variable file to charles.hilseberg at zenimaxonline dot com.

circonian 07/28/15 03:17 PM
Quote:
Originally Posted by sirinsidiator (Post 22300)
The serialization also fails to recognize recursive table structures and continues to write to your disk until the game crashes.
I've never had 114k lines, but the only time I've seen this corruption was when I tried to use saved variable data for dataItems in a scroll List.
Lua Code:
  1. local entry = ZO_ScrollList_CreateDataEntry(ROW_TYPE_ID, savedVarDataItem, categoryId)
which creates recursion in the saved variable file. That definitely crashes the game & corrupts the saved variable file.

merlight 07/28/15 05:15 PM
Well, this is embarrassing. :o Instead of publishing a new geeky widget I have for you, I've spent the whole evening creating huge saved vars with varying layouts, up to 300k lines / 80MB, trying to replicate the corruption I'm seeing with the combat log. Without success. It's a tiny add-on my friend had written, and I modified it a bit... two bits, actually... and months ago. You see where this is heading?

Mod #1 is that I do
Lua Code:
  1. charvars = ZO_SavedVars:New("SV", 1, nil, {combatlog = {}})
  2. setmetatable(charvars.combatlog, {__index = autovivify})
  3. -- autovivify is a function that creates nested tables for nonexistent keys

I suspect that when I wrote that, I didn't realize ZO_SavedVars used metatables for the defaults magic; but even taking that into account, I can't see anything wrong with this. I'm simply replacing their metatable with my own, I don't want defaults at that level anyway.

Mod #2 is pruning old logs. Basically I have a flat array of log messages for each day, saved under charvars.combatlog[date]. When the add-on loads, I do
Lua Code:
  1. for date, log in pairs(charvars.combatlog) do
  2.   if date < today - 14 then
  3.     charvars.combatlog[date] = nil
  4.   end
  5. end

For a plain table, modifying/nilling existing keys during traversal is allowed. I'm not quite sure whether it's okay with the metatables from ZO_SavedVars.

Anyway, I cleaned the saved file by hand, and added some checks to the add-on, so that next time it gets corrupted, it'll give a hint. I shall let it keep growing naturally and see.

Randactyl 07/28/15 10:34 PM
Well let's just call it foresight then, merlight!

I noticed nothing was being saved on PTS 2.1 and mentioned it to Ayantir ingame. He figured out that in this patch saved vars switched to ANSI, so files from live would not work as he mentioned in the 2.1 thread.

But I'm having a problem more dire than that - all saved variables seem to be cleared on initial game load.

I tested it with a dummy addon that just saves a few strings to a table.

Steps:

1. Delete all saved variables files
2. Start PTS and load a character
3. Save some data to saved vars
4. Reload UI and notice data was saved
5. Logout
6. Load a character
7. Notice saved variables were deleted

If you take a moment between steps five and six to check the files on disk, you should see that the data is still okay after logout. So the issue must be somewhere in initial game load since /reloadui also doesn't delete the data.

Ayantir 07/28/15 10:54 PM
At character loading, AddonManager create files of Savedvars with 0bytes, like a fopen("w").
For all addons, even disabled ones.

On live thoses files are not created at character loading
And ZO_ingame.lua don't have problem

Thanks :)

ZOS_ChipHilseberg 07/29/15 05:35 AM
Quote:
Originally Posted by Ayantir (Post 22356)
At character loading, AddonManager create files of Savedvars with 0bytes, like a fopen("w").
For all addons, even disabled ones.

On live thoses files are not created at character loading
And ZO_ingame.lua don't have problem

Thanks :)
This I was able to repro internally and a fix is in the works.

ZOS_DanBatson 08/04/15 08:34 AM
This has been resolved internally and the fix will be pushed out in the next PTS build. Thanks, everyone!

merlight 08/09/15 06:13 PM
Quote:
Originally Posted by ZOS_DanBatson (Post 22509)
This has been resolved internally and the fix will be pushed out in the next PTS build. Thanks, everyone!
Do you mean the saved vars truncation issue on the PTS? Because this was originally about mysterious saved vars corruption.

Today I caught it not long after my saved vars got corrupted, and eventually isolated a 20MB/113k lines file, wrapped it in an add-on with a ## SavedVariables directive and no code, and the game reliably destroys the saved vars file (for me at least, although I should probably try with different memory limits). I think it could be more useful than the corrupted saved vars file I sent to Chip earlier.

merlight 08/10/15 09:19 AM
I took a chunk of data from my saved vars and put it in an add-on that throws several copies of that data into saved vars. Here's the add-on: svFailTest.7z

Here are the steps I used to get corrupted saved vars:
  1. disable all other add-ons, enable svFailTest (no saved vars file yet)
  2. login
  3. /svfail
  4. /reloadui
  5. check SavedVariables/svFailTest.lua: mine has 118715 lines / 21802807 bytes
  6. /reloadui
  7. check SavedVariables/svFailTest.lua:
    • if empty (this is an error, too), go to step 3.
    • otherwise look for the string "svFailTestSV"
      for me the corrupted file has 118715 lines / 21595305 bytes (~200k less), and the corruption starts at line 115950

ZOS_DanBatson 08/10/15 04:32 PM
Quote:
Originally Posted by merlight (Post 22615)
Do you mean the saved vars truncation issue on the PTS? Because this was originally about mysterious saved vars corruption.

Today I caught it not long after my saved vars got corrupted, and eventually isolated a 20MB/113k lines file, wrapped it in an add-on with a ## SavedVariables directive and no code, and the game reliably destroys the saved vars file (for me at least, although I should probably try with different memory limits). I think it could be more useful than the corrupted saved vars file I sent to Chip earlier.
Sorry, I meant to have that quote Chip's reply to the post by Ayantir, in regards to the 0 bytes file issue. i hit "Post Reply" instead. Feel free to send your new file to Chip and myself (dan.batson at zenimaxonline dot com).

ZOS_ChipHilseberg 08/18/15 09:57 AM
I made some changes internally to expand the size of the saved variable serialization we can handle from 2^24 characters to 2^32 characters. After doing this the example table you supplied was no longer running out of storage space and I did not see any corruption in the file.

Ayantir 08/18/15 10:24 AM
Many thanks

merlight 08/18/15 07:12 PM
Quote:
Originally Posted by ZOS_ChipHilseberg (Post 22772)
I made some changes internally to expand the size of the saved variable serialization we can handle from 2^24 characters to 2^32 characters. After doing this the example table you supplied was no longer running out of storage space and I did not see any corruption in the file.
Great.

I was curious whether shrinking SavedVars files could speed-up their loading. Currently they're indented with spaces. Typical saved vars from add-ons I have are literally full of spaces. I tried replacing them with tabs (4 spaces -> 1 tab) in files larger than 10k. The results were 23% to 57% smaller (not counting the above-mentioned combat log add-on, which was only 10% because it stores long strings).

sirinsidiator 08/19/15 03:23 AM
We could avoid this problem altogether with a sqlite database.
No more loading everything into memory on ui load and (almost) no data is lost on crashes. ;)
Addons like Harvest Map or Master Merchant would really profit from a database.

QuadroTony 08/19/15 03:40 AM
i like a database idea!!! :banana:
what i must to learn first to create it

Ayantir 08/19/15 04:57 AM
Quote:
Originally Posted by sirinsidiator (Post 22788)
We could avoid this problem altogether with a sqlite database.
No more loading everything into memory on ui load and (almost) no data is lost on crashes. ;)
Addons like Harvest Map or Master Merchant would really profit from a database.
In the road for almost more than a year, but it's a very big and very long and very complicated project. and it's also a big huge time crusher when it'll be in prod so it's coming slowly.

Sasky 08/21/15 10:42 AM
Quote:
Originally Posted by merlight (Post 22782)
Great.

I was curious whether shrinking SavedVars files could speed-up their loading. Currently they're indented with spaces. Typical saved vars from add-ons I have are literally full of spaces. I tried replacing them with tabs (4 spaces -> 1 tab) in files larger than 10k. The results were 23% to 57% smaller (not counting the above-mentioned combat log add-on, which was only 10% because it stores long strings).
Depends on disk access speed, but it'd probably be minor. If disk access is really slow, compressing the SavedVars file before writing could actually speed it up.

Quote:
Originally Posted by sirinsidiator (Post 22788)
We could avoid this problem altogether with a sqlite database.
No more loading everything into memory on ui load and (almost) no data is lost on crashes. ;)
Addons like Harvest Map or Master Merchant would really profit from a database.
Sure, any of the data-oriented addons would benefit from having a partially loaded database. Most addons probably would not benefit really from that, though, and there's also the consideration of structure. Lua tables are extremely unstructured which means the SavedVars are "just use it". A relational database would need to define table structure. Just imagine how many more "SavedVars" threads there'd be with SQL added to it.

Not sure how hard it'd be to integrate Lua drivers with it, but looks like this would be the way to go for ZOS to add SQL support:
http://keplerproject.github.io/luasql/doc/us/
Potentially it could be run under a separate memory pool as well, which would take away a lot of the need to increase the Lua memory limit.

Ayantir 08/21/15 11:08 AM
That's also what i'm doing in background :D

I've chozen a sqlite db because of the hugeness of data to store. MySQL webhostings can't fit it

Sasky 08/23/15 09:43 AM
Quote:
Originally Posted by Ayantir (Post 22869)
I've chozen a sqlite db because of the hugeness of data to store. MySQL webhostings can't fit it
That's more of a problem with the hosting company than any MySQL (or client/server SQL) limitation. AWS for example limits to 2TB per table for MySQL. I'm having a hard time thinking of what could be stored from addons to even hit the GB range.

Also, the SQLite page recommends against using it for client/server interactions. It's appropriate for local managed storage for an application, like if they added SQL support to addons.

Arterion 08/23/15 11:12 AM
The only AddOn I use with a problem is PriceTracker. When its SavedVariables grows to more than 60 MiB, it will eventually save an empty table when it writes to disk. Very glad to hear that the serialization will be improved for 2.1. 2^32 is quite a lot of bytes.

ZOS_ChipHilseberg 09/17/15 09:13 AM
We have official word on the cause of this bug now. The lua virtual machine implementation that we use has a hard limit on the number of string literals that can appear in a single file. The work around for this would be to use multiple saved variable files if one gets too large. It's not optimal, but it's what we have in the short term. There is the potential to auto-split the tables across files in the future, but that won't be for a while and may not be a better solution after we investigate it.

sirinsidiator 09/17/15 10:16 AM
I don't know what exactly happens when you save or load the file, but have you tried to save it in a different form (e.g. JSON) instead of generating and parsing lua code? Splitting saved vars over multiple files sounds complicated and error prone.

merlight 09/17/15 10:52 AM
Quote:
Originally Posted by ZOS_ChipHilseberg (Post 23635)
We have official word on the cause of this bug now. The lua virtual machine implementation that we use has a hard limit on the number of string literals that can appear in a single file. The work around for this would be to use multiple saved variable files if one gets too large. It's not optimal, but it's what we have in the short term. There is the potential to auto-split the tables across files in the future, but that won't be for a while and may not be a better solution after we investigate it.
Wow :eek:

I was wondering why my combat log still gets corrupted after ~3 evenings of PvP, and started to think it might be because I regularly force /quit without waiting those 10s, and thought that events might still be appending to the table while it's being written out.

Anyway, auto-splitting tables sounds like a daunting task. The "LuaON" that goes into saved variables is such a simple subset of Lua (no expressions, keys can only be string/number/boolean, values can also be tables, and that's it) that I think it'd be much simpler to write a custom parser instead of using the limited implementation. With re2c or another simple parser generator, you could probably get it working in a single coffee buff's time (provided you already know the generator).

Fyrakin 09/17/15 11:56 AM
Why not use XML datasets instead?


All times are GMT -6. The time now is 09:02 AM.

vBulletin © 2024, Jelsoft Enterprises Ltd
© 2014 - 2022 MMOUI