Логи браузера со вкладок Network и Console и добавление их в Allure

madvlaydin · 23.Май.2020 08:50:09

Коллеги, всем привет. Продолжаю делиться опытом автоматизации тестирования, и сегодня мы будем получать логи браузера со вкладок нетворк и консоль и аттачить их в аллюр.
Зачем это нужно?

У нас на бэкенде на каждый запрос генерируется request-id, по которому можно найти всю цепочку вызовов методов на среднем слое (интеграции, бд и т.д), и их-то мы будем вытаскивать со вкладки Network
Фронтенд не стоит на месте, новое добавляется, старое обновляется, потому неплохо бы уметь отлавливать ошибки js и складывать их в Allure
При этом логи я прикладываю и к успешным тестам, и к завалившимся. Зачем? Есть тесты, которые по всему приложению прокликивают менюшки; можно потом в одном месте посмотреть ошибки js и среднего слоя, потому что руками очевидно никто не сидит и не прокликивает более ста менюшек, постоянно меняя вкладки в девтулс.

Поехали!
Для начала научимся собирать логи консоли:

Юзаем последний селениум (4.0- что-то там Alpha)
В опциях хромдрайвера включаем логирование (может оно и не надо для консольных логов, проверьте сами, для логов нетворка понадобится) :

var options = new ChromeOptions()
    {
        options.SetLoggingPreference(LogType.Driver, LogLevel.All);

        options.AddArgument("--enable-logging");

        options.AddArgument("--enable-automation");
    }

Запускаем браузер:

Browser = new ChromeDriver(ChromeDriverDir, options);

В конце теста (в моем случае в методе Dispose) вызываю метод:

public void Dispose()
    {
        if(Browser != null)
            {
                AllureReport.GetLogsFromBrowser();

                Browser.Quit();
                    
                driverProcess.Kill();

                Browser = null;
            }
    }

        [ThreadStatic] private static List<LogEntry> logEntries = null;

        /// <summary>
        /// Перед выключением браузера кладем в переменную сообщения консоли, чтобы потом добавить в отчет аллюр
        /// </summary>
        public static void GetLogsFromBrowser()
        {
            logEntries = new List<LogEntry>();

            logEntries = Browser.Manage().Logs.GetLog(LogType.Browser).ToList();
        }

Что здесь происходит?

Перед выключением браузера (пока переменная не занулилась (я это руками делаю, потому что у меня под доменными учетками запускаются браузеры, нужно аккуратно менеджить переменные, чтобы тесты друг за другом не валились)) вытаскиваем из него логи.
Browser.Manage().Logs.GetLog(LogType.Browser) – помимо логов уровня Browser есть еще 4 типа, их нужно использовать в зависимости от того, как вы запускаете тесты (локально или через грид), можете через try catch попробовать использовать разные типы, мне достаточно LogType.Browser
Далее эти логи я складываю в ThreadStatic переменную, чтобы потом доложить все это дело в Allure.
Выглядеть это дело будет примерно так:

image980×360 28.3 KB

Теперь логи вкладки Network.
Тут все немного сложнее и вот почему:

мы можем заставить хромдрайвер писать полный лог того, что он делает, в файл типа .json, который затем будем вычитывать
этот файл лога будет занят процессом хромдрайвера до тех пор, пока этот процесс не выключится, то есть работать с файлом надо уже после завершения теста И выключения браузера (именно поэтому я работаю с логами в методе Dispose())
Файлы логов просто гигантские:
и практически всегда в результате будет получаться невалидный json:
image1073×819 53.2 KB

Нас всё это дело не страшит, потому начинаем действовать:

В опциях хромдрайвера говорим, что нужно писать лог в файл

var options = new ChromeOptions()
    {
        options.SetLoggingPreference(LogType.Driver, LogLevel.All);

        options.AddArgument("--enable-logging");

        options.AddArgument("--enable-automation");

        options.AddArgument($"--log-net-log={ProjectEnvironment.TestLogs}\\{AllureScenarioUUID}.json");
    }

