Home > Articles

  • Print
  • + Share This
This chapter is from the book

This chapter is from the book

9.2 Traditional Tools

This section covers iostat(1) for disk activity summaries, perf(1) for block I/O tracing, blktrace(8), and the SCSI log.

9.2.1 iostat

iostat(1) summarizes per-disk I/O statistics, providing metrics for IOPS, throughput, I/O request times, and utilization. It can be executed by any user, and is typically the first command used to investigate disk I/O issues at the command line. The statistics it sources are maintained by the kernel by default, so the overhead of this tool is considered negligible.

iostat(1) provides many options for customizing the output. A useful combination is -dxz 1, to show disk utilization only (-d), extended columns (-x), skipping devices with zero metrics (-z), and per-second output (1). The output is so wide that I’ll show a left portion and then the right portion; this is from a production issue I helped debug:

# iostat -dxz 1
Linux 4.4.0-1072-aws (...)      12/18/2018      _x86_64_        (16 CPU)

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s \ ...
xvda              0.00     0.29    0.21    0.17     6.29     3.09 / ...
xvdb              0.00     0.08   44.39    9.98  5507.39  1110.55 \ ...
                                                                  / ...
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s \ ...
xvdb              0.00     0.00  745.00    0.00 91656.00     0.00 / ...
                                                                  \ ...
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s / ...
xvdb              0.00     0.00  739.00    0.00 92152.00     0.00 \ ...

These columns summarize the workload applied, and are useful for workload characterization. The first two provide insight into disk merges: this is where a new I/O is found to be reading or writing to a disk location adjacent (front or back) to another queued I/O, so they are merged for efficiency.

The columns are:

  • rrqm/s: Read requests queued and merged per second

  • wrqm/s: Write requests queued and merged per second

  • r/s: Read requests completed per second (after merges)

  • w/s: Write requests completed per second (after merges)

  • rkB/s: Kbytes read from the disk device per second

  • wkB/s: Kbytes written to the disk device per second

The first group of output (showing both xvda and xvdb devices) is the summary since boot, and can be used for comparison with the subsequent one-second summaries. This output shows that xvdb normally has a read throughput of 5,507 Kbytes/sec, but the current one-second summaries show over 90,000 read Kbytes/sec. The system has a heavier-than-normal read workload.

Some math can be applied to these columns to figure out the average read and write size. Dividing the rkB/s column by the r/s column shows the average read size is about 124 Kbytes. A newer version of iostat(1) includes average sizes as the rareq-sz (read average request size) and wareq-sz columns.

The right columns show:

... \ avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
... /    49.32     0.00   12.74    6.96   19.87   3.96   0.15
... \   243.43     2.28   41.96   41.75   42.88   1.52   8.25
... /
... \ avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
... /   246.06    25.32   33.84   33.84    0.00   1.35 100.40
... ... / avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
... \   249.40    24.75   33.49   33.49    0.00   1.35 100.00

These show the resulting performance by the device. The columns are:

  • avgrq-sz: Average request size in sectors (512 bytes).

  • avgqu-sz: Average number of requests both waiting in the driver request queue and active on the device.

  • await: Average I/O request time (aka response time), including time waiting in the driver request queue and the I/O response time of the device (ms).

  • r_await: Same as await, but for reads only (ms).

  • w_await: Same as await, but for writes only (ms).

  • svctm: Average (inferred) I/O response time for the disk device (ms).

  • %util: Percentage of time device was busy processing I/O requests (utilization).

The most important metric for delivered performance is await. If the application and file system use a technique to mitigate write latency (e.g., write through), then w_await may not matter as much, and you can focus on r_await instead.

For resource usage and capacity planning, %util is important, but keep in mind that it is only a measure of busy-ness (non-idle time), and may mean little for virtual devices backed by multiple disks. Those devices may be better understood by the load applied: IOPS (r/s + w/s) and throughput (rkB/s + wkB/s).

This example output shows the disk hitting 100% utilization, and an average read I/O time of 33 milliseconds. For the workload applied and the disk device, this turned out to be expected performance. The real issue was that the files being read had become so large they could no longer be cached in the page cache, and were read from disk instead.

9.2.2 perf

perf(1) was introduced in Chapter 6 for PMC analysis and timed stack sampling. Its tracing capabilities can also be used for disk analysis, especially using the block tracepoints.

