JFS DirectIO and Backup Performance

From Wiki-UX.info
Jump to: navigation, search


Abstract

The following article analyzes performance implications of using VeritasJFS DirectIO feature on HP-UX Operating Environment at the time of creating and recovering from backup media. JFS DirectIO feature is available with OnlineJFS software bundle and is extensively used on database backing storage file systems, when the data integrity has outmost importance.

The HP-UX Operating Environment pax command is used to collect the performance metrics. Similar behavior may be encountered by using other bundled backup tools, such as cpio or tar commands.

Methodology

A new logical volume /dev/vg00/directio was created on HP-UX 11i v3, using default VxFS layout 7 with support for large files (2GB+). The latest patch level is already applied to the system (2008.07.30).

The HP-UX 11i v3 pax command (PHCO_36798) is used to create a disk-to-disk ustar archive, using the maximum supported block size of 32256 bytes. The backup storage medium is a standard Ultra320 hard disk.

# what /usr/bin/pax
/usr/bin/pax:
        $Revision: 92453-07 linker linker crt0.o B.11.16.01 030415 $
         pax.c $Date: 2008/10/31 02:54:35 $Revision: r11.31/1 PATCH_11.31 (PHCO_38835)
         create.c $Date: 2008/05/09 11:03:14 $Revision: r11.31/2 PATCH_11.31 (PHCO_38321)
         namelist.c $Date: 2008/10/31 02:54:37 $Revision: r11.31/2 PATCH_11.31 (PHCO_38835)
         pass.c $Date: 2007/06/27 14:12:14 $Revision: r11.31/1 PATCH_11.31 (PHCO_36798)
         ttyio.c $Date: 2007/06/27 14:12:17 $Revision: r11.31/1 PATCH_11.31 (PHCO_36798)
# ioscan -NfnkC disk
Class     I  H/W Path  Driver S/W State   H/W Type     Description
===================================================================
disk     11  64000/0xfa00/0x2  esdisk   CLAIMED     DEVICE       HP 36.4GST336754LC
                      /dev/disk/disk11   /dev/rdisk/disk11
disk      6  64000/0xfa00/0x4  esdisk   CLAIMED     DEVICE       HP 36.4GST336754LC
                      /dev/disk/disk6   /dev/rdisk/disk6
# lvcreate -n directio -l 469 /dev/vg00
Logical volume "/dev/vg00/directio" has been successfully created with
character device "/dev/vg00/rdirectio".
Logical volume "/dev/vg00/directio" has been successfully extended.
Volume Group configuration for /dev/vg00 has been saved in /etc/lvmconf/vg00.conf
# newfs -F vxfs -o largefiles /dev/vg00/rdirectio
    version 7 layout
    3842048 sectors, 3842048 blocks of size 1024, log size 16384 blocks
    largefiles supported

The VxFS file system is mounted using default option delaylog and DirectIO options delaylog,mincache=direct,convosync=direct respectively. The file system is populated with a single large file and two small files to replicate a very basic distribution.

# bdf /directio
Filesystem          kbytes    used   avail %used Mounted on
/dev/vg00/directio 3842048 2203365 1536272   59% /directio

# ll /directio
total 4369848
-rw-r--r--   1 root       sys          39401 Jul 30 11:30 hpux__11.11_07170810.tgz
-rw-r--r--   1 root       sys        7102510 Jul 30 11:30 hpux__11.23_07160545.tgz
drwxr-xr-x   2 root       root            96 Jul 30 11:11 lost+found
-rw-r--r--   1 root       sys        2230210560 Jul 30 11:21 swtape01.iso

Performance measurements

Backup Archive Creation

In the following tests, the pax command was used to dump the file system backup directly on a direct attached disk /dev/disk/disk11 instead of a tape drive to provide near to wire speed write capacity.

Using default mount options

# timex pax -wv -b 32256 -f /dev/rdisk/disk11 /directio
/directio/
/directio/lost+found/
/directio/swtape01.iso
/directio/hpux__11.23_07160545.tgz
/directio/hpux__11.11_07170810.tgz

real     5:03.31
user        0.16
sys         9.42

Using DirectIO mount options

# timex pax -wv -b 32256 -f /dev/rdisk/disk11 /directio
/directio/
/directio/lost+found/
/directio/swtape01.iso
/directio/hpux__11.23_07160545.tgz
/directio/hpux__11.11_07170810.tgz

