my tech blog

A udev rule for my USB stick (disk-on-key)

Introduction

I use USB flash sticks for backing up my system periodically by creating an image of the filesystem, and raw-writing it directly to e.g. /dev/sdd1. It’s just a matter of time before I wipe my hard disk by selecting the wrong /dev/something. Or just some other USB stick that happened to be plugged in.

To avoid this, I wrote a udev rule for detecting the two specific USB devices that I use for backing up, and change their ownership, so I won’t be root while doing this (this protects the real disks somewhat). Also, rename the device file to something that can’t be confused with anything else. Ehm, it’s 2018, and systemd’s udev machinery don’t agree renaming /dev files. So add a symbolic link instead. It’s as good, as long as I don’t have to write /dev/sdd-something in the command wiping whatever’s there.

Writing udev rules is well-documented all over the web, but I still wrote down my own quick summary, so I have it handy for the next time. Well, actually twice. The first time was in 2011, and then in 2018, both are on this page. So this is two posts in one.

On systemd-enabled system (that’s all of them by 2018?), the system’s udev rules reside in /lib/udev/. The rules in /etc/udev take precedence, and it’s still the correct place to put local rules. Just don’t be surprised that it’s empty.

And I have another post with udev hacking (and one related to NICs). But now, let’s start with the 2018 post. Updated to Linux Mint 19, with systemd all over the place (and I love it, frankly).

And a little tip to myself and others: man udev. Really. Give it a go every now and then.

Obtaining matching parameters

The built-in udev rules in /lib/udev/rules.d set up a lot of environment variables, which are, among others, printed by e.g.

# udevadm info -q all -n /dev/sdd1

So don’t. It’s better to stick to the actual attributes, as given by

# udevadm info -a -n /dev/sdd1

Note that each segment of this output is a separate device, and hence a separate udev event. All matches in the udev rule must relate to one segment only.

Building the rule

The udevadm info command outputs a very important comment, which is worth repeating:

A rule to match can be composed by the attributes of the device and the attributes from one single parent device.

Based upon the info obtained with udevadm info (see just below), the following rule was set up:

KERNEL=="sd?1", SUBSYSTEM=="block", ATTRS{idProduct}=="5591", ATTRS{idVendor}=="0781", ATTRS{serial}=="1234567890", OWNER:="eli", SYMLINK+="backupstick_a"

One may ask why I bothered to add the match against KERNEL==”sd?1″ and SUBSYSTEM==”block”.

Without these, the match works against e.g. /dev/sdd and /dev/sdd1, even though the symbolic link ends up pointing at /dev/sdd1. However the ownership is set for both, clearly indicating that both sdd and sdd1 were processed. Having some trust in udev, I would expect it to behave in a consistent manner on this, but I don’t want to rely on it. Hence the rule is specific on a first partition (I could have gone ATTR{partition}==”1″ as well, but why).

So the rule above takes advantage of the comment in bold above: Matching from a device and its parent. And it works.

Testing the rules

Note that “udevadm test” performs the actions for real. It’s not a dry run.

There no need for any reload command for testing the rule as follows:

# udevadm test -a add $(udevadm info -q path /dev/sdd) 2>&1 | less

But in order to get it working, a reload is required:

 # udevadm control --reload

Picking the correct subsystem

The SUBSYSTEM match determines which device file the rule will apply to. For example, a USB fax/modem device appears both under the “usb” subsystem, which relates to the /dev/bus/usb/XXX/XXX device, and the “tty” subsystem, in which case it goes with the e.g. /dev/ttyACM0 device.

Likewise, when testing, the rule will take effect on one of the device files, and not the other.

The SYMLINK+= command can be useful to tell what device file is related to, but if the symlink is created, odds are we got it right anyhow…

udevadm info of this case

