jesd: add in detailed error reporting for JESD204b links

 - add version control checks and bump to match latest core
 - add detailed mykonos reporting
 - add detailed fpga deframer reporting
 - misc cleanup

Reviewed-by: Ashish Chaudhari <ashish.chaudhari@ettus.com>
Reviewed-by: Martin Braun <martin.braun@ettus.com>

2 files changed, 164 insertions, 50 deletions

diff --git a/mpm/python/usrp_mpm/cores/nijesdcore.py b/mpm/python/usrp_mpm/cores/nijesdcore.py
index 384263b90..1cde45619 100644
--- a/mpm/python/usrp_mpm/cores/nijesdcore.py
+++ b/mpm/python/usrp_mpm/cores/nijesdcore.py
@@ -36,35 +36,56 @@ class NIMgJESDCore(object):
     SYSREF_CAPTURE_CONTROL     = 0x2078
     JESD_SIGNATURE_REG         = 0x2100
     JESD_REVISION_REG          = 0x2104
+    JESD_OLD_COMPAT_REV_REG    = 0x2108
 
 
     def __init__(self, regs, slot_idx=0):
         self.regs = regs
-        self.log = get_logger("NIMgJESDCore-{}".format(slot_idx))
+        self.log = get_logger("NIJESD204bCore-{}".format(slot_idx))
         assert hasattr(self.regs, 'peek32')
         assert hasattr(self.regs, 'poke32')
         # FutureWork: The following are constants for the Magnesium board. These need
         # to change to variables to support other interfaces.
         self.qplls_used = 1
         self.cplls_used = 0
-        # Number of FPGA clock cycles per LMFC period.
-        self.lmfc_divider = 20
-
-    def unreset_qpll(self):
-        # new_val = self.regs.peek32(0x0) & ~0x8
-        # self.log.trace("Unresetting MMCM, writing value {:X}".format(new_val))
-        self.regs.poke32(0x0, 0x7)
+        self.rx_lanes = 4
+        self.tx_lanes = 4
+        self.bypass_descrambler = True
+        self.bypass_scrambler = True
+        self.lmfc_divider = 20 # Number of FPGA clock cycles per LMFC period.
+        self.tx_driver_swing = 0b1111 # See UG476, TXDIFFCTRL
+        self.tx_precursor = 0b00000 # See UG476, TXPRECURSOR
+        self.tx_postcursor = 0b00000 # See UG476, TXPOSTCURSOR
+        # Bump this whenever we stop supporting older FPGA images or boards.
+        # YYMMDDHH
+        self.oldest_compat_version = 0x17122214
+        # Bump this whenever changes are made to the host code.
+        self.current_version = 0x17122214
 
     def check_core(self):
         """
-        Verify JESD core returns correct ID
+        Verify JESD core returns correct ID and passes revision tests.
         """
         self.log.trace("Checking JESD Core...")
         if self.regs.peek32(self.JESD_SIGNATURE_REG) != 0x4A455344:
-            raise Exception('JESD Core signature mismatch! Check that core is mapped correctly')
-        #if self.regs.peek32(JESD_REVISION_REG) != 0xFF
-        #error here for date revision mismatch
-        self.log.trace("JESD Core build code: {0}".format(hex(self.regs.peek32(self.JESD_REVISION_REG))))
+            raise RuntimeError('JESD Core signature mismatch! Check that core is mapped correctly')
+        # Two revision checks are needed:
+        #   FPGA Current Rev >= Host Oldest Compatible Rev
+        #   Host Current Rev >= FPGA Oldest Compatible Rev
+        fpga_current_revision    = self.regs.peek32(self.JESD_REVISION_REG) & 0xFFFFFFFF
+        fpga_old_compat_revision = self.regs.peek32(self.JESD_OLD_COMPAT_REV_REG) & 0xFFFFFFFF
+        if fpga_current_revision < self.oldest_compat_version:
+            self.log.error("Revision check failed! MPM oldest supported revision "
+                           "(0x{:08X}) is too new for this FPGA revision (0x{:08X})."
+                           .format(self.oldest_compat_version, fpga_current_revision))
+            raise RuntimeError('This MPM version does not support the loaded FPGA image. Please update images!')
+        if self.current_version < fpga_old_compat_revision:
+            self.log.error("Revision check failed! FPGA oldest compatible revision "
+                           "(0x{:08X}) is too new for this MPM version (0x{:08X})."
+                           .format(fpga_current_revision, self.current_version))
+            raise RuntimeError('The loaded FPGA version is too new for MPM. Please update MPM!')
+        self.log.trace("JESD Core current revision: 0x{:08X}".format(fpga_current_revision))
+        self.log.trace("JESD Core oldest compatible revision: 0x{:08X}".format(fpga_old_compat_revision))
         self.log.trace("DB Slot #: {}".format( (self.regs.peek32(self.DB_ID) & 0x10000) >> 16  ))
         self.log.trace("DB PID: {:X}" .format(  self.regs.peek32(self.DB_ID) & 0xFFFF ))
         return True
