Re: I implemented the Model 3 of EPICS motor driver support, but the VAL and RBV of motor record are zero after IOC reboot.

[Torsten Bögershausen via Tech-talk <tech-talk at aps.anl.gov>]

Thinking about it:

What is special with DCM:Z1.V ?

The polling, if it works for motor 1,2,3...,
shouldn't it work for motor 0 as well ?

Did you mention that you are using a "soft motor" here ?

If not, it may be an idea to use wireshark to see what is
going on between the EPICS IOC and the motion controller.


On 2025-01-03 09:09, Torsten Bögershausen wrote:
> Hej again,
> happy new year !
> Thanks for reporting back and sharing your experiences.
>
> I think that there are 2 problems/phenomenon :
>
> a) The read back position of  "DCM:ThetaM.RBV" is flickering.
>    You see this already when the IOC is running.
>    Why is that ?
>    Mechanics are suspected to be a contributer.
>    Mechanical load, high-precision encoder ?
>    Is the controller running in closed loop ?
>
> b) The initialisation is still flaky - sometimes RBV has a value of 0.0
>    I can see 3 ways to improve it:
>    b1) Increase the sleep() even more, 5.0 seconds ??
>    b2) Use the patched version of the motor from ESS,
>        which has been improved to handle this.
>        And comes with log-prints, which allow a better remote-debug
>        using this log-prints
>        https://urldefense.us/v3/__https://github.com/EuropeanSpallationSource/motor__;!!G_uCfscf7eWS!dwNl3f4EFOswpQk0I_pPtg1IvOYnDOvqIcjpnfAs7ogIiyWag7Go045doD9S0suVaoZlVEGKOFMkUnOsdCM$ 
>    b3) I have seen the use of an EPICS (?) hook somewhere in one
>       of the motor-drivers. But after searching for hooks I still
>       can not find an example here on my disk or in old emails.
>
>
> Another question:
> How much is the motor moving ?
> /Torsten
>
>
> On 2025-01-03 02:54, LiangChih Chiang wrote:
> > I added epicsThreadSleep(1.0) after creating motor controller and axes.
> >
> > I use camonitor to trace the VAL/RBV of motor records of three axes.
> > I rebooted ioc nine times.
> > Please see the following log.
> >
> > I noticed that axes Z1 and Z2 successfully restored the VAL/RBV from 
> > the controller every time.
> > But the behavior of axis ThetaM is strange.
> > Two out of nine reboots, the VAL field of ThetaM record is 
> > successfully restored.
> > One out of nine reboots, the VAL field of ThetaM record is set to zero.
> > Six out of nine reboots, the VAL field of ThetaM record is set to 
> > (previous value - 0.02).
> > Why -0.02?
> >
> >
> > DCM:Z1.VAL                 2025-01-02 16:28:46.483683 -0.04
> > DCM:Z1.RBV                 2025-01-02 16:28:46.483683 -0.0401
> > DCM:Z2.VAL                 2025-01-02 20:41:47.713687 0.0657
> > DCM:Z2.RBV                 2025-01-02 20:41:47.713687 0.0653
> > DCM:ThetaM.VAL             2025-01-02 16:28:50.353358 7.53376  <--
> > DCM:ThetaM.RBV             2025-01-02 16:28:50.353358 7.53376
> >
> > ioc reboot
> >
> > DCM:Z1.VAL                 2025-01-03 08:46:20.410653 -0.0401
> > DCM:Z1.RBV                 2025-01-03 08:46:20.410653 -0.04
> > DCM:Z2.VAL                 2025-01-03 08:46:20.350513 0.0653
> > DCM:Z2.RBV                 2025-01-03 08:46:20.350513 0.0657
> > DCM:ThetaM.VAL             2025-01-03 08:46:20.500699 7.53376   <-- 
> > same as previous
> > DCM:ThetaM.RBV             2025-01-03 08:46:20.500699 7.53376
> >
> > ioc reboot
> >
> > DCM:Z1.VAL                 2025-01-03 08:54:04.045355 -0.04
> > DCM:Z1.RBV                 2025-01-03 08:54:04.045355 -0.0401
> > DCM:Z2.VAL                 2025-01-03 08:54:03.985246 0.0657
> > DCM:Z2.RBV                 2025-01-03 08:54:03.985246 0.0653
> > DCM:ThetaM.VAL             2025-01-03 08:54:05.156115 7.51376   <-- 
> > different -0.02
> > DCM:ThetaM.RBV             2025-01-03 08:54:05.156115 7.52741   <-- 
> > motor move
> > DCM:ThetaM.RBV             2025-01-03 08:54:05.335235 7.52131
> > DCM:ThetaM.RBV             2025-01-03 08:54:05.505113 7.51621
> > DCM:ThetaM.RBV             2025-01-03 08:54:05.675255 7.51376
> > DCM:ThetaM.RBV             2025-01-03 08:54:05.845205 7.51361
> > DCM:ThetaM.VAL             2025-01-03 08:54:05.845205 7.51376
> > DCM:ThetaM.RBV             2025-01-03 08:54:05.995251 7.51356
> > DCM:ThetaM.RBV             2025-01-03 08:54:06.495140 7.51371
> > DCM:ThetaM.RBV             2025-01-03 08:54:06.795186 7.51376
> > DCM:ThetaM.RBV             2025-01-03 08:54:06.965241 7.51381
> >
> > ioc reboot
> >
> > DCM:Z1.VAL                 2025-01-03 09:00:47.829590 -0.0401
> > DCM:Z1.RBV                 2025-01-03 09:00:47.829590 -0.04
> > DCM:Z2.VAL                 2025-01-03 09:00:47.769508 0.0653
> > DCM:Z2.RBV                 2025-01-03 09:00:47.769508 0.0657
> > DCM:ThetaM.VAL             2025-01-03 09:00:49.279478 7.49377   <-- 
> > different -0.01999
> > DCM:ThetaM.RBV             2025-01-03 09:00:49.279478 7.49611   <-- 
> > motor move
> > DCM:ThetaM.RBV             2025-01-03 09:00:49.449660 7.49371
> > DCM:ThetaM.RBV             2025-01-03 09:00:49.619596 7.49351
> > DCM:ThetaM.VAL             2025-01-03 09:00:49.619596 7.49377
> > DCM:ThetaM.RBV             2025-01-03 09:00:49.939543 7.49356
> > DCM:ThetaM.RBV             2025-01-03 09:00:50.269661 7.49376
> >
> >
> > Manually move ThetaM to 7.553761
> >
> > DCM:ThetaM.VAL             2025-01-03 09:04:05.044900 7.55378
> > DCM:ThetaM.VAL             2025-01-03 09:04:05.045646 7.55376
> > DCM:ThetaM.RBV             2025-01-03 09:04:05.371519 7.49566
> > DCM:ThetaM.RBV             2025-01-03 09:04:05.541574 7.50071
> > DCM:ThetaM.RBV             2025-01-03 09:04:05.711567 7.50711
> > DCM:ThetaM.RBV             2025-01-03 09:04:05.881592 7.51536
> > DCM:ThetaM.RBV             2025-01-03 09:04:06.061484 7.52551
> > DCM:ThetaM.RBV             2025-01-03 09:04:06.231575 7.53506
> > DCM:ThetaM.RBV             2025-01-03 09:04:06.402009 7.54296
> > DCM:ThetaM.RBV             2025-01-03 09:04:06.571571 7.54866
> > DCM:ThetaM.RBV             2025-01-03 09:04:06.741529 7.55221
> > DCM:ThetaM.RBV             2025-01-03 09:04:06.911574 7.55296
> > DCM:ThetaM.VAL             2025-01-03 09:04:06.911574 7.55376
> > DCM:ThetaM.RBV             2025-01-03 09:04:07.071671 7.55301
> > DCM:ThetaM.RBV             2025-01-03 09:04:07.241982 7.55326
> > DCM:ThetaM.RBV             2025-01-03 09:04:07.561637 7.55381
> > DCM:ThetaM.RBV             2025-01-03 09:04:07.881647 7.55346
> > DCM:ThetaM.RBV             2025-01-03 09:04:08.211724 7.55356
> > DCM:ThetaM.RBV             2025-01-03 09:04:08.531501 7.55376
> >
> > ioc reboot
> >
> > DCM:Z1.VAL                 2025-01-03 09:05:56.102804 -0.04
> > DCM:Z1.RBV                 2025-01-03 09:05:56.102804 -0.0401
> > DCM:Z2.VAL                 2025-01-03 09:05:56.042681 0.0657
> > DCM:Z2.RBV                 2025-01-03 09:05:56.042681 0.0653
> > DCM:ThetaM.VAL             2025-01-03 09:05:56.174482 7.55376   <-- 
> > same as previous
> > DCM:ThetaM.RBV             2025-01-03 09:05:56.174482 7.55376   <-- 
> > but motor move
> > DCM:ThetaM.RBV             2025-01-03 09:05:57.012778 7.55206
> > DCM:ThetaM.RBV             2025-01-03 09:05:57.502889 7.54196
> > DCM:ThetaM.RBV             2025-01-03 09:05:57.822823 7.54366
> > DCM:ThetaM.RBV             2025-01-03 09:05:57.992678 7.54791
> > DCM:ThetaM.RBV             2025-01-03 09:05:58.162720 7.55171
> > DCM:ThetaM.RBV             2025-01-03 09:05:58.342759 7.55266
> > DCM:ThetaM.RBV             2025-01-03 09:05:58.492806 7.55271
> > DCM:ThetaM.RBV             2025-01-03 09:05:58.662711 7.55371
> > DCM:ThetaM.RBV             2025-01-03 09:05:58.962828 7.55376
> > DCM:ThetaM.RBV             2025-01-03 09:05:59.132771 7.55381
> > DCM:ThetaM.RBV             2025-01-03 09:06:02.762853 7.55386
> >
> > ioc reboot
> >
> > DCM:Z1.VAL                 2025-01-03 09:09:37.385148 -0.0401
> > DCM:Z1.RBV                 2025-01-03 09:09:37.385148 -0.04
> > DCM:Z2.VAL                 2025-01-03 09:09:37.325204 0.0653
> > DCM:Z2.RBV                 2025-01-03 09:09:37.325204 0.0657
> > DCM:ThetaM.VAL             2025-01-03 09:09:38.354986 0         <-- 
> > different, zero!
> > DCM:ThetaM.RBV             2025-01-03 09:09:38.354986 7.55181   <-- 
> > motor move
> > DCM:ThetaM.RBV             2025-01-03 09:09:38.535008 7.54706
> > DCM:ThetaM.RBV             2025-01-03 09:09:38.704917 7.54026
> > DCM:ThetaM.RBV             2025-01-03 09:09:38.875048 7.53131
> > DCM:ThetaM.RBV             2025-01-03 09:09:39.045385 7.52046
> > DCM:ThetaM.RBV             2025-01-03 09:09:39.215134 7.50731
> > DCM:ThetaM.RBV             2025-01-03 09:09:39.385166 7.49361
> > DCM:ThetaM.RBV             2025-01-03 09:09:39.555112 7.48036
> > DCM:ThetaM.RBV             2025-01-03 09:09:39.725153 7.46636
> > DCM:ThetaM.RBV             2025-01-03 09:09:39.894942 7.45281
> > DCM:ThetaM.RBV             2025-01-03 09:09:40.064989 7.43961
> > DCM:ThetaM.RBV             2025-01-03 09:09:40.234971 7.42526
> > DCM:ThetaM.RBV             2025-01-03 09:09:40.405113 7.41221
> > DCM:ThetaM.RBV             2025-01-03 09:09:40.585072 7.39761
> > DCM:ThetaM.RBV             2025-01-03 09:09:40.755044 7.38401
> > DCM:ThetaM.RBV             2025-01-03 09:09:40.925113 7.37066
> > DCM:ThetaM.RBV             2025-01-03 09:09:42.095077 7.31426
> > DCM:ThetaM.VAL             2025-01-03 09:09:42.095077 7.31426  <-- I 
> > stop the motor.
> > DCM:ThetaM.RBV             2025-01-03 09:09:46.705116 7.31421
> >
> > ioc reboot
> >
> > DCM:Z1.VAL                 2025-01-03 09:12:18.906995 -0.04
> > DCM:Z1.RBV                 2025-01-03 09:12:18.906995 -0.0401
> > DCM:Z2.VAL                 2025-01-03 09:12:18.846984 0.0657
> > DCM:Z2.RBV                 2025-01-03 09:12:18.846984 0.0653
> > DCM:ThetaM.VAL             2025-01-03 09:12:21.346979 7.29431   <-- 
> > different −0.01995
> > DCM:ThetaM.RBV             2025-01-03 09:12:21.346979 7.29431   <-- 
> > motor move
> > ioc reboot
> >
> > DCM:Z1.VAL                 2025-01-03 09:18:20.230656 -0.0401
> > DCM:Z1.RBV                 2025-01-03 09:18:20.230656 -0.04
> > DCM:Z2.VAL                 2025-01-03 09:18:20.170608 0.0653
> > DCM:Z2.RBV                 2025-01-03 09:18:20.170608 0.0657
> > DCM:ThetaM.VAL             2025-01-03 09:18:20.311337 7.27437   <-- 
> > different −0.01994
> > DCM:ThetaM.RBV             2025-01-03 09:18:20.311337 7.29431   <-- 
> > motor move
> > DCM:ThetaM.RBV             2025-01-03 09:18:21.150538 7.29231
> > DCM:ThetaM.RBV             2025-01-03 09:18:21.320404 7.28771
> > DCM:ThetaM.RBV             2025-01-03 09:18:21.500407 7.28171
> > DCM:ThetaM.RBV             2025-01-03 09:18:21.670389 7.27681
> > DCM:ThetaM.RBV             2025-01-03 09:18:21.840686 7.27421
> > DCM:ThetaM.RBV             2025-01-03 09:18:22.010457 7.27406
> > DCM:ThetaM.VAL             2025-01-03 09:18:22.010457 7.27437
> > DCM:ThetaM.RBV             2025-01-03 09:18:22.330451 7.27421
> > DCM:ThetaM.RBV             2025-01-03 09:18:22.660350 7.27431
> > DCM:ThetaM.RBV             2025-01-03 09:18:22.960309 7.27436
> > DCM:ThetaM.RBV             2025-01-03 09:18:23.130896 7.27441
> >
> > ioc reboot
> >
> > DCM:Z1.VAL                 2025-01-03 09:22:00.722740 -0.04
> > DCM:Z1.RBV                 2025-01-03 09:22:00.722740 -0.0401
> > DCM:Z2.VAL                 2025-01-03 09:22:00.662695 0.0657
> > DCM:Z2.RBV                 2025-01-03 09:22:00.662695 0.0653
> > DCM:ThetaM.VAL             2025-01-03 09:22:02.912859 7.25442   <-- 
> > different −0.01995
> > DCM:ThetaM.RBV             2025-01-03 09:22:02.912859 7.25441   <-- 
> > motor move
> > ioc reboot
> >
> > DCM:Z1.VAL                 2025-01-03 09:33:58.400417 -0.0401
> > DCM:Z1.RBV                 2025-01-03 09:33:58.400417 -0.04
> > DCM:Z2.VAL                 2025-01-03 09:33:58.340350 0.0653
> > DCM:Z2.RBV                 2025-01-03 09:33:58.340350 0.0657
> > DCM:ThetaM.VAL             2025-01-03 09:33:59.330344 7.23447   <-- 
> > different −0.01995
> > DCM:ThetaM.RBV             2025-01-03 09:33:59.330344 7.25241   <-- 
> > motor move
> > DCM:ThetaM.RBV             2025-01-03 09:33:59.500272 7.24781
> > DCM:ThetaM.RBV             2025-01-03 09:33:59.680584 7.24186
> > DCM:ThetaM.RBV             2025-01-03 09:33:59.850291 7.23701
> > DCM:ThetaM.RBV             2025-01-03 09:34:00.020355 7.23431
> > DCM:ThetaM.RBV             2025-01-03 09:34:00.190267 7.23416
> > DCM:ThetaM.VAL             2025-01-03 09:34:00.190267 7.23447
> > DCM:ThetaM.RBV             2025-01-03 09:34:00.510337 7.23431
> > DCM:ThetaM.RBV             2025-01-03 09:34:00.840415 7.23441
> > DCM:ThetaM.RBV             2025-01-03 09:34:01.140389 7.23446
> > DCM:ThetaM.RBV             2025-01-03 09:34:01.310255 7.23451
> >
> >
> >
> >
> >
> >
> >
> >
> > On Thu, Jan 2, 2025 at 11:26 AM LiangChih Chiang <yehnan174 at gmail.com 
> > <mailto:yehnan174 at gmail.com>> wrote:
> >     Hi,
> >
> >      >To explain a little more, it is important that the driver has
> >     completed the first poll cycle for the position and status of each
> >     axis before iocInit.
> >      >This is because the motor record looks at those positions during
> >     iocInit, and if there are non-zero it uses those values as the
> >     current position.
> >      >You can add the following to your startup script after you create
> >     the controller and axes to sleep for 1 second.
> >      >epicsThreadSleep(1.0)
> >
> >     I did add epicsThreadSleep(1.0).
> >
> >     There are 5 motors(axis 1 to 5) connected to the motor controller.
> >
> >     After epicsThreadSleep(1.0) added, it seems that the VAL/RBV of
> >     motor records of axis 2 to 5 can be successfully loaded back from
> >     the controller after IOC reboot.
> >     But the behavior of axis 0 (this axis is the most important) is 
> > strange.
> >     After IOC reboot, the motor record of axis 0 will move.
> >     It seems that the VAL field is set to a new value
> >     and I can't figure out the relationship between the new and old 
> > values.
> >     The axis 0 is the main axis(Bragg angle) of a double crystal
> >     monochromator,
> >     and it has corresponding pseudo motor to represent the Energy of x-
> >     ray beam.
> >
> >
> >
> >
> >
> >
> >
> >
> >
> >     On Wed, Nov 20, 2024 at 11:04 PM Mark Rivers
> >     <rivers at cars.uchicago.edu <mailto:rivers at cars.uchicago.edu>> wrote:
> >
> >         To explain a little more, it is important that the driver has
> >         completed the first poll cycle for the position and status of
> >         each axis before iocInit.  This is because the motor record
> >         looks at those positions during iocInit, and if there are non-
> >         zero it uses those values as the current position.  You can add
> >         the following to your startup script after you create the
> >         controller and axes to sleep for 1 second.
> >
> >         epicsThreadSleep(1.0)
> >
> >         Let us know if this does not fix the problem.
> >
> >         Mark
> >
> >
> >         
> > ------------------------------------------------------------------------
> >         *From:* Tech-talk <tech-talk-bounces at aps.anl.gov <mailto:tech-
> >         talk-bounces at aps.anl.gov>> on behalf of Torsten Bögershausen via
> >         Tech-talk <tech-talk at aps.anl.gov <mailto:tech-talk at aps.anl.gov>>
> >         *Sent:* Wednesday, November 20, 2024 5:15 AM
> >         *To:* LiangChih Chiang <yehnan174 at gmail.com
> >         <mailto:yehnan174 at gmail.com>>; tech-talk at aps.anl.gov
> >         <mailto:tech-talk at aps.anl.gov> <tech-talk at aps.anl.gov
> >         <mailto:tech-talk at aps.anl.gov>>
> >         *Subject:* Re: I implemented the Model 3 of EPICS motor driver
> >         support, but the VAL and RBV of motor record are zero after IOC
> >         reboot.
> >         Hej,
> >
> >         without having seen ypur code, I would speculate that you run
> >         into a not-unknown issue using Model 3 motors, connected via
> >         a serial cable, USB or Ethernet?
> >
> >         The value that the motorRecord needs is read from the driver,
> >         wich must have been able to read it from your hardware.
> >         Here are ESS we have a patched motor, which can handle this.
> >         If you use the upstream version, the easist workaround may be
> >         to add a sleep() after the createController() line in your st.cmd
> >
> >         HTH
> >         /Torsten
> >
> >
> >         On 2024-11-20 09:47, LiangChih Chiang via Tech-talk wrote:
> >          > Hello, EPICS mates.
> >          >
> >          > I implemented the Model 3 of EPICS motor driver support for
> >         some motor
> >          > controller,
> >          > but the VAL and RBV of the motor record are zero after IOC
> >         reboot.
> >          >
> >          > I think the motor record doesn't restore the values of motor
> >         pulse and
> >          > encoder count from the motor controller after IOC reboot.
> >          >
> >          > What member functions of asynMotorController and
> >         asynMotorAxis classes
> >          > should I implement?
> >          >
> >          >
> >          > Best regards.
> >          >