Welcome to PenUltima Online. Click to login or register.

POL Performance Guide

This guide assumes you already know how eScript works, so you'll only get an explanation for the profiling commands.
You should at least know everything in Racalac's eScript guide before reading this.


Table of Contents:



Runaway scripts

Apart from "doesn't work", a runaway script is usually the first runtime problem you have to deal with.
I have made an example text command that goes runaway for high parameters, click here to view it.
When computing 10^2 it uses more than 1000 cycles, for 100^2 it's above 100k cycles
Let's say you typed .runawaysquare 1000 and get the following in your console:

[01/12 21:47:36 script.log] Runaway script[3034]: scripts/textcmd/test/runawaysquare.ecl (160000 cycles)
[01/12 21:47:36 script.log]  25: :=
[01/12 21:47:36 script.log]  26: #
[01/12 21:47:37 script.log]  27: local #4
[01/12 21:47:37 script.log]  28: local #2
[01/12 21:47:37 script.log]  29: <
[01/12 21:47:37 script.log] >30: if false goto 42
[01/12 21:47:37 script.log]  31: local #5
[01/12 21:47:38 script.log]  32: 1L
[01/12 21:47:38 script.log]  33: +
[01/12 21:47:38 script.log]  34: local5 :=
[01/12 21:47:38 script.log]  35: local #4

A very nice way to stop the script is to use the test-level command killpid, you type .killpid process_id, which in this case is 3034. (.killpid 3034)
If you've never done this before, trying it to confirm that the script indeed stops might be a good idea, and looking at the killpid source wouldn't hurt either :)

If your scripts go runaway like this, it means something is wrong. If you have to perform very long loops, you should add some sleeps. Let me repeat, there is never a good reason to let scripts go runaway. Ever. And increasing the runaway treshold is just ignoring the problem, not fixing it ;)

Now let's say the runaway is caused by a bug, but you have no idea where it's looping. Having compiled with the -i really helps here, as you can often immediately see where the problem is in the console window:

[01/12 21:56:37 script.log] Runaway script[3037]: scripts/textcmd/test/runawaysquare.ecl (440000 cycles)
[01/12 21:56:37 script.log]  31: :=
[01/12 21:56:37 script.log]  32: #
[01/12 21:56:37 script.log]  33: local #4
[01/12 21:56:37 script.log]  34: local #2
[01/12 21:56:37 script.log]  35: <
[01/12 21:56:37 script.log] >36: if false goto 49
[01/12 21:56:38 script.log]  37: [sum := sum + 1;]
[01/12 21:56:38 script.log]  38: local #5
[01/12 21:56:38 script.log]  39: 1L
[01/12 21:56:38 script.log]  40: +
[01/12 21:56:38 script.log]  41: local5 :=