В конце теста ПОСЛЕ выключения браузера и kill процесса хромдрайвера вызываю методы вытаскивания request-id и добавления всех собранных логов в аллюр:

public void Dispose()
    {
        if(Browser != null)
            {
                AllureReport.GetLogsFromBrowser();
                    
                driverProcess.Kill();

                Browser.Quit();

                AllureReport.GetRequestIDs();

                AllureReport.AddConsoleLogAndRequestIDs();

                Browser = null;
            }
    }

        /// <summary>
        /// После выключения браузера кладем в переменную все реквест-айди из гигантского json-файла логов
        /// </summary>
        public static void GetRequestIDs()
        {
            List<JToken> headersWithRequest = new List<JToken>();

            var log = ProjectEnvironment.TestLogs + "\\" + AllureScenarioUUID + ".json";

            while (log.IsFileLocked())
            {
                Thread.Sleep(500); // Если тест запущен под тестовой учеткой, то по какой-то причине может долго убиваться процесс драйвера, потому ждем, пока файл лога высвободится от занимающего его процесса
            }

            using (StreamReader sr = new StreamReader(log))
            {
                string file = sr.ReadToEnd();

                if (file.Substring(file.Length - 4).Contains(",")) // Json-файл логов может криво формироваться, что мешает его парсить. Проверям, что если в последних четырех символах файла содержится запятая
                {
                    file = file.TrimEnd('}') + "]}"; // тогда обрезаем стрингу файла до последней фигурной скобки и вставляем недостающие символы для нормального парсинга в json
                }

                var json = (JObject)JsonConvert.DeserializeObject(file); // десериализация в json

                try
                {

                    List<JToken> headers = json.SelectTokens("events[*].params.headers").ToList(); // вытаскиваем все headers запросов

                    headersWithRequest.AddRange(
                                                headers.FindAll(
                                                                header => header.ToString().ToLower().Contains("request-id")
                                                                &&
                                                                Regex.IsMatch(header.ToString().ToLower(), @"HTTP/1.1 [^2]\d{2}".ToLower())
                                                                )
                                                ); // ищем записи с request-id и статусом не 2ХХ
                }
                catch
                {
                    headersWithRequest = null;
                }
            }

            if (headersWithRequest != null)
            {
                RequestIDs = new List<string>();

                headersWithRequest.ForEach(header =>
                {
                    RequestIDs.Add(header.Children().First(child => child.ToString().ToLower().Contains("request-id")).ToString().ToLower().Replace("request-id: ", "")); // убираем объявление заголовка
                });

                RequestIDs = RequestIDs.Distinct().ToList(); // убираем дублирование (обязательно после удаления заголовков, иначе дубли останутся)
            }
        }


        static bool IsFileLocked(this string path)
        {
            try
            {
                using (Stream stream = new FileStream(path, FileMode.Open, FileAccess.Read, FileShare.None))
                {
                    stream.Close();
                }
            }
            catch (IOException)
            {
                return true;
            }

            return false;
        }

Что происходит?

собираем путь до файла лога
ждем, пока файл будет свободен для чтения
проверяем, что если он заканчивается на запятую, то дописываем нужные символы, чтобы правильно попарсить json
десериализуем его в переменную
по jpath events[*].params.headers ищем все запросы
Потом ищем все, которые содержат request-id, и при этом код запроса отличается от 2ХХ (Regex.IsMatch(header.ToString().ToLower(), @"HTTP/1.1 [^2]\d{2}".ToLower()))

image711×659 37.6 KB
ну и дальше вытаскиваем нужные нам request-id и складываем их в другую ThreadStatic переменную

