greatscottgadgets / luna

Amaranth HDL framework for monitoring, hacking, and developing USB devices
https://greatscottgadgets.com/cynthion/
BSD 3-Clause "New" or "Revised" License
989 stars 171 forks source link

Beagle analyzer shows orphaned packets when using CDC ACM interface #224

Closed jeremyherbert closed 12 months ago

jeremyherbert commented 12 months ago

Hi,

I'm running the LUNA latest git rev with a custom ECP5 board (but that is very similar to the OrangeCrab or other small dev boards).

I'm trying to use the CDC ACM interface and while it seems to be working fine, I am seeing orphaned packets inside the beagle analyzer log:

luna_usb_serial_issue_-_Total_Phase_Data_Center_v6_73_007

The data appears to be coming through OK to my serial terminal though.

My code is below, the expectation is that it sends "SRQ" as three separate packets repeatedly:

from amaranth import *
from amaranth.lib.fifo import AsyncFIFO
from luna.gateware.platform.core import LUNAPlatform

from ecp5_mini_platform import ECP5_Mini_25F_Platform

from luna.full_devices import USBSerialDevice

class ECP5MiniClockDomainGenerator(Elaboratable):
    def __init__(self, *args, **kwargs):
        super().__init__(*args, **kwargs)
        self.locked = Signal()

    def elaborate(self, platform):
        m = Module()
        feedback = Signal()

        # Grab our default input clock.
        print(platform.resources)
        input_clock = platform.request('clk16').i

        # Create our domains; but don't do anything else for them, for now.
        m.domains.sync = ClockDomain()
        m.domains.usb = ClockDomain()
        m.domains.usb_io = ClockDomain()
        m.domains.fast = ClockDomain()

        m.submodules.pll = Instance("EHXPLLL",

                                    # Clock in.
                                    i_CLKI=input_clock,

                                    # Generated clock outputs.
                                    o_CLKOP=feedback,
                                    o_CLKOS=ClockSignal("sync"),
                                    o_CLKOS2=ClockSignal("usb"),

                                    # Status.
                                    o_LOCK=self.locked,

                                    # PLL parameters...
                                    p_PLLRST_ENA="DISABLED",
                                    p_INTFB_WAKE="DISABLED",
                                    p_STDBY_ENABLE="DISABLED",
                                    p_DPHASE_SOURCE="DISABLED",
                                    p_CLKOS3_FPHASE=0,
                                    p_CLKOS3_CPHASE=0,
                                    p_CLKOS2_FPHASE=0,
                                    p_CLKOS2_CPHASE=0,
                                    p_CLKOS_FPHASE=0,
                                    p_CLKOS_CPHASE=0,
                                    p_CLKOP_FPHASE=0,
                                    p_CLKOP_CPHASE=9,
                                    p_PLL_LOCK_MODE=0,
                                    p_CLKOS_TRIM_DELAY="0",
                                    p_CLKOS_TRIM_POL="FALLING",
                                    p_CLKOP_TRIM_DELAY="0",
                                    p_CLKOP_TRIM_POL="FALLING",
                                    p_OUTDIVIDER_MUXD="DIVD",
                                    p_CLKOS3_ENABLE="DISABLED",
                                    p_OUTDIVIDER_MUXC="DIVC",
                                    p_CLKOS2_ENABLE="ENABLED",
                                    p_OUTDIVIDER_MUXB="DIVB",
                                    p_CLKOS_ENABLE="ENABLED",
                                    p_OUTDIVIDER_MUXA="DIVA",
                                    p_CLKOP_ENABLE="ENABLED",
                                    p_CLKOS3_DIV=1,
                                    p_CLKOS2_DIV=48,
                                    p_CLKOS_DIV=12,
                                    p_CLKOP_DIV=12,
                                    p_CLKFB_DIV=3,
                                    p_CLKI_DIV=1,
                                    p_FEEDBK_PATH="CLKOP",

                                    # Internal feedback.
                                    i_CLKFB=feedback,

                                    # Control signals.
                                    i_RST=1,
                                    i_PHASESEL0=0,
                                    i_PHASESEL1=0,
                                    i_PHASEDIR=1,
                                    i_PHASESTEP=1,
                                    i_PHASELOADREG=1,
                                    i_STDBY=0,
                                    i_PLLWAKESYNC=0,

                                    # Output Enables.
                                    i_ENCLKOP=0,
                                    i_ENCLKOS=0,
                                    i_ENCLKOS2=0,
                                    i_ENCLKOS3=0,

                                    # Synthesis attributes.
                                    a_FREQUENCY_PIN_CLKI="16.000000",
                                    a_FREQUENCY_PIN_CLKOP="48.000000",
                                    a_FREQUENCY_PIN_CLKOS="48.000000",
                                    a_FREQUENCY_PIN_CLKOS2="12.000000",
                                    a_ICP_CURRENT="12",
                                    a_LPF_RESISTOR="8"
                                    )

        # We'll use our 48MHz clock for everything _except_ the usb domain...
        m.d.comb += [
            ClockSignal("usb_io").eq(ClockSignal("sync")),
            ClockSignal("fast").eq(ClockSignal("sync")),

            ResetSignal("sync").eq(~self.locked),
            ResetSignal("usb").eq(~self.locked),
            ResetSignal("usb_io").eq(~self.locked),
            ResetSignal("fast").eq(~self.locked),
        ]

        return m