(This is the same place as last time, but compiled with -i and you see a source code line listed as instruction 37 (as you can see this increases length of a script, so you shouldn't use the -i script in a completed and debugged script!)
You're not always lucky enough to get a source code line in the runaway dump though, and then you have to find the corresponding code line manually:
The first thing you do is to generate a source listing (ecompile -l runawaysquare.src). The complete listing for runawaysquare.lst file you get is available here.

I find the following around the "30: if false goto 49" line:

for (b := 0; b < i; b := b + 1)
23: local #4
24: 0L
25: :=
26: #
27: local #4
28: local #2
29: <
30: if false goto 42
sum := sum + 1;
31: local #5
32: 1L
33: +
34: local5 :=
35: local #4
36: local #4
37: 1L
38: +
39: :=
40: #
41: goto27

Here's the same information as with the -i switch, and you can move up and down the ecl file as you please :)
The lines with numbers in front are the same as the ones you see on the console (or the ScriptExRef PC if you need it from a script)
The ones without numbers in front are lines from your source code. All your lines may not be including, for instance there's no "endfor" in the above list, but you should get enough to figure out where it happens.


















polcore()


This section is about the polcore() commands, most of them are only listed with name + a short description, but they're all used in this example code.

polcore().uptime
Returns the system uptime in seconds. Only really useful for checking how long the system takes to start up really, since ReadGameClock should be used to measure intervals

polcore().sysload
polcore().sysload_severity
Returns the sysload as a percentage (0-100) or as severity (raw number, 0->). Good to check every couple of minutes, so you can tell if something's very wrong. The percentage value is more useful since actual load is hard to tell from the raw value.

polcore().bytes_sent
polcore().bytes_received
Returns the number of bytes sent/received. Good to know if you have enough bandwidth (store the old value and display the difference every minute). Can also let you know if someone's trying to flood you, though it doesn't tell you who.

polcore().itemcount
polcore().mobilecount
Returns total number of items/mobiles. Could check that items dont increase too fast, and that the number of mobiles stays apporoximately the same.

polcore().instr_per_min
polcore().events_per_min
polcore().combat_operations_per_min
polcore().skill_checks_per_min
Returns the total number of instructions/events/combat operations/skill checks on the shard during the last minute. This can vary quite a lot, but doesn't hurt to check

polcore().script_profiles
polcore().log_profile(clear)
polcore().clear_script_profile_counters()
Now we get to the interesting part :)
clear_script_profile_counters reset the counters, and log_profile also clears after dumping if clear is set. To see what the pol.log dump from .log_profile looks like, click here
These methods tell you how much the script that have been run since the last clear (or server start), log_profile writes it to pol.log while script_profiles returns an array with the following information for each script:

name: The name of the script :)
instr: Total instructions the script has run
invocations: The number of times the script has been called
instr_per_invoc: Total instructions divided by number of invocations :)
instr_percent: How much the script has run, as a percentage of all cycles run on shard
Example:
program view_script_profiles(who)
	SendSysMessage(who, "Scripts that run a lot:");
	var vscript_profiles := polcore().script_profiles;
	foreach script in vscript_profiles
		if (script.instr_percent > 5)
			SendSysMessage(who, script.name + " has run " + script.instr +
				" (" + script.instr_percent + "%) instructions, " +
				script.instr_per_invok + " at a time");
		end if
	endforeach
endprogram

polcore().running_scripts
polcore().all_scripts
Returns the scripts that are currently in effect. running_scripts only returns the ones that aren't sleeping or waiting for events.
The return value is an array of ScriptExRef's, which can be used like normal structs to get information:

pid: Process id of the script
name: Name of the script
instr_cycles: Number of instructions the script has run so far
consec_cycles: Number of cycles run since last time the script called sleep
PC: Prog Counter, the current instruction the script is at.
call_depth: Call depth, the number of function calls currently nested
num_globals: Number of globals the script has used
Example:
program view_script_status(who)
	SendSysMessage(who, "Loaded scripts:");
	var vall_script := polcore().all_scripts;
	foreach script in vall_scripts
		SendSysMessage(who, scripts.pid + ": " + script.name + " has run " +
			script.instr_cycles + " (" + script.consec_cycles + ", " +
			script.call_depth + ", " + script.num_globals + ")");
	endforeach
endprogram


















Runtime script options