For example, tracing the queuing of requests (block_rq_insert), their issue to a storage device (block_rq_issue), and their completions (block_rq_complete):

# perf record -e block:block_rq_insert,block:block_rq_issue,block:block_rq_complete -a
^C[ perf record: Woken up 7 times to write data ]
[ perf record: Captured and wrote 6.415 MB perf.data (20434 samples) ]
# perf script
    kworker/u16:3 25003 [004] 543348.164811:   block:block_rq_insert: 259,0 RM 4096 ()
2564656 + 8 [kworker/u16:3]
    kworker/4:1H    533 [004] 543348.164815:   block:block_rq_issue: 259,0 RM 4096 ()
2564656 + 8 [kworker/4:1H]
         swapper      0 [004] 543348.164887:   block:block_rq_complete: 259,0 RM ()
2564656 + 8 [0]
   kworker/u17:0 23867  [005] 543348.164960:   block:block_rq_complete: 259,0 R ()
3190760 + 256 [0]
              dd 25337  [001] 543348.165046:   block:block_rq_insert: 259,0 R 131072 ()
3191272 + 256 [dd]
              dd 25337  [001] 543348.165050:   block:block_rq_issue: 259,0 R 131072 ()
3191272 + 256 [dd]
              dd 25337  [001] 543348.165111:   block:block_rq_complete: 259,0 R ()
3191272 + 256 [0]
[...]

The output contains many details, beginning with the process that was on-CPU when the event occurred, which may or may not be the process responsible for the event. Other details include a timestamp, disk major and minor numbers, a string encoding the type of I/O (rwbs, described earlier), and other details about the I/O.

I have in the past built tools that post-process these events for calculating latency histograms, and visualizing access patterns.1 However, for busy systems this means dumping all block events to user space for post-processing. BPF can do this processing in the kernel more efficiently, and then emit only the desired output. See the later biosnoop(8) tool as an example.

1 See iolatency(8) in perf-tools [78]: this uses Ftrace to access the same per-event tracepoint data from the trace buffer, which avoids the overhead of creating and writing a perf.data file.

9.2.3 blktrace

blktrace(8) is a specialized utility for tracing block I/O events. Using its btrace(8) front-end to trace all events:

# btrace /dev/nvme2n1
259,0    2        1     0.000000000   430  Q  WS 2163864 + 8 [jbd2/nvme2n1-8]
259,0    2        2     0.000009556   430  G  WS 2163864 + 8 [jbd2/nvme2n1-8]
259,0    2        3     0.000011109   430  P   N [jbd2/nvme2n1-8]
259,0    2        4     0.000013256   430  Q  WS 2163872 + 8 [jbd2/nvme2n1-8]
259,0    2        5     0.000015740   430  M  WS 2163872 + 8 [jbd2/nvme2n1-8]
[...]
259,0    2       15     0.000026963   430  I  WS 2163864 + 48 [jbd2/nvme2n1-8]
259,0    2       16     0.000046155   430  D  WS 2163864 + 48 [jbd2/nvme2n1-8]
259,0    2       17     0.000699822   430  Q  WS 2163912 + 8 [jbd2/nvme2n1-8]
259,0    2       18     0.000701539   430  G  WS 2163912 + 8 [jbd2/nvme2n1-8]
259,0    2       19     0.000702820   430  I  WS 2163912 + 8 [jbd2/nvme2n1-8]
259,0    2       20     0.000704649   430  D  WS 2163912 + 8 [jbd2/nvme2n1-8]
259,0   11        1     0.000664811     0  C  WS 2163864 + 48 [0]
259,0   11        2     0.001098435     0  C  WS 2163912 + 8 [0]
[...]

Multiple event lines are printed for each I/O. The columns are:

  1. Device major, minor number

  2. CPU ID

  3. Sequence number

  4. Action time, in seconds

  5. Process ID

  6. Action identifier (see blkparse(1)): Q == queued, G == get request, P == plug, M == merge, D == issued, C == completed, etc.

  7. RWBS description (see the “rwbs” section earlier in this chapter): W == write, S == synchronous, etc.

  8. Address + size [device]

The output can be post-processed and visualized using Chris Mason’s seekwatcher [91].

As with perf(1) per-event dumping, the overhead of blktrace(8) can be a problem for busy disk I/O workloads. In-kernel summaries using BPF can greatly reduce this overhead.

9.2.4 SCSI Logging

