Merge branch 'next-release' into 'master'0.5

Merge candidate for release 0.5 to master

See merge request Storage/ioriot!1

15 files changed, 1523 insertions, 522 deletions

diff --git a/.gitignore b/.gitignore
index 07f2f4b..1646026 100644
--- a/.gitignore
+++ b/.gitignore
@@ -5,3 +5,5 @@ docs/latex/
 ioriot/ioriot
 ioriot/tags
 systemtap/downloads/
+docker/
+Dockerfile
diff --git a/Dockerfile.in b/Dockerfile.in
new file mode 100644
index 0000000..60a49cf
--- /dev/null
+++ b/Dockerfile.in
@@ -0,0 +1,16 @@
+FROM centos:7
+
+RUN sed -i 's/enabled=0/enabled=1/' /etc/yum.repos.d/CentOS-{Vault,Debuginfo}.repo
+RUN yum install -y gcc systemtap yum-utils wget
+ENV kernel KERNEL
+RUN yum install -y kernel-${kernel} kernel-devel-${kernel}
+RUN debuginfo-install -y kernel-${kernel}
+
+WORKDIR /ioriot
+ADD ./ /ioriot
+
+RUN mkdir -p /ioriot/systemtap/downloads
+RUN mkdir -p /opt/ioriot
+
+VOLUME /opt
+VOLUME /ioriot/systemtap/downloads
diff --git a/Makefile b/Makefile
index 7e7099d..fb75703 100644
--- a/Makefile
+++ b/Makefile
@@ -1,4 +1,6 @@
+KERNEL ?= $(shell uname -r)
 DESTDIR=/opt/ioriot
+PWD=$(shell pwd)
 all:
 	$(MAKE) -C systemtap
 	$(MAKE) -C ioriot
@@ -19,3 +21,13 @@ doxygen:
 	doxygen ./docs/doxygen.conf
 test:
 	$(MAKE) -C ioriot test
+dockerbuild:
+	bash -c 'test ! -d $(PWD)/docker/opt/ && mkdir -p $(PWD)/docker/opt/; exit 0'
+	bash -c 'test -f /etc/fedora-release && sudo chcon -Rt svirt_sandbox_file_t $(PWD)/docker/opt; exit 0'
+	bash -c 'test -f /etc/centos-release && sudo chcon -Rt svirt_sandbox_file_t $(PWD)/docker/opt; exit 0'
+	bash -c 'test -f /etc/redhat-release && sudo chcon -Rt svirt_sandbox_file_t $(PWD)/docker/opt; exit 0'
+	sed s/KERNEL/$(KERNEL)/ Dockerfile.in > Dockerfile
+	docker build . -t ioriot:$(KERNEL)
+	docker run -v $(PWD)/docker/opt:/opt -e 'KERNEL=$(KERNEL)' -it ioriot:$(KERNEL) make all test install
+dockerclean:
+	bash -c 'test -d $(PWD)/docker && rm -Rfv $(PWD)/docker; exit 0'
diff --git a/README.md b/README.md
index e668f94..d39ed58 100644
--- a/README.md
+++ b/README.md
@@ -47,286 +47,15 @@ This is also potentially a great tool just for analysing (not replaying) the I/O
 

 Future work will also include file hole support and I/O support for memory mapped files.

 

-# Getting started

+# How to install I/O Riot

 

-I/O Riot consists of a set of SystemTap kernel modules (capturing I/O) and the tool ``ioriot`` (replaying I/O). Usually you want to capture I/O from a production machine and want to replay it on a separate load testing machine.

- 

-## System requirements

+I/O Riot depends on SystemTap and a compatible version of the Linux Kernel. To get started have a read through the [installation guide](docs/markdown/installation.md).

 

-I/O Riot has been tested on

+# How to use I/O Riot

 

-* CentOS 7.4 64Bit (latest version, all packages up to date, booted into the installed Kernel)

-* SystemTap (from the default CentOS repository)

-* GCC C-Compiler (from the default CentOS repository)

+Check out the [I/O Riot usage guide](docs/markdown/usage.md) for a full usage workflow demonstration.

 

-Before proceeding please ensure that the latest CentOS 7 kernel is installed and running on all machines involved. It should also be ensured that the capture machine and the load test machine have the same mount points mounted. This is to ensure that I/O is being replayed on the corresponding data drives on the load test machine.

-

-## Compiling and installing ioriot 

-

-I/O Riot has to be installed on all machines involved.  To install I/O Riot perform the following steps:

-

-```sh

-sudo yum install gcc systemtap yum-utils kernel-devel-$(uname -r)

-sudo debuginfo-install kernel-$(uname -r)

-make && sudo make install

-export PATH=$PATH:/opt/ioriot/bin

-```

-

-This will install the ``ioriot`` utility to ``/opt/ioriot/bin/`` and the SystemTap kernel modules to ``/opt/ioriot/systemtap/``. Run ``ioriot -h`` to print out a brief help.

-

-However, best practise is not to install any compilers on a production machine. You can either compile I/O Riot from scratch on all machines involved like shown above or only compile it on a build machine and distribute the ``/opt/ioriot`` directory to the remaining machines. In the latter case you will also need to install the ``systemtap-runtime`` package as an additional dependency.

-

-In case you decided to deinstall I/O Riot you can do so by running

-

-```sh

-sudo ioriot -P # purges all test files created by ioriot

-sudo make uninstall

-```

-

-# Operating I/O Riot

-

-## 1. Capture

-

-The following steps are required to capture all I/O operation of the entire (Linux) system to the file ``io.capture``. For efficiency and security it is only capturing the meta data (amount of bytes written and read) and not the actual data itself. It is also capturing the system time in microseconds and the process IDs (PIDs) and thread IDs (TIDs) used as well as all relevant options and flags of the corresponding I/O syscalls. It will stop capturing automatically after 60 minutes:

-

- * 1) Stop all applications on the machine. Otherwise the kernel module won't recognize any already opened file handles. Stopping the applications before starting with the capture is essential for tracing the flags in how the files were opened. All I/O operations on unknown file handles will be ignored otherwise.

- * 2) Run:

-

-```sh

-sudo ioriot -c ~/io.capture

-```

-

- * 3) Start all applications again.

- * 4) To stop capturing I/O type Ctrl+C. Alternatively one hour for the Kernel module to auto exit.

-

-To capture only I/O caused by Java process run:

-

-```sh

-sudo ioriot -c ~/io.capture -m javaioriot.ko

-```

-

-To capture the I/O of a specific process run the following respectively:

-

-```sh

-sudo ioriot -c ~/io.capture -m targetedioriot.ko -p PID

-```

-

-The resulting capture log looks like this and can be multiple GB in size:

-