@@ -84,29 +105,36 @@ class NIMgJESDCore(object):
     def init_deframer(self):
         " Initialize deframer "
         self.log.trace("Initializing deframer...")
+        # Force ADC SYNC_n to asserted, telling the transmitter to start (or stay in) CGS.
         self.regs.poke32(self.MGT_RECEIVER_CONTROL, 0x2)
-        self.regs.poke32(self.MGT_RX_DESCRAMBLER_CONTROL, 0x0)
+        # De-scrambler setup.
+        reg_val = {True: 0x1, False: 0x0}[self.bypass_descrambler]
+        self.regs.poke32(self.MGT_RX_DESCRAMBLER_CONTROL, reg_val)
         self._gt_reset('rx', reset_only=False)
+        # Remove forced SYNC_n assertion to allow link to connect normally.
         self.regs.poke32(self.MGT_RECEIVER_CONTROL, 0x0)
 
-    def init_framer(self, bypass_scrambler = True):
+    def init_framer(self):
         " Initialize framer "
         self.log.trace("Initializing framer...")
         # Disable DAC Sync from requesting CGS & Stop Deframer
         self.regs.poke32(self.MGT_TRANSMITTER_CONTROL, (0b1 << 13) | (0b1 << 1))
         # Reset, unreset, and check the GTs
         self._gt_reset('tx', reset_only=False)
-        # MGT phy control... enable TX Driver Swing
-        self.regs.poke32(self.MGT_TX_TRANSCEIVER_CONTROL, 0xF0000)
+        # MGT TX PHY control.
+        reg_val = ((self.tx_driver_swing & 0x0F) << 16) | \
+                  ((self.tx_precursor    & 0x1F) <<  8) | \
+                  ((self.tx_postcursor   & 0x1F) <<  0)
+        self.regs.poke32(self.MGT_TX_TRANSCEIVER_CONTROL, reg_val)
         time.sleep(0.001)
         # Bypass scrambler and char replacement. If the scrambler is bypassed,
         # then the char replacement is also disabled.
-        reg_val = {True: 0x01, False: 0x10}[bypass_scrambler]
+        reg_val = {True: 0x01, False: 0x10}[self.bypass_scrambler]
         self.regs.poke32(self.MGT_TX_SCRAMBLER_CONTROL, reg_val)
         # Check for Framer in Idle state
         rb = self.regs.peek32(self.MGT_TRANSMITTER_CONTROL)
         if rb & 0x100 != 0x100:
-            raise Exception('TX Framer is not idle after reset')
+            raise RuntimeError('TX Framer is not idle after reset')
         # Enable incoming DAC Sync
         self.regs.poke32(self.MGT_TRANSMITTER_CONTROL, 0b1 << 12)
         # Enable the framer
@@ -124,17 +152,42 @@ class NIMgJESDCore(object):
             self.log.warning("Framer warning: Lane Alignment failed to complete!")
         return rb & 0xFF0 == 0x6C0
 
-    def get_deframer_status(self):
+    def get_deframer_status(self, ignore_sysref=False):
         " Return True if deframer is in good status "
