Topコマンドを作ってみた

環境構築

Papyrusスクリプトの稼働状況を見えるようにするツールを作ってみました。

必要環境

以下の環境が必要です。

  • Windows版PHP
  • デバッグ情報を埋め込んたpexファイル
  • ユーザー用トレースログを開くMod

環境を選ぶので万人向けではありません。

自作Modのスクリプトの負荷を見たいとか、pscの再コンパイルができる環境を持っていて自分でチューニングしたいといったことができる方向けです。

TopコマンドのPHPスクリプト

このPHPスクリプトをtop.phpというファイ名で保存します。

Topコマンド (php)

<?php
define('PAPYRUS_USERLOG', 'Top');
define('ENABLE_PEAK_DUMP', TRUE);
define('PEAK_THRESHOLD', 400);
define('DUMP_LOG_BASE', 'dump_');

$file = PAPYRUS_USERLOG . '.0.log';
$begin = 0;
$finish = 0;
$chunk = 0;
$processList = [];
$errorList = [];
$timeList = [];
$sortedList = [];
$sortTimeList = [];
$loadList = [];
$peakList = [ 5 => 0, 15 => 0, 60 => 0 ];
$dumpList = [];
$lastChunk = '';
$peakDumped = false;

try {
    if ( !is_readable($file) ) {
        throw new Exception($file . ' is not readable.');
    }

    if ( !ENABLE_PEAK_DUMP ) {
        $peakDumped = TRUE;
    }

    $fileSize = filesize($file);
    $lastFileSize = $fileSize;
    $startUp = time();

    while (true) {
        clearstatcache(true, $file);

        $fileSize = filesize($file);
        $current = time();

        if ($lastFileSize != $fileSize) {
            if ($fileSize < $lastFileSize) {
                $lastFileSize = 0;
            }

            $fileContents = file_get_contents($file, false, null, $lastFileSize, $fileSize);

            parseLog($fileContents);

            $lastFileSize = $fileSize;
        }

        createLoad();
        createPeak();
        createSortedList();
        refreshSortedTime();

        clearTerminal();

        // 上段
        printHeader();
        echo ' ';
        printLoad();
        echo ' ';
        printPeak();
        echo ' ';
        printFooter();
        echo PHP_EOL;

        echo PHP_EOL;

        printSortedList();

        echo PHP_EOL;

        printError();

        if ( !$peakDumped ) {
            cleanDumpList();

            if ( $peakList[5] >= PEAK_THRESHOLD ) {
                dumpProcess();
                $peakDumped = TRUE;
            }
        }

        sleep(1);
    }
} catch (Exception $e) {
    echo $e->getMessage() . PHP_EOL;
}


function parseLog($infile)
{
    global $lastChunk, $begin, $finish, $chunk, $processList, $errorList, $timeList, $startUp, $current, $peakDumped, $dumpList;

    foreach ( explode("\n", $infile) as $inline ) {
        if ( $lastChunk !== '' ) {
            $inline = $lastChunk . $inline;
            $lastChunk = '';
            //$chunk--;
        }

        if ( strpos($inline, "\r") !== FALSE ) {
            $lastChunk = $inline;
            $chunk++;
            continue;
        }

        $inline = trim($inline);

        if ($inline == '') {
            continue;
        }

        $cols = explode('] ', $inline);

        if ( !isset($cols[1]) ) {
            $errorList[] = 'invalid line: ' . trim($inline);
            continue;
        }

        if ( $cols[1] == PAPYRUS_USERLOG . ' log opened (PC)' ) {
            $startUp = $current;
            $begin = 0;
            $finish = 0;
            $errorList = [];
            $processList = [];
            $timeList = [];
            //$errorList[] = $cols[1];
            continue;
        }

        $cols = explode(',', $cols[1]);

        if ( count($cols) != 4 ) {
            continue;
        }

        $value = $cols[0] . ',' . $cols[1] . ',' . $cols[2];

        if ( $cols[3] == 'begin' ) {
            $begin++;
            $processList[] = $value;
            $timeList[] = $current;

            if ( !$peakDumped ) {
                $dumpList[] = [ $current, $value ];
            }
        } else if ( $cols[3] == 'finish' ) {
            $key = array_search( $value, $processList );

            if ( $key !== FALSE ) {
                unset($processList[$key]);
                $finish++;
            } else {
                if ($current - $startUp >= 10) {
                    $errorList[] = 'process not found: ' . $value;
                }
            }
        }
    }
}


// 端末を消去
function clearTerminal()
{
    pclose( popen('cls', 'w') );
}


// ヘッダ部分を表示
function printHeader()
{
    global $begin, $finish, $running, $chunk;

    $running = $begin - $finish;

    printf('Papyrus: %d begin, %d finish, %d running, %d chunk', $begin, $finish, $running, $chunk);
}


