The disk was fine, the page was not: a two minute smartctl and a GUI that gave up

· proxmox, linux, debugging, storage

I plugged a 2.5 inch SSD into a Proxmox box through a USB-to-SATA adapter, went to Node → Disks in the web UI, and got a spinner followed by Communication Failure.

The disk itself was completely fine. lsblk listed it, fdisk read it, I mounted it and copied files to it. Every tool at the command line agreed the drive was healthy and present. Only the GUI disagreed, and it disagreed by hanging rather than by saying anything useful. journalctl, syslog and the pvedaemon logs had nothing.

That gap, everything works except the one thing that is supposed to show you that everything works, is what made it worth chasing.

Reading someone else’s Perl

Proxmox’s API is Perl, which is convenient here because it means the thing that hung is sitting on disk in readable form. Following the call path:

  • PVE/API2/Disks.pm handles the disk listing endpoint
  • which calls into PVE/Diskmanage.pm
  • where get_smart_data() shells out to smartctl

And the call site looked like this:

if (!$nosmart) {
    eval {
        my $smartdata = get_smart_data($devpath, !is_ssdlike($type));
        $health = $smartdata->{health} if $smartdata->{health};

        if (is_ssdlike($type)) { # if we have an SSD, try to get the wearout indicator
            my $wear_level = get_wear_leveling_info($smartdata);
            $wearout = $wear_level if defined($wear_level);
        }
    };
}

The eval catches errors. It does not catch slowness. And get_smart_data() invoked smartctl through run_command with no timeout at all, so if that command decided to take its time, the API request behind it simply waited.

The cheapest possible confirmation was to delete the problem:

if (!$nosmart) {
}

Then systemctl restart pvedaemon, reload the page, and the Disks view came up instantly. Not a fix, obviously, but it turned a theory into a fact in about thirty seconds.

The question that reframed it

I filed bug #6224 with that analysis, and the reply from Fabian Grünbichler was two short questions asked one after the other.

First: if you run the smartctl command manually, does it ever return?

It does:

# smartctl -a /dev/sdb
smartctl 7.3 2022-02-28 r5338 [x86_64-linux-6.8.12-6-pve] (local build)

Read NVMe Identify Controller failed: scsi error unsupported field in scsi command

Then: how long does that take? Prefix it with time.

real    2m0.758s
user    0m0.013s
sys     0m0.000s

Two minutes. Not a hang. A return.

I had been describing this as something hanging indefinitely, and the whole time it was finishing, just far too late for anything to care. That difference matters enormously for the fix. A genuine deadlock needs to be found and broken. A slow return needs a deadline. They are not the same bug and they do not have the same remedy, and I would have gone on describing it wrongly if I had not been asked to put a number on it.

Two questions, no speculation, both answerable in a terminal. It is a good model for triage.

The root cause is a reasonable default meeting an unreasonable device

Daniel Kral found the rest of it, and it is more interesting than a plain bug.

smartmontools uses a 60 second default timeout for SCSI commands. That is not carelessness: it is sized so that a disk in a large JBOD has time to spin up before the command gives up. On the hardware that default was written for, it is the right number.

Devices behind the USB Attached SCSI driver are the ones most likely to trip it, because a USB-to-SATA bridge translating SCSI commands can fail in ways that consume the full timeout instead of erroring promptly. My 2m0.758s is that 60 second budget being spent twice, plus change.

So nothing here is broken in isolation. smartmontools waits as long as its slowest supported hardware needs. The adapter fails slowly rather than quickly. Proxmox calls the command without a deadline because it has no reason to expect one is needed. Put all three together and a web page stops loading.

The fix

A three-patch series. The one that matters is a single word:

 my $returncode = eval {
-	run_command($cmd, noerr => 1, outfunc => sub {
+	run_command($cmd, noerr => 1, timeout => 10, outfunc => sub {

Ten seconds instead of sixty, on the reasoning that a healthy drive answers almost immediately and anything slower is not worth blocking a UI over. The other two patches make the failure land properly once it can happen: one separates the error path so get_smart_data() dies with the real message, and one masks that error into an unknown health value, because the web UI expects a health field and was being handed an error string instead.

That last one is the tell that a timeout was never expected here. The moment the call could fail, the error handling around it turned out to be wrong too.

The patch is in pve-storage today. Amusingly, the bug is still marked PATCH AVAILABLE rather than resolved, so the tracker is more pessimistic than the source tree.

What I took from it

The debugging lesson is the timing question. “It hangs” is a description of your patience, not of the program. time turns it into a measurement, and the measurement pointed straight at a 60 second constant that a human had chosen deliberately for a reason that was sound.

The engineering lesson is that any call into an external command is a call into someone else’s timeout policy, whether or not you have thought about it. Proxmox did not choose 60 seconds. It inherited it from smartmontools, which inherited its requirements from JBOD spin-up times, and the UI inherited the consequences from both.

I also did not write the fix, and that is fine. Filing something with the call path traced, the offending call identified, a workaround that isolates it, and then answering the maintainer’s questions with numbers, is a complete contribution. The people who own the code are much better placed to decide whether the right answer is ten seconds or thirty.

Back to writing