Log-Driven Development

If we compare the application with the alive organism the bug could be compared with a disease. The cause of this "disease" can be a number of factors, including the environment of a particular user. This is really relevant when we are talking about web platform. Sometimes the reason is very complicated and the bug that was found through testing - the result of a number of actions.

As with human illnesses, no one can explain their symptoms better than a patient, any tester can tell what happened, better than the program itself.

What to do?

To understand what is happening, we need to have a history of the actions that the user performed in our application.

In order for our program to tell us that it hurts, we will take the logrock module and link it to ElasticSearch, LogStash, and Kibana for further analysis.

LogRock

The logrock module was born when we started working on the Cleverbrush product. This is software for working with vector graphics. Working with a graphics editor implies a huge number of application use cases. We are trying to save money and time, so we optimize everything, including testing. Covering each option with test cases is too expensive and irrational, especially since it is impossible to cover all options.

This module can organize modern logging approach for your application. Basing on the logs we test our application. In this article, I am going to tell you about how you can organize your logging system for searching bugs.

ElasticStack

ElasticSearch is a powerful full-text search engine.
LogStash is a system for collecting logs from various sources that can send logs to ElasticSearch as well.
Kibana is a web interface for ElasticSearch with many addons.

How does it work?

In case of an error (or just on demand), the application sends logs to the server where they are saved to a file. Logstash incrementally saves data to ElasticSearch - to the database. The user logs to Kibana and sees the saved logs.

Above you see a well set up Kibana. It displays your data from ElasticSearch. That can help you to analyze your data and understand what happened.

In this article, I am NOT considering setup ElasticStack!

Creating logging system

For example, we are going to integrate a logging system to single page application based on React.

Step 1. Installation:

npm install logrock --save

Step 2. Setup React Application

We need to wrap up the application with a component

import { LoggerContainer } from "logrock";

<LoggerContainer>
  <App />
</LoggerContainer>

LoggerContainer is a component that reacts to errors in your application and forms a stack.

A stack is an object with information about the user's operating system, browser, which mouse or keyboard button was pressed, and of course, the actions subarray, where all the user actions that he performed in our system are recorded.

LoggerContainer has settings, consider some of them.

<LoggerContainer
  active={true|false}
  limit={20}
  onError={stack => {
    sendToServer(stack);
  }}
>
  <App />
</LoggerContainer>

active enables or disables the logging.
limit sets a limit on the number of recent actions saved by the user. If the user performs 21 actions, then the first one in this array will be automatically deleted. Thus, we will have the last 20 actions that preceded the error.
onError is a callback that is called when an error occurs. The Stack object comes to it, in which all information about the environment, user actions, etc. is stored. It is from this callback that we need to send this data to ElasticSearch or backend or save it to a file for further analysis and monitoring.

Logging

In order to produce high-quality logging of user actions, we will have to cover our code with log calls.

The logrock module comes with a logger that is linked to the LoggerContainer.

For instance, we have a component:

import React, { useState } from "react";

export default function Toggle(props) {
  const [toggleState, setToggleState] = useState("off");

  function toggle() {
    setToggleState(toggleState === "off" ? "on" : "off");
  }

  return <div className={`switch ${toggleState}`} onClick={toggle} />;
}

In order to correctly cover it with a log, we need to modify the toggle method:

import React, { useState } from "react";
import logger from "logrock";

export default function Toggle(props) {
  const [toggleState, setToggleState] = useState("off");

  function toggle() {
    let state = toggleState === "off" ? "on" : "off";

    logger.info(`React.Toggle|Toggle component changed state ${state}`);

    setToggleState(state);
  }


  return <div className={`switch ${toggleState}`} onClick={toggle} />;
}

We have added a logger in which the information is divided into 2 parts. React.Toggle shows us that this action happened at the level of React, the Toggle component, and then we have a verbal explanation of the action and the current state that came to this component. This division into levels is not necessary, but with this approach, it will be clearer where exactly our code was executed.

We can also use the "componentDidCatch" method, which was introduced in React 16, in case an error occurs.

Interaction with the server

Consider the following example.

Let's say we have a method that collects user data from the backend. The method is asynchronous, part of the logic is hidden in the backend. How to properly add logging to this code?

