Thread Tools Display Modes
07/27/15, 04:10 PM   #1
merlight
AddOn Author - Click to view addons
Join Date: Jul 2014
Posts: 671
[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.
 
07/27/15, 04:26 PM   #2
Ayantir
 
Ayantir's Avatar
AddOn Author - Click to view addons
Join Date: Jul 2014
Posts: 1,019
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.
 
07/28/15, 01:47 AM   #3
sirinsidiator
 
sirinsidiator's Avatar
AddOn Author - Click to view addons
Join Date: Apr 2014
Posts: 1,557
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.
 
07/28/15, 05:51 AM   #4
ZOS_ChipHilseberg
ZOS Staff!
Premium Member
Yes this person is from ZeniMax!
Join Date: Oct 2014
Posts: 551
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?
 
07/28/15, 06:03 AM   #5
QuadroTony
Banned
AddOn Author - Click to view addons
Join Date: Apr 2014
Posts: 828
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)
 
07/28/15, 07:40 AM   #6
kerb9729
AddOn Author - Click to view addons
Join Date: Apr 2014
Posts: 56
Originally Posted by QuadroTony View Post
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.
 
07/28/15, 07:47 AM   #7
QuadroTony
Banned
AddOn Author - Click to view addons
Join Date: Apr 2014
Posts: 828
Raetia info hub, Votans settings menu or CharInfo inspector can show you current lua usage

Last edited by QuadroTony : 07/28/15 at 08:04 AM.
 
07/28/15, 07:57 AM   #8
ZOS_ChipHilseberg
ZOS Staff!
Premium Member
Yes this person is from ZeniMax!
Join Date: Oct 2014
Posts: 551
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?
 
07/28/15, 08:30 AM   #9
kerb9729
AddOn Author - Click to view addons
Join Date: Apr 2014
Posts: 56
Something in the logged data that the save routine is interpreting as a table structure delineator maybe?
 
07/28/15, 09:39 AM   #10
merlight
AddOn Author - Click to view addons
Join Date: Jul 2014
Posts: 671
Originally Posted by ZOS_ChipHilseberg View Post
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

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,

Last edited by merlight : 07/28/15 at 09:41 AM.
 
07/28/15, 11:25 AM   #11
ZOS_ChipHilseberg
ZOS Staff!
Premium Member
Yes this person is from ZeniMax!
Join Date: Oct 2014
Posts: 551
Do your samples reflect the indentation of those pieces of code in the file?
 
07/28/15, 11:43 AM   #12
merlight
AddOn Author - Click to view addons
Join Date: Jul 2014
Posts: 671
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.
 
07/28/15, 12:16 PM   #13
ZOS_ChipHilseberg
ZOS Staff!
Premium Member
Yes this person is from ZeniMax!
Join Date: Oct 2014
Posts: 551
If you could, would you email that saved variable file to charles.hilseberg at zenimaxonline dot com.
 
07/28/15, 03:17 PM   #14
circonian
AddOn Author - Click to view addons
Join Date: May 2014
Posts: 613
Originally Posted by sirinsidiator View Post
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.
 
07/28/15, 05:15 PM   #15
merlight
AddOn Author - Click to view addons
Join Date: Jul 2014
Posts: 671
Well, this is embarrassing. 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.
 
07/28/15, 10:34 PM   #16
Randactyl
AddOn Author - Click to view addons
Join Date: Apr 2014
Posts: 251
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.
 
07/28/15, 10:54 PM   #17
Ayantir
 
Ayantir's Avatar
AddOn Author - Click to view addons
Join Date: Jul 2014
Posts: 1,019
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
 
07/29/15, 05:35 AM   #18
ZOS_ChipHilseberg
ZOS Staff!
Premium Member
Yes this person is from ZeniMax!
Join Date: Oct 2014
Posts: 551
Originally Posted by Ayantir View Post
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.
 
08/04/15, 08:34 AM   #19
ZOS_DanBatson
ZOS Staff!
 
ZOS_DanBatson's Avatar
Yes this person is from ZeniMax!
Join Date: Jul 2015
Posts: 169
This has been resolved internally and the fix will be pushed out in the next PTS build. Thanks, everyone!
 
08/09/15, 06:13 PM   #20
merlight
AddOn Author - Click to view addons
Join Date: Jul 2014
Posts: 671
Originally Posted by ZOS_DanBatson View Post
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.
 

ESOUI » Developer Discussions » Bug Reports » [fixed] There's something terribly broken in saving and/or loading SavedVariables

Thread Tools
Display Modes

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

vB code is On
Smilies are On
[IMG] code is On
HTML code is Off