# udevadm info -a -n /dev/sdd1
Udevadm info starts with the device specified by the devpath and then
walks up the chain of parent devices. It prints for every device
found, all possible attributes in the udev rules key format.
A rule to match, can be composed by the attributes of the device
and the attributes from one single parent device.

  looking at device '/devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.0/host8/target8:0:0/8:0:0:0/block/sdd/sdd1':
    KERNEL=="sdd1"
    SUBSYSTEM=="block"
    DRIVER==""
    ATTR{alignment_offset}=="0"
    ATTR{discard_alignment}=="0"
    ATTR{inflight}=="       0        0"
    ATTR{partition}=="1"
    ATTR{ro}=="0"
    ATTR{size}=="242614240"
    ATTR{start}=="32"
    ATTR{stat}=="     131        0     6184      308        0        0        0        0        0      204      308"

  looking at parent device '/devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.0/host8/target8:0:0/8:0:0:0/block/sdd':
    KERNELS=="sdd"
    SUBSYSTEMS=="block"
    DRIVERS==""
    ATTRS{alignment_offset}=="0"
    ATTRS{capability}=="51"
    ATTRS{discard_alignment}=="0"
    ATTRS{events}=="media_change"
    ATTRS{events_async}==""
    ATTRS{events_poll_msecs}=="-1"
    ATTRS{ext_range}=="256"
    ATTRS{hidden}=="0"
    ATTRS{inflight}=="       0        0"
    ATTRS{range}=="16"
    ATTRS{removable}=="1"
    ATTRS{ro}=="0"
    ATTRS{size}=="242614272"
    ATTRS{stat}=="     145        0     6296      340        0        0        0        0        0      228      340"

  looking at parent device '/devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.0/host8/target8:0:0/8:0:0:0':
    KERNELS=="8:0:0:0"
    SUBSYSTEMS=="scsi"
    DRIVERS=="sd"
    ATTRS{blacklist}==""
    ATTRS{device_blocked}=="0"
    ATTRS{device_busy}=="0"
    ATTRS{dh_state}=="detached"
    ATTRS{eh_timeout}=="10"
    ATTRS{evt_capacity_change_reported}=="0"
    ATTRS{evt_inquiry_change_reported}=="0"
    ATTRS{evt_lun_change_reported}=="0"
    ATTRS{evt_media_change}=="0"
    ATTRS{evt_mode_parameter_change_reported}=="0"
    ATTRS{evt_soft_threshold_reached}=="0"
    ATTRS{inquiry}==""
    ATTRS{iocounterbits}=="32"
    ATTRS{iodone_cnt}=="0x2ac"
    ATTRS{ioerr_cnt}=="0x1"
    ATTRS{iorequest_cnt}=="0x2ac"
    ATTRS{max_sectors}=="240"
    ATTRS{model}=="Ultra USB 3.0   "
    ATTRS{queue_depth}=="1"
    ATTRS{queue_type}=="none"
    ATTRS{rev}=="1.00"
    ATTRS{scsi_level}=="7"
    ATTRS{state}=="running"
    ATTRS{timeout}=="30"
    ATTRS{type}=="0"
    ATTRS{vendor}=="SanDisk "

  looking at parent device '/devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.0/host8/target8:0:0':
    KERNELS=="target8:0:0"
    SUBSYSTEMS=="scsi"
    DRIVERS==""

  looking at parent device '/devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.0/host8':
    KERNELS=="host8"
    SUBSYSTEMS=="scsi"
    DRIVERS==""

  looking at parent device '/devices/pci0000:00/0000:00:14.0/usb1/1-2/1-2:1.0':
    KERNELS=="1-2:1.0"
    SUBSYSTEMS=="usb"
    DRIVERS=="usb-storage"
    ATTRS{authorized}=="1"
    ATTRS{bAlternateSetting}==" 0"
    ATTRS{bInterfaceClass}=="08"
    ATTRS{bInterfaceNumber}=="00"
    ATTRS{bInterfaceProtocol}=="50"
    ATTRS{bInterfaceSubClass}=="06"
    ATTRS{bNumEndpoints}=="02"
    ATTRS{supports_autosuspend}=="1"

  looking at parent device '/devices/pci0000:00/0000:00:14.0/usb1/1-2':
    KERNELS=="1-2"
    SUBSYSTEMS=="usb"
    DRIVERS=="usb"
    ATTRS{authorized}=="1"
    ATTRS{avoid_reset_quirk}=="0"
    ATTRS{bConfigurationValue}=="1"
    ATTRS{bDeviceClass}=="00"
    ATTRS{bDeviceProtocol}=="00"
    ATTRS{bDeviceSubClass}=="00"
    ATTRS{bMaxPacketSize0}=="64"
    ATTRS{bMaxPower}=="224mA"
    ATTRS{bNumConfigurations}=="1"
    ATTRS{bNumInterfaces}==" 1"
    ATTRS{bcdDevice}=="0100"
    ATTRS{bmAttributes}=="80"
    ATTRS{busnum}=="1"
    ATTRS{configuration}==""
    ATTRS{devnum}=="10"
    ATTRS{devpath}=="2"
    ATTRS{idProduct}=="5591"
    ATTRS{idVendor}=="0781"
    ATTRS{ltm_capable}=="no"
    ATTRS{manufacturer}=="SanDisk"
    ATTRS{maxchild}=="0"
    ATTRS{product}=="Ultra USB 3.0"
    ATTRS{quirks}=="0x0"
    ATTRS{removable}=="removable"
    ATTRS{serial}=="1234567890"
    ATTRS{speed}=="480"
    ATTRS{urbnum}=="1580"
    ATTRS{version}==" 2.10"

  looking at parent device '/devices/pci0000:00/0000:00:14.0/usb1':
    KERNELS=="usb1"
    SUBSYSTEMS=="usb"
    DRIVERS=="usb"
    ATTRS{authorized}=="1"
    ATTRS{authorized_default}=="1"
    ATTRS{avoid_reset_quirk}=="0"
    ATTRS{bConfigurationValue}=="1"
    ATTRS{bDeviceClass}=="09"
    ATTRS{bDeviceProtocol}=="01"
    ATTRS{bDeviceSubClass}=="00"
    ATTRS{bMaxPacketSize0}=="64"
    ATTRS{bMaxPower}=="0mA"
    ATTRS{bNumConfigurations}=="1"
    ATTRS{bNumInterfaces}==" 1"
    ATTRS{bcdDevice}=="0415"
    ATTRS{bmAttributes}=="e0"
    ATTRS{busnum}=="1"
    ATTRS{configuration}==""
    ATTRS{devnum}=="1"
    ATTRS{devpath}=="0"
    ATTRS{idProduct}=="0002"
    ATTRS{idVendor}=="1d6b"
    ATTRS{interface_authorized_default}=="1"
    ATTRS{ltm_capable}=="no"
    ATTRS{manufacturer}=="Linux 4.15.0-20-generic xhci-hcd"
    ATTRS{maxchild}=="16"
    ATTRS{product}=="xHCI Host Controller"
    ATTRS{quirks}=="0x0"
    ATTRS{removable}=="unknown"
    ATTRS{serial}=="0000:00:14.0"
    ATTRS{speed}=="480"
    ATTRS{urbnum}=="134"
    ATTRS{version}==" 2.00"

  looking at parent device '/devices/pci0000:00/0000:00:14.0':
    KERNELS=="0000:00:14.0"
    SUBSYSTEMS=="pci"
    DRIVERS=="xhci_hcd"
    ATTRS{broken_parity_status}=="0"
    ATTRS{class}=="0x0c0330"
    ATTRS{consistent_dma_mask_bits}=="64"
    ATTRS{d3cold_allowed}=="1"
    ATTRS{dbc}=="disabled"
    ATTRS{device}=="0xa2af"
    ATTRS{dma_mask_bits}=="64"
    ATTRS{driver_override}=="(null)"
    ATTRS{enable}=="1"
    ATTRS{irq}=="35"
    ATTRS{local_cpulist}=="0-11"
    ATTRS{local_cpus}=="0,00000000,00000fff"
    ATTRS{msi_bus}=="1"
    ATTRS{numa_node}=="0"
    ATTRS{revision}=="0x00"
    ATTRS{subsystem_device}=="0x5007"
    ATTRS{subsystem_vendor}=="0x1458"
    ATTRS{vendor}=="0x8086"

  looking at parent device '/devices/pci0000:00':
    KERNELS=="pci0000:00"
    SUBSYSTEMS==""
    DRIVERS==""

The post from 2011 starts here

Following this excellent guide, I plugged in the USB stick and went

$ udevadm info -a -n /dev/sdd

Udevadm info starts with the device specified by the devpath and then walks up the chain of parent devices. It prints for every device found, all possible attributes in the udev rules key format. A rule to match, can  be composed by the attributes of the device and the attributes from one single parent device.

On another computer a similar command could be

$ udevinfo -q all -n /dev/sda