-```sh

-#|capture_version=2|

-t=1511381122062;:,i=7764:8093;:,o=open;:,d=162;:,p=///usr/local/mimecast/someapp/somesubdir/vd11-9:1;:,f=0;:,m=438;:,

-t=1511381122062;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122062;:,i=7764:8093;:,o=read;:,d=162;:,b=12;:,

-t=1511381122062;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122062;:,i=7764:8093;:,o=lseek;:,d=162;:,O=0;:,W=1;:,b=12;:,

-t=1511381122062;:,i=7764:8093;:,o=read;:,d=162;:,b=0;:,

-t=1511381122062;:,i=7764:8093;:,o=close;:,d=162;:,s=0;:,

-t=1511381122062;:,i=7764:8093;:,o=open;:,d=162;:,p=///usr/local/mimecast/someapp/somesubdir/vd11-8:1;:,f=0;:,m=438;:,

-t=1511381122062;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122062;:,i=7764:8093;:,o=read;:,d=162;:,b=12;:,

-t=1511381122062;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122062;:,i=7764:8093;:,o=lseek;:,d=162;:,O=0;:,W=1;:,b=12;:,

-t=1511381122062;:,i=7764:8093;:,o=read;:,d=162;:,b=0;:,

-t=1511381122062;:,i=7764:8093;:,o=close;:,d=162;:,s=0;:,

-t=1511381122062;:,i=7764:8093;:,o=open;:,d=162;:,p=///usr/local/mimecast/someapp/somesubdir/vd11-9:0;:,f=0;:,m=438;:,

-t=1511381122062;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122062;:,i=7764:8093;:,o=read;:,d=162;:,b=12;:,

-t=1511381122062;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122062;:,i=7764:8093;:,o=lseek;:,d=162;:,O=0;:,W=1;:,b=12;:,

-t=1511381122062;:,i=7764:8093;:,o=read;:,d=162;:,b=0;:,

-t=1511381122062;:,i=7764:8093;:,o=close;:,d=162;:,s=0;:,

-t=1511381122063;:,i=7764:8093;:,o=open;:,d=162;:,p=///usr/local/mimecast/someapp/somesubdir/vd11-7:1;:,f=0;:,m=438;:,

-t=1511381122063;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122063;:,i=7764:8093;:,o=read;:,d=162;:,b=12;:,

-t=1511381122063;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122063;:,i=7764:8093;:,o=lseek;:,d=162;:,O=0;:,W=1;:,b=12;:,

-t=1511381122063;:,i=7764:8093;:,o=read;:,d=162;:,b=0;:,

-t=1511381122063;:,i=7764:8093;:,o=close;:,d=162;:,s=0;:,

-t=1511381122063;:,i=7764:8093;:,o=open;:,d=162;:,p=///usr/local/mimecast/someapp/somesubdir/vd11-8:0;:,f=0;:,m=438;:,

-t=1511381122063;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122063;:,i=7764:8093;:,o=read;:,d=162;:,b=12;:,

-t=1511381122063;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122063;:,i=7764:8093;:,o=lseek;:,d=162;:,O=0;:,W=1;:,b=12;:,

-t=1511381122063;:,i=7764:8093;:,o=read;:,d=162;:,b=0;:,

-t=1511381122063;:,i=7764:8093;:,o=close;:,d=162;:,s=0;:,

-t=1511381122063;:,i=7764:8093;:,o=open;:,d=162;:,p=///usr/local/mimecast/someapp/somesubdir/vd11-6:1;:,f=0;:,m=438;:,

-t=1511381122063;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122063;:,i=7764:8093;:,o=read;:,d=162;:,b=12;:,

-t=1511381122063;:,i=7764:8093;:,o=fstat;:,d=162;:,s=0;:,

-t=1511381122063;:,i=7764:8093;:,o=lseek;:,d=162;:,O=0;:,W=1;:,b=12;:,

-```

-

-### Using a RAMdisk (optional)

-

-It is beneficial to write ``io.capture`` to a RAMdisk so that we are not interfering so much with the system I/O:

-

-```sh

-sudo mkdir -p /mnt/ramdisk

-sudo mount -t tmpfs -o size=32g tmpfs /mnt/ramdisk

-```

-

-Make sure that there is enough system memory available for such a RAMdisk and all the processes running on the machine. Eventually, RAM will be taken away from the Linux caches which potentially could decrease system I/O performance. Run the following command to capture to the RAMdisk respectively:

-

-```sh

-sudo ioriot -c /mnt/ramdisk/io.capture

-```

-

-## 2. Initialize

-

-### 2.1 Pre-process the capture log / generate a replay log

-

-After producing ``io.capture`` it must be pre-processed. The resulting replay log introduces the following changes (for improving replay performance and make the parsing easier):

-

-* Time stamps begin from 0

-* Use of internal opcodes rather than strings (e.g. ``30`` instead of ``open``) for faster parsing.

-* All operations on unknown file handles are _removed_.

-* All incomplete or corrupt lines from the capture file are ignored. There may be corrupt lines in the capture file because SystemTap may skips a very few probe points if it decides that capturing I/O is causing too much overhead.

-* Rewrite of all file paths. ``ioriot`` adds ``/.ioriot/NAME`` to all file paths for each file system mount point.

-

-To generate the the replay log ``io.replay`` from the capture log ``io.capture`` run:

-

-```sh

-ioriot -c io.capture -r io.replay -n NAME -u USER

-```

-

-In which NAME is a freely chosen name and USER must be a valid system user. It is the system user under which the replay test will run. This command also creates all required top level directories such as ``/.ioriot/NAME/``, ``/mnt/.ioriot/NAME/`` in all mounted file systems. These are the directories where the replay test will read/write files from/to. These directories will belong to user USER.

-

-``ioriot`` will filter out many operations, especially all operations on pseudo file systems (e.g. sysfs, procfs), as it does not make a lot of sense to replay I/O on these file systems. Also, I/O operations on unknown file handles will be filtered out as well. This can happen when we start capturing the I/O *after* an application already opened a file. As a result we won't see how the application opened that file. The best practise is to stop all applications on the machine first, start capturing the I/O, and start all applications again. This may be improved in future releases of I/O Riot.

-

-The resulting replay log will look like this: At the first line there is a meta header. It contains information about the test configuration. The meta header is followed by all the I/O operations. At the end of the file is the INIT section. It lists all files (also their sizes) and directories required to be present before replaying the I/O.

-

-

-```sh

-#|num_timelines=509591|num_mapped_pids=19189|num_mapped_fds=4292067|num_lines=55040114|replay_version=1|user=ioriotuser|name=test0|init_offset=2578735248|

-23|1|1|0|0|30|11|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-9:1|438|0|open@31|

-23|1|1|0|0|0|11|0|fstat@32|

-23|1|1|0|0|10|11|12|read@33|

-23|1|1|0|0|0|11|0|fstat@34|

-23|1|1|0|0|72|11|0|1|12|lseek@35|

-23|1|1|0|0|10|11|0|read@36|

-23|1|1|0|0|50|11|0|close@37|

-23|2|1|0|0|30|12|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-8:1|438|0|open@38|

-23|2|1|0|0|0|12|0|fstat@39|

-23|2|1|0|0|10|12|12|read@40|

-23|2|1|0|0|0|12|0|fstat@41|

-23|2|1|0|0|72|12|0|1|12|lseek@42|

-23|2|1|0|0|10|12|0|read@43|

-23|2|1|0|0|50|12|0|close@44|

-23|3|1|0|0|30|13|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-9:0|438|0|open@45|

-23|3|1|0|0|0|13|0|fstat@46|

-23|3|1|0|0|10|13|12|read@47|

-23|3|1|0|0|0|13|0|fstat@48|

-23|3|1|0|0|72|13|0|1|12|lseek@49|

-23|3|1|0|0|10|13|0|read@50|

-23|3|1|0|0|50|13|0|close@51|

-23|4|1|0|0|30|14|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-7:1|438|0|open@52|

-23|4|1|0|0|0|14|0|fstat@53|

-23|4|1|0|0|10|14|12|read@54|

-23|4|1|0|0|0|14|0|fstat@55|

-23|4|1|0|0|72|14|0|1|12|lseek@56|

-23|4|1|0|0|10|14|0|read@57|

-23|4|1|0|0|50|14|0|close@58|

-23|5|1|0|0|30|15|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-8:0|438|0|open@59|

-23|5|1|0|0|0|15|0|fstat@60|

-23|5|1|0|0|10|15|12|read@61|

-23|5|1|0|0|0|15|0|fstat@62|

-23|5|1|0|0|72|15|0|1|12|lseek@63|

-23|5|1|0|0|10|15|0|read@64|

-23|5|1|0|0|50|15|0|close@65|

-23|6|1|0|0|30|16|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-6:1|438|0|open@66|

-23|6|1|0|0|0|16|0|fstat@67|

-23|6|1|0|0|10|16|12|read@68|

-23|6|1|0|0|0|16|0|fstat@69|

-.

-.

-.

-#INIT

-0|1|688|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/8/b_dv01_11_vd11-11_a|@55290437

-0|1|2592|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/3/b_dv01_11_vd11-11_b|@33907067

-0|1|768|/mnt/14/.ioriot/test0/bmnt/2/20171101/b/d/b_dv01_11_vd11-11_c|@64247527

-0|1|1440|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/0/b_dv01_11_vd11-11_d|@2014896

-0|1|960|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/9/b_dv01_11_vd11-11_e|@17724079

-0|1|928|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/1/b_dv01_11_vd11-11_f|@4534389

-0|1|1712|/mnt/14/.ioriot/test0/bmnt/2/20171101/b/5/b_dv01_11_vd11-11_g|@2738458

-0|1|784|/mnt/14/.ioriot/test0/bmnt/2/20171101/b/b/b_dv01_11_vd11-11_h|@21136612

-0|1|624|/mnt/14/.ioriot/test0/bmnt/2/20171101/b/6/b_dv01_11_vd11-11_i|@24683427

-0|1|672|/mnt/14/.ioriot/test0/bmnt/2/20171101/b/9/b_dv01_11_vd11-11_j|@12584061

-0|1|336|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/5/b_dv01_11_vd11-11_k|@7737434

-0|1|12|/mnt/06/.ioriot/test0/bmnt/tmp/b|@42498106

-.

-.

-.

-

-```