real     5:28.78
user        0.16
sys         5.74
`

Note that backup creation time is slightly shorter when using the default options instead of the DirectIO options. On large datasets this difference may represent a sensible larger backup window.

Backup Archive Restore

Using default mount options

# timex pax -rv -p e -b 32256 -f /dev/rdisk/disk11
USTAR format archive
/directio/
/directio/lost+found/
/directio/swtape01.iso
/directio/hpux__11.23_07160545.tgz
/directio/hpux__11.11_07170810.tgz

real     1:07.67
user        0.13
sys         7.39
# tusc -p 28169
read(6, "acdd) \nd k bfa012T d7e0F ebc1' ".., 32256) ..... = 32256
write(7, "acdd) \nd k bfa012T d7e0F ebc1' ".., 32256) .... = 32256
read(6, "x O 1afe\f7fee811fe0bd1cl e79f; ".., 32256) ..... = 32256
write(7, "x O 1afe\f7fee811fe0bd1cl e79f; ".., 32256) .... = 32256
read(6, "\0" e49 / dd8de4ddc0ad9a! T a2m ".., 32256) ..... = 32256
write(7, "\0" e49 / dd8de4ddc0ad9a! T a2m ".., 32256) .... = 32256
read(6, "\na2E f f9e0b1d2d1cfca@ 86958902".., 32256) ..... = 32256
write(7, "\na2E f f9e0b1d2d1cfca@ 86958902".., 32256) .... = 32256
( Detaching from process 28169 ("pax -rv -p e -b 32256 -f /dev/rdisk/disk11") )
# tusc -c 28169
( Attached to process 28169 ("pax -rv -p e -b 32256 -f /dev/rdisk/disk11") [32-bit] )
( Detaching from process 28169 ("pax -rv -p e -b 32256 -f /dev/rdisk/disk11") )
Syscall                     Seconds       Calls      Errors
read                           0.16        7144
write                          0.67        7143
-----                         -----       -----
Sys totals:                    0.83       14287
User time:                     0.03
Interrupt time:                0.05
Elapsed time:                  6.77
# sar -d 2 5

HP-UX delta B.11.31 U 9000/800    07/30/09

12:13:10   device   %busy   avque   r+w/s  blks/s  avwait  avserv
12:13:12   disk11   65.17    0.50    1372   86413    0.00    0.47
            disk6   60.20  602.61     388   45619  505.61   10.01
12:13:14   disk11   27.00    0.50     572   36068    0.00    0.47
            disk6   74.00  423.43     411   51266 1267.78   15.69
12:13:16   disk11   54.00    0.50    1151   72513    0.00    0.47
            disk6   54.00  181.35     416   51604  207.48    9.59
12:13:18   disk11   26.13    0.50     549   34603    0.00    0.48
            disk6   98.99  265.27     508   58865  459.26   15.10
12:13:20   disk11   39.60    0.50     839   52864    0.00    0.47
            disk6   79.21  325.47     505   61050  359.17   12.05

Average    disk11   42.42    0.50     897   56537    0.00    0.47
Average     disk6   73.25  365.74     446   53682  546.44   12.60

Using DirectIO mount options

# timex pax -rv -p e -b 32256 -f /dev/rdisk/disk11
USTAR format archive
/directio/
/directio/lost+found/
/directio/swtape01.iso
/directio/hpux__11.23_07160545.tgz
/directio/hpux__11.11_07170810.tgz

real    11:46.89
user        0.15
sys        10.07
# tusc -p 27481

...
[27481] read(6, "adcf9bj f7058dd497a6& v \a= e983".., 32256) = 32256
[27481] write(7, "adcf9bj f7058dd497a6& v \a= e983".., 32256) = 32256
[27481] read(6, "s 18~ b906O 9 92O c4> b7& c491f4".., 32256) = 32256
[27481] write(7, "s 18~ b906O 9 92O c4> b7& c491f4".., 32256) = 32256
[27481] read(6, "d587| fea8p f6c98cf98b' f3O L _ ".., 32256) = 32256
[27481] write(7, "d587| fea8p f6c98cf98b' f3O L _ ".., 32256) = 32256
[27481] read(6, "c6D 930e87ad87cccbe7w c8F e0ff19".., 32256) = 32256
[27481] write(7, "c6D 930e87ad87cccbe7w c8F e0ff19".., 32256) = 32256
[27481] read(6, "e9X bb\b{ 841dd7939dE % p d abac".., 32256) = 32256
( Detaching from process 27481 ("pax -rv -p e -b 32256 -f /dev/rdisk/disk11") )
# tusc -cp 27481

( Attached to process 27481 ("pax -rv -p e -b 32256 -f /dev/rdisk/disk11") [32-bit] )
( Detaching from process 27481 ("pax -rv -p e -b 32256 -f /dev/rdisk/disk11") )
Syscall                     Seconds       Calls      Errors
read                           0.01         490
write                          0.05         490
-----                         -----       -----
Sys totals:                    0.06         980
User time:                     0.00
Interrupt time:                0.02
Elapsed time:                  5.04
# sar -d 2 5

HP-UX delta B.11.31 U 9000/800    07/30/09

11:59:23   device   %busy   avque   r+w/s  blks/s  avwait  avserv
11:59:25   disk11    4.48    0.50      99    6206    0.00    0.47
            disk6   94.03    0.50     322    7432    0.00    2.97
11:59:27   disk11    5.00    0.50      99    6237    0.00    0.47
            disk6   94.50    0.50     324    7468    0.00    2.97
11:59:29   disk11    4.48    0.50      99    6206    0.00    0.47
            disk6   93.53    0.50     322    7438    0.00    2.95
11:59:31   disk11    4.52    0.50      99    6237    0.00    0.47
            disk6   94.47    0.50     323    7491    0.00    2.99
11:59:33   disk11    4.50    0.50      98    6174    0.00    0.47
            disk6   94.00    0.50     322    7414    0.00    3.02

Average    disk11    4.60    0.50      99    6212    0.00    0.47
Average     disk6   94.11    0.50     323    7449    0.00    2.98

Conclusions

  1. DirectIO read speed is marginally affected at backup creation time: 5:03 vs 5:28 seconds.
  2. DirectIO write speed is affected up to factor of 10 at backup restore time. Specifically, the number of write system calls that can be performed is much lower: 98 write calls per second (490 / 5) than using standard mount options: 1020 write calls per second (7144 / 7).
  3. This write delay may be greater on tape based backups, since the ability of tape drives to operate at stream mode may be affected, causing hundreds or thousands of read head repositions.
  4. This behavior is consistent with the disclaimer available at the JFS Tuning and Performance (page 12) whitepaper: Direct I/O is typically slower than buffered I/O as all direct I/O is synchronous. When direct I/O is used, no read ahead or flush behind is performed. Each I/O must complete during the system call that initiated the I/O. Direct I/O works better for large I/Os that do not need to be maintained in the buffer cache and the speed of the write is not important.

Reference

Authors

Editor