The output from the first command was:

 looking at device '/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.0/host15/target15:0:0/15:0:0:0/block/sdd':
 KERNEL=="sdd"
 SUBSYSTEM=="block"
 DRIVER==""
 ATTR{range}=="16"
 ATTR{ext_range}=="256"
 ATTR{removable}=="1"
 ATTR{ro}=="0"
 ATTR{size}=="7821312"
 ATTR{alignment_offset}=="0"
 ATTR{discard_alignment}=="0"
 ATTR{capability}=="51"
 ATTR{stat}=="      49      438     3182      274        0        0        0        0        0      127      274"
 ATTR{inflight}=="       0        0"

 looking at parent device '/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.0/host15/target15:0:0/15:0:0:0':
 KERNELS=="15:0:0:0"
 SUBSYSTEMS=="scsi"
 DRIVERS=="sd"
 ATTRS{device_blocked}=="0"
 ATTRS{type}=="0"
 ATTRS{scsi_level}=="3"
 ATTRS{vendor}=="SanDisk "
 ATTRS{model}=="Cruzer Blade    "
 ATTRS{rev}=="1.01"
 ATTRS{state}=="running"
 ATTRS{timeout}=="30"
 ATTRS{iocounterbits}=="32"
 ATTRS{iorequest_cnt}=="0x1a8"
 ATTRS{iodone_cnt}=="0x1a8"
 ATTRS{ioerr_cnt}=="0x1"
 ATTRS{modalias}=="scsi:t-0x00"
 ATTRS{evt_media_change}=="0"
 ATTRS{dh_state}=="detached"
 ATTRS{queue_depth}=="1"
 ATTRS{queue_type}=="none"
 ATTRS{max_sectors}=="240"

 looking at parent device '/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.0/host15/target15:0:0':
 KERNELS=="target15:0:0"
 SUBSYSTEMS=="scsi"
 DRIVERS==""

 looking at parent device '/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.0/host15':
 KERNELS=="host15"
 SUBSYSTEMS=="scsi"
 DRIVERS==""

 looking at parent device '/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.0':
 KERNELS=="2-1:1.0"
 SUBSYSTEMS=="usb"
 DRIVERS=="usb-storage"
 ATTRS{bInterfaceNumber}=="00"
 ATTRS{bAlternateSetting}==" 0"
 ATTRS{bNumEndpoints}=="02"
 ATTRS{bInterfaceClass}=="08"
 ATTRS{bInterfaceSubClass}=="06"
 ATTRS{bInterfaceProtocol}=="50"
 ATTRS{modalias}=="usb:v0781p5567d0100dc00dsc00dp00ic08isc06ip50"
 ATTRS{supports_autosuspend}=="0"

 looking at parent device '/devices/pci0000:00/0000:00:1d.7/usb2/2-1':
 KERNELS=="2-1"
 SUBSYSTEMS=="usb"
 DRIVERS=="usb"
 ATTRS{configuration}==""
 ATTRS{bNumInterfaces}==" 1"
 ATTRS{bConfigurationValue}=="1"
 ATTRS{bmAttributes}=="80"
 ATTRS{bMaxPower}=="200mA"
 ATTRS{urbnum}=="938"
 ATTRS{idVendor}=="0781"
 ATTRS{idProduct}=="5567"
 ATTRS{bcdDevice}=="0100"
 ATTRS{bDeviceClass}=="00"
 ATTRS{bDeviceSubClass}=="00"
 ATTRS{bDeviceProtocol}=="00"
 ATTRS{bNumConfigurations}=="1"
 ATTRS{bMaxPacketSize0}=="64"
 ATTRS{speed}=="480"
 ATTRS{busnum}=="2"
 ATTRS{devnum}=="8"
 ATTRS{devpath}=="1"
 ATTRS{version}==" 2.00"
 ATTRS{maxchild}=="0"
 ATTRS{quirks}=="0x0"
 ATTRS{avoid_reset_quirk}=="0"
 ATTRS{authorized}=="1"
 ATTRS{manufacturer}=="SanDisk"
 ATTRS{product}=="Cruzer Blade"
 ATTRS{serial}=="200610803009F0712206"

 looking at parent device '/devices/pci0000:00/0000:00:1d.7/usb2':
 KERNELS=="usb2"
 SUBSYSTEMS=="usb"
 DRIVERS=="usb"
 ATTRS{configuration}==""
 ATTRS{bNumInterfaces}==" 1"
 ATTRS{bConfigurationValue}=="1"
 ATTRS{bmAttributes}=="e0"
 ATTRS{bMaxPower}=="  0mA"
 ATTRS{urbnum}=="4053"
 ATTRS{idVendor}=="1d6b"
 ATTRS{idProduct}=="0002"
 ATTRS{bcdDevice}=="0206"
 ATTRS{bDeviceClass}=="09"
 ATTRS{bDeviceSubClass}=="00"
 ATTRS{bDeviceProtocol}=="00"
 ATTRS{bNumConfigurations}=="1"
 ATTRS{bMaxPacketSize0}=="64"
 ATTRS{speed}=="480"
 ATTRS{busnum}=="2"
 ATTRS{devnum}=="1"
 ATTRS{devpath}=="0"
 ATTRS{version}==" 2.00"
 ATTRS{maxchild}=="8"
 ATTRS{quirks}=="0x0"
 ATTRS{avoid_reset_quirk}=="0"
 ATTRS{authorized}=="1"
 ATTRS{manufacturer}=="Linux 2.6.35.4-OCHO1 ehci_hcd"
 ATTRS{product}=="EHCI Host Controller"
 ATTRS{serial}=="0000:00:1d.7"
 ATTRS{authorized_default}=="1"

 looking at parent device '/devices/pci0000:00/0000:00:1d.7':
 KERNELS=="0000:00:1d.7"
 SUBSYSTEMS=="pci"
 DRIVERS=="ehci_hcd"
 ATTRS{vendor}=="0x8086"
 ATTRS{device}=="0x3b34"
 ATTRS{subsystem_vendor}=="0x1458"
 ATTRS{subsystem_device}=="0x5006"
 ATTRS{class}=="0x0c0320"
 ATTRS{irq}=="23"
 ATTRS{local_cpus}=="00000000,00000000,00000000,00000000,00000000,00000000,00000000,000000ff"
 ATTRS{local_cpulist}=="0-7"
 ATTRS{modalias}=="pci:v00008086d00003B34sv00001458sd00005006bc0Csc03i20"
 ATTRS{numa_node}=="-1"
 ATTRS{dma_mask_bits}=="32"
 ATTRS{consistent_dma_mask_bits}=="32"
 ATTRS{broken_parity_status}=="0"
 ATTRS{msi_bus}==""
 ATTRS{companion}==""

 looking at parent device '/devices/pci0000:00':
 KERNELS=="pci0000:00"
 SUBSYSTEMS==""
 DRIVERS==""

From which I extracted the idVendor, idProduct and most important, serial attributes, marked in red above.

So I generated /etc/udev/rules.d/10-local-usbstick-rules saying:

SUBSYSTEMS=="usb", ATTRS{idVendor}=="0781", ATTRS{idProduct}=="5567", ATTRS{serial}=="200610803009F0712206", NAME="usbstick_trials", OWNER="eli"

Note that I set myself as the owner of the device file. This means that the data on the USB stick is not so safe, because I can accidentally write data directly to the device file. The upside is that root privileges are not necessary, so the chances for messing up a real hard disk are significantly diminished.

That’s it. /dev/sdd doesn’t appear now, and neither do partition device files, so it’s a bit more difficult to mount the disk (but there’s a trick). On the other hand, raw writing to it just became much safer.

Plug out, plug in again and we have:

$ ls -l /dev/usbstick_trials
brw-rw----. 1 eli disk 8, 48 2011-06-16 17:54 /dev/usbstick_trials

On the other computer (Centos 5.5) the rule was /etc/udev/rules.d/90-local-imagedisk.rules as follows:

KERNEL=="sda1", ENV{ID_SERIAL}=="SATA_WDC_WD5000AAKX-_WD-WCAYUFH69712", NAME="playdisk", OWNER="eli", MODE="666", OPTIONS="last_rule"

The reason for placing the rule late is to allow 50-udev.rules to set up the ID_SERIAL environment variable, which is created from the disk’s serial number. So no other disk gets messed up this way accidentally

Alternative: Monitor events

# udevadm monitor --udev --property

This prints out the udev events as they happen. The relevant info is there too. Useful when you’re not sure which device belongs to what, but a plug-in event makes it very clear. Unfortunately, it doesn’t print out any actions udev takes as it applies the rules.

A sniff dump of a PCIe device talking with Linux host

This is just a raw dump of PCIe communication. I wrote a small sniffer on an FPGA and ran some data in a loop to and from the peripheral. The sniffer’s own data was stored while sniffing, so it doesn’t appear in the stream. The whole thing ran on a Linux machine.

I thought that after writing a few words about TLP formation, a real-life example could be in place.

I recorded headers only, and then hacked together a Perl script (too ugly and specific for any future use) and got the dump below.

All writes from host to peripheral (marked with “>>”) are register writes (to the kernel code the BAR is at 0xfacf2000, but see lspci output below).

Writes from peripheral to host (marked with “<<”) consist of DMA transmissions containing data (longer writes) and status updates (shorter).

And then we have DMA reads made by peripheral, with read requests (“<<”) and completions (“>>”).

Each TLP is given in cleartext, and then the packet’s 3-4 header words hexadecimal in parentheses. In the cleartext part the address and (sender’s) bus ID are given in hex, all other in plain decimal.

As it turned out, the host sends packets using 32-bit addressing, and the peripheral uses 64 bits (as it was told to). Note that the peripheral breaks the standard (section 2.2.4.1) by using 64-bit addressing for addresses that fit 32 bit. Even though it works on most platforms, this is really not recommended.

So before getting to the raw dumps, let’s just see what lspci -vv gave us on the specific device:

01:00.0 Class ff00: Xilinx Corporation Generic FPGA core
 Subsystem: Xilinx Corporation Generic FPGA core
 Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Step
ping- SERR- FastB2B-
 Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR-
 Latency: 0, Cache Line Size: 4 bytes
 Interrupt: pin ? routed to IRQ 42
 Region 0: Memory at fdaff000 (64-bit, non-prefetchable) [size=128]
 Capabilities: [40] Power Management version 3
 Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0-,D1+,D2+,D3hot+,D3cold-)
 Status: D0 PME-Enable- DSel=0 DScale=0 PME-
 Capabilities: [48] Message Signalled Interrupts: 64bit+ Queue=0/0 Enable+
 Address: 00000000fee0300c  Data: 4152
 Capabilities: [58] Express Endpoint IRQ 0
 Device: Supported: MaxPayload 512 bytes, PhantFunc 0, ExtTag-
 Device: Latency L0s unlimited, L1 unlimited
 Device: AtnBtn- AtnInd- PwrInd-
 Device: Errors: Correctable- Non-Fatal- Fatal- Unsupported-
 Device: RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop+
 Device: MaxPayload 128 bytes, MaxReadReq 512 bytes
 Link: Supported Speed 2.5Gb/s, Width x1, ASPM L0s, Port 0
 Link: Latency L0s unlimited, L1 unlimited
 Link: ASPM Disabled RCB 64 bytes CommClk- ExtSynch-
 Link: Speed 2.5Gb/s, Width x1
 Capabilities: [100] Device Serial Number 00-00-00-00-00-00-00-0

And now to the dump itself (unfortunately, I didn’t grab any MSI):

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff008
>> (40000001, 0000000f, fdaff008)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff034
>> (40000001, 0000000f, fdaff034)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c17000
 << (60000020, 010000ff, 00000000, 00c17000)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c17080
 << (60000020, 010000ff, 00000000, 00c17080)

 << (Write) Type = 0, fmt=3, length=11
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c17100
 << (6000000b, 010000ff, 00000000, 00c17100)

 << (Write) Type = 0, fmt=3, length=4
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c29200
 << (60000004, 010000ff, 00000000, 00c29200)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff008
>> (40000001, 0000000f, fdaff008)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff034
>> (40000001, 0000000f, fdaff034)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c15000
 << (60000020, 010000ff, 00000000, 00c15000)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c15080
 << (60000020, 010000ff, 00000000, 00c15080)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c15100
 << (60000020, 010000ff, 00000000, 00c15100)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c15180
 << (60000020, 010000ff, 00000000, 00c15180)

 << (Write) Type = 0, fmt=3, length=12
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c15200
 << (6000000c, 010000ff, 00000000, 00c15200)

 << (Write) Type = 0, fmt=3, length=4
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c29200
 << (60000004, 010000ff, 00000000, 00c29200)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff008
>> (40000001, 0000000f, fdaff008)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff034
>> (40000001, 0000000f, fdaff034)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

 << (Read Rq) Type = 0, fmt=1, length=128
 <<  Bus ID: 0100, Tag=01
 << Address = 0000000000c1f000
 << (20000080, 010001ff, 00000000, 00c1f000)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=01
>>  Completion low addr=0, byte count=512
>> (4a000010, 00000200, 01000100)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=01
>>  Completion low addr=64, byte count=448
>> (4a000010, 000001c0, 01000140)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=01
>>  Completion low addr=0, byte count=384
>> (4a000010, 00000180, 01000100)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=01
>>  Completion low addr=64, byte count=320
>> (4a000010, 00000140, 01000140)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1b000
 << (60000020, 010000ff, 00000000, 00c1b000)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=01
>>  Completion low addr=0, byte count=256
>> (4a000010, 00000100, 01000100)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=01
>>  Completion low addr=64, byte count=192
>> (4a000010, 000000c0, 01000140)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1b080
 << (60000010, 010000ff, 00000000, 00c1b080)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=01
>>  Completion low addr=0, byte count=128
>> (4a000010, 00000080, 01000100)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=01
>>  Completion low addr=64, byte count=64
>> (4a000010, 00000040, 01000140)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c000
 << (60000020, 010000ff, 00000000, 00c1c000)

 << (Read Rq) Type = 0, fmt=1, length=128
 <<  Bus ID: 0100, Tag=02
 << Address = 0000000000c1f200
 << (20000080, 010002ff, 00000000, 00c1f200)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1f400
 << (60000020, 010000ff, 00000000, 00c1f400)

 << (Write) Type = 0, fmt=3, length=2
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c29200
 << (60000002, 010000ff, 00000000, 00c29200)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c100
 << (60000010, 010000ff, 00000000, 00c1c100)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=02
>>  Completion low addr=0, byte count=512
>> (4a000010, 00000200, 01000200)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=02
>>  Completion low addr=64, byte count=448
>> (4a000010, 000001c0, 01000240)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=02
>>  Completion low addr=0, byte count=384
>> (4a000010, 00000180, 01000200)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c140
 << (60000020, 010000ff, 00000000, 00c1c140)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=02
>>  Completion low addr=64, byte count=320
>> (4a000010, 00000140, 01000240)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=02
>>  Completion low addr=0, byte count=256
>> (4a000010, 00000100, 01000200)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c1c0
 << (60000010, 010000ff, 00000000, 00c1c1c0)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=02
>>  Completion low addr=64, byte count=192
>> (4a000010, 000000c0, 01000240)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=02
>>  Completion low addr=0, byte count=128
>> (4a000010, 00000080, 01000200)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c200
 << (60000020, 010000ff, 00000000, 00c1c200)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=02
>>  Completion low addr=64, byte count=64
>> (4a000010, 00000040, 01000240)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c280
 << (60000010, 010000ff, 00000000, 00c1c280)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c2c0
 << (60000020, 010000ff, 00000000, 00c1c2c0)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff008
>> (40000001, 0000000f, fdaff008)

 << (Write) Type = 0, fmt=3, length=2
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c29200
 << (60000002, 010000ff, 00000000, 00c29200)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff008
>> (40000001, 0000000f, fdaff008)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff034
>> (40000001, 0000000f, fdaff034)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

 << (Read Rq) Type = 0, fmt=1, length=128
 <<  Bus ID: 0100, Tag=03
 << Address = 0000000000c20000
 << (20000080, 010003ff, 00000000, 00c20000)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=03
>>  Completion low addr=0, byte count=512
>> (4a000010, 00000200, 01000300)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=03
>>  Completion low addr=64, byte count=448
>> (4a000010, 000001c0, 01000340)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=03
>>  Completion low addr=0, byte count=384
>> (4a000010, 00000180, 01000300)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c340
 << (60000020, 010000ff, 00000000, 00c1c340)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=03
>>  Completion low addr=64, byte count=320
>> (4a000010, 00000140, 01000340)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=03
>>  Completion low addr=0, byte count=256
>> (4a000010, 00000100, 01000300)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=03
>>  Completion low addr=64, byte count=192
>> (4a000010, 000000c0, 01000340)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c3c0
 << (60000020, 010000ff, 00000000, 00c1c3c0)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=03
>>  Completion low addr=0, byte count=128
>> (4a000010, 00000080, 01000300)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=03
>>  Completion low addr=64, byte count=64
>> (4a000010, 00000040, 01000340)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c440
 << (60000010, 010000ff, 00000000, 00c1c440)

 << (Read Rq) Type = 0, fmt=1, length=128
 <<  Bus ID: 0100, Tag=04
 << Address = 0000000000c20200
 << (20000080, 010004ff, 00000000, 00c20200)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c480
 << (60000020, 010000ff, 00000000, 00c1c480)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c500
 << (60000010, 010000ff, 00000000, 00c1c500)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=04