Firstly, since we have a client application, all requests going to the server will pass within one user session, without reloading the page. In order to associate actions on the client with actions on the server, we must create a global SessionID and add it to the header for each request to the server. On the server, we can use any logger that will cover our logic like the example from the frontend, and if an error occurs, send this data with the attached sessionID to ElasticSearch, to the Backend plate.

Step 1. Generating SessionID on the client:

window.SESSION_ID = `sessionid-${Math.random().toString(36).substr(3, 9)}`;

Step 2. Requests.

We need to set the SessionID for all requests to the server. If we use libraries for requests, it is very easy to do this by declaring a SessionID for all requests.

let fetch = axios.create({...});

fetch.defaults.headers.common.sessionId = window.SESSION_ID;

Step 3. Connect SessionID to Log stack.

The LoggerContainer has a special field for SessionID:

<LoggerContainer
  active={true | false}
  sessionID={window.SESSION_ID}
  limit={20}
  onError={stack => {
    sendToServer(stack);
  }}
>
  <App />
</LoggerContainer>

Step 4. Interaction with backend.

The request (on the client) will look like this:

logger.info(`store.getData|User is ready for loading... User ID is ${id}`);

getData('/api/v1/user', { id })
  .then(userData => {
    logger.info(`store.getData|User have already loaded. User count is ${JSON.stringify(userData)}`);
  })
  .catch(err => {
    logger.error(`store.getData|User loaded fail ${err.message}`);
  });

How it works:

We write a log, before the request on the client. From our code, we can see that the download of data from the server will start now. We have attached the SessionID to the request. If our backend logs are covered with the addition of this SessionID and the request fails, then we can see what happened on the backend.

Thus, we monitor the entire cycle of our application, not only on the client but also on the server.

QA Engineer

Working with a QA engineer deserves a separate description of the process.

As we are startup, we have no formal requirements and sometimes not everything is logical.

If the tester does not understand the behavior, this is a case that at least needs to be considered. Also, often, a tester simply cannot repeat the same situation twice. Since the steps leading to the incorrect behavior can be numerous and non-trivial. In addition, not all errors lead to critical consequences such as Exception. Some of them can only change the behavior of the application, but not be interpreted by the system as an error. For these purposes, at staging, you can add a button in the application header to force the sending of logs. The tester sees that something is wrong, clicks on the button, and sends a Stack with actions to ElasticSearch.

In case, a critical error has occurred, we must block the interface so that the tester does not click further and get stuck.

For these purposes, we display the blue screen of death.

We see above the text with the Stack of this critical error, and below - the actions that preceded it. We also get the error ID, the tester just needs to select it and attach it to the ticket. Later this error can be easily found in Kibana by this ID.

For these purposes, the LoggerContainer has properties:

<LoggerContainer
  active={true | false}
  limit={20}
  bsodActive={true}
  bsod={BSOD}
  onError={stack => {
    sendToServer(stack);
  }}
>
  <App />
</LoggerContainer>

bsodActive enables / disables BSOD (disabling BSOD applies to production code)
bsod is React component. By default, it looks like the above screenshot.

To display the button in the UI LoggerContainer, we can use the hook:

const { getStackData, triggerError } = useLoggerApi();

triggerError(getStackData());

User interaction

Some logs are useful to the user. To output the user needs to use the stdout method:

<LoggerContainer
  active={true | false}
  limit={20}
  bsodActive={true}
  bsod={BSOD}
  onError={stack => {
    sendToServer(stack);
  }}
  stdout={(level, message, important) => {
    console[level](message);

    if (important) {
      alert(message);
    }
  }}
>
  <App />
</LoggerContainer>

stdout is the method that is responsible for printing messages.

In order for the message to become "important" it is enough to pass true to the logger as the second parameter. Thus, we can display this message to the user in a pop-up window, for example, if the data loading has failed, we can display an error message.

logger.log('Something was wrong', true);

Tips and tricks

Log applications, including in production, because no tester will find bottlenecks better than real users.
DO NOT forget to mention the collection of logs in the license agreement.
DO NOT log passwords, banking details, and other personal information!
Redundancy of logs is also bad, make messages as clear as possible.