Анализатор трассировки шаблона

[orka13]

Часто вижу вопросы типа: «Почему шаблон в 10 и в 50 потоков работает только в 2 раза быстрее а не в 5?» (свежий пример). И тогда обычно начинается холивар на тему оптимизации шаблона, выбора среды типа HDD vs RAMDisk, списки\таблицы vs БД, Intel vs AMD, поиск «узкого горлышка» через Трассировка проектов и т.д.
И вот с последним как раз проблема, ибо в трассировке легко найти по логу кубик-ошибку, но трудно посчитать среднестатистический показатель для понимания картины:
1) насколько часто эта ошибка появляется;
2) сколько в среднем времени она кушает;
3) насколько хуже тот же кубик отрабатывает в многопотоке по сравнению с однопотоком.
Вот как раз эти проблемы и закрывает мой небольшой шаблончик.

Как работает шаблон:
1. Включаем трассировку на исследуемом шаблоне (условно назовем его «Глюченый_Шаблон»).
2. Запускаем в ZennoPoster Глюченый_Шаблон в обычном режиме работы, допустим в 1…10 потоков.
3. Останавливаем работу Глюченый_Шаблон через несколько циклов работы (ну и хотя бы 60 минут чтобы он отработал). Дожидаемся завершения всех потоков. Желательно чтобы после остановки в папке из следующего пункта накопилось ~2…10 мегабайт логов.
4. Файлы трассировки (обычно они по пути типа «c:\Users\Administrator\Documents\ZennoLab\Traces\Глюченый_Шаблон.zp\») переносим в папку шаблона-анализатора «…\Analizator_Trassirovki\Input\1_Good\», то есть папка с файлами трассировки должна после этого стать пустой!
4. Запускаем Глюченый_Шаблон повторно но в режиме работы «под нагрузкой» где он по вашему мнению неоправданно «тормозит», допустим в 50…200 потоков, тут уже сами прикиньте сколько макс можно.
5. Останавливаем работу Глюченый_Шаблон как в пункте «№3» так чтобы в папке накопилось ~10…100 мегабайт логов (не рекомендую больше 100, а то может заглючить процесс). Файлы трассировки переносим в папку шаблона-анализатора «…\Analizator_Trassirovki\Input\2_Bad\».
6. Запускаем наконец-то мой шаблон-анализатор в 1 попытку и ждем. Через минут ~1...20 он обработает логи и посчитает среднее время выполнения для каждого кубика, сравнит их в обеих режимах и на выходе получим таблицы (идентичные, просто в разных форматах) типа:
«…\Analizator_Trassirovki\Table_Final_xlsx_2021-03-10-01-05.xlsx»
«…\Analizator_Trassirovki\Table_Final_csv_2021-03-10-01-05.csv»
Открываете любую таблицу, из нее можно прикинуть на каких кубиках наибольшие потери и заменить их. Например, я понял, что в моем шаблоне проблемы на кубике «71df525e-d0ff-4116-8383-eb71842933c0» («сохранения профиля») ибо в многопотоке он очень тупил, пришлось по возможности убрать его в ненужных местах.

Сортировка в таблице по последнем столбце. Везде кроме него время в миллисекундах, а вот в нем уже для удобства в минутах. Там посчитано насколько быстрее выполнился бы шаблон, если бы не было падения быстродействия. Но этот показатель еще стоит поделить на количество ваших потоков во втором режиме. То есть если у меня там было 100 потоков, значит только этот кубик украл ~4 минуты общего времени.

Кстати, если пролистать таблицу, то в низу можно найти кубики с минусовым значением. Можно было бы обрадоваться, что кубики начали быстрее выполнятся, но обычно хорошего тут мало. К примеру, у меня это кубик перехода по урлу в браузере, и среднестатистически он в многопотоке быстрее стал выполнятся из-за того, что чаще прокси не выдерживали нагрузки и пустую страницу мгновенно выдавали вместо прогрузки нормальной. Я это понял по резкому увеличению показателей в колонке «% неудач» для кубика, который в шаблоне шел следом за кубиком погрузки страницы и проверял наличие нужного текста на ней (то есть чаще по красной ветке стал выходить):


Подсказка для новичков: если вы хотите найти в таблице параметры нужного вам кубика, но не знаете его ID, то запустите в ProjectMaker его 1 раз, и из лога скопируйте ID этого действия («лог» включается через верхнее меню «Окно > Лог»):

Ну а в самом ProjectMaker кубики ищутся по ID через окно поиска (Ctrl+F):


Скачать шаблон можно в прикреплённых файлах внизу поста.

 

[radv]

Хорошая идея, попробую внедрить в свои проекты.

 

[Astraport]

Очень полезно! Трассировкой приходится иногда пользоваться в сложных случаях.

 

[backoff]

Давно админов прошу сделать такую вещь только с визуализацией, но и так думаю норм будет стата!
Молоток

 

[Mikhail B.]

Годнота. Опробую на деле!

 

[loshpek]

Пригодится!

 

[phoenixs]