>>  Completion low addr=0, byte count=512
>> (4a000010, 00000200, 01000400)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=04
>>  Completion low addr=64, byte count=448
>> (4a000010, 000001c0, 01000440)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=04
>>  Completion low addr=0, byte count=384
>> (4a000010, 00000180, 01000400)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c540
 << (60000020, 010000ff, 00000000, 00c1c540)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=04
>>  Completion low addr=64, byte count=320
>> (4a000010, 00000140, 01000440)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=04
>>  Completion low addr=0, byte count=256
>> (4a000010, 00000100, 01000400)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c5c0
 << (60000020, 010000ff, 00000000, 00c1c5c0)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=04
>>  Completion low addr=64, byte count=192
>> (4a000010, 000000c0, 01000440)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=04
>>  Completion low addr=0, byte count=128
>> (4a000010, 00000080, 01000400)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=04
>>  Completion low addr=64, byte count=64
>> (4a000010, 00000040, 01000440)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c640
 << (60000020, 010000ff, 00000000, 00c1c640)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c6c0
 << (60000010, 010000ff, 00000000, 00c1c6c0)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c700
 << (60000010, 010000ff, 00000000, 00c1c700)

 << (Write) Type = 0, fmt=3, length=2
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c29200
 << (60000002, 010000ff, 00000000, 00c29200)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff008
>> (40000001, 0000000f, fdaff008)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff034
>> (40000001, 0000000f, fdaff034)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

 << (Read Rq) Type = 0, fmt=1, length=128
 <<  Bus ID: 0100, Tag=05
 << Address = 0000000000c21000
 << (20000080, 010005ff, 00000000, 00c21000)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=05
>>  Completion low addr=0, byte count=512
>> (4a000010, 00000200, 01000500)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=05
>>  Completion low addr=64, byte count=448
>> (4a000010, 000001c0, 01000540)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=05
>>  Completion low addr=0, byte count=384
>> (4a000010, 00000180, 01000500)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c740
 << (60000020, 010000ff, 00000000, 00c1c740)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=05
>>  Completion low addr=64, byte count=320
>> (4a000010, 00000140, 01000540)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=05
>>  Completion low addr=0, byte count=256
>> (4a000010, 00000100, 01000500)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=05
>>  Completion low addr=64, byte count=192
>> (4a000010, 000000c0, 01000540)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c7c0
 << (60000020, 010000ff, 00000000, 00c1c7c0)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=05
>>  Completion low addr=0, byte count=128
>> (4a000010, 00000080, 01000500)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=05
>>  Completion low addr=64, byte count=64
>> (4a000010, 00000040, 01000540)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c840
 << (60000010, 010000ff, 00000000, 00c1c840)

 << (Read Rq) Type = 0, fmt=1, length=128
 <<  Bus ID: 0100, Tag=06
 << Address = 0000000000c21200
 << (20000080, 010006ff, 00000000, 00c21200)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c880
 << (60000020, 010000ff, 00000000, 00c1c880)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c900
 << (60000010, 010000ff, 00000000, 00c1c900)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=06
>>  Completion low addr=0, byte count=512
>> (4a000010, 00000200, 01000600)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=06
>>  Completion low addr=64, byte count=448
>> (4a000010, 000001c0, 01000640)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=06
>>  Completion low addr=0, byte count=384
>> (4a000010, 00000180, 01000600)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c940
 << (60000020, 010000ff, 00000000, 00c1c940)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=06
>>  Completion low addr=64, byte count=320
>> (4a000010, 00000140, 01000640)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=06
>>  Completion low addr=0, byte count=256
>> (4a000010, 00000100, 01000600)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1c9c0
 << (60000020, 010000ff, 00000000, 00c1c9c0)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=06
>>  Completion low addr=64, byte count=192
>> (4a000010, 000000c0, 01000640)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=06
>>  Completion low addr=0, byte count=128
>> (4a000010, 00000080, 01000600)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=06
>>  Completion low addr=64, byte count=64
>> (4a000010, 00000040, 01000640)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1ca40
 << (60000020, 010000ff, 00000000, 00c1ca40)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1cac0
 << (60000010, 010000ff, 00000000, 00c1cac0)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1cb00
 << (60000010, 010000ff, 00000000, 00c1cb00)

 << (Write) Type = 0, fmt=3, length=2
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c29200
 << (60000002, 010000ff, 00000000, 00c29200)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff008
>> (40000001, 0000000f, fdaff008)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff034
>> (40000001, 0000000f, fdaff034)

>> (Write) Type = 0, fmt=2, length=1
>>  Bus ID: 0000, Tag=00
>> Address = fdaff030
>> (40000001, 0000000f, fdaff030)

 << (Read Rq) Type = 0, fmt=1, length=128
 <<  Bus ID: 0100, Tag=07
 << Address = 0000000000c22000
 << (20000080, 010007ff, 00000000, 00c22000)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=07
>>  Completion low addr=0, byte count=512
>> (4a000010, 00000200, 01000700)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=07
>>  Completion low addr=64, byte count=448
>> (4a000010, 000001c0, 01000740)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=07
>>  Completion low addr=0, byte count=384
>> (4a000010, 00000180, 01000700)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=07
>>  Completion low addr=64, byte count=320
>> (4a000010, 00000140, 01000740)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1cb40
 << (60000020, 010000ff, 00000000, 00c1cb40)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=07
>>  Completion low addr=0, byte count=256
>> (4a000010, 00000100, 01000700)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=07
>>  Completion low addr=64, byte count=192
>> (4a000010, 000000c0, 01000740)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1cbc0
 << (60000010, 010000ff, 00000000, 00c1cbc0)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=07
>>  Completion low addr=0, byte count=128
>> (4a000010, 00000080, 01000700)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=07
>>  Completion low addr=64, byte count=64
>> (4a000010, 00000040, 01000740)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1cc00
 << (60000020, 010000ff, 00000000, 00c1cc00)

 << (Read Rq) Type = 0, fmt=1, length=128
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c22200
 << (20000080, 010000ff, 00000000, 00c22200)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c22400
 << (60000020, 010000ff, 00000000, 00c22400)

 << (Write) Type = 0, fmt=3, length=16
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c1cd00
 << (60000010, 010000ff, 00000000, 00c1cd00)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=00
>>  Completion low addr=0, byte count=512
>> (4a000010, 00000200, 01000000)

>> (Completion) Type = 10, fmt=2, length=16
>>  Bus ID: 0000, Tag=00
>>  Completion low addr=64, byte count=448
>> (4a000010, 000001c0, 01000040)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13000
 << (60000020, 010000ff, 00000000, 00c13000)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13080
 << (60000020, 010000ff, 00000000, 00c13080)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13100
 << (60000020, 010000ff, 00000000, 00c13100)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13180
 << (60000020, 010000ff, 00000000, 00c13180)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13200
 << (60000020, 010000ff, 00000000, 00c13200)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13280
 << (60000020, 010000ff, 00000000, 00c13280)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13300
 << (60000020, 010000ff, 00000000, 00c13300)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13380
 << (60000020, 010000ff, 00000000, 00c13380)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13400
 << (60000020, 010000ff, 00000000, 00c13400)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13480
 << (60000020, 010000ff, 00000000, 00c13480)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13500
 << (60000020, 010000ff, 00000000, 00c13500)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13580
 << (60000020, 010000ff, 00000000, 00c13580)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13600
 << (60000020, 010000ff, 00000000, 00c13600)

 << (Write) Type = 0, fmt=3, length=32
 <<  Bus ID: 0100, Tag=00
 << Address = 0000000000c13680
 << (60000020, 010000ff, 00000000, 00c13680)

