Попробовал воспользоваться StartMeasure, EndMeasure.
1) Кусок кода в EndMeasure, который отвечает за запись в базу был закомментирован(!)
Раскомментировал - появились данные на закладке X-Ray->Performance ))))
2) Удивительные значения я там увидел:
- Average time по функции(ям) getProperty рос как на дрожжах. Когда посчитал, оказалось он немногим больше 9 лет))). При uptime малины 2 дня. Это среднее-то время выполнения...
В коде object.class.php, в начале функции getProperty был кусок
Код: Выделить всё
if ($this->object_title) {
$value=SQLSelectOne("SELECT VALUE FROM pvalues WHERE PROPERTY_NAME = '".DBSafe($this->object_title.'.'.$property)."'");
if (isset($value['VALUE'])) {
startMeasure('getPropertyCached2');
endMeasure('getPropertyCached2', 1);
endMeasure('getProperty ('.$property.')', 1);
endMeasure('getProperty', 1);
return $value['VALUE'];
}
}
startMeasure('getProperty');
startMeasure('getProperty ('.$property.')');
Сначала закомментировал странное закрытие измерения. Помогло. Исправил на
Код: Выделить всё
startMeasure('getProperty');
startMeasure('getProperty ('.$property.')');
if ($this->object_title) {
$value=SQLSelectOne("SELECT VALUE FROM pvalues WHERE PROPERTY_NAME = '".DBSafe($this->object_title.'.'.$property)."'");
if (isset($value['VALUE'])) {
startMeasure('getPropertyCached2');
endMeasure('getPropertyCached2', 1);
endMeasure('getProperty ('.$property.')', 1);
endMeasure('getProperty', 1);
return $value['VALUE'];
}
}
Теперь, кажется, работает.
Просьба, если я не прав, скажите, т.к. очень нужен инструмент мониторинга...
PS: Система не альфа. Не скачаны обновления от 08.02.17.
UPD1:
- значения среднего времени выполнения растут медленно, но верно
- уменьшил срок хранения значений в perfomance_log c одного часа до одной минуты. Все равно используются последние 10 секунд...
- получается, что чистится эта таблица только если открыта страница X-Ray->Performance. Хорошо, что заметил... Добавил чистку в один из методов onNewMinute()
- по коду - очень неаккуратно закрываются измерения (просмотрел только setProperty и getProperty), что увидел, исправил
- посмотрим доживет ли малина до утра)))
UPD2:
Не знаю радоваться мне или, наоборот... не радоваться...
С одной стороны я нашел, что искал - замедление работы системы и в целом и в отдельных ее частях. Отсюда отваливающиеся Websocket'ы на главной странице, катастрофическое замедление чтения socket'ов в модуле MySensor и бог его знает чего еще...
С другой стороны код StartMeasure, EndMeasure стремный какой-то:
- написан в 2001-2004 гг.
- судя по всему с тех пор им вообще никто не пользовался))))
- получаемые с помощью него значения не понятно как интерпритировать, например, в текущий момент в моей системе процесс чтения сокета запускается 38 раз в 10 секунд и занимает в среднем ~3500 секунд. Это почти час. А система все еще работает....
UPD3:
Вот, например
- setProperty.jpg (25.9 КБ) 3079 просмотров
SETPROPERTY - время записи согласно модулю измерений
SETTESTPROP - время измерения конкретного свойства, замеренное напрямую, без участия модуля измерений, в одном из onNewMinute()
(Масштаб у графиков разный (!) )