Как создать и исследовать лог процесса выполнения программы

Анализ исходного кода — давно зарекомендовавшая себя практика для выявления отклонений до выхода приложения на рынок. Проверка на уязвимости, program understanding, поиск логических ошибок в использовании библиотек, code review и многие другие методы статического, динамического и ручного анализа кода широко применяются во многих компаниях занимающихся разработкой программ. 

В службе аудита нашей компании также обращают внимание на методы анализа кода и недавно было проведено соревнование между филиалами по применению этих методов на одном из разработанных приложений.

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

Чтобы не использовать код внутреннего приложения, для примера возьмем одну из старых задач по анализу данных кадастровых участков на сайте Росреестра. У нас был список номеров, по которым необходимо было найти адрес, проверить наличие и посчитать занимаемую площадь зданий на участке. Используя библиотеки selenium и opencv мы написали программу для сбора информации и расчёта необходимых параметров участка. Код этого приложения мы и попробуем исследовать при помощи нестандартного метода используя лог запуска приложения и построенный на его основе граф.

Для проведения исследования процесса выполнения программы необходимо получить лог файл запуска блоков кода. Можно добавить блок с логгером в каждый конструктор каждого создаваемого класса, но этот метод не подходит, так как нежелательно менять исходный код исследуемого приложения. Для анализа необходимо записать время запуска и время окончания запуска функции конструктора — для этого можно воспользоваться декоратором. Декоратор – это специальная функция, которая позволяет расширить функциональность кода без его изменения.

Для исследуемой программы создадим новый модуль, в котором объявим функцию декоратор. На вход подается функция, которую необходимо расширить, а внутри объявляется еще одна функция которая будет содержать логику. В данном случае это вызов метода записи информации в лог файл:

import logging import logging import datetime  def log(func):     def wrapper():         logging.info("{};{};{};{}".format(datetime.datetime.now(), func.__module__, func.__name__, "func start"))         func()         logging.info("{};{};{};{}".format(datetime.datetime.now(), func.__module__, func.__name__), "func end")     return wrapper После этого просто подключаем модуль и используем декоратор для конструкторов наших классов: import selenium from selenium import webdriver import os import screenShot import LogDecorator  class Map:     @log #Вызов декоратора     def __init__(self, webDriver, registryNumber):         self.driver = webDriver         self.registryNumber = str(registryNumber)      def getScreenShot(self, registryNumber): 

Теперь запустив программу, используя подборку кадастровых номеров, мы получим дата сет адресов и площадей кадастровых участков и лог запуска. С последним будем работать далее для исследования.

Так как формат лога в функции декоратора был составлен таким образом, чтобы без проблем перевести файл лога в csv — переводим файл и используя методы библиотеки pandas создаем на его основе дата фрейм:

import pandas as pd # Загрузка лога в дата фрейм # Для того чтобы построился граф надо переименовать колонки с параметрами в определенные библиотекой форматы: # case:concept:name - номер кейса # concept:name- наименование события # time:timestamp - время события  df = pd.read_csv("./log_cad.csv")  df['dt_call']= pd.to_datetime(df['dt_call']) df.rename(columns = {'dt_call': 'time:timestamp', 'iter':'case:concept:name'}) df['concept:name'] = df[['method', 'module', 'status']].agg(':'.join, axis=1) df.head() 

Далее используя библиотеку pm4py конвертируем дата фрейм в лог событий и используя эвристический алгоритм строим граф процесса:

import pm4py as pm  df = pm4py.format_dataframe(df, case_id='case:concept:name', activity_key='concept:name', timestamp_key='time:timestamp') event_log = pm4py.convert_to_event_log(df) heu_net = pm4py.discover_heuristics_net(event_log, dependency_threshold=0.99) pm4py.view_heuristics_net(heu_net) 

По графу процесса видно, что несколько классов были инициализированы несколько раз, если посмотреть на код, то можно увидеть, что классы Map и Filter инициализируются с различными параметрами, что не является отклонением в данном случае, а вот класс ScreenShot выбивается из общей структуры кода и вызывается несколько раз без необходимости:

def cropScreenShot(self, imageLinks):         images = []         for imageLink in imageLinks:             imageShot = screenShot.Image()             img = imageShot.cropImage(imageLink)             images.append(img)         return images 

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

Решая задачу соревнования данным методом нам удалось найти несколько кейсов по вызову конструктора внутри цикла, а также некоторые неисполняемые части кода. 

Предлагаем всем желающим попробовать применить этот метод и поделиться своими исследованиями в комментариях