(and this is where the sniffer's memory got full)

Linux character driver: What if flush() data has nowhere to go?

I know that most character drivers don’t implement the flush() method, and the more I deal with it, the more I understand why. But unfortunately, in certain modes of operation flushing is necessary, so I implemented it.

One of the problems with flush() is that it’s called when the file is closed automatically as the process exits. If the device can’t take the remaining data, flushing is stuck, and the process remains in the process table in interruptible sleep mode (which is how I chose to wait in the driver). But in reality, attempting to kill the process results in no response whatsoever, and there’s another interesting thing about this process: Its /proc/fd is empty! So it’s a kind-of zombie, only it isn’t marked as such. But in essence it’s a process waiting for someone to take some data from it, so it can rest in peace.

The only way out is a timeout. The waiting should be something like this:

if (wait_event_interruptible_timeout(dev->wait,
                                    (!dev->rd_full),
                                     HZ) == 0) { /* 1 second timeout */
 printk(KERN_WARNING "mydriver: Timed out while flushing. Output data was lost.\n");
 mutex_unlock(&dev->wr_mutex);
 return -ETIMEDOUT;
}

(Relevant Linux kernel: vanilla 2.6.37)

Getting CTRL, shift and num lock back again

This really is a note to future self. All of the sudden, terminal windows on my Fedora 12 ceased to respect num lock, shift and CTRL modifiers, and I somehow figured out that it may have something to do with the fact that I was having a Vmplayer machine running.

It’s noted a lot elsewhere, but I’ll write it down for myself here: To get things back to normal, just type

$ setxkbmap

at shell prompt, and all is fine again. This issue is too rare to waste the time to go to the bottom with.

Fedora Linux: Getting an Ebay-style USB fax/modem to receive a fax

So I bought a cheapo USB modem/fax on Ebay. I have to admit, that I didn’t really expect it to work with my Fedora 12 Linux machine, but it was actually detected as ACM modem, and /dev/ttyACM0 appeared. lsusb -v reveals it’s identified as ID 0572:1329 Conexant Systems (Rockwell), Inc.

Note to self: This is the chosen fax/modem, attached to the computer. As a matter of fact, I have two of these, since I tried to buy another type, but ended up with the same thing exactly.

The modem sends faxes properly and receives them properly when Bezeq dials me to deliver the fax. The command used below is OK with the cellular fax. Just change “filenameprefix” with whatever prefix is desired, and it works slowly but OK.

This tech note shows the fax session sequence, for information.

After symlinking /dev/modem to /dev/ttyACM0, I managed to get “fax send” to work properly. “fax receive” was a different story.

The logs revealed that the problematic part was

efax: 31:04 received 10 bytes: ff c8 c1 00 62 0f 01 00 ef 1c
efax: 31:04 received DCS - session format
efax: 31:04 session 196lpi  9600bps 8.5"/215mm 11"/A4 1D    -     -  0ms
efax: 31:04 command  "+FTS=1"
efax: 31:04 waiting 3.0 s
efax: 31:04 .253 [<CR><LF>OK<CR><LF>]
efax: 31:04 response "OK"
efax: 31:04 command  "+FRM=96"
efax: 31:04 waiting 6.0 s
efax: 31:10 Error: timed out after command:  +FRM=96
efax: 31:10 command  "+FTH=3"
efax: 31:10 waiting 3.1

Which is contrary to my previous thought that a lot of “received UNKNOWN” messages was the problem. Even if these messages have something to do with the real problem, they were still there when I got the fax to work OK.

These commands are well-documented in this document, where I found out that the command stands for receiving data in 9600 bps with no specification of training length. What happened was that something got messed up in the negotiation, leaving the phone line dry, and a timeout soon to come.

The immediate solution was to call efax directly with the -c flag set to reduce the maximal bps rate to 4800. This is painfully slow, but faxes came in OK this way:

/usr/bin/efax -r filenameprefix -c 1,1,0,2,0,0,0,0 -v ewin -v =chewmainrxtf -d/dev/modem -iZ 'i&FE0&D2S7=120' '-i&C0' -iM1L0 -l "+0 000" -kZ

This -c flag is a list of capability flags, as specified in the “man efax” manpage. The second digit, “1″, stands for maximum 4800 bps.

The weird thing is the following part in the (failed) log:

efax: 30:52 using CX93001-EIS_V0.2002-V92 in class 1
efax: 30:52 command  "+FRM=?"
efax: 30:52 waiting 5.0 s
efax: 30:52 .437 [<CR><LF>3,24,48,72,73,74,96,97,98,121,122,145,146<CR><LF>]
efax: 30:52 .437 [<CR><LF>OK<CR><LF>]
efax: 30:52 response "OK"

What happens here is that the computer asks the modem for its allowed speeds, and it explicitly says it can take FRM=96 (among others). Annoying.

Anyhow, I think I’ll settle for 4800 bps for the few times I’ll ever need to receive a fax in the future. Solving this simply isn’t worth the effort.

Bonus: send command

For an extreme case with a horrible line (remote responded with EOP to an EOP from my fax, instead of an MCF, which means page OK), I opted for a 4800 bps transmission:

# /usr/bin/efax -v ewin -v chewmainrxtf -d/dev/modem -c 1,1,0,2,0,0,0,0 -x /var/lock/LCK..modem -iZ '-i&FE0&D2S7=120' '-i&C0' -iM1L0 -l '+0 000 000 0000' -kZ -t T077777777 fax-to-send.001

Replace the argument of -T with the number to dial, and the last argument with the file to send.

The header of the fax went out with a UNIX timestamp, since I didn’t state one in the command. But who cares.

PCIe read completion reordering and how it reduces bandwidth efficiency

While the PCI Express standard is impressive in that it actually makes sense (well, most of the time) there is a pretty annoying thing about read requests reordering.

By the way, I talk about TLP packet formation in general in another post.

In section 2.4.1 of the PCIe spec 1.1, it says that read requests may be reordered as they travel across the switching network, and same goes for read completions associated with different read requests. The read-related packets, which must arrive in the same order they were sent, are read completions associated with the same read request, or as the spec puts it: “… must return in address order”.

This would be a good time to mention, that a read request may be larger than the maximal payload size, so obviously the completer must have a means of splitting the completion into several TLPs, which must be sent in rising address order. And if we’re at it, there’s a boundary restriction on how to cut the data in pieces, namely that the cuts are on boundaries of RCB, where RCB can either be 64 bytes or 128 bytes (if you’re not a Root Complex you may cut on 128-byte boundaries only, and if you are a Root Complex, you choose 64 or 128, and configure the endpoints telling then what you chose).

And there’s a restriction on the maximal read request size, but that’s a different story.

So far the specification makes sense: Read completions will be split into several TLPs pretty often, and they have to arrive to the requester in linear address order, so these packets must not be reordered.

But what if the endpoint needs to collect a chunk of data which is larger than the maximal read request size (typically 512 bytes)? It will have to issue several read requests for that. But read requests and completions from different read requests may be reordered.

So if we want to assure that the data arrives in linear order (which is necessary when the data goes into a FIFO-like data sink) each read request can be transmitted only when the last completion TLP from the previous request arrives. Otherwise, a completion TLP from the following request may arrive before that last packet. Hence there’s a time gap of non-utilized bandwidth.

In general there is no problem having several outstanding read requests. So had read requests and read completions been strictly ordered, it would be possible to send the following read request more or less immediately after the first one, and completions would arrive continuously.

Another issue, which is less likely to bother anyone, is that if some software makes assumptions on the order at which data in some buffer is updated, this can cause rare bugs. For example, if the read completions update some dual port RAM, and there’s software reading from this buffer, it may deduce from the update of some high-addressed memory cell that the entire buffer is updated.

And a final word: Since PCIe infrastructure is pretty plain when this post is written, I will be surprised if anyone manages to catch any packet reordering taking place for real. But exactly as write reordering is commonplace in modern CPUs to increase performance, it’s only a matter of time before PCIe switching networks do the same.

Update: I got an email from someone informing me that he spotted reordering taking place on some Intel desktop chipsets. So this isn’t just theory, after all.

Questions & Comments

Since the comment section of similar posts tends to turn  into a Q & A session, I’ve taken that to a separate place. So if you’d like to discuss something with me, please  post questions and comments here instead. No registration is required. The comment section below is closed.

PCI express maximal payload size: Finding it and its impact on bandwidth

Finding the maximal payload manually

The truth is, there is no need to do this manually. lspci does the work for us. But looking into the configuration table once and for all helps demystifying the issue. So here we go.

According to the PCIe spec (section 7.8), the max_payload_size the card can take is give in the PCIe Device Capabilities Register (Offset 0x04 in the PCI Express Capability structure), bits 2-0. Basically, take that three-bit field as a number, add 7 to it, and you have the log-2 of the number of bytes allowed.

Let me write this in C for clarity:

max_payload_size_capable = 1 << ( (DevCapReg & 0x07) + 7); // In bytes

The actual value used is set by host in the Device Control Register (Offset Ox08 in the PCI Express Capability structure). It’s the same drill, but with bits 7-5 instead. So in C it would be

max_payload_size_in_effect = 1 << ( ( (DevCtrlReg >> 5) & 0x07) + 7); // In bytes

OK, so how can we find these registers? How do we find the structure? Let’s start with dumping the hexadecimal representation of the 256-byte configuration space. Using lspci -xxx on a Linux machine we will get the dump for all devices, but we’ll look at one specific:

# lspci -xxx
(...)

01:00.0 Class ff00: Xilinx Corporation Generic FPGA core
00: ee 10 34 12 07 04 10 00 00 00 00 ff 01 00 00 00
10: 04 f0 af fd 00 00 00 00 00 00 00 00 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 ee 10 34 12
30: 00 00 00 00 40 00 00 00 00 00 00 00 ff 00 00 00
40: 01 48 03 70 08 00 00 00 05 58 81 00 0c 30 e0 fe
50: 00 00 00 00 71 41 00 00 10 00 01 00 c2 8f 28 00
60: 10 28 00 00 11 f4 03 00 00 00 11 00 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

The first important thing to know about lspci -xxx on a little-endian machine (x86 processors included) is that PCI and PCIe work in big endian. And that the data  is shown as little-endian DWs (or 32-bit unsigned ints). So the way to look at the output is in groups of four bytes each, and take them for a little-endian unsigned int, whose bit map matches the spec.

For example, according to the spec, bits 15-0 of the word mapped at 00h is the Vendor ID, and bits 31-16 is the Device ID. So we take the first four bytes for a little-endian 32-bit integer, and get Ox123410ee. Bits 15-0 are indeed Ox10ee, the vendor ID Xilinx, and bits 31-16 are Ox1234 which is the Device ID I made up for a custom device. So far so good.

Now we need to find the PCI Express Capability structure. It’s one of the structures in a linked list (would you believe that?), and it’s identified by a Cap ID of Ox10.

The pointer to the list is at bits 7-0 of the configuration word at Ox34. In our little-endian representation above, it’s simply the byte at Ox34, which says Ox40. The capabilities hence start at Ox40.

From here on, we can travel along the list of capability structures. Each starts 32-bit aligned, with the header always having the Capability ID on bits 7-0 (appears as the first byte above), and a pointer to the next structure in bits 15-8 (the second byte).

So we start at offset Ox40, finding it’s of Cap ID Ox01, and that the byte at offset Ox41 tells us that the next entry is at offset Ox48. Moving on to offset Ox48 we find Cap ID Ox05 and the next entry at Ox58. The entry at Ox58 is with Cap ID Ox10 (!!!), and it’s the last one (pointer to next is zero).

So we found our structure at Ox58. The Device Capabilities Register is hence at Ox5c (offset Ox04) and reads Ox00288fc2. The Device Control Register is at Ox60 (offset Ox08), and reads Ox00002810.

So we learn from bits 2-0 of the Device Capabilities Register (having value 2) that the device supports a max_payload_size of 512. But bits 7-5 (having value 0) of the Device Control Register tell us that the effective maximal payload is only 128 bytes.

Getting the info with lspci

As I mentioned above, we didn’t really need to find the addresses by hand. lspci -v gives us, for the specific device:

# lspci -v
(...)
01:00.0 Class ff00: Xilinx Corporation Generic FPGA core
 Subsystem: Xilinx Corporation Generic FPGA core
 Flags: bus master, fast devsel, latency 0, IRQ 42
 Memory at fdaff000 (64-bit, non-prefetchable) [size=128]
 Capabilities: [40] Power Management version 3
 Capabilities: [48] Message Signalled Interrupts: 64bit+ Queue=0/0 Enable+
 Capabilities: [58] Express Endpoint IRQ 0
 Capabilities: [100] Device Serial Number 00-00-00-00-00-00-00-00

So the address to the PCI Express capabilities structure is given to us, but not the internal details (maybe some newer version of lspci does). And by the way, the size=128 above  has nothing to do with maximal payload: It’s the size of the memory space allocated to the device by BIOS (BAR address space, if we’re into it).

For the details, including the maximal payload, we use the lspci -vv option.

# lspci -vv
(...)
01:00.0 Class ff00: Xilinx Corporation Generic FPGA core
 Subsystem: Xilinx Corporation Generic FPGA core
 Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B-
 Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR-
 Latency: 0, Cache Line Size: 4 bytes
 Interrupt: pin ? routed to IRQ 42
 Region 0: Memory at fdaff000 (64-bit, non-prefetchable) [size=128]
 Capabilities: [40] Power Management version 3
 Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0-,D1+,D2+,D3hot+,D3cold-)
 Status: D0 PME-Enable- DSel=0 DScale=0 PME-
 Capabilities: [48] Message Signalled Interrupts: 64bit+ Queue=0/0 Enable+
 Address: 00000000fee0300c  Data: 4171
 Capabilities: [58] Express Endpoint IRQ 0
 Device: Supported: MaxPayload 512 bytes, PhantFunc 0, ExtTag-
 Device: Latency L0s unlimited, L1 unlimited
 Device: AtnBtn- AtnInd- PwrInd-
 Device: Errors: Correctable- Non-Fatal- Fatal- Unsupported-
 Device: RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop+
 Device: MaxPayload 128 bytes, MaxReadReq 512 bytes
 Link: Supported Speed 2.5Gb/s, Width x1, ASPM L0s, Port 0
 Link: Latency L0s unlimited, L1 unlimited
 Link: ASPM Disabled RCB 64 bytes CommClk- ExtSynch-
 Link: Speed 2.5Gb/s, Width x1
 Capabilities: [100] Device Serial Number 00-00-00-00-00-00-00-0