Linux also has a built-in facility for SCSI event logging. It can be enabled via sysctl(8) or /proc. For example, both of these commands set the logging to the maximum for all event types (warning: depending on your disk workload, this may flood your system log):

# sysctl w dev.scsi.logging_level=0x1b6db6db
# echo 0x1b6db6db > /proc/sys/dev/scsi/logging_level

The format of the number is a bitfield that sets the logging level from 1 to 7 for 10 different event types. It is defined in drivers/scsi/scsi_logging.h. The sg3utils package provides a scsi_logging_level(8) tool for setting these. For example:

scsi_logging_level -s --all 3

Example events:

# dmesg
[...]
[542136.259412] sd 0:0:0:0: tag#0 Send: scmd 0x0000000001fb89dc
[542136.259422] sd 0:0:0:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
[542136.261103] sd 0:0:0:0: tag#0 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[542136.261110] sd 0:0:0:0: tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
[542136.261115] sd 0:0:0:0: tag#0 Sense Key : Not Ready [current]
[542136.261121] sd 0:0:0:0: tag#0 Add. Sense: Medium not present
[542136.261127] sd 0:0:0:0: tag#0 0 sectors total, 0 bytes done.
[...]

This can be used to help debug errors and timeouts. While timestamps are provided (the first column), using them to calculate I/O latency is difficult without unique identifying details.

BPF tracing can be used to produce custom SCSI-level and other I/O stack-level logs, with more I/O details including latency calculated in the kernel.

  • + Share This
  • 🔖 Save To Your Account

InformIT Promotional Mailings & Special Offers

I would like to receive exclusive offers and hear about products from InformIT and its family of brands. I can unsubscribe at any time.

Overview


Pearson Education, Inc., 221 River Street, Hoboken, New Jersey 07030, (Pearson) presents this site to provide information about products and services that can be purchased through this site.

This privacy notice provides an overview of our commitment to privacy and describes how we collect, protect, use and share personal information collected through this site. Please note that other Pearson websites and online products and services have their own separate privacy policies.

Collection and Use of Information


To conduct business and deliver products and services, Pearson collects and uses personal information in several ways in connection with this site, including:

Questions and Inquiries

For inquiries and questions, we collect the inquiry or question, together with name, contact details (email address, phone number and mailing address) and any other additional information voluntarily submitted to us through a Contact Us form or an email. We use this information to address the inquiry and respond to the question.

Online Store

For orders and purchases placed through our online store on this site, we collect order details, name, institution name and address (if applicable), email address, phone number, shipping and billing addresses, credit/debit card information, shipping options and any instructions. We use this information to complete transactions, fulfill orders, communicate with individuals placing orders or visiting the online store, and for related purposes.

Surveys

Pearson may offer opportunities to provide feedback or participate in surveys, including surveys evaluating Pearson products, services or sites. Participation is voluntary. Pearson collects information requested in the survey questions and uses the information to evaluate, support, maintain and improve products, services or sites, develop new products and services, conduct educational research and for other purposes specified in the survey.

Contests and Drawings

Occasionally, we may sponsor a contest or drawing. Participation is optional. Pearson collects name, contact information and other information specified on the entry form for the contest or drawing to conduct the contest or drawing. Pearson may collect additional personal information from the winners of a contest or drawing in order to award the prize and for tax reporting purposes, as required by law.

Newsletters

If you have elected to receive email newsletters or promotional mailings and special offers but want to unsubscribe, simply email information@informit.com.

Service Announcements

On rare occasions it is necessary to send out a strictly service related announcement. For instance, if our service is temporarily suspended for maintenance we might send users an email. Generally, users may not opt-out of these communications, though they can deactivate their account information. However, these communications are not promotional in nature.

Customer Service

We communicate with users on a regular basis to provide requested services and in regard to issues relating to their account we reply via email or phone in accordance with the users' wishes when a user submits their information through our Contact Us form.

Other Collection and Use of Information


Application and System Logs

Pearson automatically collects log data to help ensure the delivery, availability and security of this site. Log data may include technical information about how a user or visitor connected to this site, such as browser type, type of computer/device, operating system, internet service provider and IP address. We use this information for support purposes and to monitor the health of the site, identify problems, improve service, detect unauthorized access and fraudulent activity, prevent and respond to security incidents and appropriately scale computing resources.

Web Analytics

