Skip to content

Usage

Jump to bottom
Aleksander edited this page Jul 30, 2019 · 6 revisions

Table of Contents

General

LogBlock.class is a core class of block-logger package. It's used to create a log block.

2018-04-25 15:45:31,379 [main      ] INFO  [+] authenticate (id=100, user_name=SIDSSIDS)
2018-04-25 15:45:31,379 [main      ] INFO      checking password
2018-04-25 15:45:31,383 [main      ] WARN  [-] authenticate (PT0.008S): wrong password
2018-04-25 15:45:31,384 [main      ] INFO  [+] authenticate (id=100, user_name=SIDSSIDS)
2018-04-25 15:45:31,384 [main      ] INFO      checking password
2018-04-25 15:45:31,384 [main      ] INFO      generating sessionId
2018-04-25 15:45:31,390 [main      ] INFO  [-] authenticate (PT0.006S): sessionId=1df8fedc-d884-4131-a9e1-77f1c0ebc17d
  • The block is started with [+] followed by the block title with parameters: authenticate (id=100, user_name=SIDSSIDS).
  • Any message within the body of the block will be printed with an indent.
  • The block ends with [-] followed by the block title, duration (PT0.017S) and a result: sessionId=4a60a850-9948-4ac2-aa6d-1683ce859035.
  • Duration is a time difference between block creation and close() method invocation.
  • Result is a optional message, giving some information about result of the block invocation.
CLICK HERE to see the source code for the example above 
public static void main(String[] args) {
    Main m = new Main();
    m.authenticate(100L, "SIDSSIDS", "1111111111");
    m.authenticate(100L, "SIDSSIDS", "1234567890");
}
private void authenticate(Long id, String username, String password) {
    try (LogBlock log = LogBlockFactory.info(Main.class, "authenticate", "id=%s, user_name=%s", id, username)) {
        log.info("checking password");
        if (checkPassword(password)) {
            log.info("generating sessionId");
            log.reportSuccess("sessionId=%s", UUID.randomUUID());
        } else {
            log.reportWarning("wrong password");
        }
    }
}
private boolean checkPassword(String password) {
    return "1234567890".equals(password);
}

Creation

LogBlock is created via static methods of LogBlockFactory (trace, debug, info, warn, error). You should specify a block title and some parameters (optional).

LogBlock log = LogBlockFactory.info(Main.class, "authenticate", "id=%s, user_name=%s", id, username);
/// some code
log.close();

LogBlock implements java.io.Closeable interface, so it's convenient to use it in with try-with-resources:

try (LogBlock log = LogBlockFactory.info(Main.class, "authenticate", "id=%s, user_name=%s", id, username)) {
    /// some code
}

Methods

LogBlock implements org.slf4j.Logger interface. You can use it like a usual Logger.

try (LogBlock log = LogBlock.info(Main.class, "authenticate", "id=%s, user_name=%s", id, username)) {
    log.error("unknown user: {}", username);   // org.slf4j.Logger method
}

NOTE: Unlike most implementations of org.slf4j.Logger, the LogBlock instance is NOT thread-safe. You should not share it between different threads.

When the block is closing, it can print some additional information, so-called report.
There are several methods to specify report:

  • reportSuccess* methods.
    These methods will use the log level of the block to print report.
  try (LogBlock log = LogBlockFactory.info(Main.class, "authenticate", "id=%s, user_name=%s", id, username)) {
      // ...
      log.reportSuccess("sessionId=%s", sessionId);
  }

Output:

  2018-04-25 16:46:46,051 [main      ] INFO  [+] authenticate (id=100, user_name=SIDSSIDS)
  ...
  2018-04-25 16:46:46,059 [main      ] INFO  [-] authenticate (PT0.008S): sessionId=c0ea7dc7-1103-4a56-941a-498c9ecd7599
  • reportTrace*, reportDebug*, reportInfo*, reportWarning*, reportError* methods.
    These methods will use the specified log level to print report.
  try (LogBlock log = LogBlockFactory.info(Main.class, "authenticate", "id=%s, user_name=%s", id, username)) {
      // ...
      log.reportWarning("wrong password");
  }

Output:

  2018-04-25 16:46:46,046 [main      ] INFO  [+] authenticate (id=100, user_name=SIDSSIDS)
  ...
  2018-04-25 16:46:46,050 [main      ] WARN  [-] authenticate (PT0.01S): wrong password

Handling exceptions

Method withException(Throwable ex) can be used to report exception. For example:

    private void getFileSize(String filename) {
        try (LogBlock log = LogBlockFactory.info(Main.class, "get file size", "filename=%s", filename)) {
            try {
                long size = Files.size(Paths.get(filename));
                log.reportSuccess("size=%s", size);
            } catch (IOException e) {
                log.withException(e)                   // handle exception
                   .reportError("Unable to get file size");
            }
        }
    }

    // ...

    getFileSize("unknown_file");

Output:

2018-04-25 17:01:44,797 [main      ] INFO  [+] get file size (filename=unknown_file)
2018-04-25 17:01:44,811 [main      ] ERROR [-] get file size (PT0.012S): Unable to get file size; Exception: java.nio.file.NoSuchFileException: unknown_file
java.nio.file.NoSuchFileException: unknown_file
	at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
	at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
	at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
	at sun.nio.fs.UnixFileAttributeViews$Basic.readAttributes(UnixFileAttributeViews.java:55)
	at sun.nio.fs.UnixFileSystemProvider.readAttributes(UnixFileSystemProvider.java:144)
	at sun.nio.fs.LinuxFileSystemProvider.readAttributes(LinuxFileSystemProvider.java:99)
	at java.nio.file.Files.readAttributes(Files.java:1737)
	at java.nio.file.Files.size(Files.java:2332)
	at com.github.sidssids.test.Main.getFileSize(Main.java:16)
	at com.github.sidssids.test.Main.main(Main.java:26)

Coupling with SL4J Logger

You can use standard SL4J Logger within a block, even from other threads, and log messages will be indented according to the block level.
Simple example:

Logger logger = LoggerFactory.getLogger(Main.class);
try (LogBlock log = LogBlockFactory.info(Main.class, "block")) {
    logger.info("inside the block");
}
logger.info("outside the block");

Output:

2018-04-25 17:33:25,954 [main      ] INFO  [+] block
2018-04-25 17:33:25,961 [main      ] INFO      inside the block
2018-04-25 17:33:25,963 [main      ] INFO  [-] block (PT0.009S)
2018-04-25 17:33:25,963 [main      ] INFO  outside the block

When you start a thread within a block, the indention of the block is 'copied' to the thread, and all log messages, generated from the new thread, will be indented according to this value.

Logger logger = LoggerFactory.getLogger(Main.class);
try (LogBlock log = LogBlockFactory.info(Main.class, "block")) {
    logger.info("inside the block");
    Thread t = new Thread(() -> logger.info("inside thread"));
    t.start();
    t.join();
}
logger.info("outside the block");

Output:

2018-04-25 17:45:44,299 [main      ] INFO  [+] block
2018-04-25 17:45:44,306 [main      ] INFO      inside the block
2018-04-25 17:45:44,307 [Thread-0  ] INFO      inside thread
2018-04-25 17:45:44,310 [main      ] INFO  [-] block (PT0.01S)
2018-04-25 17:45:44,310 [main      ] INFO  outside the block

Performance issues

Do not use many LogBlock's in high-load methods. Unlike SL4J Logger, LogBlock instance is created per itch invocation. Also String.format is used in the implementation, which is quite slow compared to StringBuilder for example.

Clone this wiki locally