So there we have it, black on white: The device supports 512 bytes MaxPayload, but below we have MayPayload given as 128 bytes.

Impact on performance

A 128-byte maximal payload is not good news if one wants to get the most out of the bandwidth. By the way, switches are not permitted to split packets (but the Root Complex is allowed) so this number actually tells us how much overhead each TLP (Transaction Layer Packet) carries. I talk about the TLP structure in another post.

Let’s make a quick calculation: Each packet comes with a header of 3 DWs (a DW is a 32-bit word, right?) when using 32 bit addressing, and a header of 4 DWs for 64-bit addressing. Let’s be nice and assume 32-bit addressing, so the header is 3 DWs.

TLPs may optionally carry a one-DW TLP digest (ECRC), which is generally a stupid idea if you trust the switching chipsets not to mess up your data. Otherwise, the Data Link layer’s CRC should be enough. So we’ll assume no TLP digest.

The Data Link layer overhead is a bit more difficult to estimate, because it has its own housekeeping packets. But since most acknowledge and flow control packets go in the opposite direction and hence don’t interfere with a unidirectional bulk data transmission, we’ll focus on the actual data added to each TLP: It consists of a 2-byte header (partially filled with a TLP sequence number) and a 4-byte LCRC.

So all in all, the overhead, assuming a 3-DW header, is 12 bytes for the TLP header and another 6 bytes by the Data Link. All in all, we have 18 bytes, which takes up ~12% if transmitted along a 128-byte TLP, but only ~3.4% for a 512-byte TLP.

