About TrueZIP Extension JMX/JUL

This module instruments the TrueVFS Kernel for managing and monitoring via JMX and java.util.logging (JUL).

Warning

This module is not intended for durable use in production environments because of its performance impact due to excessive stack trace logging. Use for temporary testing and debugging only!

Usage

Add the JAR artifact of this module to the run time class path to make its services available for service location in the client API modules.

When using Maven, add the following to your pom.xml file:

<project    xmlns="http://maven.apache.org/POM/4.0.0"
            xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
            xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    ...
    <dependencies>
        ...
        <dependency>
            <groupId>de.schlichtherle.truezip</groupId>
            <artifactId>truezip-extension-jmx-jul</artifactId>
            <version>7.7.10</version>
            <scope>runtime</scope>
        </dependency>
    </dependencies>
</project>

Sample

To demonstrate this module, let's use the Tree class in the module TrueZIP Archetype File*. This class simply prints an ASCII directory tree of a directory and then terminates. When run unchanged with no arguments in the project directory of the generated archetype, it's output may look like this:

.
|-- nbactions.xml
|-- pom.xml
|-- src
|   `-- main
|       `-- java
|           `-- de
|               `-- schlichtherle
|                   `-- mavenproject1
|                       |-- Application.java
|                       |-- Cat.java
|                       |-- Copy.java
|                       |-- Pickr.java
|                       `-- Tree.java
|-- target
|   |-- classes
|   |   `-- de
|   |       `-- schlichtherle
|   |           `-- mavenproject1
|   |               |-- Application.class
|   |               |-- Cat.class
|   |               |-- Copy.class
|   |               |-- Pickr$1.class
|   |               |-- Pickr.class
|   |               `-- Tree.class
|   |-- generated-sources
|   |   `-- annotations
|   |-- maven-archiver
|   |   `-- pom.properties
|   `-- mavenproject1-1.0-SNAPSHOT.jar
|       |-- de
|       |   `-- schlichtherle
|       |       `-- mavenproject1
|       |           |-- Application.class
|       |           |-- Cat.class
|       |           |-- Copy.class
|       |           |-- Pickr$1.class
|       |           |-- Pickr.class
|       |           `-- Tree.class
|       `-- META-INF
|           |-- MANIFEST.MF
|           `-- maven
|               `-- de.schlichtherle
|                   `-- mavenproject1
|                       |-- pom.properties
|                       `-- pom.xml
`-- test.jar
    |-- archive.tar
    |   `-- pom.xml
    |-- archive.tar.gz
    |   `-- pom.xml
    |-- archive.zip
    |   `-- pom.xml
    |-- pom.xml
    `-- the-password-is-test1234.tzp
        `-- pom.xml

As you see, the Tree class recursively prints the (virtual) directory structure of the archive files mavenproject1-1.0-SNAPSHOT.jar and test.jar with its enclosed archive files.

It was said initially that you could do this without changing the client application code. However, the Tree class terminates immediately before you would even have a chance to connect to the JVM with JConsole. So let's add the following method to the base class Application:

@Override
protected void sync() throws FsSyncException {
    try {
        Thread.sleep(Long.MAX_VALUE);
    } catch (InterruptedException ok) {
    }
    super.sync();
}

This will not only make the Tree class run forever, it will also prevent it from unmounting the archive files, so that you have something to monitor and manage in the JConsole.

The MXBeans

Now, when running the tweaked utility, you see the output above and then the utility halts. Next, let's start JConsole and connect it to the JVM running the Tree class. When changing to the MBeans tab, you can now see some nice MXBeans for TrueZIP. Each of the MXBean classes provide attributes and operations with descriptions so you can figure what's going on.

The FsManager MXBean represents the singleton file system manager:

FsManager MXBean

It has two operations, one for unmounting all archive files and one for clearing all but the last I/O statistics.

The FsModel MXBeans represent federated file systems alias archive file systems:

FsModel MXBeans

Because the Tree class has found six archive files in the directory tree, we see six MXBeans, one for each mounted archive file. Each MXBean provides one operation for unmounting the respecting archive file.

Last but not least, the IOPool$Entry MXBeans represent temporary files:

IOPool$Entry MXBeans

It may be hard to follow, but one temporary file is required for each enclosed ZIP file - so in this case two temporary files for the file archive.zip and the-password-is-test1234.tzp within test.jar. Furthermore, because the TAR file format does not have a central directory, the TAR drivers unroll each TAR file when mounting them - so in this case two more temporary files for the file pom.xml in archive.tar and archive.tar.gz within test.jar.

Now you can inspect the attribute descriptions and values and/or you can use the umount/clearStatistics operations:

umount() operation

I need to add a few points, though:

  • If umount gets called on an FsModel MXBean with TrueZIP 7.1.3 or later, then the federated file system for the respective archive file and all enclosed federated file systems get unmounted. So if called on test.jar, then archive.tar, archive.tar.gz, archive.zip and the-password-is-test1234.tzp get unmounted, too. With earlier TrueZIP versions, the filtering doesn't work correctly and accidentally all archive files may get unmounted.
  • If umount gets called on the FsManager MXBean, then all federated file systems get unmounted.
  • In any case, this will only work if the federated file systems are idle! If any file system is busy doing I/O, then you will get a FsSyncException. So calling this operation is safe.

Once you unmount a federated file system, its respective FsModel and IOPool$Entry MXBeans vanish automagically. So you only see the stuff which keeps TrueZIP busy.

The Log Records

While the MXBeans are nice for managing and monitoring currently mounted archive file systems, JUL can maintain a log of all I/O activities for post-mortem analysis.

So let's add a file logging.properties with the following content:

#               Logging Configuration File
#
# You can use this file by specifying a filename
# with the java.util.logging.config.file system property.
# For example java -Djava.util.logging.config.file=myfile

#       Global properties

# "handlers" specifies a comma separated list of log Handler
# classes.  These handlers will be installed during VM startup.
# Note that these classes must be on the system classpath.
# By default we only configure a ConsoleHandler, which will only
# show messages at the INFO and above levels.
# To also add the FileHandler, use the following line instead.
#handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler
handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler

# Default global logging level.
# This specifies which kinds of events are logged across
# all loggers.  For any given facility this global level
# can be overriden by a facility specific level
# Note that the ConsoleHandler also has a separate level
# setting to limit messages printed to the console.
.level = INFO

# Handler specific properties.
# Describes specific configuration info for Handlers.

# default file output is in user's home directory.
#java.util.logging.FileHandler.pattern = %h/java%u.log
java.util.logging.FileHandler.pattern = truezip%u-%g.log
java.util.logging.FileHandler.limit = 1000000
java.util.logging.FileHandler.count = 10
java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter

# Limit the message that are printed on the console to INFO and above.
java.util.logging.ConsoleHandler.level = INFO
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter

# Example to customize the SimpleFormatter output format 
# to print one-line log message like this:
#     <level>: <log message> [<date/time>]
#
# java.util.logging.SimpleFormatter.format=%4$s: %5$s [%1$tc]%n

# Facility specific properties.
# Provides extra control for each logger.

# At the CONFIG level, you will see the configuration of services
# found on the class path. Use this to debug your class path configuration.
# The finer the level, the more information you will get.
# It's recommended to avoid the FINEST level because of its excessive output.
de.schlichtherle.truezip.level = FINER

You can activate this configuration by storing this file in the current directory and executing the JVM with the argument -Djava.util.logging.config.file=logging.properties.

The instrumented file system drivers then record a stack trace each time a temporary buffer (i.e. temporary file) is allocated or released and each time any file is opened or closed. This is nice for post-mortem analysis of issues like left-over-temporary-files or out-of-file-descriptors. Here are the log records for the Tree class with TrueZIP 7.4: ./truezip0-0.log.

Note the stack traces in the log file. As you can see from the first stack trace, the record comes from a call to TFile.exists() by the Tree class.

Note the use of different logging levels to support the filtering of interesting log records:

  • Level.FINE is used for allocating and releasing temporary buffers.
  • Level.FINER is used for opening and closing temporary buffers.
  • Level.FINEST is used for opening and closing any other file system entries.