APS-USAXS / usaxs-bluesky-ended-2023

Bluesky instrument for USAXS
0 stars 0 forks source link

PV timeout #553

Closed jilavsky closed 2 years ago

jilavsky commented 2 years ago

Started BS testing again, cannot even do preUSAXStune:

usaxs@usaxscontrol .../USAXS_data/2022-02 $ blueskyUSAXS 
Python 3.9.7 (default, Sep 16 2021, 13:09:58) 
Type 'copyright', 'credits' or 'license' for more information
IPython 7.29.0 -- An enhanced Interactive Python. Type '?' for help.

IPython profile: bluesky
Exception reporting mode: Minimal
Activating auto-logging. Current session state plus future input saved.
Filename       : /share1/USAXS_data/2022-02/.logs/ipython_console.log
Mode           : rotate
Output logging : True
Raw input log  : False
Timestamping   : True
State          : active
I Sun-11:53:38 - ############################################################ startup
I Sun-11:53:38 - logging started
I Sun-11:53:38 - logging level = 10
I Sun-11:53:38 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/collection.py
I Sun-11:53:38 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/mpl/console.py
I Sun-11:53:40 - bluesky framework
I Sun-11:53:40 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/framework/check_python.py
I Sun-11:53:41 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/framework/initialize.py
I Sun-11:53:44 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/framework/user_dir.py
I Sun-11:53:44 - User code directory: /home/beams/USAXS/.ipython/user
I Sun-11:53:44 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/framework/metadata.py
I Sun-11:53:45 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/framework/callbacks.py
I Sun-11:53:45 - writing to SPEC file: /share1/USAXS_data/2022-02/20220220-115345.dat
I Sun-11:53:45 -    >>>>   Using default SPEC file name   <<<<
I Sun-11:53:45 -    file will be created when bluesky ends its next scan
I Sun-11:53:45 -    to change SPEC file, use command:   newUser(user)
I Sun-11:53:45 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/aps_source.py
I Sun-11:53:45 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/permit.py
I Sun-11:53:45 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/diagnostics.py
I Sun-11:53:45 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/override_parameters.py
I Sun-11:53:45 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/constants.py
I Sun-11:53:45 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/general_terms.py
I Sun-11:53:45 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/amplifiers.py
I Sun-11:53:45 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/scalers.py
I Sun-11:53:49 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/sample_data.py
I Sun-11:53:49 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/user_data.py
I Sun-11:53:49 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/shutters.py
I Sun-11:53:49 - Waiting 1s for mono shutter PV to connect
I Sun-11:53:50 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/stages.py
I Sun-11:53:50 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/usaxs_motor_devices.py
I Sun-11:53:51 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/autosave.py
I Sun-11:53:51 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/axis_tuning.py
D Sun-11:53:51 - before instrument imports
I Sun-11:53:51 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/miscellaneous.py
I Sun-11:53:51 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/axis_tuning_patches.py
I Sun-11:53:54 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/emails.py
I Sun-11:53:54 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/filters.py
I Sun-11:53:54 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/linkam.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/monochromator.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/protection_plc.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/sample_rotator.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/slits.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/utils/motors.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/utils/user_sample_title.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/struck3820.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/suspenders.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/white_beam_ready_calc.py
I Sun-11:53:55 - mono shutter connected = True
I Sun-11:53:55 - Defining suspend_BeamInHutch.  Install/remove in scan plans as desired.
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/trajectories.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/usaxs_fly_scan.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/laser.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/alta_module.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/area_detector_common.py
I Sun-11:53:55 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/ad_tiff_upstream.py
W Sun-11:53:57 - Timeout connecting with Alta (9idalta:)
I Sun-11:53:57 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/blackfly_module.py
I Sun-11:53:58 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/dexela_module.py
W Sun-11:54:03 - Timeout connecting with Dexela 2315 (9idcDEX:): 9idcDEX:cam1:Acquire_RBV could not connect within 5.0-second timeout.
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/pilatus_module.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/devices/autocollect.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/area_detector.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/utils/reporter.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/axis_tuning.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/mode_changes.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/filters.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/mono_feedback.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/move_instrument.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/utils/a2q_q2a.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/requested_stop.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/command_list.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/utils/quoted_line.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/doc_run.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/sample_rotator_plans.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/no_run.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/resets.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/sample_transmission.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/scans.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/utils/cleanup_text.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/utils/setup_new_user.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/utils/check_file_exists.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/sample_imaging.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/uascan.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/plans/tune_guard_slits.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/utils/derivative.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/utils/peak_centers.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/callbacks/nxwriter.py
I Sun-11:54:03 - /home/beams/USAXS/.ipython/profile_bluesky/startup/instrument/callbacks/nxwriter_usaxs.py
I Sun-11:54:03 - bluesky startup is complete