function createLoad()
{
    global $timeList, $loadList, $current;

    $loadList = [ 5 => 0, 15 => 0, 60 => 0 ];

    foreach ($timeList as $key => $timestamp) {
        if ($current - $timestamp <= 60) {
            $loadList[60]++;

            if ($current - $timestamp <= 5) {
                $loadList[5]++;
            }

            if ($current - $timestamp <= 15) {
                $loadList[15]++;
            }
        } else {
            unset( $timeList[$key] );
        }
    }
}


function createPeak()
{
    global $loadList, $peakList;

    foreach ($loadList as $key => $value) {
        if ( $peakList[$key] < $loadList[$key] ) {
            $peakList[$key] = $loadList[$key];
        }
    }
}


function printLoad()
{
    global $loadList;

    printf('Load: %d, %d, %d', $loadList[5], $loadList[15], $loadList[60]);
}


function printPeak()
{
    global $peakList;

    printf('Peak: %d, %d, %d', $peakList[5], $peakList[15], $peakList[60]);
}


// プロセス一覧を作る
function createSortedList()
{
    global $sortedList, $processList, $sortTimeList, $current;

    $sortedList = [];

    foreach ($processList as $line) {
        if ( array_key_exists($line, $sortedList) ) {
            $sortedList[$line]++;
        } else {
            $sortedList[$line] = 1;

            if ( !array_key_exists($line, $sortTimeList) ) {
                $sortTimeList[$line] = $current;
            }
        }
    }

    ksort($sortedList);
}


// プロセス一覧を表示
function printSortedList()
{
    global $sortedList, $sortTimeList, $current;

    echo 'Time Num State Function Script';
    echo PHP_EOL;

    foreach ($sortedList as $line => $num) {
        $past = $current - $sortTimeList[$line];
        $cols = explode(',', $line);
        printf('%04d %3d %-10s %-18s %s', $past, $num, $cols[1], $cols[2], $cols[0]);
        echo PHP_EOL;
    }
}


// プロセスの経過時間一覧を整理
function refreshSortedTime()
{
    global $sortTimeList, $sortedList;

    foreach (array_keys($sortTimeList) as $line) {
        if ( !array_key_exists($line, $sortedList) ) {
            unset($sortTimeList[$line]);
        }
    }
}


// 概要部分を表示
function printFooter()
{
    global $errorList;

    printf( 'Error: %d', count($errorList) );

    /*
    global $sortedList, $sortTimeList, $errorList;

    printf('Sorted:%d Time:%d Error:%d', count($sortedList), count($sortTimeList), count($errorList));
    */
}


// エラーを表示
function printError()
{
    global $errorList;

    foreach ($errorList as $line) {
        echo $line . PHP_EOL;
    }
}


function dumpProcess()
{
    global $dumpList;

    $filename = DUMP_LOG_BASE . date('YmdHis') . '.log';

    $fp = fopen($filename, 'w');

    if (!$fp) {
        throw new Exception('could not open ' . $filename);
    }

    foreach ($dumpList as $data) {
        fputs($fp, date('Y/m/d H:i:s', $data[0]) . ' ' . $data[1] . PHP_EOL);
    }

    fclose($fp);
}


function cleanDumpList()
{
    global $dumpList, $current;

    foreach ($dumpList as $key => $data) {
        if ( $current - $data[0] > 5 ) {
            unset($dumpList[$key]);
        } else {
            break;
        }
    }
}

デバッグ情報を埋め込んだpexファイルを作る

イベントの開始と終了でデバッグログを出力するようにします。

pexファイルにデバッグ情報を埋め込む (papyrus)

Event OnUpdate()
    Debug.TraceUser("Top", "caiEffectCombatReadyScript,READY,OnUpdate,begin")

    (中略)

    Debug.TraceUser("Top", "caiEffectCombatReadyScript,READY,OnUpdate,finish")
EndEvent

ユーザーログのファイル名は Top にします。

文字列はカンマ区切りにして、左から以下の情報を埋め込みます。

  • スクリプト名
  • ステート名
  • イベント名(関数名)
  • 開始ならbegin、終了ならfinish

ユーザー用トレースログを開くMod

以下のスクリプトを実行するModを用意します。

Scriptname SampleScript Extends ReferenceAlias

Event OnInit()
    Debug.OpenUserLog("Top")
EndEvent

Event OnPlayerLoadGame()
    Debug.OpenUserLog("Top")
EndEvent

Questを作り、ReferenceAliasを作り、Playerを割り当て、上記のスクリプトを紐付けます。

起動手順

ユーザー用トレースログのあるフォルダでコマンドプロンプトを開きます。

通常は以下のパスになると思います。

C:\Users\<ユーザー名>\Documents\My Games\Skyrim Special Edition\Logs\Script\User

このフォルダにtop.phpを置いておきます。

以下のコマンドで実行します。

php top.php