Дальше мы вызываем метод добавления всего этого добра в Allure:

       public static void AddConsoleLogAndRequestIDs()
        {
            string ConsoleLogAndRequestIDs = $"Все request-id со статусом, отличным от 2ХХ (Всего таких request-id - {RequestIDs.Count}):\n";

            for (int i = 0; i < RequestIDs.Count; i++)
            {
                ConsoleLogAndRequestIDs += $"\n{i + 1}:\n";

                for (int j = 0; j < URLs.SEQ.Count; j++)
                {
                    ConsoleLogAndRequestIDs += $"{URLs.SEQ[j]}?filter=RequestId%20%3D%20'{RequestIDs[i]}'\n";
                }
            }

            ConsoleLogAndRequestIDs += "\n\nСсылки на SEC:";

            URLs.SEQ.ForEach(url => ConsoleLogAndRequestIDs += $"\n{url}");

            ConsoleLogAndRequestIDs += "\n\n\nОшибки работы в браузере со вкладки \"Console\":\n\n";

            logEntries.ForEach(entry => ConsoleLogAndRequestIDs += entry.Timestamp + "\n" + entry.Message + "\n\n");

            string logPath = ProjectEnvironment.AllureResults + @"\" + AllureScenarioUUID + ".log";

            File.WriteAllText(logPath, ConsoleLogAndRequestIDs);

            AllureLifecycle.Instance.UpdateTestCase(BaseSteps.AllureScenarioUUID, x => x.attachments.Add(new Attachment
            {
                name = "Лог консоли браузера и request-id's всех запросов с отличным от 2ХХ кодом ответа.",
                source = AllureScenarioUUID + ".log",
                type= "text/plain"
            }));
        }

Мы собираем текстовый аттач
сохраняем его в allure-results
и прикрепляем в отчет
Посмотреть доступные типы аттачей можете здесь
Поскольку на тестовом стенде у нас 2 бэкендовых сервера, лог будет находиться на одном из них, потому я собираю ссылки на оба SEQ-а, чтобы дабл-кликом можно было перейти в каждый из них.
Выглядеть по итогу это будет так:

image1220×1143 63.1 KB
И вот как выглядит система логирования, куда мы попадем по ссылкам из Allure:

image710×421 26.5 KB

Вот так выглядит файл лога

Все request-id со статусом, отличным от 2ХХ (Всего таких request-id - 4):

1:
https://dbokb-tstapp1/_logs/#/events?filter=RequestId%20%3D%20’80001047-0801-b600-b63f-84710c7967bb’
https://dbokb-tstapp2/_logs/#/events?filter=RequestId%20%3D%20’80001047-0801-b600-b63f-84710c7967bb’

2:
https://dbokb-tstapp1/_logs/#/events?filter=RequestId%20%3D%20’80006837-0001-cb00-b63f-84710c7967bb’
https://dbokb-tstapp2/_logs/#/events?filter=RequestId%20%3D%20’80006837-0001-cb00-b63f-84710c7967bb’

3:
https://dbokb-tstapp1/_logs/#/events?filter=RequestId%20%3D%20’800076a8-0001-a100-b63f-84710c7967bb’
https://dbokb-tstapp2/_logs/#/events?filter=RequestId%20%3D%20’800076a8-0001-a100-b63f-84710c7967bb’

4:
https://dbokb-tstapp1/_logs/#/events?filter=RequestId%20%3D%20’80007b90-0001-5200-b63f-84710c7967bb’
https://dbokb-tstapp2/_logs/#/events?filter=RequestId%20%3D%20’80007b90-0001-5200-b63f-84710c7967bb’

Ссылки на SEC:
https://dbokb-tstapp1/_logs/#/events
https://dbokb-tstapp2/_logs/#/events

Ошибки работы в браузере со вкладки “Console”:

22.05.2020 15:32:48
https://tstdbokb.psbnk.msk.ru/notifications-gateway/inapp/recentMessages?Limit.Value=5&MessageTypeGroupIds=884872EC-E50C-4EEF-8AE6-3CBF79131922&MessageTypeGroupIds=81E93782-80FD-4219-8E06-73CC61A647E1&MessageTypeGroupIds=2C177A62-FC2F-4857-9E43-CAF6ABB8D3D5&MessageTypeGroupIds=00E7B1C1-B06E-443F-B07E-D4AEB5E54018&MessageTypeGroupIds=EA23E487-0DDF-40D4-9876-430AAC152D44 - Failed to load resource: the server responded with a status of 500 ()