Очень искал что-то подобное, спасибо!

 

[Bas]

Супер. Отдал голос за Вас и уже запустил шаблон трассироваться. Как раз не могу победить, почему на 1 компе он выполняется за 4 секунды, на другом тоже 4 на старте, а уже через пол часа за 8-12 секунд, когда на первом так и остается 4 секунды, хотя компы одинаковые практически

 

[Bas]

Как я и подозревал собственно, вся соль и боль в банальном запуске инстанса. 4 часа процессорного времени проект тупо запускал инстанс... Всего 20 потоков запустил для теста, а время запуска сразу в 5 раз возросло. Естественно свободных ресурсов достаточно для нормальной работы всех одновременно. Уже поднимал эту тему в обсуждении билда. Так никто и не ответил

PS: спасибо за полезный шаблон, реально так намного нагляднее, чем по notepad++ бегать с помощью ctrl + f.

 

[orka13]

Посмотреть вложение 73823

Как я и подозревал собственно, вся соль и боль в банальном запуске инстанса. 4 часа процессорного времени проект тупо запускал инстанс... Всего 20 потоков запустил для теста, а время запуска сразу в 5 раз возросло. Естественно свободных ресурсов достаточно для нормальной работы всех одновременно. Уже поднимал эту тему в обсуждении билда. Так никто и не ответил

PS: спасибо за полезный шаблон, реально так намного нагляднее, чем по notepad++ бегать с помощью ctrl + f.

Спасибо за тест реальный, а то я уже задумался: "лайкают, но запускал хоть кто-то шаблон?". А тот тут нет "кнопки бабло"

 

[Lord_Alfred]

Шаблон огонь

 

[RoyalBank]

У кого есть идеи, как лучше организовать работу чекпоинтов для замера скорости общего кода.

 

[Phoenix78]

У кого есть идеи, как лучше организовать работу чекпоинтов для замера скорости общего кода.

измерять разницу времени между началом кода и концом. или чекпоинты это не то ?

 

[RoyalBank]

измерять разницу времени между началом кода и концом

Так то понятно, что можно сделать void в начеле и конце кода, в который передавать название текущего этапа, а также запускать и останавливать Stopwatch() .
Вопрос в наличии, возможного, более элегантного решения, может какая библиотека есть...

 

[Mikhail B.]

Воспользовался шаблоном. Спасибо за работу. Разбираю свой проект, нашел узкие места. Правда я не сравниваю один поток с многопотоком. Мне просто важно посмотреть узкие места шаблона. По этому дублировал файлы в обе папки.

1) Не хватает пары колонок. Максимальное значение, минимальное значение. Приведу пример, у меня GET запрос составляет 1.6 сек среднее значение. Таймаут установлен 10 сек. Понять бы в каких значениях плавает запрос. И по моему процент неудач немного не корректно работает, ну либо сама трассировка не совсем корректно отображает эти данные. Переход по красной ветке считается неудачей?

2) Еще не помешал бы блеклист ID, что бы исключить всякие паузы и прочее из анализа. После первой проверки, их загнать в список и далее мониторить только важные моменты.

Думаю в целом могу и я допилить проект. Но если вдруг у тебя есть такое желание, то проинформируй, что бы не пришлось делать двойную работу))

 

[orka13]

...Переход по красной ветке считается неудачей?

Да.

...Думаю в целом могу и я допилить проект. Но если вдруг у тебя есть такое желание, то проинформируй, что бы не пришлось делать двойную работу))

Пока к сожалению допиливать нет времени, слишком погряз в работе.

 

[Anonim]

Воспользовался шаблоном. Спасибо за работу. Разбираю свой проект, нашел узкие места. Правда я не сравниваю один поток с многопотоком. Мне просто важно посмотреть узкие места шаблона. По этому дублировал файлы в обе папки.

1) Не хватает пары колонок. Максимальное значение, минимальное значение. Приведу пример, у меня GET запрос составляет 1.6 сек среднее значение. Таймаут установлен 10 сек. Понять бы в каких значениях плавает запрос. И по моему процент неудач немного не корректно работает, ну либо сама трассировка не совсем корректно отображает эти данные. Переход по красной ветке считается неудачей?

2) Еще не помешал бы блеклист ID, что бы исключить всякие паузы и прочее из анализа. После первой проверки, их загнать в список и далее мониторить только важные моменты.

Думаю в целом могу и я допилить проект. Но если вдруг у тебя есть такое желание, то проинформируй, что бы не пришлось делать двойную работу))

а можно в Лс скинуть, если допилили шаблончик

 

[Mikhail B.]

а можно в Лс скинуть, если допилили шаблончик

Извини, забил тоже, тут обнов навалилось выше крыши. Да и нашел узкие места которые искал, и дальше не стал. Есть и другие проекты которые хотел проверть, может тогда и обновлю.

 

[Anonim]

Извини, забил тоже, тут обнов навалилось выше крыши. Да и нашел узкие места которые искал, и дальше не стал. Есть и другие проекты которые хотел проверть, может тогда и обновлю.