class ECP5Mini25FLuna(ECP5_Mini_25F_Platform, LUNAPlatform):
    name = "ECP5 mini Luna"
    clock_domain_generator = ECP5MiniClockDomainGenerator
    default_usb_connection = "usb"

class UsbSerialLuna(Elaboratable):
    def elaborate(self, platform):
        led_usr = platform.request("led_usr")
        led_act = platform.request("led_act")

        m = Module()
        m.submodules.car = platform.clock_domain_generator()

        m.submodules.outgoing_fifo = outgoing_fifo = AsyncFIFO(width=8, depth=8, r_domain="usb", w_domain="sync")

        bus = platform.request(platform.default_usb_connection)
        m.submodules.usb_serial = usb_serial = USBSerialDevice(bus=bus, idVendor=0x16d0, idProduct=0x0f3b)
        m.d.comb += [
            usb_serial.connect.eq(1),
            usb_serial.rx.ready.eq(0),

            usb_serial.tx.payload.eq(outgoing_fifo.r_data),
            usb_serial.tx.valid.eq(outgoing_fifo.r_rdy & outgoing_fifo.r_en),
            outgoing_fifo.r_en.eq(usb_serial.tx.ready),
            usb_serial.tx.first.eq(1),
            usb_serial.tx.last.eq(1)
        ]

        timer = Signal(25)
        m.d.sync += timer.eq(timer + 1)

        with m.If((outgoing_fifo.w_rdy) & (timer == (2**25)-1)):
            m.d.sync += [
                outgoing_fifo.w_en.eq(1),
                outgoing_fifo.w_data.eq(81)
            ]

        with m.Elif((outgoing_fifo.w_rdy) & (timer == (2**25)-2)):
            m.d.sync += [
                outgoing_fifo.w_en.eq(1),
                outgoing_fifo.w_data.eq(82)
            ]

        with m.Elif((outgoing_fifo.w_rdy) & (timer == (2**25)-3)):
            m.d.sync += [
                outgoing_fifo.w_en.eq(1),
                outgoing_fifo.w_data.eq(83)
            ]

        with m.Else():
            m.d.sync += [
                outgoing_fifo.w_en.eq(0),
                outgoing_fifo.w_data.eq(84)
            ]

        m.d.comb += [
            led_usr.o.eq(timer[-1]),
            led_act.o.eq(m.submodules.car.locked)
        ]

        return m

def go():
    platform = ECP5Mini25FLuna()

    platform.build(UsbSerialLuna(), do_program=True)

if __name__ == "__main__":
    go()

The Beagle trace is also attached. luna_usb_serial_issue.tdc.zip

This isn't a huge problem in itself, but the errors become much more extreme if I try to send the data as a single packet with multiple bytes in it by changing:

usb_serial.tx.first.eq(1),
usb_serial.tx.last.eq(1)

to

usb_serial.tx.first.eq(outgoing_fifo.r_level > 1),
usb_serial.tx.last.eq(outgoing_fifo.r_level == 1)
_Untitled_-_Total_Phase_Data_Center_v6_73_007

trace: luna_usb_serial_issue_single_packet.tdc.zip

But the data is still coming through OK in the serial terminal.

Could you please help me understand if I am doing something wrong here?

jeremyherbert commented 12 months ago

The situation seems to improve if use usb_serial.tx.first.eq(0), there are still some orphaned packets but far less. However, this comment: https://github.com/greatscottgadgets/luna/blob/c7617ec7b7903a6d8e1fa4f4a637bbfedb2b0616/luna/gateware/usb/usb2/transfer.py#L39C30-L39C30

seems to imply that first is unused, so I'm even more confused now.

zyp commented 12 months ago

Hi, can you try doing a sequential mode capture with the beagle? The captures you've attached are aggregate mode which discards some details, making it hard to see exactly what's going wrong.

jeremyherbert commented 12 months ago

This one has tx.first and tx.last tied to 1 (there are a lot more errors than previously for some reason):

luna_usb_serial_sequential.tdc.zip

Is this the correct format?

zyp commented 12 months ago

Yes, thanks. The packets that's showing up as orphaned are IN requests from the host without a handshake from the device. Normally the device should reply NAK to every IN token it receives when it doesn't have any data to respond with, but in the capture roughly one in two thousand IN tokens on average doesn't get a reply.

I believe this is a lower layer problem than the FIFO signals you've been experimenting with, and wouldn't expect them to actually affect the behavior.

The reason the data is still coming through fine is because this is well within what USB's error handling can deal with and recover from, but the rate this is occuring at still suggests this is a problem that should be tracked down and fixed.

I'll try porting your code to one of my boards here tomorrow and see if I can reproduce the issue.

jeremyherbert commented 12 months ago

Thank you. Please let me know if there is anything I can do to help test - I'm not too comfortable with the deeper internals of this code but happy to do what I can.

zyp commented 12 months ago

I'm unable to reproduce your issue, it's behaving fine here: image

Statistics shows no missed replies to over 10M IN requests: image

I'm testing on a colorlight i5 in a custom carrier board with a FS USB connector and apart from changing the PLL config to account for the input clock being 25 MHz instead, I'm running the exact code you provided.

jeremyherbert commented 12 months ago

Well this is embarrassing... It appears that the USB-C cable I was using was causing signal integrity issues. I have changed to a known high-quality cable and now everything works fine.

I will close this issue. Thanks very much for the reproduction attempt and sorry for wasting your time.

straithe commented 12 months ago

Thank you for the update. We're happy that you were able to find a solution!