Pearson may use third party web trend analytical services, including Google Analytics, to collect visitor information, such as IP addresses, browser types, referring pages, pages visited and time spent on a particular site. While these analytical services collect and report information on an anonymous basis, they may use cookies to gather web trend information. The information gathered may enable Pearson (but not the third party web trend services) to link information with application and system log data. Pearson uses this information for system administration and to identify problems, improve service, detect unauthorized access and fraudulent activity, prevent and respond to security incidents, appropriately scale computing resources and otherwise support and deliver this site and its services.

Cookies and Related Technologies

This site uses cookies and similar technologies to personalize content, measure traffic patterns, control security, track use and access of information on this site, and provide interest-based messages and advertising. Users can manage and block the use of cookies through their browser. Disabling or blocking certain cookies may limit the functionality of this site.

Do Not Track

This site currently does not respond to Do Not Track signals.

Security


Pearson uses appropriate physical, administrative and technical security measures to protect personal information from unauthorized access, use and disclosure.

Children


This site is not directed to children under the age of 13.

Marketing


Pearson may send or direct marketing communications to users, provided that

  • Pearson will not use personal information collected or processed as a K-12 school service provider for the purpose of directed or targeted advertising.
  • Such marketing is consistent with applicable law and Pearson's legal obligations.
  • Pearson will not knowingly direct or send marketing communications to an individual who has expressed a preference not to receive marketing.
  • Where required by applicable law, express or implied consent to marketing exists and has not been withdrawn.

Pearson may provide personal information to a third party service provider on a restricted basis to provide marketing solely on behalf of Pearson or an affiliate or customer for whom Pearson is a service provider. Marketing preferences may be changed at any time.

Correcting/Updating Personal Information


If a user's personally identifiable information changes (such as your postal address or email address), we provide a way to correct or update that user's personal data provided to us. This can be done on the Account page. If a user no longer desires our service and desires to delete his or her account, please contact us at customer-service@informit.com and we will process the deletion of a user's account.

Choice/Opt-out


Users can always make an informed choice as to whether they should proceed with certain services offered by InformIT. If you choose to remove yourself from our mailing list(s) simply visit the following page and uncheck any communication you no longer want to receive: www.informit.com/u.aspx.

Sale of Personal Information


Pearson does not rent or sell personal information in exchange for any payment of money.

While Pearson does not sell personal information, as defined in Nevada law, Nevada residents may email a request for no sale of their personal information to NevadaDesignatedRequest@pearson.com.

Supplemental Privacy Statement for California Residents


California residents should read our Supplemental privacy statement for California residents in conjunction with this Privacy Notice. The Supplemental privacy statement for California residents explains Pearson's commitment to comply with California law and applies to personal information of California residents collected in connection with this site and the Services.

Sharing and Disclosure


Pearson may disclose personal information, as follows:

  • As required by law.
  • With the consent of the individual (or their parent, if the individual is a minor)
  • In response to a subpoena, court order or legal process, to the extent permitted or required by law
  • To protect the security and safety of individuals, data, assets and systems, consistent with applicable law
  • In connection the sale, joint venture or other transfer of some or all of its company or assets, subject to the provisions of this Privacy Notice
  • To investigate or address actual or suspected fraud or other illegal activities
  • To exercise its legal rights, including enforcement of the Terms of Use for this site or another contract
  • To affiliated Pearson companies and other companies and organizations who perform work for Pearson and are obligated to protect the privacy of personal information consistent with this Privacy Notice
  • To a school, organization, company or government agency, where Pearson collects or processes the personal information in a school setting or on behalf of such organization, company or government agency.

Links


This web site contains links to other sites. Please be aware that we are not responsible for the privacy practices of such other sites. We encourage our users to be aware when they leave our site and to read the privacy statements of each and every web site that collects Personal Information. This privacy statement applies solely to information collected by this web site.

Requests and Contact


Please contact us about this Privacy Notice or if you have any requests or questions relating to the privacy of your personal information.

Changes to this Privacy Notice


We may revise this Privacy Notice through an updated posting. We will identify the effective date of the revision in the posting. Often, updates are made to provide greater clarity or to comply with changes in regulatory requirements. If the updates involve material changes to the collection, protection, use or disclosure of Personal Information, Pearson will provide notice of the change through a conspicuous notice on this site or other appropriate way. Continued use of the site after the effective date of a posted revision evidences acceptance. Please contact us if you have questions or concerns about the Privacy Notice or any objection to any revisions.

Last Update: November 17, 2020