Понял, пойду тоже тестировать.

 

[bigloafer]

Я так понимаю, чтобы проанализировать свой шаблон, надо чтобы конкретные действия находились в отдельных кубиках.
А как быть если шаблон находиться в одном кубике?

 

[backoff]

А как быть если шаблон находиться в одном кубике?

переписать один кубик на отдельные кубики )

 

[Phoenix78]

Я так понимаю, чтобы проанализировать свой шаблон, надо чтобы конкретные действия находились в отдельных кубиках.
А как быть если шаблон находиться в одном кубике?

использовать свое решение, для логирования действий.

 

[Mikhail B.]

Обновил шаблон под свои задачи. Это не сравнение, а проверка одного потока шаблона. (может и нескольких, не тестил)
Запись ведется статичную таблицу, что бы поля сохраняли свои размеры. + добавил блек лист, что бы исключать ненужные кубики. Выполнять лучше в ZP, а править в PM.

P.S. Может и вайт лист добавлю, тогда обновлю шаб.

 

[Mikhail B.]

Есть идея, но я ее реализую в следующий раз.

Есть разное время выполнения действия. Я считаю кол-во отхождений от среднего и уже считаю процент проблемных выполнений от общего. Если он уходит за установленный лимит, то проблема есть. Допустим 10%. Проценты можно будет менять.

Допустим если выполнением является пауза от 1 до 5 сек. То такой кубик будет считаться проблемным, т.к. есть явные расхождения по времени выполнения.

Таким образом можно более эффективно находить плавающие и не явные проблемы в шаблоне. Когда например среднее выполнение 1 секунда, но при этом в 20% случаев выдает 5 секунд. С математикой не очень дружу, может есть какие-то формулы для подобных расчетов, если поделитесь, то буду очень признателен.

 

[Mikhail B.]

Теперь анализатор огонь!
по крайней мере для меня)))

- Считает кол-во отклонений от среднего
- Считает процент отклонений от среднего
- Суммирует время отклонений
- Показывает минимальное время выполнения
- Показывает максимальное время выполнения

- Блеклист вывел во входящие настройки

Удалено
- Среднее время выполнения кубива

Спойлер: Как этим пользоваться?

Так смотрите у нас кубик GET-Запроса.
Мы видим, что его процент отклонений является 19%. Эти 19% скорее всего таймаут. т.к. максимальное время 10 сек. Общее время отклонений составило 260 сек, что для 2 часового выполнения не так много. Но мне эти секунды важны. Думаю надо таймаут сделать по меньше, или прикрутить быструю смену прокси на этом этапе. Уже не важно, главное проблема найдена. Пробуйте)

 

[Dimazzan]

Теперь анализатор огонь!
по крайней мере для меня)))

- Считает кол-во отклонений от среднего
- Считает процент отклонений от среднего
- Суммирует время отклонений
- Показывает минимальное время выполнения
- Показывает максимальное время выполнения

- Блеклист вывел во входящие настройки

Удалено
- Среднее время выполнения кубива

Спойлер: Как этим пользоваться?

Так смотрите у нас кубик GET-Запроса.
Мы видим, что его процент отклонений является 19%. Эти 19% скорее всего таймаут. т.к. максимальное время 10 сек. Общее время отклонений составило 260 сек, что для 2 часового выполнения не так много. Но мне эти секунды важны. Думаю надо таймаут сделать по меньше, или прикрутить быструю смену прокси на этом этапе. Уже не важно, главное проблема найдена. Пробуйте)

Посмотреть вложение 93094

Огонь да
Тип Время Сообщение
03:22:02 Выполнение действия Table Колонка D отсутствует в таблице
03:22:02 Выполнение действия Table Ошибка при обработке таблицы

 

[Mikhail B.]

Огонь да

Чет видмо накосячил.

7.3.2.1 Писал на этой версии.

 

[gospodinkot]

Круто! Спасибо за шаблон и за апдейт. Скажите, а есть ли способ отследить сколько ресурсов кушает тот или иной кубик? Сильно нагружается процессор хочу понять что именно его грузит. Это вообще возможно?

 

[Devostator]

разобрался

 

[adr1enette]

Теперь анализатор огонь!
по крайней мере для меня)))

- Считает кол-во отклонений от среднего
- Считает процент отклонений от среднего
- Суммирует время отклонений
- Показывает минимальное время выполнения
- Показывает максимальное время выполнения

- Блеклист вывел во входящие настройки

Удалено
- Среднее время выполнения кубива

Спойлер: Как этим пользоваться?

Так смотрите у нас кубик GET-Запроса.
Мы видим, что его процент отклонений является 19%. Эти 19% скорее всего таймаут. т.к. максимальное время 10 сек. Общее время отклонений составило 260 сек, что для 2 часового выполнения не так много. Но мне эти секунды важны. Думаю надо таймаут сделать по меньше, или прикрутить быструю смену прокси на этом этапе. Уже не важно, главное проблема найдена. Пробуйте)

Посмотреть вложение 93094

Есть более усовершенствованная версия?