135 replies to this topic

[Sasha Al'Therin]

Update: I have found two savegames with difference only about one hour of gameplay. One game stutters and the other does not. They are called "stutter test 2" and "stutter free test 2", and can be found by the same link http://dl.dropbox.co...est%20saves.zip

Sasha Al'Therin, you seem to know something about structure of savegames, can you please take a look into those?

There is one personal effect difference. opcode 177 which uses an EFF file called sgkat. that is on your stutter-free and not on your stutter save. else wise the # of stored variables in use is 1780 vs 1996.

These are much closer in comparison. Still if baldur.bcs works fine in the one and not the other then something was introduced to cause the problem.

[Suslik]

There is one personal effect difference. opcode 177 which uses an EFF file called sgkat.

It is a book of warrior which adds proficiency point with katana. Though it is not supposed to be lost in any way, somehow I lost it during that hour of gameplay lol. Though I doubt it can be relevant.

else wise the # of stored variables in use is 1780 vs 1996.

Unfortunately I doubt that DLCTEP/ShadowKeeper can show the theng that causes stuttering. I think it's something inside the cached data which cannot be viewed by such tools.

These are much closer in comparison. Still if baldur.bcs works fine in the one and not the other then something was introduced to cause the problem.

Even more. I'm pretty sure that if I copy all variables from stutter-free save to stuttering one, all effect and, well, everything that shadow keeper is able to import, the stuttering game will still stutter. Because it leaves that hidden cached data untouched.

Edited by Suslik, 13 April 2012 - 05:46 AM.

[Suslik]

Again, one more proof that it is GetGlobal's start stuttering and not anything else:
- if baldur.bcs consists only of a crapload of GetGlobal's() with character names longer than 23 symbols, stuttering game stutters while stutter-free does not.
- if baldur.bcs consists of the same useless crapload of the same GetGlobal's() which do the same nothing but with variables shorter than 23 symbols, neither of games stutter.

Is that not enough for you to believe that it cannot be anything else?

Edited by Suslik, 13 April 2012 - 06:03 AM.

[Sasha Al'Therin]

Infinity Explorer shows more data in .gam files including visited areas (accesses the .sav file) however it will not load either of your two saves. perhaps because I don't have the same setup as you do. That's the real kicker only you and your setup can see what is truly going on. The rest of us can only speculate.

Is that not enough for you to believe that it cannot be anything else?

Not really. If it were to cause the game to stutter at ANY POINT in the unmodified game as well, I'd believe you. The fact that it happens at ONE SPECIFIC POINT in a heavily modded game, I'm still inclined to believe that you've accessed something, activated something in someway that was poorly designed and is causing issues. The fact that you wiped out your baldur.bcs says that whatever the problem is isn't being hindered by a massively huge script. The fact that you narrowed it down to variable name length says that the processing of whatever side issue is unaffected by shorter names.
I'm not saying that the problem ISN'T with baldur.bcs at all, I'm just saying that you've triggered SOMETHING to start all this. That is what needs to be located above all else. What caused it? Other than to keep the 'patient' alive, treating the symptoms isn't going to do a damn bit of good till you find the route cause. So what did you do from stutter-free to stutter? Visit any specific areas, etc...? Anything that you can narrow down to be a potential candidate for introducing the problem...

[Suslik]

The fact that you narrowed it down to variable name length says that the processing of whatever side issue is unaffected by shorter names.

Wait, wha~? It's absolutely fundamental that script execution speed cannot be heavily affected by the only difference of 1 character in variable names. Isn't only proving this principle wrong alone look somewhat.. weird?

I'm not saying that the problem ISN'T with baldur.bcs at all, I'm just saying that you've triggered SOMETHING to start all this.

Of course triggering the game to stutter state when GetGlobal() start lagging is probably caused by some activity in some mod. But who cares which mod triggered the effect which cannot be normally triggered at all? GetGlobal's should be executed with almost the same performance regardless of variable names involved and regardless of what's going on in-game and in other mods.

Using your terminology I do not think it is necessary to find out what exactly caused such sypmtoms, because normally they should never ever be triggered by any scripts, no matter how foul or wrong they are. I think it is possible to prevent such symptoms from from appearing under any circumstances by modifying the executable even without knowing exact conditions what caused them.

So what did you do from stutter-free to stutter? Visit any specific areas, etc...? Anything that you can narrow down to be a potential candidate for introducing the problem...

Nothing specific. I have completed the same quests as I used to complete before, talked to some NPC's that I talked in previous playthroughs. And mind you, it did not introduce stutter before.

Edited by Suslik, 13 April 2012 - 06:29 AM.

[Sasha Al'Therin]

Wait, wha~? It's absolutely fundamental that script execution speed cannot be heavily affected by the only difference of 1 character in variable names? Isn't only proving this principle wrong alone look somewhat.. weird?

One character 1500+ times adds up. You forget that you have to add tons and tons and tons of these blocks for the stutter to appear. You've not stated that 1 block and 1 block alone with a long variable name causes the stutter. If variable name length was the true issue then one block is all it needs not hundreds to thousands of them. The fact the script works without error in a save shortly before the stutter began indicates that it cannot be the fault of baldur.bcs alone. Something else triggered it. You find that, then you'll know the problem and how to address it.

But who cares which mod triggered the effect which cannot be normally triggered at all?

If you don't care what started the problem, you'll never reach a solution. If it is a mod that triggered the problem, that mod author needs to be notified that under certain conditions their mod causes this problem. Could be that you've installed two incompatible mods, a situation that wasn't known by either mod author. There are lots of mods out there which would fall into that category....

I think it is possible to prevent such symptoms from under any circumstances appearing by modifying the executable even without knowing exact conditions what caused them.

And then the problem mutates into something else.

That's the issue with ToBex it modifies the executable, but some mods expect the game to behave in a certain way. If the game engine is manipulated into behaving differently, some mods may react differently and cause unforeseen problems. This is why whenever I play a modded game, I don't rule out anything for being the cause of the problem until I've fully investigated all aspects as much as possible.

You have to repeat the problem in an unmodified game in order to qualify it for being a problem with the game. Since you can't do so (or are unwilling to try), I have to stand my ground and say it's caused by a mod and all this pandering about with baldur.bcs is a waste of time.

Nothing specific. I have completed the same quests as I used to complete before, talked to some NPC's that I talked in previous playthroughs. And mind you, it did not introduce stutter before.

Different mods? Updated mods? ToBex?

Your game tho. do whatever you want with it. I'm done. You've obviously closed off your mind to any other possible reasons and therefore nothing I or anyone else can say will be of use to you.

[Suslik]

One character 1500+ times adds up. You forget that you have to add tons and tons and tons of these blocks for the stutter to appear.

1500 blocks with variable names of length 23 are executed without any noticable lag in "stuttering" save. The same blocks with variable names of length 24 are executed about 100 times slower in the same savegame. You may call me closed off my mind, but I insist that it is not normal.

Edited by Suslik, 13 April 2012 - 07:26 AM.

[Suslik]

I investigated further:

This time I was messing with my two savefiles, removing with NearInfinity stuff from their baldur.gam's.

I have cut out all unnecessary info such as NPC's that are not in party and such. It did not affect stuttering in savegame 2 in any way. Then I started removing global variables in order to reduce the files' size so it would be easier to analyze them. It's impossible to remove multiple GLOBAL variables via Near Infinity/Shadow Keeper, so I had to remove them manually one by one. I have removed about 300 random variables out of "stuttering save" and... It stopped stuttering!

Now I have two savegames with exactly the same character, both savegame are done at exactly the same location, the only difference is that one of those has ~300 variable less than the other. And one stutters in test Baldur.bcs while the other does not.

Why am I so sure that the stuttering game stutters exactly in baldur.bcs and not because of anything else? Because if I cut off my crapload of GetGlobal's(which do not affect execution of any other scripts in any way) from it, it stops stuttering.

Why am I so sure that non-stuttering game actually executes my baldur.bcs? Because I have added DisplayString() at the end of the test baldur.bcs and it is properly shown about 2 times each second.

Maybe that *certain point* when the game starts stuttering is when number of variables in savefile reaches a certain level? Last one is just a suggestion, I have not tried to prove it yet.

Edited by Suslik, 13 April 2012 - 08:11 PM.

[Ascension64]

The hash function h(s) for string variable s of length n (of maximum 32) is:

h(s) = [PI(s[i].p[i] mod t) + SIGMA(s[i].p[i])] mod t
where:
p is the prime function (in this case, the ith prime element of a prime number array)
t is size of the hash table
PI is the multiplicative sum for lower limit i=0 and upper limit i=n-1
SIGMA is the sum for lower limit i=0 and upper limit i=n-1

Anyone recognise this specific hash function? I'm not very good at all the hashing and slashing...

Note, the default values for t are:
-512 for global variables (there are two tables for these, one for GLOBAL variables, another for ?perhaps death variables)
-512 for area variables (there are two tables again, one for MYAREA variables, the other for script variables of all objects in the area)
-16 for creature LOCALS variables

Linear probing is used with step size of 1 to resolve collisions. If the collision is unresolved, the hash table size is doubled (if setting a new variable) or a NULL CVariable is returned (i.e. not found).

Theoretically then, the hash table could get very large with enough collisions, but you would still need to fill 512 variables before the table doubles.

Don't know if any of that helps.

Edited by Ascension64, 14 April 2012 - 01:58 PM.

[Suslik]

Don't know if any of that helps.

Of course it all does!

Can you give me the necessary procedure addresses so that I could try and reverse the slowdown manually please?

Theoretically then, the hash table could get very large with enough collisions, but you would still need to fill 512 variables before the table doubles.

That's a strange hashtable indeed. Am I right that they're using something like this? (pseudocode)

template<typename Key, typename Value>
class HashTable
{
public:
  Value *Find(Key key)
  {
    int bucket = Hash(key)  % table.size();
    for(int i = 0; i < table.size(); i++)
    {
      if(table[(bucket + i ) % table.size()].key == key)
        return &(table[(bucket + i ) % table.size()].value);
    } 
    return 0;
  }
  void Modify(Key key, Value value)
  {
    int bucket = Hash(key)  % table.size();
    for(int i = 0; i < table.size(); i++)
    {
      if(Empty(table[(bucket + i ) % table.size()]) || table[(bucket + i ) % table.size()].key == key)
      {
        table[(bucket + i ) % table.size()].key = key;
        table[(bucket + i ) % table.size()].value = value;
        return;
      }
    } 
    Grow(); //hashtable is full
    Modify(key, value);
  }
private:
  struct Bucket
  {
    Key key;
    Value value;
  }
  std::vector<bucket> table;
}

Why not use more standartish hashtable like:

template<typename Key, typename Value>
class HashTable
{
public:
  Value *Find(Key key)
  {
    int bucket = Hash(key)  % table.size();
    for(auto it = table[bucket].begin(); it != table[bucker].end(); it++)
    {
      if(it->key == key)
        return &(it->value);
    } 
    return 0;
  }
  void Modify(Key key, Value value)
  {
    int bucket = Hash(key)  % table.size();
    for(auto it = table[bucket].begin(); it != table[bucker].end(); it++)
    {
      if(it->key == key)
      {
        it->value = value;
      }
    } 
    table[bucket].push_back(Bucket(key, value));
  }
private:
  struct Bucket
  {
    Key key;
    Value value;
  }
  std::vector<std::list<bucket> > table;
}

In second implementation the size of hashtable is constant and there's no need to enlarge it at all: each bucket grows separately.

Edited by Suslik, 14 April 2012 - 07:35 AM.

[i30817]

Hashtables - if the domain is not limited, as these strings aren't - can't have constant sizes - they are growable datastructures, and that happens when you introduce a new value beyond a certain limit (they also normally need empty buckets, so the limit - normally - depends on the rate of empty buckets)

So the modify function always has a grow subfunction, sometimes others too, like the read function.
Maybe the extra space is being discarded or growing wrong somehow - imagine that they stupidly increased it by +1.

But that wouldn't happen constantly if the program is only "reading" from the table, as Globals does. Unless the check for new growth is more than the actual amount grown (unbelievably stupid mistake though)

Edited by i30817, 14 April 2012 - 08:50 AM.

[Suslik]

I'm going to debug the thing and check what exactly is executed so long. I only need a few basic function addresses from Asc64. I hope the GetGlobal has implementation in binary itself and is not implemented by some other script auxiliary functions.

Edited by Suslik, 14 April 2012 - 08:52 AM.

[i30817]

Oh, i see what you did with the lists Ehhh, that's less efficient supposedly.

BTW, have you heard about cuckoo hashing?
http://en.wikipedia..../Cuckoo_hashing

It's cool if you read much more than you write (like in BGScript i think).

Edited by i30817, 14 April 2012 - 09:03 AM.

[Suslik]

Oh, i see what you did with the lists Ehhh, that's less efficient supposedly.

It's not my invention, it's a hashing algorithm which I supposed was the most popular one. And it provides complexity of add/remove/modify operations of O(n/k) where k is number of buckets and n is number of elements in the table. While n << k it has constant complexity in average case and. Worst case is still O(n) with a degenerated hash function but it is really unlikely to happen irl.

BTW, have you heard about cuckoo hashing?

I have heard of it, but I have never used it myself.

I don't think that it's necessary to change the whole hashing algorithm, since in most cases it works pretty well. By reversing the code I hope to find which conditions cause it to be executed ineffectively and try to avoid them by modifying some constants/doing other minor changes. If it's possible, of course.

Btw, i30817, are you familiar with reversing the binary? Because Asc64 seems busy now and I do not want to distract him and probably I'll have to do it on my own. Since I'm far from being boss at disassembling/decompiling I can definitely use some help.

Edited by Suslik, 14 April 2012 - 10:12 AM.

[i30817]

My approach to see if the cause is the hashtable array being replaced would be to find that Growth function and to insert a breakpoint at that function and check out if it's being invoked before the "stutter" and not being invoked previously to the stutter.

I'm incompetent at both programming and debugging, much less reversing though. My last reversing "accomplishment" was taking ToEE; noting it uses CPython, finding the source of CPython; finding the function in that source that is responsible for jumping from the python dll to the C bindings, making a note of that function name and debugging ToEE with a breakpoint there so i could find the location in the executable of any C-function invoked by the game console, then using that to clarify some "mysterious" function arguments by seeing what the game provides as arguments normally.

Edited by i30817, 14 April 2012 - 11:12 AM.

[Suslik]

I'm a regular C++ programmer myself and even though I can understand disassembled code, it takes a lot of time for me. And I really need the very basic procedure addresses to start with, because debugging the executable "from scratch" is.. well.. difficult. Okay, waiting for Asc64 to give me a kickstart.

Edited by Suslik, 14 April 2012 - 11:11 AM.

[Ascension64]

I just give you the entire definition!
The implementation doesn't appear to be an STL hash_map. It looks custom-made.
Considering that one of your saved games has 1996 variables (need 2 grows to fit them all, I wouldn't be surprised if the original 512 size of the global variables hash table degenerated to O(n) and partly causes the stuttering from too many GetGlobal()).
Forgot to mention earlier above that n is limited to 32.

CVariableMap::CVariableMap(nSize)				   .text 0064A1E0
CVariableMap::~CVariableMap()					   .text 0064A2C7
BOOL CVariableMap::AddVariable(pCVariable)		  .text 0064A2E8
CVariable* CVariableMap::GetVariable(CString sName) .text 0064A709
int CVariableMap::GetHash(CString)				  .text 0064A96E
void CVariableMap::Empty()						  .text 0064AA27
void CVariableMap::MarshalGlobal(arg1, arg2)	    .text 0064AB6E
void CVariableMap::MarshalLocal(cre)			    .text 0064AE43
void CVariableMap::SetSize(int nNewSize)		    .text 0064B23D

Edited by Ascension64, 14 April 2012 - 03:04 PM.

[Suslik]

Awesome! Thanks, Ascension! I'll start reversing the code as soon as I deal with stuff at work.

I'll ask you later if I have any more questions regarding the binary.

Btw have you externalized the whole hashmap code? Is it possible to replace their hashmap with std::hash_map or something similar? Or will it take too long?

Edited by Suslik, 14 April 2012 - 02:16 PM.

[Ascension64]

Btw have you externalized the whole hashmap code? Is it possible to replace their hashmap with std::hash_map or something similar? Or will it take too long?

CVariableMap is of size 8. It is possible to wrap the entire struct so that the ptrArray at 0h points to a std::hash_map and all its member functions are wrapped to utilise the hash_map. One would have to be very careful that no other part of the engine tries to access CVariableMap's members in a public fashion.

Edited by Ascension64, 14 April 2012 - 02:41 PM.

[Suslik]

One would have to be very careful that no other part of the engine tries to access CVariableMap's members in a public fashion.

Indeed, I have not considered this point. But I hope they are good guys and access the class only by public methods.

Unfortunately the last time I tried to add something to TobEx I did not manage to overcome the difficulties with CRT version it should be linked with. But I think I'll try again prior to reversing the disassembly, because replacing their hashmap with a wrapped std::hash_map(or even std::map which has more predictable complexity) sounds way easier.

Btw does CVariableMap have a vtbl pointer?

Thanks for your time!

Edited by Suslik, 14 April 2012 - 03:03 PM.