Error from uxm_setup: 'Timeout waiting for PVs to update'

[clessler]

When running uxm_setup, we get the following error (we've already tried jackhammering, which did not get rid of it):

---------------------------------------------------------------------------
Exception                                 Traceback (most recent call last)
Cell In [43], line 1
----> 1 uxm = uxm_setup(S, cfg, bands, show_plots=True, update_cfg=True, skip_setup_amps=True)

File /usr/local/src/pysmurf/python/pysmurf/client/util/pub.py:50, in set_action.<locals>.dec.<locals>.wrapper(S, pub_action, *args, **kwargs)
     46             S.pub._action = func.__name__
     48         S.pub._action_ts = S.get_timestamp()
---> 50     rv = func(S, *args, **kwargs)
     52 finally:
     53     if is_top:

File /sodetlib/sodetlib/operations/uxm_setup.py:484, in uxm_setup(S, cfg, bands, show_plots, update_cfg, modify_attens, skip_phase_delay, skip_setup_amps)
    482 summary['timestamps'].append(('setup_phase_delay', time.time()))
    483 sdl.set_session_data(S, 'timestamps', summary['timestamps'])
--> 484 success, summary['setup_phase_delay'] = setup_phase_delay(
    485     S, cfg, bands, update_cfg=update_cfg)
    486 if not success:
    487     S.log("UXM Setup failed on setup phase delay step")

File /usr/local/src/pysmurf/python/pysmurf/client/util/pub.py:50, in set_action.<locals>.dec.<locals>.wrapper(S, pub_action, *args, **kwargs)
     46             S.pub._action = func.__name__
     48         S.pub._action_ts = S.get_timestamp()
---> 50     rv = func(S, *args, **kwargs)
     52 finally:
     53     if is_top:

File /sodetlib/sodetlib/operations/uxm_setup.py:219, in setup_phase_delay(S, cfg, bands, update_cfg, modify_attens)
    213 for b in bands:
    214     #init_att_uc = S.get_att_uc(b)
    215     #init_att_dc = S.get_att_dc(b)
    216     #S.set_att_uc(b, 30)
    217     #S.set_att_dc(b, 30)
    218     summary['bands'].append(int(b))
--> 219     band_delay_us, _ = S.estimate_phase_delay(b, make_plot=True, show_plot=False)
    220     band_delay_us = float(band_delay_us)
    221     summary['band_delay_us'].append(band_delay_us)

File /usr/local/src/pysmurf/python/pysmurf/client/util/pub.py:50, in set_action.<locals>.dec.<locals>.wrapper(S, pub_action, *args, **kwargs)
     46             S.pub._action = func.__name__
     48         S.pub._action_ts = S.get_timestamp()
---> 50     rv = func(S, *args, **kwargs)
     52 finally:
     53     if is_top:

File /usr/local/src/pysmurf/python/pysmurf/client/util/smurf_util.py:290, in SmurfUtilMixin.estimate_phase_delay(self, band, nsamp, make_plot, show_plot, save_plot, save_data, n_scan, timestamp, uc_att, dc_att, freq_min, freq_max)
    287 self.flux_ramp_off()
    289 self.log('Running full band resp')
--> 290 freq_cable, resp_cable = self.full_band_resp(
    291     band, nsamp=nsamp, make_plot=make_plot,
    292     save_data=save_data, n_scan=n_scan)
    294 idx_cable = np.where( (freq_cable > freq_min) & (freq_cable < freq_max) )
    296 cable_z = np.polyfit(freq_cable[idx_cable], np.unwrap(np.angle(resp_cable[idx_cable])), 1)

File /usr/local/src/pysmurf/python/pysmurf/client/util/pub.py:50, in set_action.<locals>.dec.<locals>.wrapper(S, pub_action, *args, **kwargs)
     46             S.pub._action = func.__name__
     48         S.pub._action_ts = S.get_timestamp()
---> 50     rv = func(S, *args, **kwargs)
     52 finally:
     53     if is_top:

File /usr/local/src/pysmurf/python/pysmurf/client/tune/smurf_tune.py:645, in SmurfTuneMixin.full_band_resp(self, band, n_scan, nsamp, make_plot, save_plot, show_plot, save_data, timestamp, save_raw_data, correct_att, swap, hw_trigger, write_log, return_plot_path, check_if_adc_is_saturated)
    642 # if true, checks whether or not playing noise file saturates the ADC.
    643 #If ADC is saturated, throws an exception.
    644 if check_if_adc_is_saturated:
--> 645     adc_is_saturated = self.check_adc_saturation(band)
    646     if adc_is_saturated:
    647         raise ValueError('Playing the noise file saturates the '+
    648             f'ADC for band {band}.  Try increasing the DC '+
    649             'attenuation for this band.')

File /usr/local/src/pysmurf/python/pysmurf/client/util/pub.py:50, in set_action.<locals>.dec.<locals>.wrapper(S, pub_action, *args, **kwargs)
     46             S.pub._action = func.__name__
     48         S.pub._action_ts = S.get_timestamp()
---> 50     rv = func(S, *args, **kwargs)
     52 finally:
     53     if is_top:

File /usr/local/src/pysmurf/python/pysmurf/client/util/smurf_util.py:1488, in SmurfUtilMixin.check_adc_saturation(self, band)
   1473 @set_action()
   1474 def check_adc_saturation(self, band):
   1475     """
   1476     Reads data directly off the ADC.  Checks for input saturation.
   1477 
   (...)
   1486        True if ADC is saturated, otherwise False.
   1487     """
-> 1488     adc = self.read_adc_data(band, data_length=2**12, make_plot=False,
   1489               save_data=False, show_plot=False, save_plot=False)
   1490     adc_max   = int(np.max((adc.real.max(), adc.imag.max())))
   1491     adc_min   = int(np.min((adc.real.min(), adc.imag.min())))

File /usr/local/src/pysmurf/python/pysmurf/client/util/pub.py:50, in set_action.<locals>.dec.<locals>.wrapper(S, pub_action, *args, **kwargs)
     46             S.pub._action = func.__name__
     48         S.pub._action_ts = S.get_timestamp()
---> 50     rv = func(S, *args, **kwargs)
     52 finally:
     53     if is_top:

File /usr/local/src/pysmurf/python/pysmurf/client/util/smurf_util.py:1574, in SmurfUtilMixin.read_adc_data(self, band, data_length, hw_trigger, make_plot, save_data, timestamp, show_plot, save_plot, plot_ylimits)
   1570 adc_number=band%4
   1572 self.setup_daq_mux('adc', adc_number, data_length,band=band)
-> 1574 res = self.read_stream_data_daq(data_length, bay=bay,
   1575     hw_trigger=hw_trigger)
   1576 dat = res[1] + 1.j * res[0]
   1578 if make_plot:

File /usr/local/src/pysmurf/python/pysmurf/client/util/pub.py:50, in set_action.<locals>.dec.<locals>.wrapper(S, pub_action, *args, **kwargs)
     46             S.pub._action = func.__name__
     48         S.pub._action_ts = S.get_timestamp()
---> 50     rv = func(S, *args, **kwargs)
     52 finally:
     53     if is_top:

File /usr/local/src/pysmurf/python/pysmurf/client/util/smurf_util.py:1464, in SmurfUtilMixin.read_stream_data_daq(self, data_length, bay, hw_trigger, write_log)
   1461     self.set_arm_hw_trigger(bay, 1, write_log=write_log)
   1463 time.sleep(.1)
-> 1464 sg.wait()
   1466 vals = sg.get_values()
   1468 r0 = vals[pvs[0]]

File /usr/local/src/pysmurf/python/pysmurf/client/command/sync_group.py:69, in SyncGroup.wait(self, epics_poll)
     67     time.sleep(.001)
     68 if time.time() - t0 > self.timeout:
---> 69     raise Exception('Timeout waiting for PVs to update.')

Exception: Timeout waiting for PVs to update.

Anyone have suggestions or experience as to what could be causing this? Also, what are PVs?

[msilvafe]

PV stands for Process Variable. Under the hood pysmurf is setting a series of firmware registers on the FPGA which are managed/exposed by the "EPICS" software. So basically "timeout waiting for PVs to update" means that pysmurf tried to set one of these registers and then query it to confirm that it changed to the expected value and it timed out waiting. This often indicates a communication issue between the smurf blade and the server. Is this a new blade? Are you connecting via fiber or over the ethernet connection? If over fiber can you query the status of the vadatech switch to confirm that the fiber link shows up between the PCIe card and switch?

[jlashner]

Hi! So this is a known issue where estimate_phase_delay sometimes fails with this error. Unfortunately the solution in the past has generally been to keep trying until it works.... Instead of running uxm_setup in its entirety, I will run the uxm_setup.setup_phase_delay function on its own, and if it fails at band 4, I will re-run that function for bands 4 onward. After it has run once for all bands the values will be stored in the device config, and you should not really need to run this again for the duration of the cooldown, hence why it's been a low priority fix.

Once it has run successfully for all bands, you can continue running uxm_setup with skip_phase_delay=True, or manually run through remaining setup steps.

If you are consistently unable to get through any of the bands when running setup_phase_delay, then this indicates a communication or fiber issue like Max mentioned.

[clessler]

Update: this seems to be fixed after another hammer. Thanks all!

[jlashner]

Nice! For the future though, I think hammering should not effect this particular problem and it's possible this was just fixed by retrying enough times.

[clessler]

Noted. Thanks for the info.