mithro / valentyusb

USB Full-Speed core written in migen/LiteX
BSD 3-Clause "New" or "Revised" License
17 stars 3 forks source link

Fix the resetinserter / clockdomainrenamer names in vcd output #18

Open mithro opened 5 years ago

mithro commented 5 years ago

Currently a bunch of the bigger tests end up with signal names like;

addr_clockdomainsrenamer_next_value
clockdomainsrenamer_state
resetinserter_state

It would be better if they actually named correctly.

Seems to be related to;

ewenmcneill commented 5 years ago

Currently I'm wondering:

For reference:

https://github.com/mithro/valentyusb/blob/usb12/valentyusb/usbcore/sm/transaction.py

seems to be affected by all of these (but it takes a long time to run all the tests there now).

https://github.com/mithro/valentyusb/blob/usb12/valentyusb/usbcore/sm/send.py

seems to have some of these issues.

https://github.com/mithro/valentyusb/blob/usb12/valentyusb/usbcore/tx/pipeline.py

has some of these issues, and runs relatively quickly.

So starting with usbcore.tx.pipeline probably makes sense.

usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 16 G resetinserter_state $end
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ grep resetinserter_state *.vcd | gre
p usbcore.tx.pipeline
usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_ACK_handshake_-_pid_error.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_ACK_handshake.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_data_with_bad_CRC16.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_data_with_good_CRC16.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_SOF_token_-_bad_crc5.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_SOF_token_-_bad_pid.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_SOF_token.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.USB2_ACK_handshake_-_pid_error.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.USB2_ACK_handshake.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.USB2_data_with_bad_CRC16.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.USB2_data_with_good_CRC16.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.USB2_SOF_token_-_bad_crc5.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.USB2_SOF_token_-_bad_pid.vcd:$var wire 16 G resetinserter_state $end
usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 16 G resetinserter_state $end
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ 

Ewen

GitHub
mithro/valentyusb
USB Full-Speed core written in migen/LiteX. Contribute to mithro/valentyusb development by creating an account on GitHub.
GitHub
mithro/valentyusb
USB Full-Speed core written in migen/LiteX. Contribute to mithro/valentyusb development by creating an account on GitHub.
GitHub
mithro/valentyusb
USB Full-Speed core written in migen/LiteX. Contribute to mithro/valentyusb development by creating an account on GitHub.
mithro commented 5 years ago

Looking at the tx.pipeline example, https://github.com/mithro/valentyusb/blob/9a785a47ea45e50b3956b6478ff65e098b41896a/valentyusb/usbcore/tx/pipeline.py#L33

Signals there should probably have shifter in the name? Compare to the vcd output from tx.shifter test?

ewenmcneill commented 5 years ago

On usbcore.tx.shifter the shifter is just a signal, so it's being called shifter, without any renaming / clock behaviour involved.

But it sounds like, eg, using the name of the variable/signal might be useful. ClockDomainsRenamer will also take a dict:

https://github.com/m-labs/migen/blob/57c44674c2a6c38bd01804e69db61a9efd287524/migen/fhdl/decorators.py#L102-L106

which gives a bit more control over what happens, so I'll experiment with that next. (Otherwise it looks like it's only renaming the "sys" signal, which you don't have here?)

Ewen

GitHub
m-labs/migen
A Python toolbox for building complex digital hardware - m-labs/migen
mithro commented 5 years ago

The clock domain renamer is renaming the sys clock domain.

ewenmcneill commented 5 years ago

Yes, that's the default of ClockDomainsRenamer, to rename "sys".

