Trace Commands in Linux

Log SCSI Commands

Enable

打開磁碟管理,先找到目標磁碟機的代號,例如 /dev/sdb

進入終端機輸入指令開始錄製 SCSI 指令:

scsi_logging_level --set --mlcomplete 2

Watch Log

然後輸入以下指令,即可把對 sdb 碟下的 SCSI Command Trace 起來至 scsi_log.txt 檔案:

tail -f /var/log/syslog | grep --line-buffered "\[sdb\]" | tee scsi_log.txt

如果不需要存檔,可以省略最後的 tee 指令。

== Do Whatever You Want with SCSI Disk ==

Disable

scsi_logging_level --set --mlcomplete 0

Sample Output

Dec 21 10:37:25 nvme kernel: [ 417.626540] sd 9:0:0:0: [sda] tag#14 CDB: Write(10) 2a 00 0a cd 93 a0 00 00 e0 00
Dec 21 10:37:25 nvme kernel: [ 417.629697] sd 9:0:0:0: [sda] tag#25 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Dec 21 10:37:25 nvme kernel: [ 417.629701] sd 9:0:0:0: [sda] tag#25 CDB: Read(10) 28 00 0a ce c0 80 00 00 08 00
Dec 21 10:37:25 nvme kernel: [ 417.630647] sd 9:0:0:0: [sda] tag#26 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Dec 21 10:37:25 nvme kernel: [ 417.630650] sd 9:0:0:0: [sda] tag#26 CDB: Read(10) 28 00 0a ce 91 b8 00 00 30 00
Dec 21 10:37:28 nvme kernel: [ 420.113000] sd 9:0:0:0: [sda] tag#6 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Dec 21 10:37:28 nvme kernel: [ 420.113037] sd 9:0:0:0: [sda] tag#6 CDB: Write(10) 2a 00 02 9a e7 e0 00 00 58 00
Dec 21 10:37:28 nvme kernel: [ 420.114952] sd 9:0:0:0: [sda] tag#7 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Dec 21 10:37:28 nvme kernel: [ 420.114986] sd 9:0:0:0: [sda] tag#7 CDB: Synchronize Cache(10) 35 00 00 00 00 00 00 00 00 00
Dec 21 10:37:28 nvme kernel: [ 420.115095] sd 9:0:0:0: [sda] tag#19 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Dec 21 10:37:28 nvme kernel: [ 420.115100] sd 9:0:0:0: [sda] tag#19 CDB: Write(10) 2a 00 02 9a e8 38 00 00 08 00

References

Log NVMe Commands

Enable

啓用 Linux 内建的 NVMe Trace 功能以錄製 NVMe 指令:

echo 1 > /sys/kernel/debug/tracing/events/nvme/enable

Add Filter (Optional)

若需要 Filter 可以參考以下寫法:

echo "qid==0" > /sys/kernel/debug/tracing/events/nvme/filter

Watch Log

== Do Whatever You Want with NVMe Disk ==

輸入以下指令查看 NVMe Command Trace 並存到 nvme_log.txt 檔案:

cat /sys/kernel/debug/tracing/trace | tee nvme_log.txt

Disable

echo 0 > /sys/kernel/debug/tracing/events/nvme/enable

Sample Output

# tracer: nop
#
# entries-in-buffer/entries-written: 390/390 #P:24
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
NVMeSimpleTool_-3299 [012] .... 380.393156: nvme_setup_cmd: nvme0: qid=0, cmdid=12, nsid=1, flags=0x0, meta=0x0, cmd=(nvme_admin_identify cns=0, ctrlid=0)
<idle>-0 [015] d.h. 380.395774: nvme_sq: nvme0: qid=0, head=1, tail=1
<idle>-0 [015] ..s. 380.395795: nvme_complete_rq: nvme0: qid=0, cmdid=12, res=0x0, retries=0, flags=0x2, status=0x0
NVMeSimpleTool_-3299 [012] .... 380.397298: nvme_setup_cmd: nvme0: qid=0, cmdid=13, nsid=0, flags=0x0, meta=0x0, cmd=(nvme_admin_identify cns=1, ctrlid=0)
<idle>-0 [015] d.h. 380.397651: nvme_sq: nvme0: qid=0, head=2, tail=2
<idle>-0 [015] ..s. 380.397664: nvme_complete_rq: nvme0: qid=0, cmdid=13, res=0x0, retries=0, flags=0x2, status=0x0
NVMeSimpleTool_-3299 [012] .... 380.398317: nvme_setup_cmd: nvme0: qid=0, cmdid=14, nsid=0, flags=0x0, meta=0x0, cmd=(nvme_admin_security_recv cdw10=00 00 00 00 00 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00)
<idle>-0 [015] d.h. 380.398577: nvme_sq: nvme0: qid=0, head=3, tail=3
<idle>-0 [015] ..s. 380.398589: nvme_complete_rq: nvme0: qid=0, cmdid=14, res=0x0, retries=0, flags=0x2, status=0x0

References

Other Common Tools

  • blktrace