-        rb = self.regs.peek32(self.MGT_RECEIVER_CONTROL)
-        self.log.trace("FPGA Deframer status: {0}".format(hex(rb & 0xFFFFFFFF)))
-        if rb & (0b1 << 2) == 0b0 << 2:
+        rb = self.regs.peek32(self.MGT_RECEIVER_CONTROL) & 0xFFFFFFFF
+        self.log.trace("FPGA Deframer Status Readback: {0}".format(hex(rb)))
+        cgs_pass     =  (rb & (0b1 <<  2)) > 0
+        ila_pass     =  (rb & (0b1 <<  3)) > 0
+        sys_ref_pass = ((rb & (0b1 <<  5)) > 0) | ignore_sysref
+        mgt_pass     =  (rb & (0b1 << 21)) == 0
+
+        if not sys_ref_pass:
+            self.log.warning("Deframer warning: SYSREF not received!")
+        elif not cgs_pass:
             self.log.warning("Deframer warning: Code Group Sync failed to complete!")
-        elif rb & (0b1 <<  3) == 0b0 << 3:
+            for lane in range(self.rx_lanes):
+                if (rb & (0b1 << (24+lane))) == 0:
+                    self.log.warning("Deframer warning: Lane {0} failed CGS!".format(lane))
+        elif not ila_pass:
             self.log.warning("Deframer warning: Channel Bonding failed to complete!")