22.05.2020 15:32:48
https://tstdbokb.psbnk.msk.ru/notifications-gateway/inapp/summary - Failed to load resource: the server responded with a status of 500 ()

22.05.2020 15:32:51
https://tstdbokb.psbnk.msk.ru/notifications-gateway/inapp/recentMessages?Limit.Value=5&MessageTypeGroupIds=884872EC-E50C-4EEF-8AE6-3CBF79131922&MessageTypeGroupIds=81E93782-80FD-4219-8E06-73CC61A647E1&MessageTypeGroupIds=2C177A62-FC2F-4857-9E43-CAF6ABB8D3D5&MessageTypeGroupIds=00E7B1C1-B06E-443F-B07E-D4AEB5E54018&MessageTypeGroupIds=EA23E487-0DDF-40D4-9876-430AAC152D44 - Failed to load resource: the server responded with a status of 500 ()

22.05.2020 15:32:51
https://tstdbokb.psbnk.msk.ru/notifications-gateway/inapp/summary - Failed to load resource: the server responded with a status of 500 ()

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

На этом, собственно, всё, спасибо за внимание!

А вам нужны логи браузера в аллюре?

Да
Нет

0 участников

Funker · 23.Май.2020 09:10:10

это очень круто все, красиво, очень интерестно, даже полезно в некоторых случаях.
Но у меня вопрос - зачем? это не работа тестировщика, это не нужно тестировщику вообще. Это работы больше Infrastructure Engineer/SRE, все эти веще куда проще смотреть/делать поиск/отчет/смотреть payloads в других более удобных иструментах, таких как c Amazon CloudWatch / ELK-stack (Kibana).

Для меня это выглядит немного по другому.

Но автору хочу сказать - молодец, очень круто.

madvlaydin · 23.Май.2020 09:12:13

а чья это работа? автотест нашел ошибку, надо ее подкрепить пруфами, пруфы вытащил из логов и положил в аллюр

BabyRoot · 23.Май.2020 09:19:25

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

Funker · 23.Май.2020 09:20:09

ошибки в логах браузера это работа FE engineer, тот кто разрабатывает.

Конкретно в моем случае я таким не занимаюсь, FE прикрутили какую-то библиотеку которая собирает и отправляет вот все-все автоматичеки со всем что Devs нужно, они там потом смотрят анализируют, фильтруют и все такое, я этим не занимаюсь.
я могу сказать, что фича не работает и в консоле много ошибок и падает, посмотрите ребята, но это на этапе development а не на staging

BabyRoot · 23.Май.2020 09:23:42

Видите - всё просто - вы работает в компании и на проекте где всё очень чётко очерчено, каждый отвечает за свой уголок. А эта фича больше для тех кто многостаночник. Вот у вас и справедливое замечание - зачем? Всё просто - есть люди которым надо, и вообще-то за эти полгода на этом и другом форуме, в общем минимум раза 4 поднимался вопрос как брать логи, значит надо людям.

madvlaydin · 23.Май.2020 09:31:58

согласен, много видел вопросов про это, по итогу пришлось все делать самостоятельно

Noksa · 23.Май.2020 09:49:29

Я у себя аттачу не просто лог браузера в конце, а прям в шаг где что-то упало, особенно если это софт ассерт.
Так проще потом соотнести ошибку в логе и ошибку в тесте.

madvlaydin · 23.Май.2020 09:54:49

в шаг неудобно аттачить, потому что надо знать, что скрины есть, шаг надо открывать, потом сам скрин

а так если тест упал, то в нём будет видно типо тут скриншот, а тут логи

madvlaydin · 23.Май.2020 10:02:25

