überspringe Navigation

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.

6 Comments

  1. 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.

  2. 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.

  3. 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.

  4. 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!


Verfasse einen Kommentar

Trage deine Daten unten ein oder klicke ein Icon um dich einzuloggen:

WordPress.com-Logo

Du kommentierst mit Deinem WordPress.com-Konto. Abmelden /  Ändern )

Google Foto

Du kommentierst mit Deinem Google-Konto. Abmelden /  Ändern )

Twitter-Bild

Du kommentierst mit Deinem Twitter-Konto. Abmelden /  Ändern )

Facebook-Foto

Du kommentierst mit Deinem Facebook-Konto. Abmelden /  Ändern )

Verbinde mit %s