Help upgrading phaser classic to phaser drtio mtdds on artiq-9 kasli-soc system

nmak

Summary/Context:

We have a master/satellite system with 2 kasli-soc cards which we recently (successfully) upgraded to artiq 9.
The gateware was built and flashed following the steps in the documentation.

The system included a phaser card (connected to master) which had the phaser classic gateware.
We then attempted to update this to the phaser_drtio mtdds gateware.

After flashing new gateware to both the phaser (connected to master) and kasli-soc (master), the system would crash on startup.
The UART logs (from the kasli-soc master) show:

A few ERROR(libboard_artiq::drtio_eem): comma alignment failed, retrying in 1s... errors after which I assume the alignment succeeds; then

A core panic when the master attempts to ping the phaser. two errors were seen

unreachable code error

    [     2.504821s]  INFO(runtime::rtio_mgt::drtio): [LINK#4] link RX became up, pinging
    [     2.515694s]  INFO(runtime::comms): no idle kernel found
    Core 0 panic at libboard_artiq/src/drtioaux_proto.rs:47:18: internal error: entered unreachable code
    Backtrace: 
    0x14eba4 
    End backtrace
    [     2.531684s] ERROR(runtime::panic): panic at libboard_artiq/src/drtioaux_proto.rs:47:18
    [     2.539669s] ERROR(runtime::panic): panic message: internal error: entered unreachable code
    Core 0 panic at /nix/store/dnns0nll2554aa2g07mrq8mzj0ikjqkv-source/libconfig/src/lib.rs:89:16: filesystem can only be initialized once: ()
    nested panic!

out of bounds error

    [     2.504820s]  INFO(runtime::rtio_mgt::drtio): [LINK#4] link RX became up, pinging
    [     2.515697s]  INFO(runtime::comms): no idle kernel found
    Core 0 panic at /build/source/libboard_artiq/src/drtioaux_proto.rs:731:43: range end index 19676 out of range for slice of length 1010
    Backtrace: 
    0x14eba4 
    End backtrace
    [     2.532108s] ERROR(runtime::panic): panic at /build/source/libboard_artiq/src/drtioaux_proto.rs:731:43
    [     2.541396s] ERROR(runtime::panic): panic message: range end index 19676 out of range for slice of length 1010
    Core 0 panic at /nix/store/dnns0nll2554aa2g07mrq8mzj0ikjqkv-source/libconfig/src/lib.rs:89:16: filesystem can only be initialized once: ()
    nested panic!`

No idea what could cause such an error, so I am posting here for help.

Steps taken:

Built phaser gateware on artiq release-9 branch
python -m artiq.gateware.targets.phaser --use-sma-clkin mtdds

Flashed gateware to phaser
artiq_flash --srcbuild -t phaser -d artiq_phaser/mtdds/

Built and flashed gateware with phaser_drtio mtdds to kalsi-soc (on artiq-zynq release-9 branch).
nix build --print-build-logs --impure --expr 'let fl = builtins.getFlake "/data/Artiq-zynq/artiq-zynq-9"; in (fl.makeArtiqZynqPackage {target="kasli_soc"; variant="master"; json=./hardware_config_master.json;}).kasli_soc-master-sd'

hardware_config_master.json

{
    "target": "kasli_soc",
    "variant": "master",
    "min_artiq_version": "8.0",
    "hw_rev": "v1.0",
    "base": "master",
    "core_addr": "10.196.56.100",
    "peripherals": [
        {
            "type": "suservo",
            "sampler_ports": [5, 6],
            "urukul0_ports": [1, 2],
            "urukul1_ports": [3, 4],
            "refclk": 1000000000.0,
            "clk_sel": 1,
            "clk_div": 1,
            "pll_en": 0,
            "proto_rev": 8
        },
        {
            "type": "phaser_drtio",
            "gateware_variant": "mtdds",
            "hardware_variant": "upconverter",
            "ports": [7],
            "tones": 26,
            "dds_bandwidth": 250e6
        },
        {
            "type": "dio",
            "ports": [9],
            "bank_direction_low": "output",
            "bank_direction_high": "output"
        }
    ]
}

Full UART logs for the two errors.

Unreachable code error

[     0.014335s]  INFO(szl): Simple Zynq Loader starting...
[     0.019541s] DEBUG(libboard_zynq::clocks::source): Set ARM_PLL to 2000000000 Hz
[     0.007034s] DEBUG(libboard_zynq::clocks::source): Set IO_PLL to 1000000000 Hz
[     0.016255s] DEBUG(libboard_zynq::clocks::source): Set DDR_PLL to 1066666666 Hz
[     0.023603s] DEBUG(libboard_zynq::ddr): DDR 3x/2x clocks: 533333328/355555552
[     0.025120s] DEBUG(libboard_zynq::ddr): DDR DCI clock: 10062892 Hz (divisors=2*53)
[     0.037000s] DEBUG(libboard_zynq::sdio): Reset SDIO!
[     0.037585s] DEBUG(libboard_zynq::sdio): Changing clock frequency to 400000
[     0.044531s]  INFO(szl): Card inserted. Mounting file system.
[     0.074164s] DEBUG(libboard_zynq::sdio): Changing clock frequency to 25000000
[     0.075664s] DEBUG(libboard_zynq::sdio::sd_card): Getting bus width
[     0.083879s] DEBUG(libboard_zynq::sdio::sd_card): 4 bit support
[     0.087798s] DEBUG(libboard_zynq::sdio::sd_card): Changing bus width
[     0.096000s] DEBUG(libboard_zynq::sdio): Set block size to 512
[     0.103382s] DEBUG(libconfig::sd_reader): Partition ID: C
[     0.106030s]  INFO(szl): Loading gateware
[     0.109537s] DEBUG(libconfig::bootgen): Partition header pointer = C80
[     0.117972s] DEBUG(libconfig::bootgen): Unencrypted length = C82EB
[     0.121997s] DEBUG(libconfig::bootgen): Partition start address: 9FC0
[     0.473557s] DEBUG(libboard_zynq::devc): Invalidate DCache for bitstream buffer
[     0.480542s] DEBUG(libboard_zynq::devc): Init preload FPGA
[     0.480681s] DEBUG(libboard_zynq::devc): Toggling PROG_B
[     0.511638s] DEBUG(libboard_zynq::devc): Waiting for done
[     0.511650s] DEBUG(libboard_zynq::devc): Init postload FPGA
[     0.516938s]  INFO(szl): Loading runtime
[     0.522984s] DEBUG(libconfig::bootgen): Partition header pointer = C80
[     0.527563s] DEBUG(libconfig::bootgen): Unencrypted length = 99F6
[     0.533431s] DEBUG(libconfig::bootgen): Unencrypted length = 66EA4
[     0.539592s] DEBUG(libconfig::bootgen): Partition start address: D22B0
[     0.728141s]  INFO(szl): Preparing for runt�+HH�� 0.000067s]  INFO(runtime): NAR3/Zynq7000 starting...
[     0.000130s]  INFO(runtime): gateware ident: 9+unknown;master
[     0.010511s]  INFO(libboard_zynq::i2c): PCA9548 detected
[     0.166596s]  INFO(runtime): log level set to INFO by default
[     0.167781s]  INFO(runtime): UART log level set to INFO by default
[     0.173952s]  INFO(runtime::rtio_clocking): bypassing the PLL for RTIO clock
[     0.393000s]  INFO(runtime::rtio_clocking): SYS CLK switched successfully
[     0.397163s]  INFO(libboard_artiq::drtio_eem): loading calibrated timing values from sd card
[     0.403617s] ERROR(libboard_artiq::drtio_eem): comma alignment failed, retrying in 1s...
[     1.411679s] ERROR(libboard_artiq::drtio_eem): comma alignment failed, retrying in 1s...
[     2.420359s]  INFO(libboard_zynq::i2c): PCA9548 detected
[     2.452078s]  INFO(runtime::comms): network addresses: MAC=e8-eb-1b-13-4a-43 IPv4=10.196.56.100 IPv6-LL=fe80::eaeb:1bff:fe13:4a43 IPv6: no configured address
[     2.474981s]  INFO(libboard_artiq::drtio_routing): could not read routing table from configuration, using default
[     2.479595s]  INFO(libboard_artiq::drtio_routing): routing table: RoutingTable { 0: 0; 1: 1 0; 2: 2 0; 3: 3 0; 4: 4 0; 5: 5 0; }
[     2.494233s]  INFO(runtime::rtio_mgt): SED spreading disabled by default
[     2.500279s]  INFO(runtime::rtio_mgt::drtio): [DEST#0] destination is up
[     2.504821s]  INFO(runtime::rtio_mgt::drtio): [LINK#4] link RX became up, pinging
[     2.515694s]  INFO(runtime::comms): no idle kernel found
Core 0 panic at libboard_artiq/src/drtioaux_proto.rs:47:18: internal error: entered unreachable code
Backtrace: 
0x14eba4 
End backtrace
[     2.531684s] ERROR(runtime::panic): panic at libboard_artiq/src/drtioaux_proto.rs:47:18
[     2.539669s] ERROR(runtime::panic): panic message: internal error: entered unreachable code
Core 0 panic at /nix/store/dnns0nll2554aa2g07mrq8mzj0ikjqkv-source/libconfig/src/lib.rs:89:16: filesystem can only be initialized once: ()
nested panic!

Out of bounds error

[     0.014336s]  INFO(szl): Simple Zynq Loader starting...
[     0.019542s] DEBUG(libboard_zynq::clocks::source): Set ARM_PLL to 2000000000 Hz
[     0.007034s] DEBUG(libboard_zynq::clocks::source): Set IO_PLL to 1000000000 Hz
[     0.016255s] DEBUG(libboard_zynq::clocks::source): Set DDR_PLL to 1066666666 Hz
[     0.023600s] DEBUG(libboard_zynq::ddr): DDR 3x/2x clocks: 533333328/355555552
[     0.025117s] DEBUG(libboard_zynq::ddr): DDR DCI clock: 10062892 Hz (divisors=2*53)
[     0.037000s] DEBUG(libboard_zynq::sdio): Reset SDIO!
[     0.037582s] DEBUG(libboard_zynq::sdio): Changing clock frequency to 400000
[     0.044528s]  INFO(szl): Card inserted. Mounting file system.
[     0.074161s] DEBUG(libboard_zynq::sdio): Changing clock frequency to 25000000
[     0.075661s] DEBUG(libboard_zynq::sdio::sd_card): Getting bus width
[     0.083876s] DEBUG(libboard_zynq::sdio::sd_card): 4 bit support
[     0.087796s] DEBUG(libboard_zynq::sdio::sd_card): Changing bus width
[     0.096000s] DEBUG(libboard_zynq::sdio): Set block size to 512
[     0.103378s] DEBUG(libconfig::sd_reader): Partition ID: C
[     0.106027s]  INFO(szl): Loading gateware
[     0.109534s] DEBUG(libconfig::bootgen): Partition header pointer = C80
[     0.117969s] DEBUG(libconfig::bootgen): Unencrypted length = C82EB
[     0.121995s] DEBUG(libconfig::bootgen): Partition start address: 9FC0
[     0.473528s] DEBUG(libboard_zynq::devc): Invalidate DCache for bitstream buffer
[     0.480514s] DEBUG(libboard_zynq::devc): Init preload FPGA
[     0.480652s] DEBUG(libboard_zynq::devc): Toggling PROG_B
[     0.511608s] DEBUG(libboard_zynq::devc): Waiting for done
[     0.511620s] DEBUG(libboard_zynq::devc): Init postload FPGA
[     0.516909s]  INFO(szl): Loading runtime
[     0.522954s] DEBUG(libconfig::bootgen): Partition header pointer = C80
[     0.527534s] DEBUG(libconfig::bootgen): Unencrypted length = 99F6
[     0.533402s] DEBUG(libconfig::bootgen): Unencrypted length = 66EA4
[     0.539563s] DEBUG(libconfig::bootgen): Partition start address: D22B0
[     0.728099s]  INFO(szl): Preparing for runt�+HH�� 0.000067s]  INFO(runtime): NAR3/Zynq7000 starting...
[     0.000130s]  INFO(runtime): gateware ident: 9+unknown;master
[     0.010518s]  INFO(libboard_zynq::i2c): PCA9548 detected
[     0.166595s]  INFO(runtime): log level set to INFO by default
[     0.167782s]  INFO(runtime): UART log level set to INFO by default
[     0.173950s]  INFO(runtime::rtio_clocking): bypassing the PLL for RTIO clock
[     0.393000s]  INFO(runtime::rtio_clocking): SYS CLK switched successfully
[     0.397162s]  INFO(libboard_artiq::drtio_eem): loading calibrated timing values from sd card
[     0.403615s] ERROR(libboard_artiq::drtio_eem): comma alignment failed, retrying in 1s...
[     1.411677s] ERROR(libboard_artiq::drtio_eem): comma alignment failed, retrying in 1s...
[     2.420358s]  INFO(libboard_zynq::i2c): PCA9548 detected
[     2.452072s]  INFO(runtime::comms): network addresses: MAC=e8-eb-1b-13-4a-43 IPv4=10.196.56.100 IPv6-LL=fe80::eaeb:1bff:fe13:4a43 IPv6: no configured address
[     2.474981s]  INFO(libboard_artiq::drtio_routing): could not read routing table from configuration, using default
[     2.479595s]  INFO(libboard_artiq::drtio_routing): routing table: RoutingTable { 0: 0; 1: 1 0; 2: 2 0; 3: 3 0; 4: 4 0; 5: 5 0; }
[     2.494230s]  INFO(runtime::rtio_mgt): SED spreading disabled by default
[     2.500278s]  INFO(runtime::rtio_mgt::drtio): [DEST#0] destination is up
[     2.504820s]  INFO(runtime::rtio_mgt::drtio): [LINK#4] link RX became up, pinging
[     2.515697s]  INFO(runtime::comms): no idle kernel found
Core 0 panic at /build/source/libboard_artiq/src/drtioaux_proto.rs:731:43: range end index 19676 out of range for slice of length 1010
Backtrace: 
0x14eba4 
End backtrace
[     2.532108s] ERROR(runtime::panic): panic at /build/source/libboard_artiq/src/drtioaux_proto.rs:731:43
[     2.541396s] ERROR(runtime::panic): panic message: range end index 19676 out of range for slice of length 1010
Core 0 panic at /nix/store/dnns0nll2554aa2g07mrq8mzj0ikjqkv-source/libconfig/src/lib.rs:89:16: filesystem can only be initialized once: ()
nested panic!

Edits to post:

fixed formatting

morgan

Hello, do you have a block diagram detailing how the clocks are connected to Kasli SoC and phaser with their respective frequency? As the phaser mtdds gateware variant now used drtio_over_eem and the clock requirement is different from the phaser classic gateware.

Guest

There is a 125MHz clock signal, which is split using a power splitter.
One output is used to clock the kasli-soc.
The other is used to clock the phaser through the external sma connector.

If the clock signal to the phaser is disconnected, then the UART log shows an infinite loop of comma alignment failures.
ERROR(libboard_artiq::drtio_eem): comma alignment failed, retrying in 1s...

nmak

The post above was me. I did not realise I was logged out.

morgan

Thanks for the information, in that case we need to recalibrate the eem_drtio_delay{n} value. We need to follow the Link recalibration section and remove the value in the same power cycle:

Power on the setup with two 125 MHz clock signal to SoC and Phaser respectively
Disconnect the 125 MHz signal to Phaser
Connect HS2 jtag to Phaser and run artiq_flash erase=storage -t phaser to erase the calibrated value
Power down the setup and remove the SD card from SoC
remove the eem_drtio_delay{n} line from the Config file in the SD card
Replug the SD card back in and let the system recalibrate and it should work.

Btw, as the Link recalibration section suggested, if the clock cable to Phaser is changed. the link will fail as the calibration value is no longer correct.

If the clock signal to the phaser is disconnected, then the UART log shows an infinite loop of comma alignment failures.
ERROR(libboard_artiq::drtio_eem): comma alignment failed, retrying in 1s...

This is expected as the mtdds gateware used the sma / mmcx clock instead of the internal oscillator. So without a proper clock signal, the phaser won't send any comma symbol and SoC cannot align serdes to the comma and keep spamming comma alignment failed, retrying in 1s... in the UART log.

Guest

Thanks morgan, following the instructions above fixed the issue.

I had seen this section on recalibrating an EEM link, but I mistakenly believed the eem_drtio_delay value was already deleted. I will briefly list why I thought this for others to see.

I tried to read the value of eem_drtio_delay{n} through artiq_coremgmt config read -s eem_drtio_delay7 and saw that the key did not exist raising OSError: Device failed to read config. The key may not exist. error from the frontent/artiq_coremgmt.py

Then trying to read artiq_coremgmt config read -s eem_drtio_delay0 gave no error, but just printed a newline character to the terminal.

However, after seeing your message above and checking the contents of CONFIG.txt in a hex editor, I can see some bytes after the = 0E 0D 0D 0F 0A.

ip=10.196.56.100
#ip=use_dhcp
rtio_clock=ext0_bypass
eem_drtio_delay0=>

<

I guess my mistake was twofold, first assuming that the correct key was eem_drtio_delay7 since the phaser was connected on port 7. Then assuming that the value of eem_drtio_delay0 was not set (since nothing was printed to the terminal).

nmak

A follow up question for future reference.

If I add a second phaser card to the kasli on port 0, then would I need to delete the calibrated values?
I am not sure how the kasli-soc would understand that eem_drtio_delay0 refers to the original phaser on port 7, and not the new phaser on port 0.

Secondly, assuming I do not change the clocking cables, would I also need to delete the value from the (original port 7) phaser card in such a situation.

morgan

If I add a second phaser card to the kasli on port 0, then would I need to delete the calibrated values?

It depends on the card order in the json file. As the n in eem_drtio_delay{n} means the nth drtio_over_eem cards. Let's say you added the second Phaser (port 0) entry after the first Phaser (port 7) in the json. The SoC will store the calibrated value for second Phaser (port 0) in eem_drtio_delay1.

I am not sure how the kasli-soc would understand that eem_drtio_delay0 refers to the original phaser on port 7, and not the new phaser on port 0.

The n actually represent the nth drtio_over_eem_transceiver in gateware or trx_no in firmware. In other words, n just depends on the order of the json (or data_pads to be specific) and there are little correlation between n and the eem port number.

Secondly, assuming I do not change the clocking cables, would I also need to delete the value from the (original port 7) phaser card in such a situation.

No, if you put the second Phaser (port 0) after the old Phaser (port 7) in the json. BTW the calibration value eem_drtio_delay{n} actually represent the phase relationship between Kasli SoC rtio clock and the Phaser rtio clock. That's why eem_drtio_delay0 is still valid in this case.

Btw, the above also applies when adding a Shuttler or Songbird to an existing setup. As they are both using drtio_over_eem to communicate with Kasli / Kasli SoC.

Hope that clears things up.