-

-### 2.2 Initialize the replay test

-

-It is very likely that the replay test wants to access already existing files. Therefore it has to be ensured that all of these exist already before starting the test. To create all files and directories required by the test run the following command:

-

-```sh

-sudo ioriot -i io.replay

-```

-

-For that ``ioriot`` makes use of the INIT section in ``io.replay``.

-

-## 3. Replay

-

-To replay the log run:

-

-```sh

-sudo ioriot -r io.replay

-```

-

-It is beneficial to read ``io.replay`` from RAMdisk so that we are not interfering so much with the system I/O. 

-

-*Init and replay in one go*

-

-It is posisble to initialise the test and run the test with one single command, just replace option `-r` with `-R`:

-

-```sh

-sudo ioriot -R io.replay

-```

-

-*Speed factor*

-

-By default `ioriot` tries to replay all I/O operations as fast as it can. To replay the I/O at a different speed it is possible to configure the speed factor by using the `-s` command line option.

-

-The following pseudo code demonstrates how the speed factor affects the replay speed. Here `current_time` represents the current time while replaying the I/O, `time_in_log` represents the time as logged in `io.replay` and `time_ahead` indicates whether the replay is too quick or not. 

-

-```code

-if (speed_factor != 0) {

-  time_ahead = time_in_log / speed_factor - current_time

-  if (time_ahead > 0) {

-    sleep(time_ahead)

-  }

-}

-```

-

-A speed factor of `0` is interpreted as "replay as fast as possible". A speed factor of `1` can be used to replay everything in original speed (same speed as on the original host where the I/O was captured). A speed factor of `2` would double the speed and a speed factor of `0.5` would half the speed.

-In order to replay the I/O in original speed the factor of `1` can be used as follows:

-

-```sh

-sudo ioriot -R io.replay -s 1

-```

-

-## 4. Analyse

-

-Look at various operating system statistics during the test. Useful commands are for example ``iostat -x 1``, ``dstat --disk`` and ``sudo iotop -o``. Best would be to collect all I/O statistics of all drives to a time series database with graphing capabilities such as Collectd/Graphite/Whisper.

-

-## 5. Repeat

-

-It is important to understand the I/O statistics observed. It is possible to repeat the same test any time again. Each time with different settings applied. 

-

-## Cleanup

-

-To purge all temporally data files of all tests run

-

-```sh

-sudo ioriot -P

-```

-

-Note: It's not required to cleanup any test data manually when you intend to re-run a test or run a new test. During initialization (``-i`` or ``-R`` switch) ``ioriot`` will automatically move all old data to ``.ioriot/.trash/`` sub-folders. The data will be ignored there. However, once you intend to completely delete all test files and directories (e.g. you run out of disk space or want to deinstall ``ioriot`` you should purge them with ``-P`` as shown above.

+# Appendix

 

 ## Supported file systems

 

diff --git a/docs/doxygen.conf b/docs/doxygen.conf
index 0627fff..0485dab 100644
--- a/docs/doxygen.conf
+++ b/docs/doxygen.conf
@@ -38,7 +38,7 @@ PROJECT_NAME           = "I/O Riot"
 # could be handy for archiving the generated documentation or if some version
 # control system is used.
 
-PROJECT_NUMBER         = 0.4.2
+PROJECT_NUMBER         = 0.5
 
 # Using the PROJECT_BRIEF tag one can provide an optional one line description
 # for a project that appears at the top of each page and should give viewer a