прошу обратить сюда внимание, если вам логи не нужны - не пытайтесь тогда с ними работать

так-то логи помогают понять, где ошибка:

в самом тесте
на бэке
на ui

да и вообще, у меня на проекте в баг желательно прикладывать реквест айди, скрины, ссылки на тз, .har файл из браузера

так что получить что-то ещё на этапе упавшего автотеста - весьма неплохо

Noksa · 23.Май.2020 10:04:18

Это неудобно, если не пользоваться вот этим пакетом: GitHub - Noksa/Allure.NUnit: C# NUnit Allure with improvements and SpecFlow3 adapter
А если пользоваться, то достаточно передать лямбдой что делать в случае если в шаге случилась ошибка

madvlaydin · 23.Май.2020 10:07:30

Александр, вам и так памятник надо при жизни ставить за развитие дотнет веб тестирования

Noksa · 23.Май.2020 10:21:11

Всё правильно вы говорите.

Я тоже разработчиков приобщил к тому, чтобы они смотрели отчеты аллюра.
В итоге для них очень удобно, если есть консольный лог браузера, который даст им информацию о том, где проблемное место.
А так же прикладывается видос теста, если у него статус не passed.
А все эти разговоры о том, что автотестирование не должно этим заниматься - ну хз.
Прикрутить логи браузера - 5-10 минут.
Почему бы это не сделать для упрощения поиска ошибок для своих коллег?

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

BabyRoot · 23.Май.2020 10:36:44

А у кого-то цели видимо другие на работе.

Разделять сферы ответственности. И устанавливать рамки.

madvlaydin · 23.Май.2020 11:31:50

опишите ваш flow разработки ui и как вы, будучи тестировщиком, в нем участвуете? я правильно понимаю, что разработчики как-то автоматически получают информацию о том, чем вы занимаетесь в браузере?

pbezpal5 · 23.Май.2020 17:06:08

У меня как-то проще получилось)

Вначале инициализации драйвера

LoggingPreferences logPrefs = new LoggingPreferences();
logPrefs.enable(LogType.PERFORMANCE, Level.ALL);
capabilities.setCapability("goog:loggingPrefs", logPrefs);

Затем прикручиваю логи к allure

 @Attachment(value = "Browser network log", type = "text/plain")
    public static String ABrowserLogNetwork() {
        LogEntries logs = WebDriverRunner.getWebDriver().manage().logs().get("performance");
        String logsBrowser = "";

        for (LogEntry le : logs) {
            Gson gson = new GsonBuilder().setPrettyPrinting().create();
            JsonParser jp = new JsonParser();
            JsonElement je = jp.parse(le.getMessage());

            //String prettyJsonString = gson.toJson(je);
            if (gson.toJson(je).contains("webSocketFrame"))  logsBrowser = logsBrowser + gson.toJson(je);


        }

        return logsBrowser;
    }

    @Attachment(value = "Browser console log", type = "text/plain")
    public static String ABrowserLogConsole() {

        List logList = Selenide.getWebDriverLogs(LogType.BROWSER);
        StringBuilder sb = new StringBuilder();

        for(Object line : logList) {
            sb.append(line);
            sb.append("\n");
        }

        return sb.toString();
    }

И вызываю эти функции после тестов)

madvlaydin · 23.Май.2020 17:22:07

я игрался с этими перформанс логами, и у меня не получилось, может не так гуглил

у вас в логах там с кодами ответов и вот этим всем добром?

а, так ещё и джава, эти советы я видел, у меня не взлетало почему-то

pbezpal5 · 23.Май.2020 17:57:31

У меня это выглядит вот так. Поговорил с разработчиками их устраивают такие логи)
Единственный нюанс, на firefox network ничего не возвращает

pbezpal5 · 23.Май.2020 21:58:09

Странно, у меня довольно быстро взлетело

Maksim_Laptev1 · 12.Июль.2020 14:55:42

Вопрос, каким образом получать Performance лог только с конкретным типом, например, xhr?