Versions Compared

Key

  • This line was added.
  • This line was removed.
  • Formatting was changed.

...

dstat can show the IRQ rate (interrupts/sec), here for an idle system with 2 datadev devices:

claus@drp-srcf-cmp005:~$ dstat -tiy -I 369,370 10
----system---- -interrupts ---system--
     time     | 369   370 | int   csw
10-02 13:23:45| 101   101 |3699  5985
10-02 13:23:55| 100   100 |3807  6088

With IRQ Hold / cfgIrqHold set to 10000, the IRQ rate is seen to not exceed be around 22.4 KHz for datadev devices.

HSD

  • look at configured parameters using (for example) "hsdpva DAQ:LAB2:HSD:DEV06_3D:A"
  • for kcu firmware that is built to use both QSFP links, the naming of the qsfp's is swapped.  i.e. the qsfp that is normally called /dev/datadev_0 is now called /dev/datadev_1
  • HSD is not configured to do anything (Check the HSD config tab for no channels enabled)
  • if hsd timing frames are not being received at 929kHz (status here), click TxLink Reset in XPM window.  Typically when this is an issue the receiving rate is ~20kHz.
  • The HSD readoutGroup number does not match platform number in .cnf file (Check the HSD "Config" tab)
  • also check that HEADERCNTL0 is incrementing in "Timing" tab of HSD cfg window.
  • in hsd Timing tab timpausecnt is number of clocks we are dead
  • in hsd expert window "full threshold(events)" sets threshold for hsd deadtime
  • in hsd Buffer tab "fex free events" and "raw free events" are the current free events.
  • in hsd status window "write fifo count" is number of timing headers waiting for HSD data to associate.
  • "readcntsum" on hsd timing tab goes up when we send a transition OR L1Accepts. "trigcntsum" counts L1Accepts only.
  • check kcuStatus for "locPause" non-zero (a low level pgp FIFO being full).  If this happens then:  configure hsd, clear readout, reboot drp node with KCU