set_priority( priority )
This sets a scripts priority (the number of instructions it runs at a time). A higher number means your script gets run faster, on behalf of all the other scripts. The default number is 1, and the function returns the previous priority. set_script_option( optnum, optval )
This sets the various script options:
SCRIPTOPT_NO_INTERRUPT: Makes the script run until it sleeps (like calling set_priority('infinite'). In effect this halts!! the shard until your script is done
SCRIPTOPT_DEBUG: Prints any debug info included. Not used much.
SCRIPTOPT_NO_RUNAWAY: Doesn't warn about runaway for this script. Only use this if you're sure what you're doing!
SCRIPTOPT_CAN_ACCESS_OFFLINE_MOBILES: Whether or not the script has access to offline mobs
Example:
program lag_scripts(who)
	SendSysMessage(who, "That was not a good idea...");
	var i,i2;
	set_priority(200);
	set_script_option(SCRIPTOPT_NO_RUNAWAY);
	for (i := 0; i < 100000; i := i + 1)
		for (i2 := 0; i2 < 100; i2 := i2 + 1)
			i2 := 122 + i2 + 12 * 12 - 22 + (5 * 5) - 25;
		endfor
	endfor
	SendSysMessage(who, "Phew...");
endprogram
set_critical( critical )
This is the same as calling set_script_option for the SCRIPTOPT_NO_INTERRUPT flag. Don't use this unless you have to, it freezes the shard! What it does is prevent the rest of the scripts from running at all until you turn critical off. The best use for this is when something has to be done without *anything* happening while its running. For instance this could be when you creating and modifying an object and it all has to happen at once so nothing can happen on the shard between creation and when you're done setting properties (remember to set_critical(0)!). Another example would be if you are using a global prop and you have to be sure it doesn't change. These situations usually can, and should, be avoided.















--- various code ---















runawaysquare.src (Back)
use uo;
// this is *not* the right way to compute squares ;)
program runawaysquare(who, text)
	var i := CInt(text);
	var a,b,sum := 0;
	for (a := 0; a < i; a := a + 1)
		for (b := 0; b < i; b := b + 1)
			sum := sum + 1;
		endfor
	endfor
	SendSysMessage(who, i + "^2 = " + sum);
endprogram
(Back)































runawaysquare.lst (Back)
program runawaysquare(who, text)
use uo;
0: get arg 'who'
1: get arg 'text'
var i := CInt(text);
2: decl local #2
3: local #1
4: Func(0,0): left
5: :=
6: #
var a,b,sum := 0;
7: decl local #3
8: #
9: decl local #4
10: #
11: decl local #5
12: 0L
13: :=
14: #
for (a := 0; a < i; a := a + 1)
15: local #3
16: 0L
17: :=
18: #
19: local #3
20: local #2
21: <
22: if false goto 49
for (b := 0; b < i; b := b + 1)
23: local #4
24: 0L
25: :=
26: #
27: local #4
28: local #2
29: <
30: if false goto 42
sum := sum + 1;
31: local #5
32: 1L
33: +
34: local5 :=
35: local #4
36: local #4
37: 1L
38: +
39: :=
40: #
41: goto27
42: local #3
43: local #3
44: 1L
45: +
46: :=
47: #
48: goto19
SendSysMessage(who, i + "^2 = " + sum);
49: local #0
50: local #2
51: "^2 = "
52: +
53: local #5
54: +
55: 3L
56: 1000L
57: Func(2,0): Accessible
58: #
59: leave block(6)
60: progend
(Back)















Example of logged script profile (Back)
Script passes:    89469002
Script                                       cycles  invoc    cyc/invoc      %
scripts/misc/chrdeath.ecl                     59049    114          517      0
scripts/misc/death.ecl                        81944    340          241      0
scripts/misc/help.ecl                          1743      3          581      0
pkg/foundations/hooks/attributeCore.ecl       40015     32         1250      0
pkg/items/doors/closeDoor.ecl                 11313     73          154      0
pkg/items/doors/door.ecl                      67139    159          422      0
pkg/items/doors/openDoor.ecl                  10614     73          145      0
pkg/skills/alchemy/yellowPotion.ecl             702      8           87      0
pkg/skills/anatomy/anatomy.ecl                25626    144          177      0
pkg/skills/armslore/armsLore.ecl                165      1          165      0
pkg/skills/evalint/evalInt.ecl                17486    101          173      0
pkg/skills/healing/healing.ecl               949169    939         1010      3
pkg/skills/hiding/hiding.ecl                  24496    233          105      0
pkg/skills/meditation/medCheck.ecl          2653781     32        82930     10
pkg/skills/meditation/meditation.ecl            645      3          215      0
pkg/skills/spells/archProt.ecl                 1009      1         1009      0
pkg/skills/spells/bladeSpirit.ecl              9916      9         1101      0
pkg/skills/spells/bless.ecl                   22968     26          883      0
pkg/skills/spells/cure.ecl                     1116      3          372      0
pkg/skills/spells/eBolt.ecl                    1691      2          845      0
pkg/skills/spells/explosion.ecl               41158     79          520      0
pkg/skills/spells/fireball.ecl                63570    116          548      0
pkg/skills/spells/fstrike.ecl                 18623     84          221      0
pkg/skills/spells/gheal.ecl                  190957    962          198      0
pkg/skills/spells/harm.ecl                    73102    134          545      0
pkg/skills/spells/lightning.ecl               65582    127          516      0
pkg/skills/spells/paralyze.ecl                33259     61          545      0
pkg/skills/spells/poison.ecl                  68405    119          574      0
pkg/skills/spells/poisonDamage.ecl            89594    164          546      0
pkg/skills/spells/poisonField.ecl               487      1          487      0
pkg/skills/spells/protection.ecl               6929      8          866      0
pkg/skills/spells/reflect.ecl                 22964     91          252      0
pkg/skills/stealth/stealth.ecl                  249      3           83      0
pkg/skills/taming/taming.ecl                    121      1          121      0
pkg/skills/tinkering/tinkerTraps.ecl            346      2          173      0
pkg/systems/combat/bladeSpiritHit.ecl          6898     89           77      0
pkg/systems/combat/destroy.ecl                16518    285           57      0
pkg/systems/combat/earthElemental.ecl         14566    136          107      0
pkg/systems/combat/equip.ecl                 119729   1787           67      0
pkg/systems/combat/itemControl.ecl             7185    330           21      0
pkg/systems/combat/maceHit.ecl               154075   1022          150      0
pkg/systems/combat/mainHitScript.ecl         929549   3911          237      3
pkg/systems/combat/mobPoisonHit.ecl           19983    247           80      0
pkg/systems/combat/reactiveArmorHit.ecl      361106   5920           60      1
pkg/systems/combat/unequip.ecl                75054   1787           42      0
pkg/systems/combat/wrestlingHitScript.ecl    443890   2009          220      1
pkg/tools/motd/logon.ecl                        224     32            7      0
pkg/tools/motd/textcmd/player/motd.ecl         1024     32           32      0
scripts/misc/unmod.ecl                        10567     87          121      0
scripts/ai/bladeSpirit.ecl                    34475      5         6895      0
scripts/ai/dumbKillPCs.ecl                   839025    403         2081      3
scripts/ai/firebreather.ecl                   92077     57         1615      0
scripts/ai/immobile.ecl                     1123980     14        80284      4
scripts/ai/immobileSpell.ecl                 475435      3       158478      1
scripts/ai/killPCs.ecl                      5785841   1489         3885     22
scripts/ai/packFirebreather.ecl              103719     15         6914      0
scripts/ai/spellFire.ecl                     259221      2       129610      0
scripts/ai/spellKillPCs.ecl                 7041261    348        20233     26
scripts/ai/undead.ecl                       1317271     45        29272      5
scripts/boneControl.ecl                        1026    114            9      0
scripts/console/online.ecl                      230      2          115      0
scripts/control/canInsert.ecl                 17845    541           32      0
scripts/control/canRemove.ecl                 27882    992           28      0
scripts/control/corpseControl.ecl             20844    454           45      0
scripts/control/onInsert.ecl                  16042    553           29      0
scripts/control/onRemove.ecl                  19844    992           20      0
scripts/control/trashControl.ecl                378      2          189      0
scripts/control/trashInsert.ecl                 416     32           13      0
scripts/control/trashRemove.ecl                   9      1            9      0
scripts/items/bladed.ecl                        306      1          306      0
scripts/items/key.ecl                           808      6          134      0
scripts/misc/dblclickself.ecl                   225     15           15      0
scripts/misc/logoff.ecl                        8178     37          221      0
scripts/misc/logofftest.ecl                  120111     37         3246      0
scripts/misc/logon.ecl                        48058     32         1501      0
scripts/NPCKeeper.ecl                        648469   2376          272      2
(Back)

The above guide was written by ToGu. No animals were hurt during the making of this document.