コマンドラインで実行する形になりますので、Skyrimを実行させたまま別のPCからSSHで接続してモニタリングするなどということも可能です。

画面の見かた

項目名説明
begin開始したイベント数
finish終了したイベント数
running稼働中のイベント数
chunkログファイルの分断を検知した回数
(デバッグ用です)
Loadイベントの時間あたりの稼働数
(左から順に5秒間、15秒間、60秒間)
Peak稼働数の最大値
Errorエラーの検知数
(デバッグ用です)

ピーク時にダンプする機能

起動後に1度だけ、同時稼働数が上限を超えた際に、稼働中のプロセス一覧を吐き出す機能があります。

define('ENABLE_PEAK_DUMP', TRUE);
define('PEAK_THRESHOLD',   400);

ENABLE_PEAK_DUMPをTRUEに設定します。FALSEでダンプが無効になります。

PEAK_THRESHOLDが同時稼働数です。

活用方法

実際に使ってみてできたことです。

動くべきイベント、動くべきではないイベントの検知

イベントの処理が想定している通りなのかどうかを実際に検証できます。

OnActorAction

Actorの抜刀、納刀を検知する方法のひとつにOnActorActionがあります。

簡単そうに見えるのですが、大きな問題があることに気が付きました。

このイベントはRegisterすると、ロードされているすべてのActorのイベントを捕捉します。ですのでOnActorActionイベント内でakActor引数を確認する必要があります。

問題は、NPC側でNPC自身の抜刀を検知するためにRegisterしていると、プレイヤーが抜刀してもNPC側でイベントが発火するということです。NPCが20体いると、20のインスタンスが同時に生成されます。武器の持ち替えも抜刀扱いです。当該NPCには関係のないイベントなので無視することになりますが、このようにあきらかに無駄なスクリプトが稼働するのは好ましくないです。

それから、RegisterForActorActionに注意書きがありますが、このイベントで捕捉できるのはPlayerのActionだけと書かれています。ではなぜakActor引数があるのか、よくわかりません。私が試した限りでは、すべてのActorの抜刀を検知していました。

OnActorActionのかわりにOnAnimationEventを使い、weaponDrawとweaponSheatheイベントを捕捉する方が効率が良いです。

OnHit

OnHitは当該Actorが攻撃を受けたときに発火します。このOnHitの注意事項としては、連続で発火するので高負荷になりやすいということです。

例えばエンチャント付きの武器で殴られると、武器の基本ダメージで1回、エンチャント処理で1回、それぞれ別々に合計2回発生します。

もっと酷いのがConcentrateのスペルで、押している間は出っぱなしになるスペルです。はじめから所持している火炎が該当します。

このConcentrate方式のスペルは、とても小さなダメージを毎秒5~6回の頻度で発生させます。よってOnHitも5~6回発火します。OnHitの内部処理にもよりますが、数秒間打ち続けているとスタックエラーが起こります。

OnHitが発火したら必ずステートを移行させて、しばらくの間はOnHitを発火させない時間を作るべきです。

OnCombatStateChanged

戦闘状態が移行したときに発火します。CombatStateが普段は0で、敵を察知したら2に移行し、敵を目視確認できたら1へ移行し、倒したら0に戻るという流れをたどります。

ところが、戦闘中に標的が切り替わったり、スクリプトによってStopCombatやStartCombatが実行されるなどすると、このCombatStateが目まぐるしく変化します。一瞬の間に1、0、1と移行したりするのです。

この移行のすべてでOnCombatStateChangedが発火するので、愚直に処理をしているとおかしなことになります。

OnCombatStateChangedが発火したらまずはステートを移行させ、連続で発火しないようにします。その場で処理はせずにOnRegisterSingleUpdateで1秒後に予約を行うことで、CombatStateの移行が落ち着くのを待ちます。OnUpdateの発火時にあらためてCombatStateを取得して処理します。

各種Modの動作がわかる

  • YASH2のYASHerに仕込んで、YASHed処理が終わったのかどうか。
  • Dark DungeonのOnCellLoadに仕込んで、ダンジョンの準備が終わったのかどうか。

Actorの挙動がおかしくなったのがわかる

突然Actorがおかしくなり、スクリプトの応答がなくなることがあります。

akTarget.IsDead()

この関数は生きているならFALSE、死んでいるならTRUEを返しますが、おかしくなったActorにたいして実行すると応答が返ってきません。よってスクリプトが無限に待機する状態になってしまいます。

なぜこうなるのかはわかりません。スクリプトの同時稼働数が多すぎるとか、Skyrim自体の負荷が高すぎるとか、メモリリークの結果によるものなのか、いくつか予想できますが、はっきりとしたことはわかっていません。

こうなると回復する方法はひとつしかなく、その場でセーブしてロードです。後回しにするメリットがまったくないので、この状況を検知したらただちにセーブ&ロードした方がいいです。この状況の検知ができます。

タイトルとURLをコピーしました