Author Topic: Script Execution Time  (Read 493 times)

Legacy_Ne0nx3r0

  • Newbie
  • *
  • Posts: 46
  • Karma: +0/-0
Script Execution Time
« on: October 21, 2010, 10:32:21 pm »


               Somewhat out of curiosity, but would using something like:

GetTimeSecond()*1000 + GetTimeMillisecond()

twice and measuring the difference be a fair way to measure a script's execution time? 

Are there better ways? 
               
               

               
            

Legacy_Lightfoot8

  • Hero Member
  • *****
  • Posts: 4797
  • Karma: +0/-0
Script Execution Time
« Reply #1 on: October 21, 2010, 10:46:00 pm »


               I dont see why it would not work.  I do not see where you would need to track the seconds though.  If any of your scripts take a whole second to run you have big problems.  

               
               

               
            

Legacy_Mudeye

  • Full Member
  • ***
  • Posts: 238
  • Karma: +0/-0
Script Execution Time
« Reply #2 on: October 21, 2010, 10:48:25 pm »


               Even milliseconds might be a long time. Probably a lot of scripts will run in less than 1 millisecond.
               
               

               
            

Legacy_Ne0nx3r0

  • Newbie
  • *
  • Posts: 46
  • Karma: +0/-0
Script Execution Time
« Reply #3 on: October 21, 2010, 11:23:42 pm »


               

Lightfoot8 wrote...

I dont see why it would not work.  I do not see where you would need to track the seconds though.  If any of your scripts take a whole second to run you have big problems.  


My thought was if the milliseconds returned 998, then it took four milliseconds, it would return a result like -996. I suppose you could do the math yourself, but it seemed like a good idea at the time.
               
               

               
            

Legacy_Ne0nx3r0

  • Newbie
  • *
  • Posts: 46
  • Karma: +0/-0
Script Execution Time
« Reply #4 on: October 21, 2010, 11:59:20 pm »


               

Mudeye wrote...

Even milliseconds might be a long time. Probably a lot of scripts will run in less than 1 millisecond.


Do the time functions use the time when the script was ran or something?

I tried running a script to copy over 300 items from one object to another then back and it still showed the same milliseconds. Actually no matter what I did it showed 0. Didn't see that coming. 


string sTest = IntToString(GetTimeMillisecond());SendMessageToAllDMs(sTest);
// Random things to do...
string sTest2 = IntToString(GetTimeMillisecond());SendMessageToAllDMs(sTest2);
               
               

               
            

Legacy_Lightfoot8

  • Hero Member
  • *****
  • Posts: 4797
  • Karma: +0/-0
Script Execution Time
« Reply #5 on: October 22, 2010, 12:46:55 am »


               The reason is the script took less then a millisecond to run.  



processors are currently cycling at ranges measuring in GHz   that is 1,000,000,000 cycles per second.

Or one billion cycles per.  With the advent  of branch prediction and out of order instruction execution. the cpu can normally execute one machine instruction per core of the CPU per cycle.  Even  if your  script is running on only one cpu, it would still have to compile to around one million machine instructions for one millisecond to take place.  that is if you CPU is only 1GHz.  If it is a 3 GHz CPU,  you will have to compile to about 3 million instruction for a millisecond to take place.  





Moving items back a forth 300 times will not come close to getting to that point.  



now if you start reading from the disk with Get2DAString calls you may get there.  Or storing things to a DB.
               
               

               
            

Legacy_Ne0nx3r0

  • Newbie
  • *
  • Posts: 46
  • Karma: +0/-0
Script Execution Time
« Reply #6 on: October 22, 2010, 01:01:34 am »


               Well actually they were all being shipped to and from a database; I was testing moving* them to an NPC then to the campaign database; that is interesting though.

2DAs are all cached now though, right?


*copying I suppose is a more accurate term
               
               

               


                     Modifié par Ne0nx3r0, 22 octobre 2010 - 12:09 .
                     
                  


            

Legacy_Lightfoot8

  • Hero Member
  • *****
  • Posts: 4797
  • Karma: +0/-0
Script Execution Time
« Reply #7 on: October 22, 2010, 01:31:46 am »


               With moving them to a NPC and then writing to the DB it is only one block write to the DB.



Also disk drives have some ram.  since your write to the drive was smaller then amount or ram that most drives have, the data would have just been stored on the diskdrives ram letting the drive write it to the disk in its own time.  small reads from the drive will take more time then small writes to the drive. So yes I should have said reading stuff from the DB in the post above.  



and yes 2DA are cached for a time after they are read.  But if they are not used for a time they will have to be loaded again.
               
               

               
            

Legacy_FunkySwerve

  • Hero Member
  • *****
  • Posts: 2325
  • Karma: +0/-0
Script Execution Time
« Reply #8 on: October 22, 2010, 01:57:33 am »


               Why not use NWNX's profiler, or bioware's, if you want to profile? Just shut it down afterwards, to preserve server performance.



2DAs are all cached now though, right?


No, they just upped the number that stay cached, and allowed us to adjust it - I think 10 is default, where it used to be 3. That happened, I suspect, at least partly in response to a thread I posted comparing 2da times to variable and scripted data storage times, showing how unusably slow 2das were unless cached (cached they were fastest), and how 3 was an unworkably small number to cache for applications making serious use of them. There was a question or two from Biowareans in it, anyway. Nowadays 2das are often a great option for mass data storage, though we usually wind up using either NWNX_hashsets or MySQL.



Funky
               
               

               
            

Legacy_FunkySwerve

  • Hero Member
  • *****
  • Posts: 2325
  • Karma: +0/-0
Script Execution Time
« Reply #9 on: October 22, 2010, 01:58:59 am »


               

Lightfoot8 wrote...
and yes 2DA are cached for a time after they are read.  But if they are not used for a time they will have to be loaded again.

I've not heard that anywhere. My understanding, though I could be mistaken, is that the last X stay cached, whre X defaults to 10.

Funky
               
               

               
            

Legacy_Ne0nx3r0

  • Newbie
  • *
  • Posts: 46
  • Karma: +0/-0
Script Execution Time
« Reply #10 on: October 22, 2010, 02:07:54 am »


               Pretty impressive stuff; honestly I was really just curious about a way to compare one way of doing something to another. In the end I suppose it's micro managing, but in web development it's a lot of fun to compare page generation/client side loading times using different methods of caching/etc; so I thought I'd try it in nwn... Too fast for it, I guess ; ).
               
               

               


                     Modifié par Ne0nx3r0, 22 octobre 2010 - 01:09 .
                     
                  


            

Legacy_Lightfoot8

  • Hero Member
  • *****
  • Posts: 4797
  • Karma: +0/-0
Script Execution Time
« Reply #11 on: October 22, 2010, 02:28:31 am »


               

FunkySwerve wrote...

Lightfoot8 wrote...
and yes 2DA are cached for a time after they are read. But if they are not used for a time they will have to be loaded again.

I've not heard that anywhere. My understanding, though I could be mistaken, is that the last X stay cached, whre X defaults to 10.

Funky



You are correct Funky. My for a time = your X other have been accessed. Your description is more accurate then mine.