Vielleicht ist dem Einen oder Anderen aufgefallen, dass das Modul im letzten Monat nicht mehr stabil lief und häufiger abstürzte.
Ich vermute als Ursache Konflikte zwischen den OnHeartbeat-Scripten einiger NPCs, die alle sechs Sekunden ausgeführt werden, und Auslösern für Animationen, die teilweise eben länger als sechs Sekunden dauern sollen.
Ich baue in die entsprechenden Scripte gerade Sicherungen ein, damit das in Zukunft nicht passiert, und habe probehalber die NPCs auf Eis gelegt, deren Scripte meiner Meinung nach für die Abstürze verantwortlich sind.
Geschichten von der Alten Erde 
6 Comments
Ich habe jetzt den NWNX-Profiler angeworfen und geschaut, welche Scripte am häufigsten ausgeführt werden und wieviel Rechenzeit dafür nötig war.
Am stärksten belastet wird die CPU durch die OnHeartbeat-Scripte des HTF-Systems, dicht gefolgt durch die Abfragen des Sparky-Spawners vom CEP 2.4 (den ich nicht nutze), dann kamen schon die 156 OnHeartbeats der CEP-Kerzen im Tempel des Lebens.
Erstaunlicherweise sind auch die genuinen Wegfindungsroutinen des Madrigaler Milizhauptmannes ganz vorne mit dabei, was ich nie gedacht hätte. Fischer Ellis hingegen, der relativ komplizierte Abfragen hat, rangiert deutlich weiter hinten (tja, ist ja auch selbst geschrieben).
Nach den ersten Entrümpelungsmaßnahmen liest sich die Statistik wie folgt:
Module: AE-2013-08-27
Current statistics
———————————————————————————————–
x2_def_percept 1568 msec 7583 calls
tk_zomb_onspawn 36 msec 12 calls
crpd_door_unlock 0 msec 10 calls
x3_mod_def_enter 46 msec 2 calls
ae_playerequip 0 msec 1 calls
u_var_skelspawn 1 msec 2 calls
tbx0_social_hb 1240 msec 14205 calls *
nw_c2_defaulte 0 msec 5 calls
wrap_mod_onaqu 485 msec 1185 calls
u_guard_doorclos 0 msec 9 calls
heartbeat_pulse 414 msec 4739 calls *
wrap_mod_onenter 76 msec 1 calls
loc_spawn_omni 0 msec 4 calls
ae_mod_schedule 145 msec 8444 calls *
gun2_mod_def_equ 0 msec 6 calls
11_explore_nord 0 msec 2 calls
htf_mod_onenter 0 msec 1 calls
default 0 msec 37 calls
htf_exwater 0 msec 4 calls
$rp_madrigal 0 msec 5 calls
ae_mod_unaquired 0 msec 20 calls
wrap_ar_onexit 21 msec 10 calls
zep_on_modloaded 26 msec 18 calls
@MA_ELLIS 164 msec 13071 calls *
nw_c2_default4 0 msec 6 calls
htf_cold_rate 19 msec 269 calls
htf_rate 97 msec 269 calls
hologram_spawn 0 msec 2 calls
loc_spawn_herb 4 msec 32 calls
tk_zomb_ondeath 1 msec 12 calls
x2_def_spawn 145 msec 84 calls
x2_def_heartbeat 46433 msec 165734 calls *
x2_mod_def_unaqu 0 msec 20 calls
wrap_ar_onenter 1405 msec 269 calls
@MA_MILIZCAPT 11083 msec 253162 calls *
tbx0_social_ud 3726 msec 28410 calls *
u_build_ar_enter 168 msec 182 calls
loc_ani_htbt 826 msec 85245 calls *
nw_c2_dropin9 0 msec 2 calls
tk_zomb_hb 8 msec 24 calls
u_guns_onenter 0 msec 1 calls
aps_onload 0 msec 2 calls
$ma_f1 37 msec 32 calls
deity_ae_onenter 0 msec 1 calls
nw_c2_default7 0 msec 12 calls
htf_ar_onexit 0 msec 20 calls
nw_c2_default1 4475 msec 649123 calls *
servitor_onspawn 189 msec 2511 calls
crpz_armor_enc 0 msec 6 calls
wrap_mod_onunaqu 4 msec 20 calls
crpd_doorop_clos 0 msec 3 calls
deity_ae_onload 5 msec 2 calls
zep_torchspawn 310 msec 9638 calls *
ae_seraf_spawn 0 msec 2 calls
htf_mod_onload 0 msec 2 calls
living_heartbeat 1380 msec 9682 calls *
fes_mod_onenter 0 msec 1 calls
zep_on_enter 74 msec 1 calls
ae_altars_onload 1 msec 2 calls
wrap_mod_onload 75 msec 2 calls
tk_detector_ent 0 msec 12 calls
wrap_ar_onheart 97311 msec 464358 calls *
ae_mod_equip 1 msec 6 calls
x2_mod_def_aqu 15 msec 1185 calls
zep_gob_worg_spw 0 msec 2 calls
u_npc_animate1 11 msec 350 calls
crpz_torchlife 0 msec 6 calls
wrap_mod_onheart 794 msec 8444 calls *
wrap_mod_onequip 44 msec 6 calls
mod_enter 16 msec 1 calls
loc_percept 1 msec 380 calls
x2_def_onblocked 21 msec 5 calls
x2_mod_def_equ 0 msec 6 calls
NW_G0_Transition 942 msec 18 calls
u_npc_aktion1 1 msec 55 calls
nw_c2_omnivore 0 msec 4 calls
11_explore_east 0 msec 4 calls
nw_c2_herbivore 13 msec 80 calls
enc_checksparky 19178 msec 464358 calls *
nw_c2_default2 72 msec 16208 calls
spawner_onenter 3 msec 269 calls
u_start_xp1 0 msec 2 calls
u_build_parser 166 msec 18 calls
nw_c2_default9 5596 msec 37194 calls *
u_npc_schedule 632 msec 4741 calls *
htf_enwater 0 msec 4 calls
door_close60s 0 msec 6 calls
———————————————————————————————–
Elapsed time : 10063 msec
Runtime delta : 28 msec
Total cumulative runtime : 199504 msec
Total number of scriptcalls : 2251907
———————————————————————————————–
———————————————————————————————–
Gut ist, dass ich durch die bisherigen Maßnahmen schon etwa ein Drittel der Rechenzeit eingespart habe.
Myteriös bleibt, warum der Milizhauptmann für einfache Dinge mehr Rechenzeit braucht als Fischer Ellis für komplizierte Aktionen.
Und dann sollte ich mich mal mit den Funktionen des Sparky Spawners beschäftigen, um zu entscheiden, ob ich den überhaupt benutzen will.
Current statistics (neues Modul auf dem alten Server)
———————————————————————————————–
x2_def_percept 10904 msec 7079 calls | tk_zomb_onspawn 3 msec 6 calls |
crpd_door_unlock 0 msec 8 calls | u_var_skelspawn 1 msec 1 calls |
tbx0_social_hb 446 msec 12290 calls *| nw_c2_defaulte 0 msec 3 calls |
wrap_mod_onaqu 251 msec 559 calls | heartbeat_pulse 218 msec 4097 calls |
loc_spawn_omni 0 msec 3 calls | ae_mod_schedule 163 msec 7307 calls *|
htf_exwater 0 msec 5 calls | ae_mod_unaquired 0 msec 10 calls |
wrap_ar_onexit 0 msec 3 calls | zep_on_modloaded 8 msec 9 calls |
@MA_ELLIS 145 msec 13250 calls | htf_cold_rate 9 msec 129 calls |
htf_rate 45 msec 129 calls | hologram_spawn 0 msec 1 calls |
loc_spawn_herb 2 msec 16 calls | tk_zomb_ondeath 0 msec 6 calls |
x2_def_spawn 65 msec 43 calls | x2_def_heartbeat 305331 msec 143419 calls *|
x2_mod_def_unaqu 0 msec 10 calls | wrap_ar_onenter 405 msec 129 calls |
tbx0_social_ud 332 msec 24580 calls *| u_build_ar_enter 0 msec 76 calls |
loc_ani_htbt 804 msec 77838 calls *| nw_c2_dropin9 0 msec 1 calls |
tk_zomb_hb 4 msec 12 calls | aps_onload 0 msec 1 calls |
nw_c2_default7 0 msec 6 calls | htf_ar_onexit 0 msec 6 calls |
nw_c2_default1 4079 msec 544914 calls *| servitor_onspawn 0 msec 1 calls |
wrap_mod_onunaqu 1 msec 10 calls | crpd_doorop_clos 0 msec 3 calls |
deity_ae_onload 2 msec 1 calls | zep_torchspawn 149 msec 8348 calls *|
ae_seraf_spawn 0 msec 1 calls | htf_mod_onload 0 msec 1 calls |
living_heartbeat 1071 msec 8402 calls *| ae_altars_onload 0 msec 1 calls |
wrap_mod_onload 16 msec 1 calls | tk_detector_ent 0 msec 6 calls |
wrap_ar_onheart 988 msec 401164 calls *| u_npc_aktion_del 0 msec 13 calls |
u_onspawn_skel 0 msec 1 calls | x2_mod_def_aqu 4 msec 559 calls |
zep_gob_worg_spw 0 msec 1 calls | u_npc_animate1 10 msec 585 calls |
wrap_mod_onheart 645 msec 7293 calls *| loc_percept 0 msec 190 calls |
x2_def_onblocked 16 msec 3 calls | NW_G0_Transition 688 msec 9 calls |
u_npc_aktion1 1 msec 65 calls | nw_c2_omnivore 0 msec 2 calls |
nw_c2_herbivore 6 msec 37 calls | nw_c2_default2 73 msec 14152 calls *|
nw_c2_default9 10442 msec 124663 calls *| u_npc_schedule 314 msec 4099 calls *|
htf_enwater 0 msec 5 calls | door_close60s 0 msec 6 calls |
———————————————————————————————–
Elapsed time : 10069 msec
Runtime delta : 154 msec
Total cumulative runtime : 337641 msec
Total number of scriptcalls : 1405568
Current statistics (neues Modul auf dem neuen Server)
———————————————————————————————–
u_respawn_to_wp 1 msec 14 calls | x2_def_percept 3524 msec 10379 calls *|
tk_zomb_onspawn 33 msec 27 calls | NW_G0_Conversat 5 msec 5 calls |
zep_on_activate2 22 msec 7 calls | crpd_door_unlock 0 msec 9 calls |
ae_mod_unequip 1 msec 3 calls | x3_mod_def_enter 9 msec 18 calls |
ae_playerequip 0 msec 3 calls | u_var_skelspawn 3 msec 4 calls |
crpz_torchlife2 0 msec 3 calls | tbx0_social_hb 946 msec 19362 calls *|
ma_chapel_an 5 msec 2 calls | pray_altar_start 0 msec 10 calls |
nw_c2_defaulte 0 msec 16 calls | wrap_mod_onaqu 1014 msec 2314 calls |
nw_ch_ac5 0 msec 3 calls | u_guard_doorclos 0 msec 27 calls |
wrap_mod_onact 38 msec 7 calls | oe_change_music 0 msec 6 calls |
heartbeat_pulse 498 msec 6451 calls *| nw_ch_ac1 3 msec 33 calls |
$rp_madrigal_f 0 msec 28 calls | wrap_mod_onenter 258 msec 3 calls |
loc_spawn_omni 2 msec 12 calls | oe_achtung_msg1 0 msec 4 calls |
pray_alt_doreen 0 msec 2 calls | ae_mod_schedule 296 msec 7953 calls *|
wrap_mod_onrespa 111 msec 1 calls | gun2_mod_def_equ 3 msec 15 calls |
11_explore_nord 0 msec 8 calls | ae_mod_death 0 msec 2 calls |
htf_mod_onenter 169 msec 3 calls | U_SEELENSTEIN 19 msec 6 calls |
nw_ch_ace 0 msec 1 calls | default 5 msec 303 calls |
htf_exwater 0 msec 13 calls | $rp_madrigal_m 11 msec 20 calls |
pray_cleric 5 msec 16 calls | $rp_madrigal 1 msec 28 calls |
ae_mod_unaquired 1 msec 53 calls | wrap_ar_onexit 3 msec 41 calls |
$ma_c5 11 msec 23 calls | ae_mod_dying 4 msec 40 calls |
htf_mod_act_item 4 msec 10 calls | NW_S1_Rage1 0 msec 2 calls |
u_oe_create_kit 1 msec 1 calls | zep_on_modloaded 14 msec 36 calls |
@MA_ELLIS 277 msec 21046 calls | nw_walk_wp 0 msec 6 calls |
nw_c2_default4 1 msec 17 calls | nw_ch_ac3 15 msec 10 calls |
htf_cold_rate 65 msec 554 calls | htf_rate 2067 msec 645 calls |
11_explore_west 0 msec 6 calls | hologram_spawn 0 msec 4 calls |
loc_spawn_herb 14 msec 64 calls | nw_c2_default5 7 msec 8 calls |
open_wirt 0 msec 1 calls | tk_zomb_ondeath 9 msec 28 calls |
nw_c2_defaultb 0 msec 1 calls | x2_def_spawn 208 msec 171 calls |
NW_S2_TurnDead 1 msec 5 calls | x2_def_heartbeat 90104 msec 225917 calls *|
u_1starea_enter 116 msec 2 calls | x2_mod_def_unaqu 3 msec 53 calls |
htf_mod_respawn 93 msec 1 calls | wrap_ar_onenter 974 msec 552 calls |
X2_S0_MagcWeap 16 msec 1 calls | @MA_MILIZCAPT 17936 msec 283313 calls *|
tbx0_social_ud 924 msec 38724 calls *| nw_ch_ac2 2 msec 33 calls |
u_build_ar_enter 128 msec 404 calls | nw_ch_ac4 2 msec 2 calls |
$ma_a3 0 msec 2 calls | crpi_paw 0 msec 3 calls |
NW_S3_ActItem01 0 msec 7 calls | loc_ani_htbt 1425 msec 122614 calls *|
htf_fishing 2 msec 7 calls | nw_c2_dropin9 1 msec 5 calls |
$ma_d5 0 msec 9 calls | @NW_S_BADGERDIRE 0 msec 2 calls |
cf_rest_exit 0 msec 2 calls | $ma_b1 110 msec 33 calls |
tk_zomb_hb 32 msec 60 calls | wrap_mod_onrest 10 msec 4 calls |
$rp_madrigal_hof 36 msec 36 calls | u_guns_onenter 0 msec 3 calls |
aps_onload 1 msec 4 calls | crpt_popup_msg 0 msec 2 calls |
$ma_a2 7 msec 22 calls | wrap_mod_ondying 1 msec 2 calls |
deity_ae_onenter 70 msec 5 calls | nw_c2_default7 2 msec 27 calls |
htf_ar_onexit 0 msec 80 calls | ae_mod_respawn 17 msec 8 calls |
u_togame_msg 0 msec 3 calls | nw_c2_default1 6293 msec 858958 calls *|
servitor_onspawn 436 msec 3899 calls | $rp_far_tavern 9 msec 52 calls |
ae_pray_spawn 1 msec 4 calls | crpz_armor_enc 0 msec 19 calls |
nw_ch_acb 0 msec 2 calls | wrap_mod_ondeath 0 msec 1 calls |
wrap_mod_onunaqu 20 msec 53 calls | oil_mod_onact 0 msec 7 calls |
crpd_doorop_clos 0 msec 10 calls | deity_ae_onload 16 msec 4 calls |
zep_torchspawn 210 msec 9017 calls *| wrap_mod_onunequ 3 msec 3 calls |
x2_pc_umdcheck 0 msec 2 calls | ou_port_here 0 msec 3 calls |
x2_mod_def_rest 5 msec 4 calls | cf_rest_enter 0 msec 3 calls |
ae_mod_on_rest 2 msec 12 calls | ae_seraf_spawn 0 msec 4 calls |
htf_mod_onload 0 msec 4 calls | living_heartbeat 3207 msec 13205 calls *|
u_oe_ursprung 1 msec 10 calls | tk_zomb_rise 7 msec 6 calls |
fes_mod_onenter 0 msec 3 calls | zep_on_enter 13 msec 3 calls |
ae_altars_onload 4 msec 4 calls | wrap_mod_onload 55 msec 4 calls |
tk_detector_ent 9 msec 31 calls | wrap_ar_onheart 757 msec 436140 calls *|
u_npc_aktion_del 1 msec 20 calls | u_player_grave 0 msec 6 calls |
nw_d1_startstore 0 msec 1 calls | ae_mod_equip 6 msec 15 calls |
nw_c2_default6 1 msec 5 calls | u_onspawn_skel 0 msec 4 calls |
pray_alt_thoem 0 msec 4 calls | x2_mod_def_aqu 39 msec 2314 calls |
crpz_racial_mvmt 0 msec 3 calls | zep_gob_worg_spw 1 msec 4 calls |
u_npc_animate1 22 msec 835 calls | crpz_torchlife 0 msec 15 calls |
wrap_mod_onheart 2284 msec 7931 calls *| wrap_mod_onequip 20 msec 15 calls |
mod_enter 2 msec 3 calls | loc_percept 4 msec 764 calls |
cf_mod_act_item 0 msec 7 calls | nw_ch_summon_9 0 msec 1 calls |
x2_def_onblocked 4 msec 16 calls | NW_S0_Summon 10 msec 1 calls |
x2_mod_def_equ 3 msec 15 calls | NW_G0_Transition 654 msec 78 calls |
u_npc_aktion1 3 msec 84 calls | nw_c2_omnivore 2 msec 8 calls |
11_explore_east 0 msec 2 calls | nw_c2_herbivore 40 msec 148 calls |
nw_c2_default2 184 msec 23307 calls *| u_start_xp1 372 msec 13 calls |
u_build_parser 115 msec 68 calls | pray_alt_aiope 0 msec 2 calls |
nw_c2_default9 6666 msec 35120 calls *| NW_G0_fear 0 msec 2 calls |
u_npc_schedule 575 msec 6449 calls *| u_npc_converse 0 msec 2 calls |
x2_mod_def_unequ 0 msec 3 calls | htf_enwater 0 msec 13 calls |
nw_c2_default3 13 msec 9 calls | $ma_c4 0 msec 5 calls |
door_close60s 0 msec 34 calls |
———————————————————————————————–
Elapsed time : 10013 msec
Runtime delta : 27 msec
Total cumulative runtime : 143765 msec
Total number of scriptcalls : 2140628
In der unteren Statistik fällt auf, dass hier auch spielerbezogene Scripte auftauchen, da ich mehrmals zum Test der Datenbank mit Toons rein- und rausgegangen bin, gespeichert habe, Rüstung gewechslt habe, gekämpft und gezaubert habe.
Daher auch die höhere Anzahl von Scriptcalls insgesamt. Auffallend ist auch, dass das Runtime Delta bei der alten Hardware oben jetzt doch wieder wächst, während es unten schön niedrig bleibt. Die Zahl der ausgeführten Scripte ist oben deutlich niedriger als beim neuen Server unten, die dafür benötigte Rechenzeit ist dagegen mehr als doppelt so hoch.
Das scheint mir doch auf ein Hardware-Problem nach längerer Laufzeit hinzuweisen. Mal sehen, ob und wann der alte Server wieder abstürzt.
Jedenfalls sind durch die Veränderungen der Sripte jetzt die Rechenzeiten doch insgesamt deutlich verringert.
Sollte es tatsächlich auf diesem Wege gelungen sein, die geistige Kapazität von Militärpersonal objektiv einzuschätzen und zu beurteilen? Das wäre doch einen Hinweis an die Hardthöhe wert!
Ich befürchte, dass die Ergebnisse sich auf ideale Bedingungen in einer fiktiven Welt beziehen, die jedoch erschreckende Parallelen zur Realität aufweist: Schließlich tut der Hauptmann nichts anderes, als den ganzen Tag dumm herumzustehen und über Nacht in seinem Quartier zu verschwinden.
Geistige Höchstleistung eben.
Ich versuche gerade herauszufinden, was letzten Endes für die Abstürze verantwortlich ist:
A) die Hardware von 2005, die seit 4 Jahren 24/7 läuft
B) der NWNX2-Datenbank-Extender
C) Scriptfehler im Modul
Der Test von A) wurde mir etwas verhagelt durch den Stromausfall, den wir hier am Wochenende hatten.
Jetzt teste ich gerade C), indem ich das alte Modul von Ende Februar 2012 ohne die ganzen Scripte geladen habe. Wer sich also ein nostalgisches Erlebnis gönnen möchte, nur zu.
Wie es so meine Art ist, versuche ich alle Fehlerquellen gleichzeitig zu beheben.
1. Neuen Server-Rechner angeschafft. HP Proliant MicroServer, war für das Heimnetzwerk eh mal fällig. NWN nochmal sauber neu installiert. Patch GER 1.69 und CEP 2.4 installiert, alle Haks drauf. NWNX neu installiert, alte Datenbankdaten übertragen und im LAN getestet. Die gefühlte Fluppdizität von dem Ding ist GUUUT, es läuft alles gleich viel flüssiger.
2. Sparky Spawner, NESS und AISS-Skriptsysteme aufgespürt und ausgeschaltet; teilweise fehlerhafte Verweise entfernt (zu Scripten, die gar nicht vorhanden sind), teilweise weiss ich nicht, was für Scripte das sein sollen; im Falle des Sparky Spawners muss ich mir noch überlegen, ob ich den überhaupt benutzen muss; ich bin der Meinung, ich habe mir bereits eine eigene bessere Lösung einfallen lassen.
3. Dauertest der letzten Modulversion vom 2.9.13 auf zwei Rechnern, mal sehen, wie lange es ohne Absturz läuft.
Puuh, Arbeit, Arbeit!