diff --git a/docs/markdown/installation.md b/docs/markdown/installation.md
new file mode 100644
index 0000000..d38f8d0
--- /dev/null
+++ b/docs/markdown/installation.md
@@ -0,0 +1,55 @@
+[Main page](../../README.md)
+
+# I/O Riot installation
+
+I/O Riot consists of a set of SystemTap kernel modules (capturing I/O) and the tool ``ioriot`` (replaying I/O). Usually you want to capture I/O from a production machine and want to replay it on a separate load testing machine.
+ 
+## System requirements
+
+I/O Riot has been tested on
+
+* CentOS 7.6 64Bit (latest version, all packages up to date, booted into the installed Kernel)
+* SystemTap (from the default CentOS repository)
+* GCC C-Compiler (from the default CentOS repository)
+
+Before proceeding please ensure that the latest CentOS 7 kernel is installed and running on all machines involved. It should also be ensured that the capture machine and the load test machine have the same mount points mounted. This is to ensure that I/O is being replayed on the corresponding data drives on the load test machine.
+
+## Compiling and installing I/O Riot
+
+I/O Riot has to be installed on all machines involved.  To install I/O Riot perform the following steps:
+
+```sh
+sudo yum install gcc systemtap yum-utils kernel-devel-$(uname -r)
+sudo debuginfo-install kernel-$(uname -r)
+make && sudo make install
+export PATH=$PATH:/opt/ioriot/bin
+```
+
+This will install the ``ioriot`` utility to ``/opt/ioriot/bin/`` and the SystemTap kernel modules to ``/opt/ioriot/systemtap/``. Run ``ioriot -h`` to print out a brief help.
+
+However, best practise is not to install any compilers on a production machine. You can either compile I/O Riot from scratch on all machines involved like shown above or only compile it on a build machine and distribute the ``/opt/ioriot`` directory to the remaining machines. In the latter case you will also need to install the ``systemtap-runtime`` package as an additional dependency.
+
+In case you decided to deinstall I/O Riot you can do so by running
+
+```sh
+sudo ioriot -P # purges all test files created by ioriot
+sudo make uninstall
+```
+
+# Compiling I/O Riot using Docker
+
+It is possible to compile I/O Riot using Docker. The benefit is that it is much easier to get together the required dependencies. Docker build support has been tested on macOS X High Sierra (with Docker Desktop CE from https://www.docker.com) and Fedora Linux 28 (Docker installed from the default repositories). It will work most likely on all other systems with Docker up and running. Keep in mind that we use Docker only to compile I/O Riot and not to operate I/O Riot.
+
+First of all you have to install a Docker engine. Depending on the system in use the steps involved differ. Please consult the Docker documentation in how to accomplish that. Once Docker is up and running you can run for example the following commands to build everything for CentOS 7 and Linux Kernel 3.10.0-957.1.3.el7.x86_64:
+
+```sh
+export KERNEL=3.10.0-957.1.3.el7.x86_64
+make dockerbuild
+```
+
+Keep in mind that ther Kernel version must be a valid kernel version of CentOS 7!
+
+The above command will fetch a CentOS 7 base image and will install all for the build required packages. Depending on the network speed the whole procedure can take quite a while. I/O Riot will be compiled via Docker to directory ``./docker/opt/ioriot``. That directory can be distributed to ``/opt/ioriot`` to all boxes with that particular running kernel version.
+
+By repeating the steps above (setting KERNEL environment variable and invoking ``make dockerbuild``) it is possible to compile the SystemTap Kernel modules for multiple Kernel versions. All the modules will be found seamlessly in ``./docker/opt/ioriot``.
+
diff --git a/docs/markdown/usage.md b/docs/markdown/usage.md
new file mode 100644
index 0000000..17e1131
--- /dev/null
+++ b/docs/markdown/usage.md
@@ -0,0 +1,254 @@
+[Main page](../../README.md)
+
+# I/O Riot usage
+
+## 1. Capture
+
+The following steps are required to capture all I/O operation of the entire (Linux) system to the file ``io.capture``. For efficiency and security it is only capturing the meta data (amount of bytes written and read) and not the actual data itself. It is also capturing the system time in microseconds and the process IDs (PIDs) and thread IDs (TIDs) used as well as all relevant options and flags of the corresponding I/O syscalls. It will stop capturing automatically after 60 minutes:
+
+ * 1) Stop all applications on the machine. Otherwise the kernel module won't recognize any already opened file handles. Stopping the applications before starting with the capture is essential for tracing the flags in how the files were opened. All I/O operations on unknown file handles will be ignored otherwise.
+ * 2) Run:
+
+```sh
+sudo ioriot -c ~/io.capture
+```
+
+ * 3) Start all applications again.
+ * 4) To stop capturing I/O type Ctrl+C. Alternatively one hour for the Kernel module to auto exit.
+
+To capture only I/O caused by Java process run:
+
+```sh
+sudo ioriot -c ~/io.capture -m javaioriot.ko
+```
+
+To capture the I/O of a specific process run the following respectively:
+
+```sh
+sudo ioriot -c ~/io.capture -m targetedioriot.ko -p PID
+```
+
+The resulting capture log looks like this and can be multiple GB in size:
+
+```sh
+#|capture_version=3|
+t=1545902286266599478;:,D=6253;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/c;:,s=0;:,
+t=1545902286266607592;:,D=3207;:,i=24702:25810;:,o=fcntl;:,d=27;:,F=2;:,G=1;:,s=0;:,
+t=1545902286266618764;:,D=6769;:,i=24702:25810;:,o=getdents;:,d=27;:,c=32768;:,b=80;:,
+t=1545902286266629658;:,D=24054;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/8;:,s=0;:,
+t=1545902286266642396;:,D=16506;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/0/riot/20181130;:,s=0;:,
+t=1545902286266651561;:,D=3753;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/0/riot/20181130;:,s=0;:,
+t=1545902286266658507;:,D=24732;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/e;:,s=0;:,
+t=1545902286266664305;:,D=1390;:,i=24702:25810;:,o=getdents;:,d=27;:,c=32768;:,b=0;:,
+t=1545902286266671200;:,D=2627;:,i=24702:25810;:,o=close;:,d=27;:,s=0;:,
+t=1545902286266675423;:,D=837;:,i=24702:25810;:,o=close;:,d=119;:,s=0;:,
+t=1545902286266685659;:,D=23300;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/1;:,s=0;:,
+t=1545902286266704122;:,D=14658;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/f;:,s=0;:,
+t=1545902286266709835;:,D=2022;:,i=24702:25799;:,o=close;:,d=63;:,s=0;:,
+t=1545902286266721094;:,D=40107;:,i=24702:25810;:,o=open;:,d=27;:,p=/store/02/1/1A1/20181105/b;:,f=0;:,m=0;:,
+t=1545902286266732025;:,D=3190;:,i=24702:25810;:,o=fstat;:,d=27;:,s=0;:,
+t=1545902286266734491;:,D=21159;:,i=24702:25799;:,o=close;:,d=67;:,s=0;:,
+t=1545902286266745975;:,D=3737;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/f/riot;:,s=-2;:,
+t=1545902286266756861;:,D=6131;:,i=24702:25799;:,o=open;:,d=67;:,p=/store/13/1/1A1/20181022/b;:,f=0;:,m=0;:,
+t=1545902286266765401;:,D=2275;:,i=24702:25799;:,o=fstat;:,d=67;:,s=0;:,
+t=1545902286266767643;:,D=12190;:,i=24702:25810;:,o=fcntl;:,d=27;:,F=3;:,G=139845964703088;:,s=32768;:,
+t=1545902286266772388;:,D=1100;:,i=24702:25810;:,o=fcntl;:,d=27;:,F=2;:,G=1;:,s=0;:,
+t=1545902286266782571;:,D=3904;:,i=24702:25799;:,o=fcntl;:,d=67;:,F=3;:,G=139846284661488;:,s=32768;:,
+t=1545902286266787978;:,D=1227;:,i=24702:25799;:,o=fcntl;:,d=67;:,F=2;:,G=1;:,s=0;:,
+t=1545902286266803693;:,D=28014;:,i=24702:25810;:,o=getdents;:,d=27;:,c=32768;:,b=432;:,
+t=1545902286266810495;:,D=18988;:,i=24702:25799;:,o=getdents;:,d=67;:,c=32768;:,b=432;:,
+t=1545902286266819391;:,D=3919;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/6;:,s=0;:,
+t=1545902286266822623;:,D=14447;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/c;:,s=0;:,
+t=1545902286266830423;:,D=3205;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/9;:,s=0;:,
+t=1545902286266837505;:,D=4034;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/a;:,s=0;:,
+t=1545902286266844222;:,D=2968;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/0;:,s=0;:,
+t=1545902286266848050;:,D=14112;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/e;:,s=0;:,
+t=1545902286266854966;:,D=3056;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/1;:,s=0;:,
+t=1545902286266861804;:,D=3917;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/9;:,s=0;:,
+t=1545902286266868780;:,D=3009;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/d;:,s=0;:,
+t=1545902286266872547;:,D=14063;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/d;:,s=0;:,
+t=1545902286266879442;:,D=3113;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/f;:,s=0;:,
+t=1545902286266886259;:,D=3935;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/5;:,s=0;:,
+t=1545902286266892951;:,D=2982;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/c;:,s=0;:,
+t=1545902286266897104;:,D=14134;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/7;:,s=0;:,
+t=1545902286266904170;:,D=3137;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/3;:,s=0;:,
+t=1545902286266910438;:,D=3961;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/8;:,s=0;:,
+t=1545902286266917133;:,D=2989;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/e;:,s=0;:,
+t=1545902286266921997;:,D=14212;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/5;:,s=0;:,
+t=1545902286266928972;:,D=3112;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/4;:,s=0;:,
+t=1545902286266934468;:,D=13903;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/1;:,s=0;:,
+t=1545902286266941300;:,D=3086;:,i=24702:25799;:,o=stat;:,p=/store/13/1/1A1/20181022/b/f;:,s=0;:,
+t=1545902286266946528;:,D=13997;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/2;:,s=0;:,
+t=1545902286266953372;:,D=3065;:,i=24702:25810;:,o=stat;:,p=/store/02/1/1A1/20181105/b/6;:,s=0;:,
+```
+
+### Using a RAMdisk (optional)
+
+It is beneficial to write ``io.capture`` to a RAMdisk so that we are not interfering so much with the system I/O:
+
+```sh
+sudo mkdir -p /mnt/ramdisk
+sudo mount -t tmpfs -o size=32g tmpfs /mnt/ramdisk
+```
+
+Make sure that there is enough system memory available for such a RAMdisk and all the processes running on the machine. Eventually, RAM will be taken away from the Linux caches which potentially could decrease system I/O performance. Run the following command to capture to the RAMdisk respectively:
+
+```sh
+sudo ioriot -c /mnt/ramdisk/io.capture
+```
+
+## 2. Initialize
+
+### 2.1 Pre-process the capture log / generate a replay log
+
+After producing ``io.capture`` it must be pre-processed. The resulting replay log introduces the following changes (for improving replay performance and make the parsing easier):
+
+* Time stamps begin from 0
+* Use of internal opcodes rather than strings (e.g. ``30`` instead of ``open``) for faster parsing.
+* All operations on unknown file handles are _removed_.
+* All incomplete or corrupt lines from the capture file are ignored. There may be corrupt lines in the capture file because SystemTap may skips a very few probe points if it decides that capturing I/O is causing too much overhead.
+* Rewrite of all file paths. ``ioriot`` adds ``/.ioriot/NAME`` to all file paths for each file system mount point.
+
+To generate the the replay log ``io.replay`` from the capture log ``io.capture`` run:
+
+```sh
+ioriot -c io.capture -r io.replay -n NAME -u USER
+```
+
+In which NAME is a freely chosen name and USER must be a valid system user. It is the system user under which the replay test will run. This command also creates all required top level directories such as ``/.ioriot/NAME/``, ``/mnt/.ioriot/NAME/`` in all mounted file systems. These are the directories where the replay test will read/write files from/to. These directories will belong to user USER.
+
+``ioriot`` will filter out many operations, especially all operations on pseudo file systems (e.g. sysfs, procfs), as it does not make a lot of sense to replay I/O on these file systems. Also, I/O operations on unknown file handles will be filtered out as well. This can happen when we start capturing the I/O *after* an application already opened a file. As a result we won't see how the application opened that file. The best practise is to stop all applications on the machine first, start capturing the I/O, and start all applications again. This may be improved in future releases of I/O Riot.
+
+The resulting replay log will look like this: At the first line there is a meta header. It contains information about the test configuration. The meta header is followed by all the I/O operations. At the end of the file is the INIT section. It lists all files (also their sizes) and directories required to be present before replaying the I/O.
+
+
+```sh
+#|num_timelines=509591|num_mapped_pids=19189|num_mapped_fds=4292067|num_lines=55040114|replay_version=1|user=ioriotuser|name=test0|init_offset=2578735248|
+23|1|1|0|0|30|11|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-9:1|438|0|open@31|
+23|1|1|0|0|0|11|0|fstat@32|
+23|1|1|0|0|10|11|12|read@33|
+23|1|1|0|0|0|11|0|fstat@34|
+23|1|1|0|0|72|11|0|1|12|lseek@35|
+23|1|1|0|0|10|11|0|read@36|
+23|1|1|0|0|50|11|0|close@37|
+23|2|1|0|0|30|12|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-8:1|438|0|open@38|
+23|2|1|0|0|0|12|0|fstat@39|
+23|2|1|0|0|10|12|12|read@40|
+23|2|1|0|0|0|12|0|fstat@41|
+23|2|1|0|0|72|12|0|1|12|lseek@42|
+23|2|1|0|0|10|12|0|read@43|
+23|2|1|0|0|50|12|0|close@44|
+23|3|1|0|0|30|13|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-9:0|438|0|open@45|
+23|3|1|0|0|0|13|0|fstat@46|
+23|3|1|0|0|10|13|12|read@47|
+23|3|1|0|0|0|13|0|fstat@48|
+23|3|1|0|0|72|13|0|1|12|lseek@49|
+23|3|1|0|0|10|13|0|read@50|
+23|3|1|0|0|50|13|0|close@51|
+23|4|1|0|0|30|14|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-7:1|438|0|open@52|
+23|4|1|0|0|0|14|0|fstat@53|
+23|4|1|0|0|10|14|12|read@54|
+23|4|1|0|0|0|14|0|fstat@55|
+23|4|1|0|0|72|14|0|1|12|lseek@56|
+23|4|1|0|0|10|14|0|read@57|
+23|4|1|0|0|50|14|0|close@58|
+23|5|1|0|0|30|15|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-8:0|438|0|open@59|
+23|5|1|0|0|0|15|0|fstat@60|
+23|5|1|0|0|10|15|12|read@61|
+23|5|1|0|0|0|15|0|fstat@62|
+23|5|1|0|0|72|15|0|1|12|lseek@63|
+23|5|1|0|0|10|15|0|read@64|
+23|5|1|0|0|50|15|0|close@65|
+23|6|1|0|0|30|16|/usr/local/mimecast/.ioriot/test0/someapp/somesubdir/vd11-6:1|438|0|open@66|
+23|6|1|0|0|0|16|0|fstat@67|
+23|6|1|0|0|10|16|12|read@68|
+23|6|1|0|0|0|16|0|fstat@69|
+.
+.
+.
+#INIT
+0|1|688|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/8/b_dv01_11_vd11-11_a|@55290437
+0|1|2592|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/3/b_dv01_11_vd11-11_b|@33907067
+0|1|768|/mnt/14/.ioriot/test0/bmnt/2/20171101/b/d/b_dv01_11_vd11-11_c|@64247527
+0|1|1440|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/0/b_dv01_11_vd11-11_d|@2014896
+0|1|960|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/9/b_dv01_11_vd11-11_e|@17724079
+0|1|928|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/1/b_dv01_11_vd11-11_f|@4534389
+0|1|1712|/mnt/14/.ioriot/test0/bmnt/2/20171101/b/5/b_dv01_11_vd11-11_g|@2738458
+0|1|784|/mnt/14/.ioriot/test0/bmnt/2/20171101/b/b/b_dv01_11_vd11-11_h|@21136612
+0|1|624|/mnt/14/.ioriot/test0/bmnt/2/20171101/b/6/b_dv01_11_vd11-11_i|@24683427
+0|1|672|/mnt/14/.ioriot/test0/bmnt/2/20171101/b/9/b_dv01_11_vd11-11_j|@12584061
+0|1|336|/mnt/15/.ioriot/test0/bmnt/2/20171101/b/5/b_dv01_11_vd11-11_k|@7737434
+0|1|12|/mnt/06/.ioriot/test0/bmnt/tmp/b|@42498106
+.
+.
+.
+
+```
+
+### 2.2 Initialize the replay test
+
+It is very likely that the replay test wants to access already existing files. Therefore it has to be ensured that all of these exist already before starting the test. To create all files and directories required by the test run the following command:
+
+```sh
+sudo ioriot -i io.replay
+```
+
+For that ``ioriot`` makes use of the INIT section in ``io.replay``.
+
+## 3. Replay
+
+To replay the log run:
+
+```sh
+sudo ioriot -r io.replay
+```
+
+It is beneficial to read ``io.replay`` from RAMdisk so that we are not interfering so much with the system I/O. 
+
+*Init and replay in one go*
+
+It is posisble to initialise the test and run the test with one single command, just replace option `-r` with `-R`:
+
+```sh
+sudo ioriot -R io.replay
+```
+
+*Speed factor*
+
+By default `ioriot` tries to replay all I/O operations as fast as it can. To replay the I/O at a different speed it is possible to configure the speed factor by using the `-s` command line option.
+
+The following pseudo code demonstrates how the speed factor affects the replay speed. Here `current_time` represents the current time while replaying the I/O, `time_in_log` represents the time as logged in `io.replay` and `time_ahead` indicates whether the replay is too quick or not. 
+
+```code
+if (speed_factor != 0) {
+  time_ahead = time_in_log / speed_factor - current_time
+  if (time_ahead > 0) {
+    sleep(time_ahead)
+  }
+}
+```
+
+A speed factor of `0` is interpreted as "replay as fast as possible". A speed factor of `1` can be used to replay everything in original speed (same speed as on the original host where the I/O was captured). A speed factor of `2` would double the speed and a speed factor of `0.5` would half the speed.
+In order to replay the I/O in original speed the factor of `1` can be used as follows:
+
+```sh
+sudo ioriot -R io.replay -s 1
+```
+
+## 4. Analyse
+
+Look at various operating system statistics during the test. Useful commands are for example ``iostat -x 1``, ``dstat --disk`` and ``sudo iotop -o``. Best would be to collect all I/O statistics of all drives to a time series database with graphing capabilities such as Collectd/Graphite/Whisper.
+
+## 5. Repeat
+
+It is important to understand the I/O statistics observed. It is possible to repeat the same test any time again. Each time with different settings applied. 
+
+## Cleanup
+
+To purge all temporally data files of all tests run
+
+```sh
+sudo ioriot -P
+```
+
+Note: It's not required to cleanup any test data manually when you intend to re-run a test or run a new test. During initialization (``-i`` or ``-R`` switch) ``ioriot`` will automatically move all old data to ``.ioriot/.trash/`` sub-folders. The data will be ignored there. However, once you intend to completely delete all test files and directories (e.g. you run out of disk space or want to deinstall ``ioriot`` you should purge them with ``-P`` as shown above.
diff --git a/ioriot/src/datas/amap.c b/ioriot/src/datas/amap.c
index 806a3f8..a80305e 100644
--- a/ioriot/src/datas/amap.c
+++ b/ioriot/src/datas/amap.c
@@ -246,17 +246,17 @@ void _amap_test(amap_s *a)
 
 void amap_test(void)
 {
-    // First test the non-mmapped version
+    Put("amap: First test the non-mmapped version");
     amap_s* a = amap_new(1024*1024*10);
     _amap_test(a);
     amap_destroy(a);
 
-    // Now test the mapped version
+    Put("amap: Now test the mapped version");
     a = amap_new_mmapped(1024*1024*10);
     _amap_test(a);
     amap_destroy(a);
 
-    // Another test with non-alligned size
+    Put("amap: Another test with non-alligned size");
     a = amap_new(1024*1024*10+1);
     _amap_test(a);
     amap_destroy(a);
diff --git a/ioriot/src/defaults.h b/ioriot/src/defaults.h
index 24399a9..9e5e125 100644
--- a/ioriot/src/defaults.h
+++ b/ioriot/src/defaults.h
@@ -18,7 +18,7 @@
 #include "utils/utils.h"
 
 /** Version of the supported .capture format */
-#define CAPTURE_VERSION 2
+#define CAPTURE_VERSION 3
 /** Version of the supported .replay format */
 #define REPLAY_VERSION 2
 /** Max amount of tokens per line in the .capture file */
@@ -28,7 +28,7 @@
 /** Controls how many tasks can be queued and buffered per worker thread */
 #define TASK_BUFFER_PER_THREAD 512
 /** Version of I/O Riot */
-#define IORIOT_VERSION "0.4.2"
+#define IORIOT_VERSION "0.5"
 /** Copyright information */
 #define IORIOT_COPYRIGHT "(c) Mimecast 2018"
 /** Max open files resource user limit */
diff --git a/ioriot/src/generate/gparser.c b/ioriot/src/generate/gparser.c
index 2f3b250..ff171f4 100644
--- a/ioriot/src/generate/gparser.c
+++ b/ioriot/src/generate/gparser.c
@@ -294,6 +294,9 @@ status_e gparser_extract_tok(gparser_s *p, gtask_s *t, char *tok)
     case 'T':
         break;
 
+    case 'D':
+        break;
+
     default:
         // Unknown key
     {
diff --git a/ioriot/src/utests.c b/ioriot/src/utests.c
index 8a54f42..8f65866 100644
--- a/ioriot/src/utests.c
+++ b/ioriot/src/utests.c
@@ -38,8 +38,8 @@ void utests_run()
     fprintf(stderr, "Running utils_test()\n");
     utils_test();
 
-    fprintf(stderr, "Running amap_test()\n");
-    amap_test();
+    //fprintf(stderr, "Running amap_test()\n");
+    //amap_test();
 
     fprintf(stderr, "Great success, run all unit tests without any errors!\n");
 }
diff --git a/systemtap/Makefile b/systemtap/Makefile
index 49f1977..97e24d6 100644
--- a/systemtap/Makefile
+++ b/systemtap/Makefile
@@ -8,7 +8,7 @@ prepare:
 	sed 's/execname() != "stapio"/pid() == target()/' ./src/ioriot.stp > ./src/targetedioriot.stp
 	sed 's/execname() != "stapio"/execname() == "java"/' ./src/ioriot.stp > ./src/javaioriot.stp
 compile:
-	@echo Crosscompiling for Kernel version $(KERNEL)
+	@echo Compiling for Kernel version $(KERNEL)
 	for stp in ioriot javaioriot targetedioriot; do \
 		stap -v ./src/$$stp.stp -p 4 -r $(KERNEL) -m $$stp \
 		-D MAXSTRINGLEN=255 -D MAXACTION=10000 -D MAXSKIPPED=10000\
diff --git a/systemtap/src/ioriot.stp b/systemtap/src/ioriot.stp
index ee77263..cefc8da 100644
--- a/systemtap/src/ioriot.stp
+++ b/systemtap/src/ioriot.stp
@@ -34,6 +34,7 @@
 #
 # Format keys:
 # t: Time
+# D: Duration
 # i: PID:TID (process and thread ID)
 # o: Operation name
 # O: Offset or owner/user UID
@@ -54,6 +55,8 @@
 # A: Address 2
 #
 
+global PROBE_ENTRY_TIMES%[8096]
+
 # Return the full qualified version of path
 function absolute_path (path) {
     # Is it already a full qualified path?
@@ -77,14 +80,21 @@ probe timer.s(3600) {
 }
 
 probe begin {
-    printf("#|capture_version=%d|\n", 2);
+    printf("#|capture_version=%d|\n", 3);
+}
+
+probe syscall.open, syscall.openat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
+    }
 }
 
 probe syscall.open.return, syscall.openat.return {
     if (execname() != "stapio") {
+        ns = gettimeofday_ns()
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,m=%d;:,\n",
-                gettimeofday_ms(),
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,m=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -92,13 +102,21 @@ probe syscall.open.return, syscall.openat.return {
                 absolute_path(pathname),
                 @entry($flags),
                 @entry($mode));
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.lseek {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.lseek.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -106,13 +124,21 @@ probe syscall.lseek.return {
                 @entry($offset),
                 @entry($whence),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.llseek {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.llseek.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -120,13 +146,21 @@ probe syscall.llseek.return {
                 (@entry($offset_high) << 32 | @entry($offset_low)),
                 @entry($whence),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fcntl {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fcntl.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,F=%d;:,G=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,F=%d;:,G=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -134,53 +168,85 @@ probe syscall.fcntl.return {
                 @entry($cmd),
                 @entry($arg),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.creat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.creat.return {
     if (execname() != "stapio") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 $return,
                 absolute_path(pathname),
                 @entry($mode));
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.write, syscall.writev {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.write.return, syscall.writev.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.unlink {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.unlink.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.unlinkat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.unlinkat.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -188,6 +254,13 @@ probe syscall.unlinkat.return {
                 absolute_path(pathname),
                 @entry($flag),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.rename, syscall.renameat, syscall.renameat2 {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
@@ -195,33 +268,50 @@ probe syscall.rename.return, syscall.renameat.return, syscall.renameat2.return {
     if(execname() != "stapio") {
         oldname = user_string(@entry($oldname))
         newname = user_string(@entry($newname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,P=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,P=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(oldname),
                 absolute_path(newname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.read, syscall.readv {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.read.return, syscall.readv.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readahead {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readahead.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%ld;:,O=%ld;:,c=%ld\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%ld;:,O=%ld;:,c=%ld\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -229,63 +319,103 @@ probe syscall.readahead.return {
                 $return,
                 @entry($offset),
                 @entry($count));
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readdir {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readdir.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readlink {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readlink.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($path))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readlinkat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readlinkat.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fdatasync, syscall.fsync {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fdatasync.return, syscall.fsync.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.sync_file_range {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.sync_file_range.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%ld;:,b=%ld;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%ld;:,b=%ld;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -293,89 +423,145 @@ probe syscall.sync_file_range.return {
                 @entry($offset),
                 @entry($nbytes),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.sync {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.sync.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.syncfs {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.syncfs.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.close {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.close.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.getdents {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.getdents.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,c=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,c=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 @entry($count),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mkdir {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mkdir.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.rmdir {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.rmdir.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mkdirat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mkdirat.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -383,77 +569,125 @@ probe syscall.mkdirat.return {
                 absolute_path(pathname),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.stat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.stat.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.statfs, syscall.statfs64 {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.statfs.return, syscall.statfs64.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fstatfs, syscall.fstatfs64 {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fstatfs.return, syscall.fstatfs64.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.lstat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.lstat.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fstat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fstat.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fstatat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fstatat.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%ld;:,p=%s;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%ld;:,p=%s;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -461,33 +695,57 @@ probe syscall.fstatat.return {
                 absolute_path(pathname),
                 @entry($flag),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.chmod, syscall.fchmodat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.chmod.return, syscall.fchmodat.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fchmod {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fchmod.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.chown, syscall.chown16,
+      syscall.lchown, syscall.lchown16 {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
@@ -495,8 +753,9 @@ probe syscall.chown.return, syscall.chown16.return,
       syscall.lchown.return, syscall.lchown16.return {
     if(execname() != "stapio") {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -504,13 +763,21 @@ probe syscall.chown.return, syscall.chown16.return,
                 @entry($user),
                 @entry($group),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fchown, syscall.fchown16 {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fchown.return, syscall.fchown16.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%ld;:,O=%d;:,G=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%ld;:,O=%d;:,G=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -518,14 +785,22 @@ probe syscall.fchown.return, syscall.fchown16.return {
                 @entry($user),
                 @entry($group),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fchownat {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fchownat.return {
     pathname = user_string(@entry($filename))
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -534,13 +809,21 @@ probe syscall.fchownat.return {
                 @entry($group),
                 @entry($flag),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mmap2 {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mmap2.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,m=%d;:,f=%d;:,d=%d;:,O=%ld;:,A=%ld;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,m=%d;:,f=%d;:,d=%d;:,O=%ld;:,A=%ld;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -551,13 +834,21 @@ probe syscall.mmap2.return {
                 @entry($fd),
                 @entry($pgoff),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mremap {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mremap.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,A=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,A=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -566,26 +857,42 @@ probe syscall.mremap.return {
                 @entry($new_len),
                 @entry($flags),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.munmap {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.munmap.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($addr),
                 @entry($len),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.msync {
+    if (execname() != "stapio") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.msync.return {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -593,16 +900,19 @@ probe syscall.msync.return {
                 @entry($len),
                 @entry($flags),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
     }
 }
 
 probe syscall.exit_group {
     if(execname() != "stapio") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name);
+        delete PROBE_ENTRY_TIMES[tid(),name]
     }
 }
 
diff --git a/systemtap/src/javaioriot.stp b/systemtap/src/javaioriot.stp
index b0e960c..4600aee 100644
--- a/systemtap/src/javaioriot.stp
+++ b/systemtap/src/javaioriot.stp
@@ -34,6 +34,7 @@
 #
 # Format keys:
 # t: Time
+# D: Duration
 # i: PID:TID (process and thread ID)
 # o: Operation name
 # O: Offset or owner/user UID
@@ -54,6 +55,8 @@
 # A: Address 2
 #
 
+global PROBE_ENTRY_TIMES%[8096]
+
 # Return the full qualified version of path
 function absolute_path (path) {
     # Is it already a full qualified path?
@@ -77,14 +80,21 @@ probe timer.s(3600) {
 }
 
 probe begin {
-    printf("#|capture_version=%d|\n", 2);
+    printf("#|capture_version=%d|\n", 3);
+}
+
+probe syscall.open, syscall.openat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
+    }
 }
 
 probe syscall.open.return, syscall.openat.return {
     if (execname() == "java") {
+        ns = gettimeofday_ns()
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,m=%d;:,\n",
-                gettimeofday_ms(),
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,m=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -92,13 +102,21 @@ probe syscall.open.return, syscall.openat.return {
                 absolute_path(pathname),
                 @entry($flags),
                 @entry($mode));
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.lseek {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.lseek.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -106,13 +124,21 @@ probe syscall.lseek.return {
                 @entry($offset),
                 @entry($whence),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.llseek {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.llseek.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -120,13 +146,21 @@ probe syscall.llseek.return {
                 (@entry($offset_high) << 32 | @entry($offset_low)),
                 @entry($whence),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fcntl {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fcntl.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,F=%d;:,G=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,F=%d;:,G=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -134,53 +168,85 @@ probe syscall.fcntl.return {
                 @entry($cmd),
                 @entry($arg),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.creat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.creat.return {
     if (execname() == "java") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 $return,
                 absolute_path(pathname),
                 @entry($mode));
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.write, syscall.writev {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.write.return, syscall.writev.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.unlink {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.unlink.return {
     if(execname() == "java") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.unlinkat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.unlinkat.return {
     if(execname() == "java") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -188,6 +254,13 @@ probe syscall.unlinkat.return {
                 absolute_path(pathname),
                 @entry($flag),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.rename, syscall.renameat, syscall.renameat2 {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
@@ -195,33 +268,50 @@ probe syscall.rename.return, syscall.renameat.return, syscall.renameat2.return {
     if(execname() == "java") {
         oldname = user_string(@entry($oldname))
         newname = user_string(@entry($newname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,P=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,P=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(oldname),
                 absolute_path(newname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.read, syscall.readv {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.read.return, syscall.readv.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readahead {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readahead.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%ld;:,O=%ld;:,c=%ld\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%ld;:,O=%ld;:,c=%ld\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -229,63 +319,103 @@ probe syscall.readahead.return {
                 $return,
                 @entry($offset),
                 @entry($count));
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readdir {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readdir.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readlink {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readlink.return {
     if(execname() == "java") {
         pathname = user_string(@entry($path))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readlinkat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readlinkat.return {
     if(execname() == "java") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fdatasync, syscall.fsync {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fdatasync.return, syscall.fsync.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.sync_file_range {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.sync_file_range.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%ld;:,b=%ld;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%ld;:,b=%ld;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -293,89 +423,145 @@ probe syscall.sync_file_range.return {
                 @entry($offset),
                 @entry($nbytes),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.sync {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.sync.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.syncfs {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.syncfs.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.close {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.close.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.getdents {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.getdents.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,c=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,c=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 @entry($count),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mkdir {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mkdir.return {
     if(execname() == "java") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.rmdir {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.rmdir.return {
     if(execname() == "java") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mkdirat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mkdirat.return {
     if(execname() == "java") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -383,77 +569,125 @@ probe syscall.mkdirat.return {
                 absolute_path(pathname),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.stat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.stat.return {
     if(execname() == "java") {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.statfs, syscall.statfs64 {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.statfs.return, syscall.statfs64.return {
     if(execname() == "java") {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fstatfs, syscall.fstatfs64 {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fstatfs.return, syscall.fstatfs64.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.lstat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.lstat.return {
     if(execname() == "java") {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fstat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fstat.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fstatat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fstatat.return {
     if(execname() == "java") {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%ld;:,p=%s;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%ld;:,p=%s;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -461,33 +695,57 @@ probe syscall.fstatat.return {
                 absolute_path(pathname),
                 @entry($flag),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.chmod, syscall.fchmodat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.chmod.return, syscall.fchmodat.return {
     if(execname() == "java") {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fchmod {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fchmod.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.chown, syscall.chown16,
+      syscall.lchown, syscall.lchown16 {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
@@ -495,8 +753,9 @@ probe syscall.chown.return, syscall.chown16.return,
       syscall.lchown.return, syscall.lchown16.return {
     if(execname() == "java") {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -504,13 +763,21 @@ probe syscall.chown.return, syscall.chown16.return,
                 @entry($user),
                 @entry($group),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fchown, syscall.fchown16 {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fchown.return, syscall.fchown16.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%ld;:,O=%d;:,G=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%ld;:,O=%d;:,G=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -518,14 +785,22 @@ probe syscall.fchown.return, syscall.fchown16.return {
                 @entry($user),
                 @entry($group),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fchownat {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fchownat.return {
     pathname = user_string(@entry($filename))
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -534,13 +809,21 @@ probe syscall.fchownat.return {
                 @entry($group),
                 @entry($flag),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mmap2 {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mmap2.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,m=%d;:,f=%d;:,d=%d;:,O=%ld;:,A=%ld;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,m=%d;:,f=%d;:,d=%d;:,O=%ld;:,A=%ld;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -551,13 +834,21 @@ probe syscall.mmap2.return {
                 @entry($fd),
                 @entry($pgoff),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mremap {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mremap.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,A=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,A=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -566,26 +857,42 @@ probe syscall.mremap.return {
                 @entry($new_len),
                 @entry($flags),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.munmap {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.munmap.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($addr),
                 @entry($len),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.msync {
+    if (execname() == "java") {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.msync.return {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -593,16 +900,19 @@ probe syscall.msync.return {
                 @entry($len),
                 @entry($flags),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
     }
 }
 
 probe syscall.exit_group {
     if(execname() == "java") {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name);
+        delete PROBE_ENTRY_TIMES[tid(),name]
     }
 }
 
diff --git a/systemtap/src/targetedioriot.stp b/systemtap/src/targetedioriot.stp
index 539b826..642c382 100644
--- a/systemtap/src/targetedioriot.stp
+++ b/systemtap/src/targetedioriot.stp
@@ -34,6 +34,7 @@
 #
 # Format keys:
 # t: Time
+# D: Duration
 # i: PID:TID (process and thread ID)
 # o: Operation name
 # O: Offset or owner/user UID
@@ -54,6 +55,8 @@
 # A: Address 2
 #
 
+global PROBE_ENTRY_TIMES%[8096]
+
 # Return the full qualified version of path
 function absolute_path (path) {
     # Is it already a full qualified path?
@@ -77,14 +80,21 @@ probe timer.s(3600) {
 }
 
 probe begin {
-    printf("#|capture_version=%d|\n", 2);
+    printf("#|capture_version=%d|\n", 3);
+}
+
+probe syscall.open, syscall.openat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
+    }
 }
 
 probe syscall.open.return, syscall.openat.return {
     if (pid() == target()) {
+        ns = gettimeofday_ns()
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,m=%d;:,\n",
-                gettimeofday_ms(),
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,m=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -92,13 +102,21 @@ probe syscall.open.return, syscall.openat.return {
                 absolute_path(pathname),
                 @entry($flags),
                 @entry($mode));
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.lseek {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.lseek.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -106,13 +124,21 @@ probe syscall.lseek.return {
                 @entry($offset),
                 @entry($whence),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.llseek {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.llseek.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%d;:,W=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -120,13 +146,21 @@ probe syscall.llseek.return {
                 (@entry($offset_high) << 32 | @entry($offset_low)),
                 @entry($whence),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fcntl {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fcntl.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,F=%d;:,G=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,F=%d;:,G=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -134,53 +168,85 @@ probe syscall.fcntl.return {
                 @entry($cmd),
                 @entry($arg),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.creat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.creat.return {
     if (pid() == target()) {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 $return,
                 absolute_path(pathname),
                 @entry($mode));
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.write, syscall.writev {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.write.return, syscall.writev.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.unlink {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.unlink.return {
     if(pid() == target()) {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.unlinkat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.unlinkat.return {
     if(pid() == target()) {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -188,6 +254,13 @@ probe syscall.unlinkat.return {
                 absolute_path(pathname),
                 @entry($flag),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.rename, syscall.renameat, syscall.renameat2 {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
@@ -195,33 +268,50 @@ probe syscall.rename.return, syscall.renameat.return, syscall.renameat2.return {
     if(pid() == target()) {
         oldname = user_string(@entry($oldname))
         newname = user_string(@entry($newname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,P=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,P=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(oldname),
                 absolute_path(newname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.read, syscall.readv {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.read.return, syscall.readv.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readahead {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readahead.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%ld;:,O=%ld;:,c=%ld\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,b=%ld;:,O=%ld;:,c=%ld\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -229,63 +319,103 @@ probe syscall.readahead.return {
                 $return,
                 @entry($offset),
                 @entry($count));
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readdir {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readdir.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readlink {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readlink.return {
     if(pid() == target()) {
         pathname = user_string(@entry($path))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.readlinkat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.readlinkat.return {
     if(pid() == target()) {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fdatasync, syscall.fsync {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fdatasync.return, syscall.fsync.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.sync_file_range {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.sync_file_range.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%ld;:,b=%ld;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,O=%ld;:,b=%ld;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -293,89 +423,145 @@ probe syscall.sync_file_range.return {
                 @entry($offset),
                 @entry($nbytes),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.sync {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.sync.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.syncfs {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.syncfs.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.close {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.close.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.getdents {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.getdents.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,c=%d;:,b=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,c=%d;:,b=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 @entry($count),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mkdir {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mkdir.return {
     if(pid() == target()) {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.rmdir {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.rmdir.return {
     if(pid() == target()) {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mkdirat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mkdirat.return {
     if(pid() == target()) {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,p=%s;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -383,77 +569,125 @@ probe syscall.mkdirat.return {
                 absolute_path(pathname),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.stat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.stat.return {
     if(pid() == target()) {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.statfs, syscall.statfs64 {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.statfs.return, syscall.statfs64.return {
     if(pid() == target()) {
         pathname = user_string(@entry($pathname))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fstatfs, syscall.fstatfs64 {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fstatfs.return, syscall.fstatfs64.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.lstat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.lstat.return {
     if(pid() == target()) {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fstat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fstat.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fstatat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fstatat.return {
     if(pid() == target()) {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%ld;:,p=%s;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%ld;:,p=%s;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -461,33 +695,57 @@ probe syscall.fstatat.return {
                 absolute_path(pathname),
                 @entry($flag),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.chmod, syscall.fchmodat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.chmod.return, syscall.fchmodat.return {
     if(pid() == target()) {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 absolute_path(pathname),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fchmod {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fchmod.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%d;:,m=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%d;:,m=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($fd),
                 @entry($mode),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.chown, syscall.chown16,
+      syscall.lchown, syscall.lchown16 {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
@@ -495,8 +753,9 @@ probe syscall.chown.return, syscall.chown16.return,
       syscall.lchown.return, syscall.lchown16.return {
     if(pid() == target()) {
         pathname = user_string(@entry($filename))
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -504,13 +763,21 @@ probe syscall.chown.return, syscall.chown16.return,
                 @entry($user),
                 @entry($group),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fchown, syscall.fchown16 {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fchown.return, syscall.fchown16.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,d=%ld;:,O=%d;:,G=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,d=%ld;:,O=%d;:,G=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -518,14 +785,22 @@ probe syscall.fchown.return, syscall.fchown16.return {
                 @entry($user),
                 @entry($group),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.fchownat {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.fchownat.return {
     pathname = user_string(@entry($filename))
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,p=%s;:,O=%d;:,G=%d;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -534,13 +809,21 @@ probe syscall.fchownat.return {
                 @entry($group),
                 @entry($flag),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mmap2 {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mmap2.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,m=%d;:,f=%d;:,d=%d;:,O=%ld;:,A=%ld;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,m=%d;:,f=%d;:,d=%d;:,O=%ld;:,A=%ld;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -551,13 +834,21 @@ probe syscall.mmap2.return {
                 @entry($fd),
                 @entry($pgoff),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.mremap {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.mremap.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,A=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,A=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -566,26 +857,42 @@ probe syscall.mremap.return {
                 @entry($new_len),
                 @entry($flags),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.munmap {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.munmap.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
                 @entry($addr),
                 @entry($len),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
+    }
+}
+
+probe syscall.msync {
+    if (pid() == target()) {
+        PROBE_ENTRY_TIMES[tid(),name] = gettimeofday_ns()
     }
 }
 
 probe syscall.msync.return {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,a=%ld;:,b=%ld;:,f=%d;:,s=%d;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name,
@@ -593,16 +900,19 @@ probe syscall.msync.return {
                 @entry($len),
                 @entry($flags),
                 $return);
+        delete PROBE_ENTRY_TIMES[tid(),name]
     }
 }
 
 probe syscall.exit_group {
     if(pid() == target()) {
-        printf("t=%d;:,i=%d:%d;:,o=%s;:,\n",
-                gettimeofday_ms(),
+        ns = gettimeofday_ns()
+        printf("t=%ld;:,D=%ld;:,i=%d:%d;:,o=%s;:,\n",
+                ns, ns-PROBE_ENTRY_TIMES[tid(),name],
                 pid(),
                 tid(),
                 name);
+        delete PROBE_ENTRY_TIMES[tid(),name]
     }
 }