For a 1x configuration, which has 2.5 Gbps on the wires, and effective 2.0 Gbps (10/8 bit coding), we could dream about 250 MBytes/sec. But when the TLPs are 128 bytes long each, our upper limit goes down to some ~219 Mbytes/sec. With 512-bytes TLPs it’s ~241 Mbytes/sec. Does it matter at all? I suppose it depends. In benchmark testing, it’s important to know these limits, or you start thinking something is wrong, when it’s actually the packet network limiting the speed.

Compiling a kernel module after “make clean” on the sources.

The textbook says, that if one wants to compile a module against a kernel, the headers must be there. Those who run distribution kernels are urged to apt-get or yum-install something, and their trouble is over. People like me, who cook their own food and download vanilla kernels, need to handle this themselves.

In the old times, I used to have the kernel compiled on the disk, but nowadays the kernel subdirectory takes a few Gigabytes after compilation, so one has to do a “make clean” sooner or later. Which should be OK, since the following comment can be found in the kernel source’s Makefile, in its very root directory:

# make clean     Delete most generated files
#                Leave enough to build external modules

But unfortunately, it’s not possible to compile any module after “make clean”. It blows with a nasty error message. (Ehm, see update at the bottom)

As it turns out, “make clean” removes two header files, whose absence kills the possibility to compile a module:  include/generated/asm-offsets.h and include/generated/bounds.h. As a matter of fact, the removal of these two files is the only change in the “include” subdirectory.

So a quick workaround is to make a copy of the “include” subdirectory, run “make clean” and then restore “include” to its pre-make-clean state.

Which make you wonder why those files are removed in the first place. Someone overlooked this issue? No, no and no. Is there any real reason to remove these files? I don’t know. Has this issue been fixed since 2.6.35? I’ll check it sometime.

If you know something I don’t, please comment below.

Update (Oct 1st, 2015):

$ make prepare scripts

on the machine that the kernel runs on solves this on v3.16.

Update (May 4th, 2016): Maybe this?

$ make modules_prepare

Will try next time. See Documentation/kbuild/modules.txt on your favorite kernel tree.

Perl-only CRC32 function (without C code)

It may look like a stupid idea, since the CRC32 has been implemented in some Perl modules which can be downloaded from CPAN. But all functions I found involve an XS part, which essentially means that a compilation of C code has to take place during the installation.

In other words, these modules can’t be just attached to a bundle of Perl code, but they have to be installed on a machine where it’s permitted. Or at least, compilation capabilities are necessary. Which can turn into a mess if the target is a Windows-running computer barely having Perl installed.

So I adapted one of the implementations of the mostly used CRC32 calculation, and wrote it in pure Perl. It’s really not the efficient way to obtain a CRC, and I wouldn’t try it on long sequences. Its advantage is also its disadvantage: It’s all in Perl.

Before giving the function away, I’d just point out that if one tries the following snippet

#!/usr/bin/perl

use warnings;
use strict;
require String::CRC32;
require Digest::CRC;

my $str = "This is just any string.";

my $refcrc = String::CRC32::crc32($str);
my $refcrc2 = Digest::CRC::crc32($str);
my $mycrc = mycrc32($str);

then $refcrc, $refcrc2 and $mycrc will have the same value (the last of which is calculated by the function at the end of this post).

And if we’re at it, I’d also point out that for any string $str, the following code

my $append = mycrc32($str) ^ 0xffffffff;
my $res = mycrc32($str.pack("V", $append));

yields a CRC in $res which equals Oxffffffff. This is a well-known trick with CRCs: Append the CRC to the string for which it was calculated, and get a fixed value. And by they way, the CRC is done in Little Endian setting, so the parallel Linux kernel operation would be crc32_le(~0, string, len), only that crc32_le returns the value XORed by Oxffffffff (or is it the Perl version being upside down? I don’t know). Also note that the initial value of the CRC is set to ~0, which is effectively Oxffffffff again.

OK, time to show the function. It’s released to the public domain (Creative Commons’ CC0, if you like), so feel free to make any use of it.

sub mycrc32 {
 my ($input, $init_value, $polynomial) = @_;

 $init_value = 0 unless (defined $init_value);
 $polynomial = 0xedb88320 unless (defined $polynomial);

 my @lookup_table;

 for (my $i=0; $i<256; $i++) {
   my $x = $i;
   for (my $j=0; $j<8; $j++) {
     if ($x & 1) {
       $x = ($x >> 1) ^ $polynomial;
     } else {
       $x = $x >> 1;
     }
   }
   push @lookup_table, $x;
 }

 my $crc = $init_value ^ 0xffffffff;

 foreach my $x (unpack ('C*', $input)) {
   $crc = (($crc >> 8) & 0xffffff) ^ $lookup_table[ ($crc ^ $x) & 0xff ];
 }

 $crc = $crc ^ 0xffffffff;

 return $crc;
}

Workaround: Pending signal making wait_event_interruptible() return prematurely

It all starts with this: I’m not ready to return from my character device’s release() method before I know that the underlying hardware has acknowledged the shutdown. It is actually expected to do so quickly, so I relied on a wait_event_interruptible() call within the release method to do the short wait for the acknowledge.

And it actually worked well, until specific cases where I hit CTRL-C while a read() was blocking. I’m not exactly sure of why, but if the signal arrived while a blocking on wait_event_interruptible() within read(), the signal wouldn’t be cleared, so release() was called with the signal pending. As was quite evident with this little snippet in the release() code.

if (signal_pending(current))
  printk(KERN_WARNING "Signal is pending on release()...\n");

… which ended up with the wait_event_interruptible() in the release() method returning immediately, yelling that the hardware didn’t respond.

Blocking indefinitely is out of the question, so the simple workaround is to sleep another 100ms if wait_event_interruptible() returns prematurely, and then check if the hardware is done. That should be far more than needed for the hardware, and a fairly small time penalty for the user.

So the waiting part in release() now goes:

if (wait_event_interruptible(fstr->wait, (!fstr->flag)))
  msleep(100);

The cute trick here is that the sleep takes place only in the event of an interrupt, so in a normal release() call we quit much faster.