-        elif rb & (0b1 << 21) == 0b1 << 21:
-            self.log.warning("Deframer warning: Misc link error!")
-        return rb & 0xFFFFFFFF == 0xF000001C
+            for lane in range(self.rx_lanes):
+                if (rb & (0b1 << (28+lane))) == 0:
+                    self.log.warning("Deframer warning: Lane {0} failed ILA!".format(lane))
+        elif not mgt_pass:
+            self.log.warning("Deframer warning, Misc Link Error!")
+            # Specific sticky bits for link errors. The only way to clear these is to
+            # issue the RX MGT reset.
+            link_disparity    = (rb & (0b1 << 16)) > 0
+            link_not_in_table = (rb & (0b1 << 17)) > 0
+            link_misalignment = (rb & (0b1 << 18)) > 0
+            adc_cgs_request   = (rb & (0b1 << 19)) > 0
+            unexpected_k_char = (rb & (0b1 << 20)) > 0
+            self.log.warning("Deframer warning, Link Disparity Error: {}".format(link_disparity))
+            self.log.warning("Deframer warning, Link Not In Table Error: {}".format(link_not_in_table))
+            self.log.warning("Deframer warning, Link Misalignment Error: {}".format(link_misalignment))
+            self.log.warning("Deframer warning, Link ADC CGS Request Error: {}".format(adc_cgs_request))
+            self.log.warning("Deframer warning, Link Unexpected K Char Error: {}".format(unexpected_k_char))
+        return cgs_pass & ila_pass & sys_ref_pass & mgt_pass
 
     def init(self):
         """
@@ -183,7 +236,7 @@ class NIMgJESDCore(object):
                     self.log.trace("%s MGT Reset Cleared!" % tx_or_rx.upper())
                     return True
                 time.sleep(0.001)
-            raise Exception('Timeout in GT {trx} Reset (Readback: 0x{rb:X})'.format(
+            raise RuntimeError('Timeout in GT {trx} Reset (Readback: 0x{rb:X})'.format(
                 trx=tx_or_rx.upper(),
                 rb=(rb & 0xFFFF0000),
             ))
@@ -251,7 +304,7 @@ class NIMgJESDCore(object):
                  locked_val = locked_val | 0x2 << nibble*4
                  rb_mask    = rb_mask    | 0xF << nibble*4
               if (rb & rb_mask) != locked_val:
-                  raise Exception("One or more GT QPLLs failed to lock!")
+                  raise RuntimeError("One or more GT QPLLs failed to lock!")
               self.log.trace("QPLL(s) reporting locked!")
 
     def set_drp_target(self, mgt_or_qpll, dev_num):
@@ -293,7 +346,7 @@ class NIMgJESDCore(object):
         # Check the DRP port is not busy.
         if (self.regs.peek32(self.JESD_MGT_DRP_CONTROL) & (0b1 << 20)) != 0:
             self.log.error("MGT/QPLL DRP Port is reporting busy during an attempted access.")
-            raise Exception("MGT/QPLL DRP Port is reporting busy during an attempted access.")
+            raise RuntimeError("MGT/QPLL DRP Port is reporting busy during an attempted access.")
 
         # Access the DRP registers...
         rd_data = 0x0
diff --git a/mpm/python/usrp_mpm/dboard_manager/magnesium.py b/mpm/python/usrp_mpm/dboard_manager/magnesium.py
index b6743cdc0..80e058597 100644
--- a/mpm/python/usrp_mpm/dboard_manager/magnesium.py
+++ b/mpm/python/usrp_mpm/dboard_manager/magnesium.py
@@ -641,7 +641,7 @@ class Magnesium(DboardManagerBase):
         self.log.trace("Starting JESD204b Link Initialization...")
         # Generally, enable the source before the sink. Start with the DAC side.
         self.log.trace("Starting FPGA framer...")
-        jesdcore.init_framer(bypass_scrambler=True)
+        jesdcore.init_framer()
         self.log.trace("Starting Mykonos deframer...")
         self.mykonos.start_jesd_rx()
         # Now for the ADC link. Note that the Mykonos framer will not start issuing CGS
@@ -652,35 +652,96 @@ class Magnesium(DboardManagerBase):
         self.mykonos.start_jesd_tx()
         jesdcore.enable_lmfc(True)
         jesdcore.send_sysref_pulse()
+        # Allow a bit of time for SYSREF to reach Mykonos and then CGS to appear. In
+        # several experiments this time requirement was only in the 100s of nanoseconds.
+        time.sleep(0.001)
         self.log.trace("Starting FPGA deframer...")
         jesdcore.init_deframer()
 
         # Allow a bit of time for CGS/ILA to complete.
         time.sleep(0.100)
-
-        for attempt in range(5):
-            if not jesdcore.get_deframer_status():
-                self.log.warning("FPGA Deframer Error! Re-starting FPGA deframer (attempt {}/5)...".format(attempt+1))
-                jesdcore.init_deframer()
-            else:
-                break
-
+        error_flag = False
         if not jesdcore.get_framer_status():
-            self.log.error("FPGA Framer Error!")
-            raise Exception('JESD Core Framer is not synced!')
-        if (self.mykonos.get_deframer_status() & 0x7F) != 0x28:
-            self.log.error("Mykonos Deframer Error: 0x{:X}".format((self.mykonos.get_deframer_status() & 0x7F)))
-            raise Exception('Mykonos Deframer is not synced!')
+            self.log.error("JESD204b FPGA Core Framer is not synced!")
+            error_flag = True
+        if not self.check_mykonos_deframer_status():
+            self.log.error("Mykonos JESD204b Deframer is not synced!")
+            error_flag = True
         if not jesdcore.get_deframer_status():
-            self.log.error("FPGA Deframer Error!")
-            raise Exception('JESD Core Deframer is not synced, even after 5 attempts!')
-        if (self.mykonos.get_framer_status() & 0x3F) != 0x3E:
-            self.log.error("Mykonos Framer Error: 0x{:X}".format((self.mykonos.get_framer_status() & 0xFF)))
-            raise Exception('Mykonos Framer is not synced!')
+            self.log.error("JESD204b FPGA Core Deframer is not synced!")
+            error_flag = True
+        if not self.check_mykonos_framer_status():
+            self.log.error("Mykonos JESD204b Framer is not synced!")
+            error_flag = True
         if (self.mykonos.get_multichip_sync_status() & 0xB) != 0xB:
-            raise Exception('Mykonos multi chip sync failed!')
+            self.log.error("Mykonos Multi-chip Sync failed!")
+            error_flag = True
+        if error_flag:
+            raise RuntimeError('JESD204B Link Initialization Failed. See MPM logs for details.')
         self.log.info("JESD204B Link Initialization & Training Complete")
 
+    def check_mykonos_framer_status(self):
+        " Return True if Mykonos Framer is in good state "
+        rb = self.mykonos.get_framer_status()
+        self.log.trace("Mykonos Framer Status Register: 0x{:04X}".format(rb & 0xFF))
+        tx_state =   {0: 'CGS',
+                      1: 'ILAS',
+                      2: 'ADC Data'}[rb & 0b11]
+        ilas_state = {0: 'CGS',
+                      1: '1st Multframe',
+                      2: '2nd Multframe',
+                      3: '3rd Multframe',
+                      4: '4th Multframe',
+                      5: 'Last Multframe',
+                      6: 'invalid state',
+                      7: 'ILAS Complete'}[(rb & 0b11100) >> 2]
+        sysref_rx =              (rb & (0b1 << 5)) > 0
+        fifo_ptr_delta_changed = (rb & (0b1 << 6)) > 0
+        sysref_phase_error =     (rb & (0b1 << 7)) > 0
+        # According to emails with ADI, fifo_ptr_delta_changed may be buggy.
+        # Deterministic latency is still achieved even when this bit is toggled, so
+        # ADI's recommendation is to ignore it. The expected state of this bit 0, but
+        # occasionally it toggles to 1. It is unclear why exactly this happens.
+        success = ((tx_state == 'ADC Data') &
+                   (ilas_state == 'ILAS Complete') &
+                   sysref_rx &
+                   (not sysref_phase_error))
+        logger = self.log.trace if success else self.log.warning
+        logger("Mykonos Framer, TX State: %s", tx_state)
+        logger("Mykonos Framer, ILAS State: %s", ilas_state)
+        logger("Mykonos Framer, SYSREF Received: {}".format(sysref_rx))
+        logger("Mykonos Framer, FIFO Ptr Delta Change: {} (ignored, possibly buggy)".format(fifo_ptr_delta_changed))
+        logger("Mykonos Framer, SYSREF Phase Error: {}".format(sysref_phase_error))
+        return success
+
+    def check_mykonos_deframer_status(self):
+        " Return True if Mykonos Deframer is in good state "
+        rb = self.mykonos.get_deframer_status()
+        self.log.trace("Mykonos Deframer Status Register: 0x{:04X}".format(rb & 0xFF))
+
+        frame_symbol_error =  (rb & (0b1 << 0)) > 0
+        ilas_multifrm_error = (rb & (0b1 << 1)) > 0
+        ilas_framing_error =  (rb & (0b1 << 2)) > 0
+        ilas_checksum_valid = (rb & (0b1 << 3)) > 0
+        prbs_error =          (rb & (0b1 << 4)) > 0
+        sysref_received =     (rb & (0b1 << 5)) > 0
+        deframer_irq =        (rb & (0b1 << 6)) > 0
+        success = ((not frame_symbol_error) &
+                   (not ilas_multifrm_error) &
+                   (not ilas_framing_error) &
+                   ilas_checksum_valid &
+                   (not prbs_error) &
+                   sysref_received &
+                   (not deframer_irq))
+        logger = self.log.trace if success else self.log.warning
+        logger("Mykonos Deframer, Frame Symbol Error: {}".format(frame_symbol_error))
+        logger("Mykonos Deframer, ILAS Multiframe Error: {}".format(ilas_multifrm_error))
+        logger("Mykonos Deframer, ILAS Frame Error: {}".format(ilas_framing_error))
+        logger("Mykonos Deframer, ILAS Checksum Valid: {}".format(ilas_checksum_valid))
+        logger("Mykonos Deframer, PRBS Error: {}".format(prbs_error))
+        logger("Mykonos Deframer, SYSREF Received: {}".format(sysref_received))
+        logger("Mykonos Deframer, Deframer IRQ Received: {}".format(deframer_irq))
+        return success
 
     def set_jesd_rate(self, jesdcore, new_rate, force=False):
         """