Skip to content
This repository has been archived by the owner on Nov 3, 2021. It is now read-only.

ascan macro fails when 2D counter is enabled #1703

Open
tox1c90 opened this issue Oct 28, 2021 · 3 comments
Open

ascan macro fails when 2D counter is enabled #1703

tox1c90 opened this issue Oct 28, 2021 · 3 comments

Comments

@tox1c90
Copy link

tox1c90 commented Oct 28, 2021

I am just setting up a fresh Sardana installation on the latest development branch. I am encountering now a problem with my 2D counters when trying to run a scan macro, even when its generated by the DummyTwoDController.

What I did:

defctrl DummyTwoDController dummy2Dctrl
defelem dummy2D dummy2Dctrl 0

Enable the dummy2D via expconf (doing this already throws an error in spock), and then run the ascan macro. The result is the following error:

An error occurred while running ascan:
TypeError: must be real number, not tuple

Additionally, when I write to an HDF5 file, the error changes:

An error occurred while running ascan:
TypeError: Object dtype dtype('O') has no native HDF5 equivalent

The same behavior occurs for the real 2D camera devices. Am I doing something wrong?
@reszelaz
Copy link
Collaborator

Hi @tox1c90,
For the moment just a quick hint (I'm now starting to process a long queue of issues/PRs after a one month break). The dummy one works for me. I think the problem you get for the dummy one comes from the 0 axis number you gave it. I assume its controller expects that the axes numbers starts from 1. The sar_demo macro creates them like this:

Door_zreszela_1 [8]: ls2d
     Name             Type   Controller   Axis
 -------- ---------------- ------------ ------
   twod01   TwoDExpChannel   twodctrl01      1

And also the HDF5 recorder works for me with the dummy one:

Door_zreszela_1 [10]: ascan mot01 0 1 1 0.1
Operation will be saved in /tmp/test2d.h5 (HDF5::NXscan from NXscanH5_FileRecorder)
Scan #1 started at Thu Oct 28 22:56:16 2021. It will take at least 0:00:00.765685
 #Pt No    mot01     twod01      dt   
   0         0      (1024, 1024)  0.335496
   1         1      (1024, 1024)  0.79753 
Operation saved in /tmp/test2d.h5 (HDF5::NXscan)
Scan #1 ended at Thu Oct 28 22:56:17 2021, taking 0:00:00.957603. Dead time 78.5% (setup time 0.6%, motion dead time 62.7%)

But, I don't know why your controller gives problems. Please attach here the server logs (with --log-level=debug) from a single acquisition e.g. ct macro execution.

Cheers!

@tox1c90
Copy link
Author

tox1c90 commented Nov 1, 2021 •
edited
Loading

Hi @reszelaz ,

thanks for your reply! The problem seems to be more complicated then. I created a new Sardana instance and only created the demo environment via sar_demo.
But for me, the twod01 is not working when running ascan and I get the same error again (just ct is running fine).

This is the debug level log during the ascan macro:

MainThread     INFO     2021-11-01 11:54:39,044 TaurusRootLogger: Ready to accept request in 0:00:00.721353
Dummy-1        DEBUG    2021-11-01 11:54:42,613 ThreadPool: Starting ThreadPool.W001
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,901 Controller.ctctrl02: StateOne(1): entering...
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,901 Controller.ctctrl02: StateOne(1): returning (0, 'Stopped')
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,901 Controller.ctctrl02: StateOne(2): entering...
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,901 Controller.ctctrl02: StateOne(2): returning (0, 'Stopped')
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,901 Controller.ctctrl02: StateOne(3): entering...
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,901 Controller.ctctrl02: StateOne(3): returning (0, 'Stopped')
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,901 Controller.ctctrl02: StateOne(4): entering...
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,901 Controller.ctctrl02: StateOne(4): returning (0, 'Stopped')
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,904 Controller.ctctrl02: StateOne(1): entering...
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,904 Controller.ctctrl02: StateOne(1): returning (0, 'Stopped')
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,904 Controller.ctctrl02: StateOne(2): entering...
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,904 Controller.ctctrl02: StateOne(2): returning (0, 'Stopped')
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,904 Controller.ctctrl02: StateOne(3): entering...
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,904 Controller.ctctrl02: StateOne(3): returning (0, 'Stopped')
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,904 Controller.ctctrl02: StateOne(4): entering...
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,904 Controller.ctctrl02: StateOne(4): returning (0, 'Stopped')
ThreadPool.W001 INFO     2021-11-01 11:54:44,910 newton.nano.lab:10000.mntgrp02: Configuration changed
ThreadPool.W001 WARNING  2021-11-01 11:54:44,914 newton.nano.lab:10000.mntgrp02: getTimer() is deprecated since 3.0.3. Global measurement group timer does not exist
ThreadPool.W001 INFO     2021-11-01 11:54:44,914 SScan: ExtraColumns is not defined
ThreadPool.W001 INFO     2021-11-01 11:54:44,914 SScan: JsonRecorder is not defined. Use "senv JsonRecorder True" to enable it
ThreadPool.W001 WARNING  2021-11-01 11:54:44,915 Door/demo/1.Macro[ascan]: ScanDir is not defined. This operation will not be stored persistently. Use "expconf" or "newfile" to configure data storage (or eventually "senv ScanDir <abs directory>")
ThreadPool.W001 INFO     2021-11-01 11:54:44,915 SScan: SharedMemory is not defined. Use "senv SharedMemory sps" to enable it
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,947 Door/demo/1.MacroExecutor: [START] runMacro Macro 'ascan(mot05, 0.0, 1.0, 1, 0.1) -> 1fa97726-3b02-11ec-8675-1f1f56b060b1'
ThreadPool.W001 INFO     2021-11-01 11:54:44,948 Door/demo/1.Macro[ascan]: Scan #3 started at Mon Nov  1 11:54:44 2021. It will take at least 0:00:00.482843
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,953 newton.nano.lab:10000.mntgrp02.IntegrationTime: [Tango] read failed (PyDs_PythonError): Exception: The synchronization description group has not been initialized

ThreadPool.W001 DEBUG    2021-11-01 11:54:44,970 SScan: [START] motion
ThreadPool.W001 INFO     2021-11-01 11:54:44,971 motor/motctrl02/1: write_Position(0.0)
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,975 mot05: Start motion user=0.000000, dial=0.000000, backlash? False, dial_backlash=0.000000
SardanaTP.W001 DEBUG    2021-11-01 11:54:44,983 mot05.Motion: -> action_loop
SardanaTP.W001 DEBUG    2021-11-01 11:54:44,986 mot05: Stopped
SardanaTP.W001 DEBUG    2021-11-01 11:54:44,989 mot05.Motion: <- action_loop
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,992 SScan: [ END ] motion
ThreadPool.W001 DEBUG    2021-11-01 11:54:44,993 SScan: [START] acquisition
SardanaTP.W003 DEBUG    2021-11-01 11:54:44,997 mntgrp02.Acquisition: start event with id: 0 received at: 2021-11-01 11:54:44.997412
SardanaTP.W003 DEBUG    2021-11-01 11:54:44,997 mntgrp02.Acquisition: active event with id: 0 received at: 2021-11-01 11:54:44.997819
SardanaTP.W003 DEBUG    2021-11-01 11:54:44,998 mntgrp02.Acquisition: Executing software acquisition.
SardanaTP.W004 DEBUG    2021-11-01 11:54:44,998 mntgrp02.Acquisition.Synchronization: -> action_loop
SardanaTP.W005 DEBUG    2021-11-01 11:54:44,999 mntgrp02.Acquisition.SoftwareAcquisition: -> start_action
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,000 Controller.ctctrl02: PreStartOne(2): entering...
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,000 Controller.ctctrl02: StartOne(2): entering...
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,000 Controller.ctctrl02: PreStartOne(3): entering...
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,000 Controller.ctctrl02: StartOne(3): entering...
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,000 Controller.ctctrl02: PreStartOne(4): entering...
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,001 Controller.ctctrl02: StartOne(4): entering...
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,001 Controller.ctctrl02: PreStartOne(1): entering...
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,001 Controller.ctctrl02: StartOne(1): entering...
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,004 mntgrp02.Acquisition.SoftwareAcquisition: <- start_action
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,004 mntgrp02.Acquisition.SoftwareAcquisition: -> action_loop
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,004 Controller.ctctrl02: StateOne(1): entering...
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,005 Controller.ctctrl02: StateOne(1): returning (6, 'Acquiring')
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,006 Controller.ctctrl02: StateOne(2): entering...
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,006 Controller.ctctrl02: StateOne(2): returning (6, 'Acquiring')
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,006 Controller.ctctrl02: StateOne(3): entering...
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,006 Controller.ctctrl02: StateOne(3): returning (6, 'Acquiring')
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,006 Controller.ctctrl02: StateOne(4): entering...
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,006 Controller.ctctrl02: StateOne(4): returning (6, 'Acquiring')
SardanaTP.W008 DEBUG    2021-11-01 11:54:45,074 Controller.ctctrl02: ReadOne(1): entering...
SardanaTP.W008 DEBUG    2021-11-01 11:54:45,074 Controller.ctctrl02: ReadOne(1): returning 0.07051491737365723
SardanaTP.W008 DEBUG    2021-11-01 11:54:45,074 Controller.ctctrl02: ReadOne(2): entering...
SardanaTP.W008 DEBUG    2021-11-01 11:54:45,074 Controller.ctctrl02: ReadOne(2): returning 0.14102983474731445
SardanaTP.W008 DEBUG    2021-11-01 11:54:45,074 Controller.ctctrl02: ReadOne(3): entering...
SardanaTP.W008 DEBUG    2021-11-01 11:54:45,075 Controller.ctctrl02: ReadOne(3): returning 0.21154475212097168
SardanaTP.W008 DEBUG    2021-11-01 11:54:45,075 Controller.ctctrl02: ReadOne(4): entering...
SardanaTP.W008 DEBUG    2021-11-01 11:54:45,075 Controller.ctctrl02: ReadOne(4): returning 0.2820596694946289
SardanaTP.W010 DEBUG    2021-11-01 11:54:45,086 Controller.ctctrl02: StateOne(1): entering...
SardanaTP.W010 DEBUG    2021-11-01 11:54:45,086 Controller.ctctrl02: StateOne(1): returning (6, 'Acquiring')
SardanaTP.W010 DEBUG    2021-11-01 11:54:45,086 Controller.ctctrl02: StateOne(2): entering...
SardanaTP.W010 DEBUG    2021-11-01 11:54:45,086 Controller.ctctrl02: StateOne(2): returning (6, 'Acquiring')
SardanaTP.W010 DEBUG    2021-11-01 11:54:45,086 Controller.ctctrl02: StateOne(3): entering...
SardanaTP.W010 DEBUG    2021-11-01 11:54:45,086 Controller.ctctrl02: StateOne(3): returning (6, 'Acquiring')
SardanaTP.W010 DEBUG    2021-11-01 11:54:45,086 Controller.ctctrl02: StateOne(4): entering...
SardanaTP.W010 DEBUG    2021-11-01 11:54:45,086 Controller.ctctrl02: StateOne(4): returning (6, 'Acquiring')
SardanaTP.W003 DEBUG    2021-11-01 11:54:45,095 mntgrp02.Acquisition: passive event with id: 0 received at: 2021-11-01 11:54:45.095096
SardanaTP.W003 DEBUG    2021-11-01 11:54:45,095 mntgrp02.Acquisition: end event with id: 0 received at: 2021-11-01 11:54:45.095273
SardanaTP.W002 DEBUG    2021-11-01 11:54:45,096 Controller.ctctrl02: StateOne(1): entering...
SardanaTP.W002 DEBUG    2021-11-01 11:54:45,097 Controller.ctctrl02: StateOne(1): returning (6, 'Acquiring')
SardanaTP.W002 DEBUG    2021-11-01 11:54:45,097 Controller.ctctrl02: StateOne(2): entering...
SardanaTP.W002 DEBUG    2021-11-01 11:54:45,097 Controller.ctctrl02: StateOne(2): returning (6, 'Acquiring')
SardanaTP.W002 DEBUG    2021-11-01 11:54:45,097 Controller.ctctrl02: StateOne(3): entering...
SardanaTP.W002 DEBUG    2021-11-01 11:54:45,097 Controller.ctctrl02: StateOne(3): returning (6, 'Acquiring')
SardanaTP.W002 DEBUG    2021-11-01 11:54:45,097 Controller.ctctrl02: StateOne(4): entering...
SardanaTP.W002 DEBUG    2021-11-01 11:54:45,097 Controller.ctctrl02: StateOne(4): returning (6, 'Acquiring')
SardanaTP.W004 DEBUG    2021-11-01 11:54:45,100 mntgrp02.Acquisition.Synchronization: <- action_loop
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,107 Controller.ctctrl02: StateOne(1): entering...
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,108 Controller.ctctrl02: StateOne(1): returning (0, 'Stopped')
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,108 Controller.ctctrl02: StateOne(2): entering...
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,108 Controller.ctctrl02: StateOne(2): returning (0, 'Stopped')
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,108 Controller.ctctrl02: StateOne(3): entering...
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,108 Controller.ctctrl02: StateOne(3): returning (0, 'Stopped')
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,108 Controller.ctctrl02: StateOne(4): entering...
SardanaTP.W006 DEBUG    2021-11-01 11:54:45,108 Controller.ctctrl02: StateOne(4): returning (0, 'Stopped')
SardanaTP.W008 DEBUG    2021-11-01 11:54:45,108 Controller.twodctrl02: ReadOne(1): entering...
SardanaTP.W008 DEBUG    2021-11-01 11:54:45,109 Controller.twodctrl02: ReadOne(1): returning array([[8.88178420e-18, 9.50380790e-18, 1.01680472e-17, ...,
        1.01680472e-17, 9.50380790e-18, 8.88178420e-18],
       [9.50380790e-18, 1.01693942e-17, 1.08801526e-17, ...,
        1.08801526e-17, 1.01693942e-17, 9.50380790e-18],
       [1.01680472e-17, 1.08801526e-17, 1.16405872e-17, ...,
        1.16405872e-17, 1.08801526e-17, 1.01680472e-17],
       ...,
       [1.01680472e-17, 1.08801526e-17, 1.16405872e-17, ...,
        1.16405872e-17, 1.08801526e-17, 1.01680472e-17],
       [9.50380790e-18, 1.01693942e-17, 1.08801526e-17, ...,
        1.08801526e-17, 1.01693942e-17, 9.50380790e-18],
       [8.88178420e-18, 9.50380790e-18, 1.01680472e-17, ...,
        1.01680472e-17, 9.50380790e-18, 8.88178420e-18]])
SardanaTP.W009 DEBUG    2021-11-01 11:54:45,109 Controller.ctctrl02: ReadOne(1): entering...
SardanaTP.W009 DEBUG    2021-11-01 11:54:45,109 Controller.ctctrl02: ReadOne(1): returning 0.1
SardanaTP.W009 DEBUG    2021-11-01 11:54:45,109 Controller.ctctrl02: ReadOne(2): entering...
SardanaTP.W009 DEBUG    2021-11-01 11:54:45,109 Controller.ctctrl02: ReadOne(2): returning 0.2
SardanaTP.W009 DEBUG    2021-11-01 11:54:45,109 Controller.ctctrl02: ReadOne(3): entering...
SardanaTP.W009 DEBUG    2021-11-01 11:54:45,109 Controller.ctctrl02: ReadOne(3): returning 0.30000000000000004
SardanaTP.W009 DEBUG    2021-11-01 11:54:45,109 Controller.ctctrl02: ReadOne(4): entering...
SardanaTP.W009 DEBUG    2021-11-01 11:54:45,109 Controller.ctctrl02: ReadOne(4): returning 0.4
SardanaTP.W005 DEBUG    2021-11-01 11:54:45,161 mntgrp02.Acquisition.SoftwareAcquisition: <- action_loop
ThreadPool.W001 DEBUG    2021-11-01 11:54:45,247 SScan: [ END ] acquisition
ThreadPool.W001 OUTPUT   2021-11-01 11:54:45,247 Door/demo/1.Macro[ascan]:  #Pt No    mot05      ct05      ct06      ct07      ct08     twod02      dt   
ThreadPool.W001 DEBUG    2021-11-01 11:54:45,248 Door/demo/1.MacroExecutor: Sending exception event
ThreadPool.W001 DEBUG    2021-11-01 11:54:45,248 Door/demo/1.MacroExecutor: [ENDEX] (MacroServerException) runMacro ascan
ThreadPool.W001 DEBUG    2021-11-01 11:54:45,248 Door/demo/1: Traceback (most recent call last):
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/gscan.py", line 1061, in step_scan
    for i in self.scan_loop():
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/gscan.py", line 1164, in scan_loop
    self.stepUp(i, step, lstep)
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/gscan.py", line 1276, in stepUp
    self.data.addRecord(data_line)
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/scandata.py", line 393, in addRecord
    self.datahandler.addRecord(self, rc)
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/recorder/datarecorder.py", line 68, in addRecord
    recorder.writeRecord(record)
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/recorder/datarecorder.py", line 142, in writeRecord
    self._writeRecord(record)
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/recorders/output.py", line 269, in _writeRecord
    cell %= record.data
TypeError: must be real number, not tuple

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/msmacromanager.py", line 1676, in runMacro
    for step in macro_obj.exec_():
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/macro.py", line 2362, in exec_
    for i in it:
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/macros/scan.py", line 291, in run
    for step in self._gScan.step_scan():
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/gscan.py", line 1076, in step_scan
    self.end()
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/gscan.py", line 1027, in end
    self.data.end()
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/scandata.py", line 503, in end
    self.datahandler.addRecord(self, rc)
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/recorder/datarecorder.py", line 68, in addRecord
    recorder.writeRecord(record)
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/scan/recorder/datarecorder.py", line 142, in writeRecord
    self._writeRecord(record)
  File "/home/labuser/.local/lib/python3.8/site-packages/sardana/macroserver/recorders/output.py", line 269, in _writeRecord
    cell %= record.data
TypeError: must be real number, not tuple

ThreadPool.W001 ERROR    2021-11-01 11:54:45,249 Door/demo/1: An error occurred while running ascan:
TypeError: must be real number, not tuple
ThreadPool.W001 INFO     2021-11-01 11:54:45,249 Door/demo/1: Hint: in Spock execute `www`to get more details
ThreadPool.W001 DEBUG    2021-11-01 11:54:45,249 Door/demo/1.MacroExecutor: Job ended (stopped=False, aborted=False)

@teresanunez
Copy link

Hi, I have also checked it now and for me, like for Zibi, it works.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@teresanunez @reszelaz @tox1c90