Okay, thank you all for coming. The next talk is "Universal Serial Bug - a tale of spontaneous
modem resets" from Sebastian. Give a big round of applause please.
- So hi, I'm Sebastian Krzyszkowiak, I'm also known as dos, and I have many hobbies. I make
games for example, maybe you have played Animatch. But there are other hobbies, there is also mobile
GNU/Linux, which started many years ago when I got an Openmoko Neo Freerunner, and eventually I had been
contracted by Purism to work on the Librem 5 phone, which is this chonky boy here, and within this
device there is a USB connected cellular modem on an M.2 card, Broadmobi BM818, and this is the
main character of our talk today, because we had a problem with it, and the problem manifested itself
in this way that sometimes, occasionally, seemingly at random, the modem would just disappear from
the bus. It would be just as if it was unplugged from the socket, and it would come back right away,
even though it did come back, it was still pretty disruptive, because the network interface would
go down, the audio routing would be torn down if you were during the call, so this wasn't really
great. The modem wasn't crashing, it wasn't rebooting, because it maintained its state, at least some of
its state, but it was just as if you would pull the plug and plug it back in very quickly,
with some external power connected to the modem, and there were also other instances where the modem
wouldn't come back, or when the whole USB bus would actually die together with it, however we
won't be talking about those - those turned out, even though they were worse, they turned out to be
connected, but separate issues that weren't as technically interesting as those resets turned out to be.
So this talk will be some kind of debugging case study, and I would just like to talk about how we
identified the issue, how we debugged it, and worked around in the end, and at the start I would like
to note that this is not some groundbreaking research, this is not a new discovery, because
it turns out that this was known for ages already, but I think it's not a common knowledge still,
and it turns out that it can still bite, so I thought that this would be an interesting thing to
talk about and to share. So in order to understand what's going on, I'll quickly go through the
topology of the devices on the Librem 5 - so we have two M.2 slots inside, one of them is the cellular
modem, and the second one is the Wi-Fi and Bluetooth card, and there are two USB controllers, one of
them goes to the USB-C port, and it role-swaps, and the other one is connected to the internal USB
hub, and therefore it works as host only. The internal hub is USB2642, which has three
downstream ports, one of them is internal, as this hub has a microSD reader built-in,
and the other one, the one that we will be interested in today, is the modem's port that goes to its
M.2 slot, and there's also the third port that goes to the Wi-Fi M.2 slot, however none of the cards
that we use on this phone actually use USB, they use different interfaces, so this third
port effectively remains unused. So Universal Serial Bus. I'm just going to assume that
everyone here knows what USB is, we all used it, so I won't read Wikipedia definitions, I will however
go through some of the properties of USB, either to remind you or to make you aware of how this
works on the wire. So the first thing is that the devices can be suspended, this is a power
management thing, you can put a USB device to sleep. Theoretically all of them can be put to sleep,
not all of them react well to that, the specification says that they should, but
yeah, reality is different. There are two ways in which you can suspend a device, you can either
selectively suspend a single port or put the whole bus into so-called global suspend.
Another thing is that no device on the bus speaks unsolicited, every communication is actually
handled by the host, it's the host that keeps polling each of the devices for whether it has
something to say or not, and then the device only responds to what the host is asking it for.
There is one exception, when a device is suspended, it can actually signal that it wants to be
woken up, but that's the only thing that it can signal on its own. One interesting thing is that,
I think not everyone is aware of that, that all USB hubs are technically "smart", they are on their
own a proper USB device that you can talk to, that you can send commands to and that can respond and
send some status. The features that you can control this way vary, so not every hub will, for instance,
provide power switching control, however, this is exactly how suspend is implemented - you send a
message to the hub and the hub interprets it and does it. Internally, on the wire,
USB works with two wires that form a differential pair, and on two wires you can have
four states, however, one of them is illegal in the specification, USB doesn't use it, so we are
down to three states, they are called J, K, those two are when one of the wires is high and the other
is low, and there is SE0, which is when both of the wires are low. There are some differences between
various speed modes between USB 1 and USB 2, we won't be going into newer versions as they are
different, and the modem here uses USB 2. However, the differences between USB 1 and 2 are
small, their all states are similar, they use different voltages, but logically it's basically the same thing.
So, let's go back to the bug.
At some point we have noticed that those modem resets are somewhat dependent on movement or
signal strength. The easy way to trigger them was, for instance, to ride a train, you could
often see the cellular connection icon just disappearing for a moment, or when you downloaded
some file, it maybe could drop out, and that was pretty annoying.
And also, sometimes in some places it basically never happened, like at my desk when I worked on it,
and it quite often happened in my bedroom, for example, where I would wake up to
a bunch of resets happening overnight. So, in order to look at those issues, we have to check some
logs, I have showed the dmesg earlier, but that's not enough, and Linux has this pretty useful feature
called dynamic debug, and pretty much all the kernel's code, drivers are sprinkled with
debug print messages, however, they are by default compiled out for performance reasons,
however, you don't need to recompile the kernel to put them back in. They can be dynamically
patched in, and this is how you can do it. Using this interface, this invocation tells the kernel
to re-enable all the print statements from .c files from drivers/usb/core directory in the
kernel source tree. So, we did that, and this told us a bit more. It turns out that this is an example
of such a reset happening, and it turns out it happens when the device wants to wake itself up
from USB suspend, and here we can see the status given by the hub to its ports. The port one is
the microSD reader, and we can see that there is 0507, which means that five that is connected and
enumerated properly, seven is that it's suspended, and change zero means that nothing changes,
and port two is the modem, and here we can see that it's different. 01 means that it is
connected, however, it didn't actually went through the whole process of connecting, so something
happened there. 01 means that it's not suspended, and change five tells us that it both
changed its suspend status and connection status, so it's just like it would be pulled
from the plug, and put quickly back in at this point. To compare it, this is an example of
when things go right. After the port has been resumed, we can see that status is 0503,
which is different from the port one, because port one is still suspended, and port two is already
woken up, so there's three at the end, and change four tells us that only the suspend status has
changed, so this is how it looks when it works fine. That told us something but not much. There is
another feature called usbmon, which can be used to sniff on the traffic on the USB bus,
and can be used with such common tools like Wireshark, however, it still didn't tell us anything new,
and it's just like if the device was disconnected and plugged back in, so not very useful at this
level. We have to take a few steps back, and the first Librem 5 phones shipped to the first customers
in December 2019, and the issue about those resets was filled, actually by myself, in August 2020, so
there was plenty of time to notice this issue, and it hasn't been noticed earlier, so
it's safe to assume that it wasn't there initially, and just came up later.
So looking at what was the state that those first phones have shipped in, the USB power management
was already enabled with the software that was running on them, however, it turned out that the
SD card reader, the driver for it, kept the USB hub active all the time. It was basically polling it
for media change status, and that's why it never suspended, so the whole USB hub was kept active,
and it was fixed in August 2020, and there is a somewhat lengthy
thread on the Linux Kernel Mailing List that you can follow if you're interested in that,
and there was also another thing, at some point I have noticed that ModemManager polls the modem
for signal strength every 30 seconds, and I wanted to change that because that's not very nice on the
battery, and to make it start listening to the messages coming from the modem whenever
signal strength changes instead, and I got it working the first time in the context of Librem 5
in August 2020, and later I noticed that with this change the resets popped up more often,
without this change they were still there once the hub started suspending, but not as often as with
this patch. So now we know that this is related to power management, and it turns out that disabling
suspend may be the issue go away, so yay! However, doing so eats almost half a watt, so not
so yay. Basically this was the main reason behind a poor reputation of battery life on those
devices when they first shipped, so power management is essential and it must be kept on,
we just have to find a way to solve it without disabling suspend. There was one vital observation,
I think Elias Rudberg observed it first that the issue only ever happens if the hub has just
been suspended, never if the hub sleeps for some time already, and then the modem wants to wake up,
it's always: the hub goes into suspend and right away the modem wants to wake itself up,
and things go wrong. So this starts to smell like some kind of race condition.
So what we do with race conditions, we start playing with some timeouts, if not in hopes to
fix it then maybe to make it happen all the time, just to learn something about what's going on.
Martin Keplinger was earlier working on that other issue that made the modem not come back,
he had some progress on that, however he didn't really make progress on this one,
when I took it over I started, I based on his work and to figure out what's going on with the
kernel code in USB and started changing some timeouts, eventually I figured out that this
isn't going to help because at this point when was the earliest possible point where we could
query the hub for its status, it was already telling us that something wrong happened, so
this didn't really help. Vital thing what really helped was finding out that you could
reproduce it by pinging the phone. If you pinged it over the network interface, cellular network
interface and set the packet interval just right, I think it was about slightly above two seconds,
you could actually make the modem reset this way, so this helped tremendously to investigate it,
and at some point I also started playing with an USB M.2 adapter to pull the modem from the phone
and put it into other kinds of USB sockets in other devices, the idea was to identify whether it
was the hub or the SoC or the modem itself that caused troubles, and I found out that with
blacklisted kernel modules for the modem and sleep timeouts all set to 0, I could make it into
some kind of reset loop, it would basically reset every second or two and keep resetting.
At some point I noticed that when it was plugged to some USB hubs, I gathered pretty much all the
hubs I had in my house, some pretty ancient ones as well, and with some of them it never reset,
I couldn't make it reset with some of the hubs with others, it was pretty easy, and whenever it was
connected to the house directly with no hub in between, it always worked, it never reset,
it even applied to this port on the Librem 5 itself, when it was plugged to the USB-C port,
the resets were never there. So there was time to start to read some specs to find out
what's going on or should be going on, and it turns out that the USB device enters
Suspend state after three milliseconds of no activity seen on the bus, and this can happen in
two ways, you can send a message to the hub to enable PORT_SUSPEND feature, and this is how the
hub stops sending frames to that port anymore so it doesn't see activity, and it suspends itself,
or you can stop any communication on the bus, we just call it global suspend, and then all the
devices on that bus see no activity and go into suspend. When the device detects that the
data lines have been in the idle state for at least three milliseconds, and high-speed idle state
is SE0, it must revert to the full-speed configuration, which is J, so D+ high if I remember
correctly, and then it must sample the state of the line, so it checks what hub has, or host, has
asserted, and if it's full-speed J, then it continues with the suspend process, it is required
because SE0 is also a reset signal, if at this point it would stay in SE0, it means that this is
the default state that the bus is put in and the device must reset, but if it's J then it means that
this is a suspend that has been requested, so the device then asserts J itself and stays in J.
We now know how suspend works and how about resume? The host can resume the port at any
time, it must send the resume signaling, which is K, for at least 20 milliseconds, and after resuming the
bus the host must resume communication within three milliseconds, because otherwise the device would
go into suspend again. And what if it's the device that wants to wake itself up?
It cannot wake itself up after being put into suspend for at least five milliseconds,
and then it can, and it must hold the resume signaling, which is still K, for at least one
millisecond, but for no more than 15 milliseconds, and the controlling hub, which is the hub that
actually handles the resume, as there might be more on the tree, must
re-broadcast that to upstream within one millisecond and ensures that it is signaled for at least
20 milliseconds, so it kind of takes over that signaling. So now it was time to get dirty,
fortunately I didn't have to do that myself, Eric Kuzmenko, who is the hardware guy at
Purism did it for me, and soldered some wires and put a differential probe to it in order to
sniff what's going on electrically on the wires, so this could be then seen on an oscilloscope
and recorded, and this is an example of what's going on. We can see here at the beginning some kind
of high-speed communication, as it's a lower voltage than full-speed, at this point we can see that
the modem went into suspend, this is the J state for some time, and then here we can see
the K state, which means that it was either resumed by host or it wanted to wake itself up, and it
happened, cycled this way for some time, and eventually something went wrong here, so to zoom it up,
what happened here is that there was some kind of high-speed communication, it stopped for three
milliseconds, at which point the modem went into suspend, and there was a J signal for another
three milliseconds, then it went into K state, we can assume that the modem wanted to wake itself up,
and it lasted about 20 milliseconds, but then the bus went into SE0 and communication did not
resume, it stayed at zero, at which point after another three milliseconds the modem just suspended
itself again, so this is somewhat informative but still not enough. My hypothesis at this point was
that the specification requires a grace period of five milliseconds before sending a remote wake-up
request, but I wasn't quite sure whether the wording isn't ambiguous, because it says that
it needs to stay continuously in the idle state for five milliseconds, but if we check here,
we have two idle states, there is high-speed idle state for three milliseconds, and full-speed
idle state for another three milliseconds, so when is this point where it starts?
However, there is also, aside of English description, there is also a bit more formal
state machine description in the specification, and after deciphering that it turns out that
both of these idle states actually counted as one continuous idle state, so this probably wasn't it.
So we go back to getting dirty, and this time instead of just sniffing what's going on between
the modem and the hub, we also sniffed what's going on between the hub and the phone's processor,
at the same time, which required quite interesting contraptions to be made,
but it worked, and we got some data, and this is an example of things going wrong,
and we can see some USB microframes here, so host polling the devices, and then some communication
actual, and then nothing for three milliseconds on the modem port, on the bottom we can see the
port between the hub and the SoC, and there the microframes continue, and the modem goes into
suspend, and after I think here it was two milliseconds, it wants to wake itself up, so it
assets K, and the hub takes over, then 20 milliseconds later it stops, but what happens here at the
bottom, and the microframes continue when the modem is suspended, and when it wakes itself up,
starts to wake itself up, the communication still happens, until this point, then it stops.
This is the point where the hub has been suspended by the host, and then after three milliseconds
the hub went into suspend process by itself, and what happens here is that at this point,
at this exact point the hub started to wake itself up, however at this point also it should start
sending frames to the modem, start forwarding frames from the host to the modem, but the hub
itself was waking up, so there was no data to transmit, so it all fell apart at this point,
and I started looking closely into the specification, and following the state machine,
and I couldn't really figure out what the hub was exactly supposed to do in this case,
when the Upstream Facing Port went into the Suspending state while a Downstream Facing Port
was already in the Resuming state, and I wasn't sure whether it was my misunderstanding or whatever,
what's worse, at this point in time the host has no way to know that the Downstream Facing Port is
already attempting to wake itself up, if here we would query the status of the port, it would say
that it's still suspended, there was no indication, and that's actually how it works in the spec,
that information only becomes available when the port already finishes resuming, so
now I knew what was going on, and I had the knowledge what to put into the search engine,
and I found this email from many years ago from Alan Stern, who is a guru of
USB and Power Management subsystems in Linux, and he stated that the USB 2 spec does not
take into account that possibility, so Alan basically validated my suspicion, years before
I made that suspicion, so at this point I could safely assume that my suspicion was true,
and what's worse, that mail ended with "I don't know what we should do. Suggestions, anybody?"
There were some replies but it didn't really go anywhere. However that mail pointed to an
errata, and errata said that there is a very unlikely possibility of a race condition, and this issue
can be avoided if system software suspends a downstream facing hub ports before suspending a
hub. I completely forgot to check erratas, at this point this was the first time I seen it, and
I was so happy that this was the first time I seen it, because what the hell, this recommendation
suspending the port before suspending the hub is exactly what makes this issue happen, and Alan
Stern said so himself in his mail that this errata is completely bonkers, so I'm so glad I didn't
see it because I would be so confused. So the workaround, what I did to actually
stop, prevent it from happening: so I have added a port quirk in the USB
subsystem in the kernel, which when it was enabled the port was never actually suspended
selectively, Linux only pretended to suspend it, but didn't actually send the command to the hub.
Since this would cause troubles as if we just pretend that the device is suspended we stop
polling it for more information, but the device isn't actually suspended, so it can't wake itself up,
so to prevent that from happening, we keep such quirked port active whenever
any sibling port is active as well, and when the hub gets resumed, all ports marked with this quirk
are also resumed as well, and this lets us rely on global suspend when we just
stop sending any communication, and all the devices suspend at the same time,
preventing this race condition from happening, and this works well with the topology on the
Librem 5, but breaks apart on different topologies, if we added another device, for example on this
third port that also wanted to use remote wake-up, it wouldn't work. There's the code,
so what can we do now? This hack isn't really suitable for mainlining, it's really a bad hack,
so for now it stays in our downstream tree, however I believe there is a way to do it
in a way that could be potentially upstreamed, it wouldn't be the default, I'm pretty sure,
because it would be quite inefficient, but I think it should be possible to have this as an
option if you have such devices that are resetting in this way, that you could actually have them
work reliably and wouldn't have to disable power management completely, and to do so we would
have to ensure that no downstream wake-up capable port is suspended while the hub goes into suspend,
and there's also another thing that made me implement it as this hack instead of a proper
solution first, is that while the proper solution is less efficient, this hack actually gives us
some efficiency because we can skip suspending each device one by one, we just suspend them all
at once and it takes less time, so this lets us make the modem go to sleep more often saving more
battery. So that's basically it, I'm available for consulting so I can turn your money into code
if you're interested to have something done in mobile GNU/Linux space, and if you have some
questions like my reviewer had here you can ask them now, thank you.
- Great tale.
You already have a question here?
- You mentioned the influence of the ModemManager on this effect, can this be explained
with your findings? - Yes, this is because when the ModemManager is polling every 30 seconds,
it's the host that initiates the communication, but if we switch to unsolicited messages from the
modem, then it's the modem that actually initiates it, so it wakes itself up more as opposed
to the host waking it up when this issue never happens.
- Hello, thanks for your presentation, how many man hours went into this bug fix?
- Oh, I don't really know, it took many false starts let's say and red herrings,
so this is obviously just a chunk of it because I had to fit it into the presentation, but
yeah there were many approaches, we were really in the dark at the beginning, I didn't know
anything about how USB works initially, I had to learn it from scratch, so it took some time.
- Hi, quick question for you, actually two questions. The first one is,
is the USB the ideal way to connect the modem or is there a better protocol that we could
be using in the future, in another design? - It depends what you have available, perhaps
on the Librem 5 we could theoretically use PCI Express, however PCI Express would be
at least on this SoC would be much more power-hungry than USB and USB makes it easy to find
such devices that you can actually have on a replaceable card that you can put into the phone
pretty much off-the-shelf, so the options are quite limited in this place.
- And second question actually on that, when it comes to adding a different modem,
this isn't a modem issue, obviously it didn't come down to which modem you were using, but
are you guys looking at releasing a Gemalto modem because that would be pretty cool?
- I'm not really a person that has anything, like any power in this regard, so I can really say
much about it. - We have a question from the Matrix channel. - When will it be fixed upstream,
hopefully? - Hopefully soon. Making this presentation, submitting it here, was actually a way to force
myself into going through this again because after getting this hack done, I just wanted to
take a break from all this USB stuff, so maybe soon, maybe not, we'll see. I think it should be
pretty simple, in fact. We'll see what the maintainers will say, whether they will be
happy to take such a quirk approach or maybe they'll have another ideas. We'll see.
- Are there any proper solutions to this problem, like in the USB specification, for example,
are there any hubs that don't have that issue? - So the specification of USB 2 never fixed it.
USB 3 works in a completely different way and there are also
supplemental low power modes in USB 2 that could be used and that also don't have this
issue, but you have to have a device that supports those modes and we don't.
So we can say that it's fixed because it's all completely different in USB 3 and higher.
And for USB 2 devices, it's all up to the hub and how it's implemented. If it's implemented
to the word of the spec, there's a high probability that it will have this issue,
but some hubs are like, specs gives you some time to do things. You can do it
like the minimum and maximum time and some hubs are faster and then you may not
see this issue happening with them. So yeah, at this point with USB 2 devices, it's probably up to
your luck with what components you are using.
- I'm working on open source USB debugging tools, sniffers, software, so I'll be interested in
talking to you about capturing this as a test case to make sure that we're able to spot this
happening on the wire in future. - Okay. - Very nice. Yeah, first another from the chat apparently,
then I'll pass it to you. - Is there known other mobile devices that suffer this issue? I relate
some aspects of the bug on Pinebook Pro Wi-Fi. - Honestly, I have no idea. This was the first time I
experienced this issue and had to basically go through what I told you today. So I don't know.
This was known for years. The email was 12 years ago and Alan Sterm has said that this came up in
testing. So obviously this came up somewhere, but where it was and which devices were affected,
I have no idea. - So you mentioned the other USB bug you were facing where the whole bus died.
Did you fix that as well? And can you say like two sentences about that?
- Sorry, once again? - The other bug you mentioned in the beginning where the whole USB stack died
and the modem didn't come back. Did you fix that as well? And can you say maybe two sentences about
what the cause was? - Basically that one was pretty boring. It ended up to be a missing
quirk in the host driver that was already implemented, but wasn't enabled in the device
tree. And at some point, actually, NXP has enabled that for all i.MX 8M boards. So this is fixed now in
mainline. - So please give another round of applause. - Thank you.