Почему профилировщик Node.js говорит, что большая часть приложения тратит время на функцию, которая не работает? - PullRequest
0 голосов
/ 01 февраля 2019

У меня есть простое серверное приложение Node.js, которое выполняет игровую логику.Логика игры в основном управляется классом Director, который управляет объектами Actor.Я тестирую и профилирую свой сервер, порождая огромное количество актеров (10 000), чтобы увидеть, где игровая логика тратит большую часть своего времени.У меня проблема в том, что выходные данные Node.js говорят мне, что огромная часть времени, проводимого на сервере, происходит в функции, которая, похоже, вообще не вызывается.

Я довольнонеопытный в Javascript, поэтому я могу просто не понимать, что происходит на уровне интерпретатора, но у меня достаточно опыта в создании игровых движков, поэтому моя путаница определенно связана с выходными данными Javascript или Node.

Я запустилПрофилировщик Node.js выглядит так:

NODE_ENV=production node --prof Server.js
sed -r 's/C\:\\[^,]+/"&"/g' isolate-0000022596D596F0-v8.log | sed -r '/C\:./ { s/\\/\//g }' > converted.log
node --prof-process converted.log > profile.log

Вторая строка необходима, потому что узел имеет ошибку в окнах, которая превращает каталоги окон в escape-символы.Файл profile.log показывает следующее:

 [Bottom up (heavy) profile]:
  Note: percentage shows a share of a particular caller in the total
  amount of its parent calls.
  Callers occupying less than 1.0% are not shown.

   ticks parent  name
  57843   60.9%  "C:/programs/nodejs/node.exe"
  46489   80.4%    "C:/programs/nodejs/node.exe"
  16070   34.6%      LazyCompile: *Actor "C:/git/tv/static/Actor.js:7:15"
  16054   99.9%        LazyCompile: *Director.step "C:/git/tv/static/Director.js:139:35"
  15585   97.1%          LazyCompile: *processTimers timers.js:220:23
    469    2.9%          LazyCompile: ~<anonymous> "C:/git/tv/Server.js:99:21"
    469  100.0%            LazyCompile: ~ontimeout timers.js:429:19
  11388   24.5%      LazyCompile: *GeometryPartitioner.addShapeComponent "C:/git/tv/static/GeometryPartitioner.js:8:59"
  11388  100.0%        LazyCompile: *Actor.stepComponents "C:/git/tv/static/Actor.js:74:42"
  11367   99.8%          LazyCompile: *Director.step "C:/git/tv/static/Director.js:139:35"
  11047   97.2%            LazyCompile: *processTimers timers.js:220:23
    320    2.8%            LazyCompile: ~<anonymous> "C:/git/tv/Server.js:99:21"

Глядя на верхнюю часть восходящего профиля, я вижу, что строка 7 Actor.js, по-видимому, вызывает 34,6% работы! ??Второй по величине блок имеет смысл, потому что GeometryPartitioner - это место, где я делаю широкофазное обнаружение столкновений, но Actor.js: 7 - это просто конструктор Actor - и он даже не вызывается!Вот как выглядит Actor: 7:

function Actor(actorType){
    this.actorType = actorType;
    this.id = undefined;
    this.flagNullify = false;
    this.localPosition = V2();
    this.localRadians = 0;
    this.localScale = V2(1,1);
    this.rootSceneComponent = null;
    this.components         = [];
    this.sceneComponents    = [];
    this.director           = null;
    this.movementComponent  = null;
    this.gunComponent       = null;
    this.totalAabb = AxisAlignedBox();
}

Я поместил console.log в конструктор Actor, просто чтобы посмотреть, действительно ли он вызывается внутри Director.step, как предполагает профиль, но он никогда не печатается во времяосновной цикл!Единственный раз, когда он запускается, это когда я создаю 10 000 актеров до запуска основного цикла, и он выполняется очень быстро (примечание: я удалил console.log, который я вставил в конструктор Actor во время сеанса профилирования, чтобы предотвратить 10 000 строк журналов спама):

(function(){
    console.log("spawning ton of actors...");
    for(var a = 0; a < 10000; a++){
        var roid = director.spawnActor(Actor.prototype.TYPE_ROID);
        roid.setPosition(V2(
            TV.randRange(0, 1000000), 
            TV.randRange(0, 1000000)));
    }
    console.log("done!");
})();

Я в полном замешательстве.Есть ли что-то происходящее на заднем плане, которое заставляет объекты Actor конструироваться без моего ведома?Все, что я сейчас знаю, это то, что Director хранит и управляет объектами Actor следующим образом:

function Director(context2d, netAuthorityType){
    this.actors = {};

Таким образом, все объекты-субъекты хранятся в переменной this.actors директора, и я перебираю ключи этого объектаи доступ к его значениям для обработки их внутри функции Director.step следующим образом:

    for(var id in this.actors){
        actorCount++;
        var actor = this.actors[id];
        actor.step(deltaSeconds);
        actor.stepComponents(deltaSeconds, geoPartitioner, gfxPartitioner);
        if(actor.flagNullify){
            cleanup.push(actor.id);
        }
    }

Я просто не понимаю, почему выходные данные профилировщика Node.js говорят мне, что Director создает новые объекты Actor внутриего пошаговая функция, хотя это явно не так?Я неправильно читаю вывод профилировщика Node.js?Я делаю что-то в корне неправильно в Javascript?

Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.
...