And as best I can tell the shifter thing is called shifter in the usbcore.tx.pipeline VCD as well (at least there's a bunch of shifter signals):

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ grep shifter usbcore.tx.pipeline*vcd
 | tail
usbcore.tx.pipeline.USB2_SOF_token_-_bad_pid.vcd:$var wire 1 2 shifter_reset $end
usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 8 * shifter_i_data $end
usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 1 + shifter_o_get $end
usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 1 , shifter_o_empty $end
usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 1 - shifter_o_data $end
usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 8 . shifter_shifter $end
usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 8 / shifter_pos $end
usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 1 0 shifter_empty $end
usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 1 1 shifter_ce $end
usbcore.tx.pipeline.USB2_SOF_token.vcd:$var wire 1 2 shifter_reset $end
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ 

So my current hypothesis is that interposing the ClockDomainsRenamer / ResetInserter is causing the magic "find it on the stack" name detection to get confused by the extra layer, and come up with silly names (I ran into that "confused by extra layer" while working on the VCD file naming change). Which might need special casing within migen. I'll do some digging and see if I can figure out where some of those names get derived...

It also seems likely that usbcore.tx.pipeline is not a good test candidate for the ClockDomainsRenamer issue (despite referencing it), only for the ResetInserter case.

Ewen

ewenmcneill commented 5 years ago

It looks like the @ResetInserter on usbcore.tx.shifter is then appearing in usbcore.tx.pipeline (which uses that shifter...) with the problematic name. So my guess is that the actual triggering condition is that there's an additional layer of indirection, which is obscuring the naming of the signals. Eg, that the resetinserter_.... one should belong to shifter.

However I've yet to track down how that collection of signals from used modules works.

Ewen

ewenmcneill commented 5 years ago

Interestingly, the usbcore.tx.shifter reset as used by usbcore.tx.pipeline does appear with the name shifter_reset (and shifter_ce) which is what would be expected. It's just that there's also the resetinserter_... signal as well.

Still trying to figure out why (ie, what the triggering condition is).

Ewen

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ grep wire usbcore.tx.shifter.basic_shift_out_1.vcd | cut -f 5 -d ' ' >/tmp/shifter-signals.txt
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ grep wire usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_ACK_handshake_-_pid_error.vcd | grep shifter | cut -f 5 -d ' ' >/tmp/pipeline-signals.txt
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ cat /tmp/shifter-signals.txt 
i_data
o_get
o_empty
o_data
shifter
pos
empty
ce
reset
sys_clk
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ cat /tmp/pipeline-signals.txt 
shifter_i_data
shifter_o_get
shifter_o_empty
shifter_o_data
shifter_shifter
shifter_pos
shifter_empty
shifter_ce
shifter_reset
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ 
mithro commented 5 years ago

Is it just the ASCII versions of the state machines?

mithro commented 5 years ago

If so, it might have something to do with the special _enumeration property...

https://github.com/m-labs/migen/blob/dcfec40c9d0cd3abab264897b424f0f53eeb58b4/migen/sim/vcd.py#L76-L83

https://github.com/m-labs/migen/search?q=_enumeration&unscoped_q=_enumeration

GitHub
m-labs/migen
A Python toolbox for building complex digital hardware - m-labs/migen
ewenmcneill commented 5 years ago

By "chain saw" debugging (cut bits out, see what happens), I've determined that for usbcore.tx.pipeline the triggering condition seems to be using usbcore.tx.bitstuff when that has an @ResetInserter decorator. It appears not to make a difference what is done with usbcore.tx.shifter.

Currently I don't know why usbcore.tx.bitstuff triggers that. But yes, it's definitely plausible it's related to the way that signals are being enumerated by the simulator....

Ewen

PS: FTR, in order to remove the @ResetInserter on usbcore.tx.bitstuff and/or usbcore.tx.shifter, it's necessary to also comment out the use of that reset signal in usbcore.tx.pipeline (because obviously the reset signal of the component is no longer there...)

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ grep ResetInsert usbcore/tx/bitstuff.py 
from migen.fhdl.decorators import CEInserter, ResetInserter
#@ResetInserter()
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ python -m usbcore.tx.pipeline >/dev/null
.
----------------------------------------------------------------------
Ran 1 test in 2.719s

OK
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ grep resetinserter vcd/usbcore.tx.pipeli
ne.*
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ vi usbcore/tx/bitstuff.py (LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ grep ResetInsert usbcore/tx/bitstuff.py from migen.fhdl.decorators import CEInserter, ResetInserter
@ResetInserter()
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ python -m usbcore.tx.pipeline >/dev/null
.
----------------------------------------------------------------------
Ran 1 test in 2.694s

OK
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ grep resetinserter vcd/usbcore.tx.pipeline.*
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_ACK_handshake_-_pid_error.vcd:$var wire 16 G resetinserter_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_ACK_handshake_-_pid_error.vcd:$var wire 32 H resetinserter_next_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_ACK_handshake.vcd:$var wire 16 G resetinserter_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_ACK_handshake.vcd:$var wire 32 H resetinserter_next_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_data_with_bad_CRC16.vcd:$var wire 16 G resetinserter_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_data_with_bad_CRC16.vcd:$var wire 32 H resetinserter_next_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_data_with_good_CRC16.vcd:$var wire 16 G resetinserter_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_data_with_good_CRC16.vcd:$var wire 32 H resetinserter_next_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_SOF_token_-_bad_crc5.vcd:$var wire 16 G resetinserter_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_SOF_token_-_bad_crc5.vcd:$var wire 32 H resetinserter_next_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_SOF_token_-_bad_pid.vcd:$var wire 16 G resetinserter_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_SOF_token_-_bad_pid.vcd:$var wire 32 H resetinserter_next_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_SOF_token.vcd:$var wire 16 G resetinserter_state $end
vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_SOF_token.vcd:$var wire 32 H resetinserter_next_state $end
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ 
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ grep ResetInsert usbcore/tx/shifter.py 
from migen.fhdl.decorators import CEInserter, ResetInserter
@ResetInserter()
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ 
ewenmcneill commented 5 years ago

I have a theory it might be related to the fact that usbcore.tx.bitstuff uses a FSM, which usbcore.tx.shifter does not. And in particular the FSM has a NextState value, which would be an obvious thing to make into a signal. So if the FSM was ending up with the wrong name, when the @ResetInserter decorator was used, then that might explain both resetinserter_state and resetinserter_nextstate, which appear to be exactly the two signals we're getting that we're not expecting.

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ grep resetinserter vcd/usbcore.tx.pipeli
ne.* | cut -f 2 -d : | cut -f 5 -d ' ' | sort | uniq
resetinserter_next_state
resetinserter_state
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ 

And obviously usbcore.sm.send and usbcore.sm.transaction both use FSMs heavily :-)

My guess is that the same "guessed the wrong name" root cause also applies to the @ClockDomainRenamer case too, perhaps in the same context too (ie, FSM). The signal names seem to make sense for that to be the cause:

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ grep clockdomainsrenamer *.vcd | cut
 -f 2 -d : | cut -f 5 -d ' ' | sort | uniq
addr_clockdomainsrenamer_next_value1
addr_clockdomainsrenamer_next_value_ce1
clockdomainsrenamer_next_state
clockdomainsrenamer_state
endp_clockdomainsrenamer_next_value2
endp_clockdomainsrenamer_next_value_ce2
response_pid_clockdomainsrenamer_next_value3
response_pid_clockdomainsrenamer_next_value_ce3
tok_clockdomainsrenamer_next_value0
tok_clockdomainsrenamer_next_value_ce0
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ 

(with the suffixes to deal with "oops, we seem to have used that name already", because the unique naming bit is breaking in this case).

Ewen

ewenmcneill commented 5 years ago

FSM has two Signals, which have default names (no name parameter):

https://github.com/m-labs/migen/blob/57c44674c2a6c38bd01804e69db61a9efd287524/migen/genlib/fsm.py#L215-L218

Default Signal names are apparently auto-generated, with a uniqueness suffix if needed:

https://github.com/m-labs/migen/blob/57c44674c2a6c38bd01804e69db61a9efd287524/migen/fhdl/structure.py#L324-L329

which matches the symptoms. Still hunting for where that auto-generation of the name happens...

Ewen

GitHub
m-labs/migen
A Python toolbox for building complex digital hardware - m-labs/migen
GitHub
m-labs/migen
A Python toolbox for building complex digital hardware - m-labs/migen
mithro commented 5 years ago

I think it happens in https://github.com/m-labs/migen/blob/e6ff283a467dc0657019dedadc5b06fa7130b744/migen/fhdl/tracer.py

GitHub
m-labs/migen
A Python toolbox for building complex digital hardware - m-labs/migen
ewenmcneill commented 5 years ago

Okay, I think we know the root cause now:

The decorators derive from ModuleTransformer and that only derives (implicitly) from Object:

https://github.com/m-labs/migen/blob/master/migen/fhdl/decorators.py#L10

but the tracer code only skips things derived from the same class as the code calling the tracer:

https://github.com/m-labs/migen/blob/e6ff283a467dc0657019dedadc5b06fa7130b744/migen/fhdl/tracer.py#L65-L70

which I assume ultimately is some migen superclass.

Thus the decorators are not skipped, and become part of the name of the FSM Signal names. Causing the behaviour we're seeing.

We need to figure out a way to cause the decorators to also be skipped in that investigation... and then my guess is it'll magically work as we want.

Ewen

GitHub
m-labs/migen
A Python toolbox for building complex digital hardware - m-labs/migen
GitHub
m-labs/migen
A Python toolbox for building complex digital hardware - m-labs/migen
ewenmcneill commented 5 years ago

@mithro I have... a kludgy workaround, via a potential small change to migen. Basically it recognises migen decorators from their module name, and then skips them the same way that "things with __del__" are skipped (dict, etc, I assume; there's no comments).

As noted in IRC, the original tracing code I was looking at is apparently only used for clocks, not for "general naming". Instead Signal, etc, seems to rely on a backtrace, which is done by:

https://github.com/m-labs/migen/blob/e6ff283a467dc0657019dedadc5b06fa7130b744/migen/fhdl/tracer.py#L90-L136

This work around seems to work. With this kludgy change in place I get:

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ grep "_state" usbcore.tx.pipeline.Te
stTxPipeline.*vcd | cut -f 2 -d : | cut -f 5 -d ' ' | sort | uniq
get_fragment_next_state
get_fragment_state
txnrziencoder_next_state
txnrziencoder_state
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ 

which looks plausible to me. You'd know the code better to know if get_fragment_... makes sense as a name.

The migen change looks like this:

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/migen/migen/fhdl$ git diff
diff --git a/migen/fhdl/tracer.py b/migen/fhdl/tracer.py
index f89794c..cb0f057 100644
--- a/migen/fhdl/tracer.py
+++ b/migen/fhdl/tracer.py
@@ -108,6 +108,17 @@ def trace_back(varname=None):
         if hasattr(obj, "__del__"):
             obj = None

+        # Skip frames that are decorators, since they are supposed to
+        # be invisible glue, and not candiates for picking a name.
+        #
+        # We recognise these from their class's module name
+        # as this is the most obvious indicator they are *our* decorators.
+        # (Yes, this is a kludge)
+        #
+        if (obj and obj.__class__ and
+                    obj.__class__.__module__ == "migen.fhdl.decorators"):
+            obj = None
+
         if obj is None:
             if varname is not None:
                 coname = frame.f_code.co_name
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/migen/migen/fhdl$ 

and I'm not really happy with it (particularly the reliance on the __module__ name). But pretty much the only other way I can think of is to stuff a magic attribute onto the class in the decorators and look for that. (Unfortunately it appears that migen/fhdl/tracer.py cannot import migen/fhdl/decorators.py to, eg, get a class to do isinstance() on, because of the other things that get imported; I stopped trying to debug that and focused on finding a working option to prove that the naming idea worked.)

Where do you want to go from here?

Ewen

PS: FTR, this is what we were getting before for these:

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ grep _state /tmp/before/*.vcd | cut 
-f 2 -d : | cut -f 5 -d ' ' | sort | uniq
resetinserter_next_state
resetinserter_state
txnrziencoder_next_state
txnrziencoder_state
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb/vcd$ 

so txnrziencoder is retaining its name, and the other one is becoming get_fragment.

GitHub
m-labs/migen
A Python toolbox for building complex digital hardware - m-labs/migen
ewenmcneill commented 5 years ago

@mithro Turns out that get_fragment was still not the right name. It's the function within the decorator implementation (without the class, etc); see https://github.com/m-labs/migen/blob/57c44674c2a6c38bd01804e69db61a9efd287524/migen/fhdl/decorators.py#L25.

To avoid that we need to skip the frame much earlier in the tracing loop, so that we don't save anything from the decorator frames.

With the migen tracer.py patch below we get:

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv/thi
rd_party/usb-bootloader/valentyusb/vcd$ grep "_state" usbcore.tx.pipeline.TestTxPipe
line.*vcd | cut -f 2 -d : | cut -f 5 -d ' ' | sort | uniq
txbitstuffer_next_state
txbitstuffer_state
txnrziencoder_next_state
txnrziencoder_state
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv/thi
rd_party/usb-bootloader/valentyusb/vcd$ 

which actually looks sensible.

So I believe we've identified the root cause. And it's now just down to "how do we best fix this".

To replicate notes from IRC, yes functools.wraps() does add a __wrapped__ attribute (in functools.update_wrapper()) from Python 3.2 onwards.

But:

(Maybe we change the migen decorator.py behaviour to emulate adding the attribute that functools.wraps adds, and look for that?)

Ewen

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/migen/migen/fhdl$ git diff
diff --git a/migen/fhdl/tracer.py b/migen/fhdl/tracer.py
index f89794c..3b85d37 100644
--- a/migen/fhdl/tracer.py
+++ b/migen/fhdl/tracer.py
@@ -94,6 +94,23 @@ def trace_back(varname=None):
     l = []
     frame = inspect.currentframe().f_back.f_back
     while frame is not None:
+        # Skip frames that are decorators, since they are supposed to
+        # be invisible glue, and not candiates for picking a name.
+        #
+        # We recognise these from their class's module name
+        # as this is the most obvious indicator they are *our* decorators.
+        #
+        # This needs to be done very early to avoid detecting just the
+        # function name on this frame: we want to skip the *whole* frame.
+        # (Yes, this is a kludge)
+        #
+        if ("self" in frame.f_locals and
+            frame.f_locals["self"].__class__.__module__ ==
+                "migen.fhdl.decorators"):
+            # Skip this frame
+            frame = frame.f_back
+            continue
+
         if varname is None:
             varname = get_var_name(frame)
         if varname is not None:
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/migen/migen/fhdl$ 
GitHub
m-labs/migen
A Python toolbox for building complex digital hardware - m-labs/migen
GitHub
m-labs/migen
A Python toolbox for building complex digital hardware - m-labs/migen
mithro commented 5 years ago

I'm pretty sure Migen doesn't support Python 2 at all.

Migen is designed for Python 3.5. Note that Migen is not spelled MiGen.

mithro commented 5 years ago

I do think making the Migen decorators do the proper __wrapped__ and then looking for that.

ewenmcneill commented 5 years ago

@mithro After a bunch of experimentation for where to add the __wrapped__ attribute so that we can easily detect it (some things look like they get wrapped/decorated more times than I expected), I think I have something that works detecting the __wrapped__ attribute on the object, with only a couple of small changes in decorators.py. I'm not sure that this exactly replicates what functools.wraps() / functools.update_wrapper() actually does, but it's at least similar and not reliant on hard coded class names.

It seems to work again for the specific test case I've been testing with. And is somewhat less hard coded/fragile than the previous attempt.

Thoughts?

Ewen

PS: Of note, the class wrapper seems to attempt to copy over the victim __name__, __module__, etc, presumably for a reason like this, but for some reason that's not sufficient. Possibly due to the additional layers of wrapping that go on (eg get_fragment() itself is doing another layer of wrapping).

(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ python -m usbcore.tx.pipeline 2>/dev/null
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ grep "_state" vcd/usbcore.tx.pipeline.TestTxPipeline.*vcd | cut -f 2 -d : | cut -f 5 -d ' ' | sort | uniq
txbitstuffer_next_state
txbitstuffer_state
txnrziencoder_next_state
txnrziencoder_state
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/usb-bootloader/valentyusb$ 
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/migen/migen/fhdl$ git diff
diff --git a/migen/fhdl/decorators.py b/migen/fhdl/decorators.py
index 3250e4f..26ae3e7 100644
--- a/migen/fhdl/decorators.py
+++ b/migen/fhdl/decorators.py
@@ -17,6 +17,8 @@ class ModuleTransformer:
         pass

     def wrap_class(self, victim):
+        self.__wrapped__ = victim
+
         class Wrapped(victim):
             def __init__(i, *args, **kwargs):
                 victim.__init__(i, *args, **kwargs)
@@ -33,6 +35,7 @@ class ModuleTransformer:
         return Wrapped

     def wrap_instance(self, victim):
+        self.__wrapped__ = victim
         self.transform_instance(victim)
         orig_get_fragment = victim.get_fragment

diff --git a/migen/fhdl/tracer.py b/migen/fhdl/tracer.py
index f89794c..e28653c 100644
--- a/migen/fhdl/tracer.py
+++ b/migen/fhdl/tracer.py
@@ -94,6 +94,20 @@ def trace_back(varname=None):
     l = []
     frame = inspect.currentframe().f_back.f_back
     while frame is not None:
+        # Skip frames that are decorators, since they are supposed to
+        # be invisible glue, and not candiates for picking a name.  We
+        # rely on finding a __wrapped__ attribute on the "self" object
+        # in the frame, which migen.fhdl.decorators adds mimicking
+        # what functools.wraps() / functools.update_wrapper() adds.
+        #
+        # This check needs to be done very early to avoid detecting just the
+        # function name on this frame; we want to skip the *whole* frame.
+        #
+        if ("self" in frame.f_locals and
+            hasattr(frame.f_locals["self"], "__wrapped__")):
+            frame = frame.f_back             # Skip this frame
+            continue
+
         if varname is None:
             varname = get_var_name(frame)
         if varname is not None:
(LX P=tinyfpga_bx.minimal F=micropython) ewen@parthenon:/src/fpga/litex-buildenv
/third_party/migen/migen/fhdl$ 
ewenmcneill commented 5 years ago

@mithro Patch in comment above (this time against migen master) is now at https://github.com/ewenmcneill/migen/tree/fsm-decorator-signal-names. For these two files it appears the version that litex-buildenv is pinned on currently matches migen master.

I think we probably need to do a bit more testing of this change to make sure it doesn't impact anything (other than decorators) else before trying to push upstream.

Ewen

GitHub
ewenmcneill/migen
A Python toolbox for building complex digital hardware - ewenmcneill/migen
ewenmcneill commented 5 years ago

@mithro The good news is that I've managed to cobble together some extracted bits of your repo into a smaller example that demonstrates a class using a FSM, and then something using that, with @ResetInserter and ClockDomainRenamer involved, and figured out a simulation test case that seems to advance through both clocks (which I just made the same speed for simplicity) and step through the FSM as expected based on input "data" bits.

The bad news is that with this setup, I'm not seeing the signal names in the .vcd file preceded with anything at all (not resetinserter_, not clockdomainrenamer_, not anything -- just called reset0, reset1, etc), which means it doesn't actually reproduce the problem that we set out to fix :-(

Any ideas what might be missing that is causing the issue not to be reproduced in the VCD signal names? I've tried a few variations in code arrangement, but I'm still just getting simple signal names, not ones scoped by the class names / submodule names / etc.

Ewen

PS: This was loosely based on rx/detect.py and rx/pipeline.py cobbled together into one test case.

(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/migen$ rm test_fsmuser.vcd 
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/migen$ python migen/test/test_fsmuser.py 
.
----------------------------------------------------------------------
Ran 1 test in 0.008s

OK
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/migen$ grep wire test_fsmuser.vcd 
$var wire 1 ! reset0 $end
$var wire 1 " bit_dat $end
$var wire 1 # o_pkt_start0 $end
$var wire 1 $ i_data $end
$var wire 1 % pkt_start $end
$var wire 1 & pkt_active $end
$var wire 1 ' o_pkt_start1 $end
$var wire 1 ( o_pkt_active $end
$var wire 1 ) reset1 $end
$var wire 80 * state $end
$var wire 96 + next_state $end
$var wire 1 , sys_clk $end
$var wire 1 - usb_12_clk $end
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/migen$ cp -p migen/test/test_fsmuser.py ~/Desktop/test_fsmuser_py.txt
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/migen$ 

test_fsmuser_py.txt

ewenmcneill commented 5 years ago

Looks like having two submodules which themselves use FSM is a necessary precondition to getting the names prefixed by the class names. And if the class names are the same, you'll still get 0/1 suffixes in that case, so the class names really need to be different.

This is closer to what we need to demonstrate the problem, but still doesn't seem to demonstrate the problem with clockdomaininserter_ or resetinserter_ names -- I keep getting sensible class names. (In an ideal world (a) the reset signals would also get prefixed rather than just numbered, and (b) the FSM signals would probably actually be SUBMODULE_FSMNAME_state and SUBMODULE_FSMNAME_next_state, not named after the class, but those are separate problems from this specific mis-naming issue.)

At a guess we need yet another level of wrapping, but I'm unsure what I'm actually missing from the test case which happens in your code to trigger this.

Ewen

(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/migen$ rm test_fsmuser.vcd 
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/migen$ python migen/test/test_fsmuser.py 
/src/fpga/litex-buildenv/third_party/migen/migen/fhdl/tracer.py
.
----------------------------------------------------------------------
Ran 1 test in 0.011s

OK
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/migen$ grep wire test_fsmuser.vcd 
$var wire 1 ! reset $end
$var wire 1 " bit_dat $end
$var wire 1 # o_pkt_start $end
$var wire 1 $ rxdetect_i_data $end
$var wire 1 % rxdetect_pkt_start $end
$var wire 1 & rxdetect_pkt_active $end
$var wire 1 ' rxdetect_o_pkt_start $end
$var wire 1 ( rxdetect_o_pkt_active $end
$var wire 1 ) rxdetect_reset $end
$var wire 1 * txdetect_i_data $end
$var wire 1 + txdetect_pkt_start $end
$var wire 1 , txdetect_pkt_active $end
$var wire 1 - txdetect_o_pkt_start $end
$var wire 1 . txdetect_o_pkt_active $end
$var wire 1 / txdetect_reset $end
$var wire 80 0 rxpacketdetect_state $end
$var wire 96 1 rxpacketdetect_next_state $end
$var wire 80 2 txpacketdetect_state $end
$var wire 96 3 txpacketdetect_next_state $end
$var wire 1 4 sys_clk $end
$var wire 1 5 usb_12_clk $end
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/migen$ cp -p migen/test/test_fsmuser.py ~/Desktop/test_fsmuser2_py.txt
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/migen$ 

test_fsmuser2_py.txt

ewenmcneill commented 5 years ago

Aha, it didn't happen all the time in your code either. Some modules were okay, and others were not:

(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/litex-buildenv/third_p
arty/usb-bootloader/valentyusb$ python -m usbcore.tx.pipeline
[...]
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/litex-buildenv/third_party/usb-bootloader/valentyusb$ grep next_state vcd/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_ACK_handshake_-_pid_error.vcd
$var wire 32 H resetinserter_next_state $end
$var wire 48 J txnrziencoder_next_state $end
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/litex-buildenv/third_party/usb-bootloader/valentyusb$ grep next_state vcd.old/usbcore.tx.pipeline.TestTxPipeline.test_pkt_decode.USB2_ACK_handshake_-_pid_error.vcd
$var wire 32 H txbitstuffer_next_state $end
$var wire 48 J txnrziencoder_next_state $end
(LX P=arty T=base F=micropython) ewen@parthenon:/src/fpga/litex-buildenv/third_p
arty/usb-bootloader/valentyusb$ 

(vcd is a run with an unfixed migen; vcd.old is a run with a fixed migen.)

So txbitstuffer was triggering this issue, but txnrziencoder was not. I'm still puzzled as to what's different about them...

ETA: At this point I suspect the only way to get a reproducible test case is probably to start with usbcore/tx in its entirety, and then remove things while the naming issue keeps happening with the unfixed migen. Because constructing an example that triggers it is clearly non-trivial (having spent several hours trying various things).

Ewen