In [1]: newUser("Chaney")
I Sun-11:54:29 - Creating user directory: /share1/USAXS_data/2022-02/02_20_Chaney
I Sun-11:54:29 - Current working directory: /share1/USAXS_data/2022-02
I Sun-11:54:29 - SPEC file name : /share1/USAXS_data/2022-02/02_20_Chaney/02_20_Chaney.dat
I Sun-11:54:29 - File will be created at end of next bluesky scan.
W Sun-11:54:30 - No unexpired ESAFs found that match user Chaney
W Sun-11:54:30 - No unexpired proposals found that match user Chaney
W Sun-11:54:30 - APSBSS not updated.
W Sun-11:54:30 - You should check that PVs in APSBSS contain correct information.
Out[1]: '/share1/USAXS_data/2022-02/02_20_Chaney'

In [2]: RE(preUSAXStune())
TimeoutError: Control layer pyepics failed to send connection and access rights information within 5.0 sec

The above exception was the direct cause of the following exception:
ConnectionTimeoutError: Failed to connect to 9idcLAX:USAXS:DY0 within 5.00 sec

In [3]: RE(preUSAXStune())
TimeoutError: Control layer pyepics failed to send connection and access rights information within 5.0 sec

The above exception was the direct cause of the following exception:
ConnectionTimeoutError: Failed to connect to 9idcLAX:USAXS:DY0 within 5.00 sec

In [4]: 
jilavsky commented 2 years ago

restart BS has helped for now

prjemian commented 2 years ago

That's the best first step. It assumes this is a one-time connection timeout issue.

prjemian commented 2 years ago

I'll look into which PyEpics version (expecting 3.5.0) and also add diagnostic to inform which version of libca is in use.

prjemian commented 2 years ago

We still do not know the root cause why connection timeouts continue to be a problem. For certain it is an unidentified situation that happens here randomly.

prjemian commented 2 years ago
In [7]: epics.__version__
Out[7]: '3.5.0'
prjemian commented 2 years ago
In [10]: epics.ca.find_libca()
Out[10]: '/share1/bluesky/conda_envs/bluesky_2022_1/epics/lib/linux-x86_64/libca.so'

In [16]: epics.ca.version()
Out[16]: '4.13'
prjemian commented 2 years ago

Per https://github.com/APS-USAXS/ipython-usaxs/issues/546#issuecomment-1042407960, hard-code the PYEPICS_LIBCA environment variable in the startup shell script.

prjemian commented 2 years ago

The version of libca referenced above was installed from the epics-base package:

(/share1/bluesky/conda_envs/bluesky_2022_1) bash-4.2$ conda list epics
# packages in environment at /share1/bluesky/conda_envs/bluesky_2022_1:
#
# Name                    Version                   Build  Channel
epics-base                7.0.5.0              h295b1ef_0    conda-forge
pyepics                   3.5.0            py39hf3d152e_1    conda-forge
prjemian commented 2 years ago

PyEpics also provides its own libca, installed locally here:

/share1/bluesky/conda_envs/bluesky_2022_1/lib/python3.9/site-packages/epics/clibs/linux64/libca.so
prjemian commented 2 years ago

Still version 4.13:

(/share1/bluesky/conda_envs/bluesky_2022_1) bash-4.2$ export PYEPICS_LIBCA=/share1/bluesky/conda_envs/bluesky_2022_1/lib/python3.9/site-packages/epics/clibs/linux64/libca.so
(/share1/bluesky/conda_envs/bluesky_2022_1) bash-4.2$ ipython
Python 3.9.7 (default, Sep 16 2021, 13:09:58) 
Type 'copyright', 'credits' or 'license' for more information
IPython 7.29.0 -- An enhanced Interactive Python. Type '?' for help.

In [1]: import ophyd

In [2]: sr = ophyd.EpicsSignalRO("S:SRcurrentAI", name="sr")

In [3]: sr.get()
Out[3]: 102.131801510282

In [5]: import epics

In [6]: epics.ca.version()
Out[6]: '4.13'

In [7]: epics.ca.find_libca()
Out[7]: '/share1/bluesky/conda_envs/bluesky_2022_1/lib/python3.9/site-packages/epics/clibs/linux64/libca.so'

In [8]: 
prjemian commented 2 years ago

Interesting. Same 4.13 version with older EPICS base libca:

In [6]: epics.ca.version()
Out[6]: '4.13'

In [7]: epics.ca.find_libca()
Out[7]: '/APSshare/epics/base-3.15.6/lib/linux-x86_64/libca.so'
prjemian commented 2 years ago

Another:

In [5]: epics.ca.version()
Out[5]: '4.13'

In [6]: epics.ca.find_libca()
Out[6]: '/APSshare/epics/base-7.0.4.1/lib/linux-x86_64/libca.so'
prjemian commented 2 years ago

Note:

In [7]: epics.ca.version??
Signature: epics.ca.version()
Source:   
@withCA
def version():
    """   Print Channel Access version string.
    Currently, this should report '4.13' """
    return bytes2str(libca.ca_version())

So do not expect epics.ca.version() to be a useful diagnostic.

prjemian commented 2 years ago

nothing more to do here