update on variables in hsdpva gui from Matt (06/05/2020):

  • timing tab
    • timpausecnt (clock ticks of dead time)
    • trigcnt: triggers over last second
    • trigcntsum: total l1accept
    • readcntsum: number of events readout total
    • msgdelayset: (units: mhz clock ticks) should be 98 or 99 (there is an "off by one" in the epics variable, and what the hsd sees).  if too short, trigger decision is made too early, and there isn't enough buffering in hsd (breaks the buffer model)
    • headercntof: should always be zero (ben's module).  non-zero indicates that too many l1accepts have been sent and we've overwritten the available buffering
    • headercntl0: sum of number of headers received by ben's module.
    • headerfifor: the watermark for when ben's stuff asserts dead time
    • fulltotrig/nfulltotrig:  counters to determine the round trip time from sending an event to getting back the full signal (depends on fiber lengths, for example).  nfulltotrig is same thing but with opposite logic.
  • pgp tab
    • loclinkrdy/remlinkrdy should be ready
    • tx/rx clk frequencies should be 156.
    • txcnt: counts per second of things being send, but only 16 bits so doesn't really display right value
    • txcntsum is transitions and l1accepts (only 16 bits so rolls over frequently)
  • buffers tab
    • freesz: units of rows of adc readout (40samples*2bytes).
    • freeevt: number of free events.  if they go below thresholds set in config tab: dead time.
  • flow tab
    • fmask: bit mask of streams remaining to contribute to event
    • fcurr: current stream being read
    • frdy: bit mask of streams ready to be read
    • srdy: downstream slave (byte packer) is ready
    • mrdy: b0 is master valid assert, b1 is PGP transmit queue (downstream of byte packer) ready
    • rdaddr: current stream cache read pointer
    • npend: next buffer to write
    • ntrig: next buffer to trigger
    • nread: next buffer to read
    • pkoflow: overflow count in byte packer
    • oflow: current stream cache write pointer

On Nov. 18, 2020 saw a failure mode where hsd_4 did not respond on configure phase 2.  Matt tracked this down to the fact that the kcu→hsd links weren't locked (visible with "kcuStatus" and "hsdpva").  Note that kcuStatus is currently not an installed binary: has to be run from the build area.  This was caused by the fact that we were only running one-half of a pair of hsd's, and the other half is responsible for setting the clock frequencies on the kcu, which is required for link-lock.  We set the clock frequencies by hand running "kcuStatus -I" (I for Initialize, I guess) on the drp node.  Matt is thinking about a more robust solution.

When we attempted to test the DAQ in SRCF with a couple of HSDs, we initially had trouble getting phase 2 of transitions through.  The two "sides" 1_DA:A and B behaved differently with pgpread.  Sometimes some events came through one side but not the other, but with significant delay from when the groupca Events tab Run box was checked and not when the transition buttons were clicked.  Also some of the entries in hsdpva's tabs were odd (Buffers:raw:freesz reset to 65535 for one, 4094 for the other).  Some work had been done on the PV gateway.  hsdioc on daq-tmo-hsd-01 had been restarted and got into a bad state.  Restarting it again cleared up the problem.

BUG: Soft lockup messages

If there is significant deadtime coming from an HSD pair when running at high rate and 'kernel:NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [swapper/0:0]' messages appear in dmesg, etc., it may be that the interrupts are being handled for both datadev devices by one core, usually CPU0.  To avoid this, the interrupt handling can be moved to two different cores, e.g. CPU4 and 5.  First, disable the irqbalance service:

sudo systemctl stop irqbalance

Then set the IRQ affinity values, e.g.:

sudo sh -c "echo 4 > /proc/irq/369/smp_affinity_list"
sudo sh -c "echo 5 > /proc/irq/370/smp_affinity_list"

For a more permanent solution, it may be better to modify /etc/sysconfig/irqbalance to avoid the datadev's IRQs:

IRQBALANCE_ARGS=--banirq=369 --banirq=370

Add the following to the kcu or tdetsim service file, e.g.:

ExecStartPost=/usr/bin/sh -c "/usr/bin/echo 4 > /proc/irq/369/smp_affinity_list"
ExecStartPost=/usr/bin/sh -c "/usr/bin/echo 5 > /proc/irq/370/smp_affinity_list"

KHz at a trigger rate of 71 KHz.

Note that the datadev driver can handle multiple buffers (O(1000)) per interrupt, so the IRQ rate tends to fall well below the rate set by the IRQ HOLD / cfgIrqHold value at high trigger rates.  At 1 MHz trigger rate, the IRQ rate is a few hundred Hz.

'BUG: Soft lockup' messages

If there is significant deadtime coming from a node hosting multiple DRPs at high trigger rate and kernel:NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [swapper/0:0] messages appear in dmesg, etc., it may be that the interrupts are being handled for both datadev devices by one core, usually CPU0.  To avoid this, the interrupt handling can be moved to two different cores, e.g. CPU4 and 5 (to avoid the Weka cores).  First, disable the irqbalance service and then set the IRQ affinity values (here datadev IRQs 369 and 370, as found from dmesg):

sudo sh -c "echo 4 > /proc/irq/369/smp_affinity_list"
sudo sh -c "echo 5 > /proc/irq/370/smp_affinity_list"

For a more permanent solution, it may be better to modify /etc/sysconfig/irqbalance to avoid the datadev's IRQs:

IRQBALANCE_ARGS=--banirq=369 --banirq=370

Add the following to the kcu or tdetsim service file, e.g.:

ExecStartPost=/usr/bin/sh -c "/usr/bin/echo 4 > /proc/irq/369/smp_affinity_list"
ExecStartPost=/usr/bin/sh -c "/usr/bin/echo 5 > /proc/irq/370/smp_affinity_list"

Note that since nothing sets the datadev's IRQ numbers to any particular value (as far as I can tell), we may need to consider the possibility that they can change from system (or driver?) restart to restart or be different from node to node.  However, I've seen no evidence that this is the case.

HSD

  • look at configured parameters using (for example) "hsdpva DAQ:LAB2:HSD:DEV06_3D:A"
  • for kcu firmware that is built to use both QSFP links, the naming of the qsfp's is swapped.  i.e. the qsfp that is normally called /dev/datadev_0 is now called /dev/datadev_1
  • HSD is not configured to do anything (Check the HSD config tab for no channels enabled)
  • if hsd timing frames are not being received at 929kHz (status here), click TxLink Reset in XPM window.  Typically when this is an issue the receiving rate is ~20kHz.
  • The HSD readoutGroup number does not match platform number in .cnf file (Check the HSD "Config" tab)
  • also check that HEADERCNTL0 is incrementing in "Timing" tab of HSD cfg window.
  • in hsd Timing tab timpausecnt is number of clocks we are dead
  • in hsd expert window "full threshold(events)" sets threshold for hsd deadtime
  • in hsd Buffer tab "fex free events" and "raw free events" are the current free events.
  • in hsd status window "write fifo count" is number of timing headers waiting for HSD data to associate.
  • "readcntsum" on hsd timing tab goes up when we send a transition OR L1Accepts. "trigcntsum" counts L1Accepts only.
  • check kcuStatus for "locPause" non-zero (a low level pgp FIFO being full).  If this happens then:  configure hsd, clear readout, reboot drp node with KCU

update on variables in hsdpva gui from Matt (06/05/2020):

  • timing tab
    • timpausecnt (clock ticks of dead time)
    • trigcnt: triggers over last second
    • trigcntsum: total l1accept
    • readcntsum: number of events readout total
    • msgdelayset: (units: mhz clock ticks) should be 98 or 99 (there is an "off by one" in the epics variable, and what the hsd sees).  if too short, trigger decision is made too early, and there isn't enough buffering in hsd (breaks the buffer model)
    • headercntof: should always be zero (ben's module).  non-zero indicates that too many l1accepts have been sent and we've overwritten the available buffering
    • headercntl0: sum of number of headers received by ben's module.
    • headerfifor: the watermark for when ben's stuff asserts dead time
    • fulltotrig/nfulltotrig:  counters to determine the round trip time from sending an event to getting back the full signal (depends on fiber lengths, for example).  nfulltotrig is same thing but with opposite logic.
  • pgp tab
    • loclinkrdy/remlinkrdy should be ready
    • tx/rx clk frequencies should be 156.
    • txcnt: counts per second of things being send, but only 16 bits so doesn't really display right value
    • txcntsum is transitions and l1accepts (only 16 bits so rolls over frequently)
  • buffers tab
    • freesz: units of rows of adc readout (40samples*2bytes).
    • freeevt: number of free events.  if they go below thresholds set in config tab: dead time.
  • flow tab
    • fmask: bit mask of streams remaining to contribute to event
    • fcurr: current stream being read
    • frdy: bit mask of streams ready to be read
    • srdy: downstream slave (byte packer) is ready
    • mrdy: b0 is master valid assert, b1 is PGP transmit queue (downstream of byte packer) ready
    • rdaddr: current stream cache read pointer
    • npend: next buffer to write
    • ntrig: next buffer to trigger
    • nread: next buffer to read
    • pkoflow: overflow count in byte packer
    • oflow: current stream cache write pointer

On Nov. 18, 2020 saw a failure mode where hsd_4 did not respond on configure phase 2.  Matt tracked this down to the fact that the kcu→hsd links weren't locked (visible with "kcuStatus" and "hsdpva").  Note that kcuStatus is currently not an installed binary: has to be run from the build area.  This was caused by the fact that we were only running one-half of a pair of hsd's, and the other half is responsible for setting the clock frequencies on the kcu, which is required for link-lock.  We set the clock frequencies by hand running "kcuStatus -I" (I for Initialize, I guess) on the drp node.  Matt is thinking about a more robust solution.

When we attempted to test the DAQ in SRCF with a couple of HSDs, we initially had trouble getting phase 2 of transitions through.  The two "sides" 1_DA:A and B behaved differently with pgpread.  Sometimes some events came through one side but not the other, but with significant delay from when the groupca Events tab Run box was checked and not when the transition buttons were clicked.  Also some of the entries in hsdpva's tabs were odd (Buffers:raw:freesz reset to 65535 for one, 4094 for the other).  Some work had been done on the PV gateway.  hsdioc on daq-tmo-hsd-01 had been restarted and got into a bad state.  Restarting it again cleared up the problemNote that since nothing sets the datadev's IRQ numbers to any particular value (as far as I can tell), we may need to consider the possibility that they can change from system (or driver?) restart to restart or be different from node to node.  However, I've seen no evidence that this is the case.

Cable Swaps

hsd cables can be plugged into the wrong place (e.g. "pairs" can be swapped).  They must match the mapping documentation Matt has placed at the bottom of hsd.cnf (which is reflected in the lines in hsd.cnf that start up processes, making sure those are consistent is a manual process).  Matt has the usual "remote link id" pattern that can be used to check this, by using "kcuStatus" on the KCU end and "hsdpva" on the other end. e.g.

...