ct seems a bit slow
We are not saving the ct, so the overhead seems a bit higher than it was in the last run...
TDXRD [20]: s.statistics
Out [20]: func_name min mean max std total
------------------------------------ --------- --------- --------- --------- ---------
scan.prepare.node 1.420s 1.420s 1.420s 1.420s
scan.prepare.user_scan_meta 15.828ms 673.335ms 1.331s 657.508ms 1.347s
TDXRD [21]: ACTIVE_MG
Out [21]: MeasurementGroup: mg_tdxrd (state='default')
- Existing states : 'default'
Enabled Disabled
-------------------------------------- --------------------------------------
keithley:pico4 frelon1:image
keithley:pico5 frelon2:image
p201_20:ct2_counters_controller:fpico3 frelon3:image
p201_20:ct2_counters_controller:fpico4 keithley:pico3
p201_20:ct2_counters_controller:fpico5 machinfo:current
p201_20:ct2_counters_controller:sec machinfo:refill
machinfo:sbcurr
marana:image
musst_tdxrd:mch4
musst_tdxrd:mch5
musst_tdxrd:mch6
TDXRD [16]: ct(0.01)
DEBUG 2021-03-30 18:52:08,057 id11/metaexp/tdxrd: call ping()
DEBUG 2021-03-30 18:52:08,058 id11/metaexp/tdxrd: returned: 122
DEBUG 2021-03-30 18:52:08,058 id11/metadata/tdxrd: call ping()
DEBUG 2021-03-30 18:52:08,059 id11/metadata/tdxrd: returned: 119
DEBUG 2021-03-30 18:52:08,059 id11/metadata/tdxrd: call State()
DEBUG 2021-03-30 18:52:08,062 id11/metadata/tdxrd: returned: STANDBY
DEBUG 2021-03-30 18:52:08,063 bliss.scanning.scan_saving: create eval_dict (method 'proposal_name')
DEBUG 2021-03-30 18:52:08,064 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:08,065 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:08,068 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:08,070 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:08,072 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:08,073 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:08,073 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:08,074 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:08,074 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:08,074 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:08,074 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:08,074 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:08,075 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:08,075 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:08,075 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:08,075 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:08,075 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:08,075 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:08,076 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:08,076 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:08,076 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:08,076 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:08,076 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:08,077 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:08,077 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:08,077 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:08,078 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:08,078 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:08,078 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:08,079 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:08,079 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:08,079 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:08,079 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:08,079 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:08,080 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:08,080 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:08,080 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:08,080 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:08,080 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:08,081 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:08,081 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:08,081 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:08,081 bliss.scanning.scan_saving: filled eval_dict (method 'proposal_name')
DEBUG 2021-03-30 18:52:08,082 id11/metaexp/tdxrd: getting attribute 'proposal': blc12852
DEBUG 2021-03-30 18:52:08,082 id11/metadata/tdxrd: call notifyCommand('ct(0.01)',)
DEBUG 2021-03-30 18:52:08,163 id11/metadata/tdxrd: returned: None
INFO 2021-03-30 18:52:08,165 bliss.scans: Doing ct
DEBUG 2021-03-30 18:52:08,166 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:08,470 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:08,472 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:08,473 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:08,475 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:08,476 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:08,478 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:08,479 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:08,480 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:08,482 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:08,485 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:08,486 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:08,488 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:08,489 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:08,490 id11/limaccds/frelon1: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:08,492 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:08,796 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:08,798 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:08,799 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:08,801 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:08,802 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:08,803 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:08,805 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:08,806 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:08,808 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:08,809 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:08,811 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:08,812 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:08,813 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:08,815 id11/limaccds/frelon2: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:08,816 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:09,120 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:09,121 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:09,123 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:09,125 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:09,126 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:09,128 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:09,129 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:09,131 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:09,132 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:09,134 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:09,135 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:09,137 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:09,138 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:09,139 id11/limaccds/frelon3: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:09,141 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:09,445 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:09,447 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:09,448 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:09,449 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:09,451 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:09,452 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:09,453 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:09,455 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:09,456 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:09,458 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:09,461 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:09,463 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'bpm')
DEBUG 2021-03-30 18:52:09,464 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'roicounter')
DEBUG 2021-03-30 18:52:09,465 id11/limaccds/marana: call command_inout('getPluginDeviceNameFromType', 'roi2spectrum')
DEBUG 2021-03-30 18:52:09,470 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'setattr' args=('read_all_triggers', False)
DEBUG 2021-03-30 18:52:09,476 bliss.scans: Start scan.init.chain
DEBUG 2021-03-30 18:52:09,476 bliss.scans: End scan.init.chain Took 0.000407s
DEBUG 2021-03-30 18:52:09,477 bliss.scans: Start scan.init.saving
DEBUG 2021-03-30 18:52:09,477 bliss.config.settings: In ESRFScanSaving.__init__(esrf_scan_saving:tdxrd,
default_values={'images_path_template': 'scan{scan_number}', 'images_prefix': '{img_acq_device}_', 'date_format': '%Y%m%d', 'scan_number_format': '%04d', 'dataset_number_format': '%04d', 'technique': '', '_writer_module': 'nexus', '_proposal': '', '_ESRFScanSaving__proposal_timestamp': 0, '_collection': '', '_dataset': '', '_mount': '', '_reserved_dataset': ''},
property_attributes=['session', 'date', 'user_name', 'scan_name', 'scan_number', 'img_acq_device', 'writer', 'data_policy', 'template', 'beamline', 'proposal_name', 'base_path', 'collection_name', 'dataset_name', 'data_filename', 'images_path_relative', 'mount_point', 'proposal', 'collection', 'dataset'],
not_removable=dict_keys(['images_path_template', 'images_prefix', 'date_format', 'scan_number_format', 'dataset_number_format', 'technique', '_writer_module', '_proposal', '_ESRFScanSaving__proposal_timestamp', '_collection', '_dataset', '_mount', '_reserved_dataset'])
)
DEBUG 2021-03-30 18:52:09,478 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,482 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,484 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,487 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,489 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,491 bliss.scans: End scan.init.saving Took 0.014441s
DEBUG 2021-03-30 18:52:09,491 bliss.scans: Start scan.init.display
DEBUG 2021-03-30 18:52:09,492 bliss.config.settings: In ScanDisplay.__init__(tdxrd:scan_display_params,
default_values={'auto': False, 'motor_position': True, '_extra_args': [], '_scan_metadata': {}, 'displayed_channels': [], 'scan_display_filter_enabled': True},
property_attributes=('session', 'extra_args', 'flint_output_enabled'),
not_removable=('auto', 'motor_position', 'displayed_channels', '_scan_metadata', 'scan_display_filter_enabled')
)
DEBUG 2021-03-30 18:52:09,494 bliss.config.settings: In ScanDisplay.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,496 bliss.config.settings: In ScanDisplay(tdxrd:scan_display_params).add(_session_name, value=tdxrd)
DEBUG 2021-03-30 18:52:09,497 bliss.config.settings: In ScanDisplay.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,499 bliss.config.settings: In ScanDisplay.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,501 bliss.config.settings: In ScanDisplay.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,503 bliss.config.settings: In ScanDisplay.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,505 bliss.scans: End scan.init.display Took 0.013510s
DEBUG 2021-03-30 18:52:09,505 bliss.scans: Start scan.init.scan_info
DEBUG 2021-03-30 18:52:09,506 bliss.scans: End scan.init.scan_info Took 0.001069s
DEBUG 2021-03-30 18:52:09,506 bliss.scans: Start scan.init.writer
DEBUG 2021-03-30 18:52:09,507 bliss.scanning.scan_saving: create eval_dict (method 'get')
DEBUG 2021-03-30 18:52:09,507 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,508 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,511 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,512 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,514 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,515 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,515 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,516 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,516 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,516 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,516 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,516 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,516 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,517 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,517 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,517 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,517 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,517 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,517 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,517 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,518 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,518 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,518 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,518 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,519 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,519 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,519 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,520 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,520 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,520 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,520 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,520 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,521 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,521 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,521 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,521 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,521 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,521 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,522 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,522 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,522 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,522 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,522 bliss.scanning.scan_saving: filled eval_dict (method 'get')
DEBUG 2021-03-30 18:52:09,523 bliss.scanning.scan_saving: fget eval property 'root_path'
DEBUG 2021-03-30 18:52:09,523 bliss.scanning.scan_saving: eval_dict['root_path'] = '/data/id11/3dxrd/blc12852/id11/vibrations/vibrations_vib_monochromatic'
DEBUG 2021-03-30 18:52:09,523 bliss.scanning.scan_saving: fget eval property 'data_path'
DEBUG 2021-03-30 18:52:09,523 bliss.scanning.scan_saving: fget eval property 'eval_data_filename'
DEBUG 2021-03-30 18:52:09,524 bliss.scanning.scan_saving: eval_dict['eval_data_filename'] = 'vibrations_vib_monochromatic'
DEBUG 2021-03-30 18:52:09,524 bliss.scanning.scan_saving: eval_dict['data_path'] = '/data/id11/3dxrd/blc12852/id11/vibrations/vibrations_vib_monochromatic/vibrations_vib_monochromatic'
DEBUG 2021-03-30 18:52:09,524 bliss.scanning.scan_saving: fget eval property 'images_path'
DEBUG 2021-03-30 18:52:09,525 bliss.scanning.scan_saving: eval_dict['images_path'] = '/data/id11/3dxrd/blc12852/id11/vibrations/vibrations_vib_monochromatic/scan{scan_number}/{img_acq_device}_'
DEBUG 2021-03-30 18:52:09,525 bliss.scanning.scan_saving: fget eval property '_db_path_items'
DEBUG 2021-03-30 18:52:09,525 bliss.scanning.scan_saving: fget eval property '_db_path_keys'
DEBUG 2021-03-30 18:52:09,525 bliss.scanning.scan_saving: eval_dict['_db_path_keys'] = ['tdxrd', 'data', 'id11', '3dxrd', 'blc12852', 'vibrations', 'vibrations_vib_monochromatic']
DEBUG 2021-03-30 18:52:09,526 bliss.scanning.scan_saving: eval_dict['_db_path_items'] = [('tdxrd', 'container'), ('data', 'container'), ('id11', 'container'), ('3dxrd', 'container'), ('blc12852', 'proposal'), ('vibrations', 'dataset_collection'), ('vibrations_vib_monochromatic', 'dataset')]
DEBUG 2021-03-30 18:52:09,526 bliss.scanning.scan_saving: fget eval property 'writer_object'
DEBUG 2021-03-30 18:52:09,526 bliss.scanning.scan_saving: eval_dict['writer_object'] = <bliss.scanning.writer.nexus.Writer object at 0x7f370e009050>
DEBUG 2021-03-30 18:52:09,527 bliss.scans: End scan.init.writer Took 0.020192s
DEBUG 2021-03-30 18:52:09,527 bliss.scans: Start scan.init.flint
DEBUG 2021-03-30 18:52:09,527 bliss.scans: End scan.init.flint Took 0.000673s
DEBUG 2021-03-30 18:52:09,528 bliss.scans: Start scan.prepare.node
DEBUG 2021-03-30 18:52:09,528 bliss.scanning.scan_saving: create eval_dict (method '_db_path_items')
DEBUG 2021-03-30 18:52:09,529 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,530 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,532 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,533 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,535 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,535 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,536 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,536 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,536 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,537 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,537 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,537 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,537 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,537 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,537 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,538 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,538 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,538 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,538 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,538 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,538 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,538 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,539 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,539 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,539 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,539 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,540 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,540 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,540 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,541 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,541 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,541 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,541 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,541 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,541 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,542 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,542 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,542 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,542 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,542 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,542 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,543 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,543 bliss.scanning.scan_saving: filled eval_dict (method '_db_path_items')
DEBUG 2021-03-30 18:52:09,543 bliss.scanning.scan_saving: fget eval property '_db_path_keys'
DEBUG 2021-03-30 18:52:09,543 bliss.scanning.scan_saving: fget eval property 'eval_data_filename'
DEBUG 2021-03-30 18:52:09,543 bliss.scanning.scan_saving: eval_dict['eval_data_filename'] = 'vibrations_vib_monochromatic'
DEBUG 2021-03-30 18:52:09,544 bliss.scanning.scan_saving: eval_dict['_db_path_keys'] = ['tdxrd', 'data', 'id11', '3dxrd', 'blc12852', 'vibrations', 'vibrations_vib_monochromatic']
DEBUG 2021-03-30 18:52:09,546 bliss.scanning.scan_saving: create eval_dict (method 'proposal_name')
DEBUG 2021-03-30 18:52:09,547 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,548 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,550 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,552 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,553 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,554 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,554 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,554 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,555 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,555 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,555 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,555 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,555 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,555 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,555 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,556 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,556 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,556 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,556 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,556 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,556 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,556 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,557 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,557 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,557 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,557 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,558 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,558 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,558 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,558 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,559 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,559 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,559 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,559 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,559 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,559 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,559 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,560 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,560 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,560 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,560 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,560 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,561 bliss.scanning.scan_saving: filled eval_dict (method 'proposal_name')
DEBUG 2021-03-30 18:52:09,561 bliss.scanning.scan_saving: create eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,561 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,562 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,565 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,566 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,567 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,568 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,568 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,568 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,569 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,569 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,569 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,569 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,569 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,569 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,569 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,570 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,570 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,570 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,570 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,570 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,570 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,570 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,571 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,571 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,571 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,571 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,572 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,572 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,572 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,572 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,572 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,573 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,573 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,573 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,573 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,573 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,573 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,574 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,574 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,574 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,574 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,574 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,574 bliss.scanning.scan_saving: filled eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,574 bliss.scanning.scan_saving: fget eval property 'icat_base_path'
DEBUG 2021-03-30 18:52:09,575 bliss.scanning.scan_saving: eval_dict['icat_base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,576 bliss.scanning.scan_saving: create eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,577 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,577 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,580 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,581 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,583 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,583 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,583 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,584 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,584 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,584 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,584 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,584 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,584 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,585 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,585 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,585 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,585 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,585 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,585 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,585 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,585 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,586 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,586 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,586 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,586 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,587 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,587 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,587 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,587 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,587 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,588 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,588 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,588 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,588 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,588 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,588 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,588 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,588 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,589 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,589 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,589 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,589 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,589 bliss.scanning.scan_saving: filled eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,589 bliss.scanning.scan_saving: fget eval property 'icat_base_path'
DEBUG 2021-03-30 18:52:09,590 bliss.scanning.scan_saving: eval_dict['icat_base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,591 bliss.scanning.scan_saving: create eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,591 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,592 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,594 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,596 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,597 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,598 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,598 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,598 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,598 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,598 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,599 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,599 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,599 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,599 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,599 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,599 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,599 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,599 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,600 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,600 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,600 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,600 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,600 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,600 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,601 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,601 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,601 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,601 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,602 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,602 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,602 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,602 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,602 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,602 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,602 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,602 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,603 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,603 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,603 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,603 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,603 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,603 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,603 bliss.scanning.scan_saving: filled eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,604 bliss.scanning.scan_saving: fget eval property 'icat_base_path'
DEBUG 2021-03-30 18:52:09,604 bliss.scanning.scan_saving: eval_dict['icat_base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,606 bliss.scanning.scan_saving: create eval_dict (method '_db_path_items')
DEBUG 2021-03-30 18:52:09,606 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,607 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,609 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,610 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,612 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,612 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,612 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,613 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,613 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,613 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,613 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,613 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,613 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,614 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,614 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,614 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,614 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,614 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,614 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,614 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,614 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,614 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,615 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,615 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,615 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,615 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,616 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,616 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,616 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,616 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,616 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,616 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,616 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,617 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,617 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,617 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,617 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,617 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,617 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,617 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,617 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,618 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,618 bliss.scanning.scan_saving: filled eval_dict (method '_db_path_items')
DEBUG 2021-03-30 18:52:09,618 bliss.scanning.scan_saving: fget eval property '_db_path_keys'
DEBUG 2021-03-30 18:52:09,618 bliss.scanning.scan_saving: fget eval property 'eval_data_filename'
DEBUG 2021-03-30 18:52:09,618 bliss.scanning.scan_saving: eval_dict['eval_data_filename'] = 'vibrations_vib_monochromatic'
DEBUG 2021-03-30 18:52:09,618 bliss.scanning.scan_saving: eval_dict['_db_path_keys'] = ['tdxrd', 'data', 'id11', '3dxrd', 'blc12852', 'vibrations', 'vibrations_vib_monochromatic']
DEBUG 2021-03-30 18:52:09,620 bliss.scanning.scan_saving: create eval_dict (method 'proposal_name')
DEBUG 2021-03-30 18:52:09,621 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,622 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,624 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,625 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,626 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,627 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,627 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,627 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,627 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,627 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,628 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,628 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,628 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,628 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,628 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,628 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,628 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,628 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,628 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,629 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,629 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,629 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,629 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,629 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,629 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,630 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,630 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,630 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,630 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,630 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,630 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,631 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,631 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,631 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,631 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,631 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,631 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,631 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,631 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,632 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,632 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,632 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,632 bliss.scanning.scan_saving: filled eval_dict (method 'proposal_name')
DEBUG 2021-03-30 18:52:09,632 bliss.scanning.scan_saving: create eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,633 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,633 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,635 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,636 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,638 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,638 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,638 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,639 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,639 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,639 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,639 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,639 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,639 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,639 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,639 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,640 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,640 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,640 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,640 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,640 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,640 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,640 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,640 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,641 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,641 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,641 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,641 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,641 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,642 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,642 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,642 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,642 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,642 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,642 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,642 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,642 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,642 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,643 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,643 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,643 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,643 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,643 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,643 bliss.scanning.scan_saving: filled eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,643 bliss.scanning.scan_saving: fget eval property 'icat_base_path'
DEBUG 2021-03-30 18:52:09,644 bliss.scanning.scan_saving: eval_dict['icat_base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,644 bliss.scanning.scan_saving: create eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,645 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,646 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,648 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,649 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,650 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,650 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,650 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,651 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,651 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,651 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,651 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,651 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,651 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,651 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,652 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,652 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,652 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,652 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,652 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,652 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,652 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,652 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,652 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,653 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,653 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,653 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,653 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,653 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,654 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,654 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,654 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,654 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,654 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,654 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,654 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,654 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,654 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,655 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,655 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,655 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,655 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,655 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,655 bliss.scanning.scan_saving: filled eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,655 bliss.scanning.scan_saving: fget eval property 'icat_base_path'
DEBUG 2021-03-30 18:52:09,656 bliss.scanning.scan_saving: eval_dict['icat_base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,656 bliss.scanning.scan_saving: create eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,657 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,658 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,659 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,660 bliss.config.settings: In ESRFScanSaving.switch(default,copy=None)
DEBUG 2021-03-30 18:52:09,662 bliss.scanning.scan_saving: fget normal property 'session'
DEBUG 2021-03-30 18:52:09,662 bliss.scanning.scan_saving: eval_dict['session'] = 'tdxrd'
DEBUG 2021-03-30 18:52:09,662 bliss.scanning.scan_saving: fget normal property 'date'
DEBUG 2021-03-30 18:52:09,663 bliss.scanning.scan_saving: eval_dict['date'] = '20210330'
DEBUG 2021-03-30 18:52:09,663 bliss.scanning.scan_saving: fget normal property 'scan_name'
DEBUG 2021-03-30 18:52:09,663 bliss.scanning.scan_saving: eval_dict['scan_name'] = '{scan_name}'
DEBUG 2021-03-30 18:52:09,663 bliss.scanning.scan_saving: fget normal property 'scan_number'
DEBUG 2021-03-30 18:52:09,663 bliss.scanning.scan_saving: eval_dict['scan_number'] = '{scan_number}'
DEBUG 2021-03-30 18:52:09,663 bliss.scanning.scan_saving: fget normal property 'img_acq_device'
DEBUG 2021-03-30 18:52:09,663 bliss.scanning.scan_saving: eval_dict['img_acq_device'] = '{img_acq_device}'
DEBUG 2021-03-30 18:52:09,663 bliss.scanning.scan_saving: fget normal property 'writer'
DEBUG 2021-03-30 18:52:09,663 bliss.scanning.scan_saving: eval_dict['writer'] = 'nexus'
DEBUG 2021-03-30 18:52:09,663 bliss.scanning.scan_saving: fget normal property 'data_policy'
DEBUG 2021-03-30 18:52:09,664 bliss.scanning.scan_saving: eval_dict['data_policy'] = 'ESRF'
DEBUG 2021-03-30 18:52:09,664 bliss.scanning.scan_saving: fget normal property 'template'
DEBUG 2021-03-30 18:52:09,664 bliss.scanning.scan_saving: eval_dict['template'] = '{proposal_name}/{beamline}/{collection_name}/{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,664 bliss.scanning.scan_saving: fget normal property 'beamline'
DEBUG 2021-03-30 18:52:09,664 bliss.scanning.scan_saving: eval_dict['beamline'] = 'id11'
DEBUG 2021-03-30 18:52:09,664 bliss.scanning.scan_saving: fget eval property 'proposal_name'
DEBUG 2021-03-30 18:52:09,664 bliss.scanning.scan_saving: eval_dict['proposal_name'] = 'blc12852'
DEBUG 2021-03-30 18:52:09,665 bliss.scanning.scan_saving: fget eval property 'base_path'
DEBUG 2021-03-30 18:52:09,665 bliss.scanning.scan_saving: fget eval property 'proposal_type'
DEBUG 2021-03-30 18:52:09,665 bliss.scanning.scan_saving: eval_dict['proposal_type'] = 'inhouse'
DEBUG 2021-03-30 18:52:09,665 bliss.scanning.scan_saving: eval_dict['base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,665 bliss.scanning.scan_saving: fget normal property 'collection_name'
DEBUG 2021-03-30 18:52:09,665 bliss.scanning.scan_saving: eval_dict['collection_name'] = 'vibrations'
DEBUG 2021-03-30 18:52:09,666 bliss.scanning.scan_saving: fget normal property 'dataset_name'
DEBUG 2021-03-30 18:52:09,666 bliss.scanning.scan_saving: eval_dict['dataset_name'] = 'vib_monochromatic'
DEBUG 2021-03-30 18:52:09,666 bliss.scanning.scan_saving: fget normal property 'data_filename'
DEBUG 2021-03-30 18:52:09,666 bliss.scanning.scan_saving: eval_dict['data_filename'] = '{collection_name}_{dataset_name}'
DEBUG 2021-03-30 18:52:09,666 bliss.scanning.scan_saving: fget normal property 'images_path_relative'
DEBUG 2021-03-30 18:52:09,666 bliss.scanning.scan_saving: eval_dict['images_path_relative'] = True
DEBUG 2021-03-30 18:52:09,666 bliss.scanning.scan_saving: fget normal property 'mount_point'
DEBUG 2021-03-30 18:52:09,666 bliss.scanning.scan_saving: eval_dict['mount_point'] = ''
DEBUG 2021-03-30 18:52:09,666 bliss.scanning.scan_saving: fget normal property 'creation_date'
DEBUG 2021-03-30 18:52:09,667 bliss.scanning.scan_saving: eval_dict['creation_date'] = '2020-03-17-10:11'
DEBUG 2021-03-30 18:52:09,667 bliss.scanning.scan_saving: fget normal property 'last_accessed'
DEBUG 2021-03-30 18:52:09,667 bliss.scanning.scan_saving: eval_dict['last_accessed'] = '2021-03-30-18:52'
DEBUG 2021-03-30 18:52:09,667 bliss.scanning.scan_saving: filled eval_dict (method 'icat_root_path')
DEBUG 2021-03-30 18:52:09,667 bliss.scanning.scan_saving: fget eval property 'icat_base_path'
DEBUG 2021-03-30 18:52:09,667 bliss.scanning.scan_saving: eval_dict['icat_base_path'] = '/data/id11/3dxrd'
DEBUG 2021-03-30 18:52:09,670 bliss.scans: End scan.prepare.node Took 0.142575s
DEBUG 2021-03-30 18:52:09,670 bliss.scans: Start scan.run.start_data_watcher
Tue Mar 30 18:52:09 2021: Scan(name=ct, path='not saved')
DEBUG 2021-03-30 18:52:09,671 bliss.scans: End scan.run.start_data_watcher Took 0.000356s
DEBUG 2021-03-30 18:52:09,671 bliss.scans: Start timer.wait_ready
DEBUG 2021-03-30 18:52:09,671 bliss.scans: End timer.wait_ready Took 0.000175s
DEBUG 2021-03-30 18:52:09,672 bliss.scans: Start keithley.wait_ready
DEBUG 2021-03-30 18:52:09,672 bliss.scans: Start keithley.wait_ready
DEBUG 2021-03-30 18:52:09,672 bliss.scans: Start p201_20.wait_ready
DEBUG 2021-03-30 18:52:09,672 bliss.scans: End keithley.wait_ready Took 0.000486s
DEBUG 2021-03-30 18:52:09,672 bliss.scans: End keithley.wait_ready Took 0.000458s
DEBUG 2021-03-30 18:52:09,672 bliss.scans: End p201_20.wait_ready Took 0.000432s
DEBUG 2021-03-30 18:52:09,673 bliss.scans: Start ct2_counters_controller.wait_ready
DEBUG 2021-03-30 18:52:09,673 bliss.scans: End ct2_counters_controller.wait_ready Took 0.000174s
DEBUG 2021-03-30 18:52:09,673 bliss.scans: Start scan.preset._prepare
DEBUG 2021-03-30 18:52:09,674 bliss.scans: End scan.preset._prepare Took 0.000167s
DEBUG 2021-03-30 18:52:09,674 bliss.scans: Start scan.prepare.devices
DEBUG 2021-03-30 18:52:09,683 bliss.scans: End scan.prepare.devices Took 0.009163s
DEBUG 2021-03-30 18:52:09,683 bliss.scans: Start scan.prepare.writer
DEBUG 2021-03-30 18:52:09,683 bliss.scans: End scan.prepare.writer Took 0.000373s
DEBUG 2021-03-30 18:52:09,684 bliss.scans: Start scan.prepare.motion_hooks
DEBUG 2021-03-30 18:52:09,684 bliss.scans: End scan.prepare.motion_hooks Took 0.000162s
DEBUG 2021-03-30 18:52:09,684 global.controllers.multiplexer:mux_tdxrd: Multiplexer.switch TRIGGER_MODE to COUNTER_CARD
DEBUG 2021-03-30 18:52:09,684 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=14 b'IMA 0x0 0x80\r\n'
DEBUG 2021-03-30 18:52:09,684 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'IMA 0x0 0x80\r\n'),)
DEBUG 2021-03-30 18:52:09,686 id11/serial/lid112_16: returned: 14
DEBUG 2021-03-30 18:52:09,686 global.controllers.multiplexer:mux_tdxrd: Multiplexer.switch CAM1 to ON
DEBUG 2021-03-30 18:52:09,686 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=13 b'IMA 0x4 0x4\r\n'
DEBUG 2021-03-30 18:52:09,686 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'IMA 0x4 0x4\r\n'),)
DEBUG 2021-03-30 18:52:09,687 id11/serial/lid112_16: returned: 13
DEBUG 2021-03-30 18:52:09,687 global.controllers.multiplexer:mux_tdxrd: Multiplexer.switch CAM2 to ON
DEBUG 2021-03-30 18:52:09,687 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=13 b'IMA 0x8 0x8\r\n'
DEBUG 2021-03-30 18:52:09,687 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'IMA 0x8 0x8\r\n'),)
DEBUG 2021-03-30 18:52:09,689 id11/serial/lid112_16: returned: 13
DEBUG 2021-03-30 18:52:09,689 global.controllers.multiplexer:mux_tdxrd: Multiplexer.switch CAM3 to ON
DEBUG 2021-03-30 18:52:09,689 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=15 b'IMA 0x10 0x10\r\n'
DEBUG 2021-03-30 18:52:09,689 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'IMA 0x10 0x10\r\n'),)
DEBUG 2021-03-30 18:52:09,690 id11/serial/lid112_16: returned: 15
DEBUG 2021-03-30 18:52:09,690 global.controllers.multiplexer:mux_tdxrd: Multiplexer.switch MARANA to ON
DEBUG 2021-03-30 18:52:09,690 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=13 b'IMA 0x1 0x1\r\n'
DEBUG 2021-03-30 18:52:09,690 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'IMA 0x1 0x1\r\n'),)
DEBUG 2021-03-30 18:52:09,692 id11/serial/lid112_16: returned: 13
DEBUG 2021-03-30 18:52:09,692 bliss.scans: Start ct2_counters_controller.prepare
DEBUG 2021-03-30 18:52:09,692 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'getattr' args=('INPUT_CHANNELS',)
DEBUG 2021-03-30 18:52:09,692 bliss.scans: Start p201_20.prepare
DEBUG 2021-03-30 18:52:09,692 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'setattr' args=('acq_mode', <AcqMode.IntTrigMulti: 3>)
DEBUG 2021-03-30 18:52:09,693 bliss.scans: Start keithley.prepare
DEBUG 2021-03-30 18:52:09,693 bliss.scans: End keithley.prepare Took 0.000171s
DEBUG 2021-03-30 18:52:09,693 bliss.scans: Start keithley.prepare
DEBUG 2021-03-30 18:52:09,693 bliss.scans: End keithley.prepare Took 0.000136s
DEBUG 2021-03-30 18:52:09,693 bliss.scans: Start timer.prepare
DEBUG 2021-03-30 18:52:09,693 bliss.scans: End timer.prepare Took 0.000128s
DEBUG 2021-03-30 18:52:09,694 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'getattr' args=('internal_timer_counter',)
DEBUG 2021-03-30 18:52:09,694 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'setattr' args=('acq_expo_time', 0.01)
DEBUG 2021-03-30 18:52:09,695 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'getattr' args=('internal_point_nb_counter',)
DEBUG 2021-03-30 18:52:09,695 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'setattr' args=('acq_nb_points', 1)
DEBUG 2021-03-30 18:52:09,695 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'getattr' args=('timer_freq',)
DEBUG 2021-03-30 18:52:09,696 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'setattr' args=('acq_point_period', None)
DEBUG 2021-03-30 18:52:09,696 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'setattr' args=('acq_channels', [1, 2, 3])
DEBUG 2021-03-30 18:52:09,697 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'call' args=['prepare_acq']
DEBUG 2021-03-30 18:52:09,698 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'call' args=['prepare_acq']
DEBUG 2021-03-30 18:52:09,699 bliss.scans: End p201_20.prepare Took 0.007103s
DEBUG 2021-03-30 18:52:09,701 bliss.scans: End ct2_counters_controller.prepare Took 0.009242s
DEBUG 2021-03-30 18:52:09,702 bliss.scans: Start scan.fill_metadata
DEBUG 2021-03-30 18:52:09,702 bliss.scans: End scan.fill_metadata Took 0.000185s
DEBUG 2021-03-30 18:52:09,702 bliss.scans: Start scan.preset.start
DEBUG 2021-03-30 18:52:09,702 bliss.scans: End scan.preset.start Took 0.000146s
DEBUG 2021-03-30 18:52:09,702 global.controllers.multiplexer:mux_tdxrd: Multiplexer.getOutputStat SHUTTER_SESSION
DEBUG 2021-03-30 18:52:09,702 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=5 b'?IM\r\n'
DEBUG 2021-03-30 18:52:09,703 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'?IM\r\n'),)
DEBUG 2021-03-30 18:52:09,704 id11/serial/lid112_16: returned: 5
DEBUG 2021-03-30 18:52:09,704 id11/serial/lid112_16: call DevSerReadChar(2,)
DEBUG 2021-03-30 18:52:09,777 id11/serial/lid112_16: returned: [ 48 120 56 48 13 10]
DEBUG 2021-03-30 18:52:09,778 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: readline bytes=5 b'0x80\r'
DEBUG 2021-03-30 18:52:09,778 global.controllers.multiplexer:mux_tdxrd.opiom:opiom_tdxrd: Read b'0x80'
DEBUG 2021-03-30 18:52:09,778 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=6 b'?IMA\r\n'
DEBUG 2021-03-30 18:52:09,779 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'?IMA\r\n'),)
DEBUG 2021-03-30 18:52:09,780 id11/serial/lid112_16: returned: 6
DEBUG 2021-03-30 18:52:09,780 id11/serial/lid112_16: call DevSerReadChar(2,)
DEBUG 2021-03-30 18:52:09,801 id11/serial/lid112_16: returned: [ 48 120 49 68 13 10]
DEBUG 2021-03-30 18:52:09,802 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: readline bytes=5 b'0x1D\r'
DEBUG 2021-03-30 18:52:09,802 global.controllers.multiplexer:mux_tdxrd.opiom:opiom_tdxrd: Read b'0x1D'
DEBUG 2021-03-30 18:52:09,803 global.controllers.multiplexer:mux_tdxrd: Multiplexer.switch SHUTTER to OPEN
DEBUG 2021-03-30 18:52:09,803 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=12 b'IM 0x1 0x7\r\n'
DEBUG 2021-03-30 18:52:09,803 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'IM 0x1 0x7\r\n'),)
DEBUG 2021-03-30 18:52:09,805 id11/serial/lid112_16: returned: 12
DEBUG 2021-03-30 18:52:09,820 bliss.scans: Start ct2_counters_controller.start
DEBUG 2021-03-30 18:52:09,821 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,821 bliss.scans: End scan.events.device Took 0.000211s
DEBUG 2021-03-30 18:52:09,821 bliss.scans: End ct2_counters_controller.start Took 0.000768s
DEBUG 2021-03-30 18:52:09,821 bliss.scans: Start p201_20.start
DEBUG 2021-03-30 18:52:09,821 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,822 bliss.scans: End scan.events.device Took 0.000121s
DEBUG 2021-03-30 18:52:09,822 bliss.scans: End p201_20.start Took 0.000445s
DEBUG 2021-03-30 18:52:09,822 bliss.scans: Start keithley.start
DEBUG 2021-03-30 18:52:09,822 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,822 bliss.scans: End scan.events.device Took 0.000112s
DEBUG 2021-03-30 18:52:09,822 bliss.scans: End keithley.start Took 0.000391s
DEBUG 2021-03-30 18:52:09,822 bliss.scans: Start keithley.start
DEBUG 2021-03-30 18:52:09,823 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,823 bliss.scans: End scan.events.device Took 0.000110s
DEBUG 2021-03-30 18:52:09,823 bliss.scans: End keithley.start Took 0.000385s
DEBUG 2021-03-30 18:52:09,823 bliss.scans: Start timer.start
DEBUG 2021-03-30 18:52:09,823 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,823 bliss.scans: End scan.events.device Took 0.000113s
DEBUG 2021-03-30 18:52:09,823 bliss.scans: Start timer.trigger_slaves
DEBUG 2021-03-30 18:52:09,824 bliss.scans: End timer.trigger_slaves Took 0.000141s
DEBUG 2021-03-30 18:52:09,824 bliss.scans: Start timer.wait_slaves
DEBUG 2021-03-30 18:52:09,824 bliss.scans: Start keithley.trigger
DEBUG 2021-03-30 18:52:09,824 bliss.scans: End keithley.trigger Took 0.000125s
DEBUG 2021-03-30 18:52:09,824 bliss.scans: Start p201_20.trigger
DEBUG 2021-03-30 18:52:09,824 bliss.scans: Start p201_20.trigger_slaves
DEBUG 2021-03-30 18:52:09,824 bliss.scans: End p201_20.trigger_slaves Took 0.000133s
DEBUG 2021-03-30 18:52:09,825 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'call' args=['start_acq']
DEBUG 2021-03-30 18:52:09,825 bliss.scans: Start keithley.trigger
DEBUG 2021-03-30 18:52:09,825 bliss.scans: End keithley.trigger Took 0.000132s
DEBUG 2021-03-30 18:52:09,825 bliss.scans: Start scan.events.channel
DEBUG 2021-03-30 18:52:09,825 bliss.scans: End scan.events.channel Took 0.000283s
DEBUG 2021-03-30 18:52:09,826 bliss.scans: Start scan.events.channel
DEBUG 2021-03-30 18:52:09,826 bliss.scans: End scan.events.channel Took 0.000232s
DEBUG 2021-03-30 18:52:09,826 global.controllers.KeithleySCPI(SCPI(Gpib[enet://gpibid11b_esrf_fr:21])).SCPI(Gpib[enet://gpibid11b_esrf_fr:21]): [start] read bytes=6 READ?\x0a
DEBUG 2021-03-30 18:52:09,826 global.controllers.KeithleySCPI(SCPI(Gpib[enet://gpibid11b_esrf_fr:21])).SCPI(Gpib[enet://gpibid11b_esrf_fr:21]).Gpib[enet://gpibid11b_esrf_fr:21]: write bytes=6 b'READ?\n'
DEBUG 2021-03-30 18:52:09,827 Socket[gpibid11b.esrf.fr:5000]: write bytes=18 b'b\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\x00READ?\n'
DEBUG 2021-03-30 18:52:09,827 bliss.scans: Start ct2_counters_controller.trigger
DEBUG 2021-03-30 18:52:09,827 bliss.scans: End ct2_counters_controller.trigger Took 0.000129s
DEBUG 2021-03-30 18:52:09,827 global.controllers.KeithleySCPI(SCPI(Gpib[enet://gpibid11b_esrf_fr:20])).SCPI(Gpib[enet://gpibid11b_esrf_fr:20]): [start] read bytes=6 READ?\x0a
DEBUG 2021-03-30 18:52:09,827 global.controllers.KeithleySCPI(SCPI(Gpib[enet://gpibid11b_esrf_fr:20])).SCPI(Gpib[enet://gpibid11b_esrf_fr:20]).Gpib[enet://gpibid11b_esrf_fr:20]: write bytes=6 b'READ?\n'
DEBUG 2021-03-30 18:52:09,828 Socket[gpibid11b.esrf.fr:5000]: write bytes=18 b'b\x00\x00\x00\x00\x00\x00\x06\x00\x00\x00\x00READ?\n'
DEBUG 2021-03-30 18:52:09,828 bliss.scans: End p201_20.trigger Took 0.003791s
DEBUG 2021-03-30 18:52:09,828 bliss.scans: End timer.wait_slaves Took 0.004374s
DEBUG 2021-03-30 18:52:09,833 Socket[gpibid11b.esrf.fr:5000]: received bytes=16 b'\x00\x00\x00\x0c\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x06'
DEBUG 2021-03-30 18:52:09,833 Socket[gpibid11b.esrf.fr:5000]: read bytes=4 b'\x00\x00\x00\x0c'
DEBUG 2021-03-30 18:52:09,834 Socket[gpibid11b.esrf.fr:5000]: read bytes=12 b'\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x06'
DEBUG 2021-03-30 18:52:09,834 Socket[gpibid11b.esrf.fr:5000]: write bytes=12 b'\x16\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00'
DEBUG 2021-03-30 18:52:09,835 bliss.scans: End timer.start Took 0.011781s
DEBUG 2021-03-30 18:52:09,835 Socket[gpibid11b.esrf.fr:5000]: received bytes=16 b'\x00\x00\x00\x0c\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x06'
DEBUG 2021-03-30 18:52:09,836 Socket[gpibid11b.esrf.fr:5000]: read bytes=4 b'\x00\x00\x00\x0c'
DEBUG 2021-03-30 18:52:09,836 Socket[gpibid11b.esrf.fr:5000]: read bytes=12 b'\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x06'
DEBUG 2021-03-30 18:52:09,837 Socket[gpibid11b.esrf.fr:5000]: write bytes=12 b'\x16\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00'
DEBUG 2021-03-30 18:52:09,837 bliss.scans: Start timer.wait_ready
DEBUG 2021-03-30 18:52:09,837 bliss.scans: End timer.wait_ready Took 0.000230s
DEBUG 2021-03-30 18:52:09,838 bliss.scans: Start keithley.wait_ready
DEBUG 2021-03-30 18:52:09,838 bliss.scans: Start keithley.wait_ready
DEBUG 2021-03-30 18:52:09,838 bliss.scans: Start p201_20.wait_ready
DEBUG 2021-03-30 18:52:09,839 Socket[gpibid11b.esrf.fr:5000]: received bytes=16 b'\x00\x00\x00\x0c\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
DEBUG 2021-03-30 18:52:09,839 Socket[gpibid11b.esrf.fr:5000]: read bytes=4 b'\x00\x00\x00\x0c'
DEBUG 2021-03-30 18:52:09,839 Socket[gpibid11b.esrf.fr:5000]: read bytes=12 b'\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
DEBUG 2021-03-30 18:52:09,839 bliss.scans: End p201_20.wait_ready Took 0.001092s
DEBUG 2021-03-30 18:52:09,840 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'getattr' args=('read_all_triggers',)
DEBUG 2021-03-30 18:52:09,841 bliss.scans: Start scan.events.channel
DEBUG 2021-03-30 18:52:09,841 bliss.scans: End scan.events.channel Took 0.000454s
DEBUG 2021-03-30 18:52:09,841 bliss.scans: Start scan.events.channel
DEBUG 2021-03-30 18:52:09,842 bliss.scans: End scan.events.channel Took 0.000227s
DEBUG 2021-03-30 18:52:09,842 bliss.scans: Start scan.events.channel
DEBUG 2021-03-30 18:52:09,842 bliss.scans: End scan.events.channel Took 0.000220s
DEBUG 2021-03-30 18:52:09,842 bliss.scans: Start scan.events.channel
DEBUG 2021-03-30 18:52:09,842 bliss.scans: End scan.events.channel Took 0.000217s
DEBUG 2021-03-30 18:52:09,868 Socket[gpibid11b.esrf.fr:5000]: received bytes=47 b'\x00\x00\x00++9.864126E-05A,+5.297880E+05,+0.000000E+00\n'
DEBUG 2021-03-30 18:52:09,868 Socket[gpibid11b.esrf.fr:5000]: read bytes=4 b'\x00\x00\x00+'
DEBUG 2021-03-30 18:52:09,868 Socket[gpibid11b.esrf.fr:5000]: read bytes=43 b'+9.864126E-05A,+5.297880E+05,+0.000000E+00\n'
DEBUG 2021-03-30 18:52:09,868 Socket[gpibid11b.esrf.fr:5000]: received bytes=4 b'\x00\x01\x00\x00'
DEBUG 2021-03-30 18:52:09,869 Socket[gpibid11b.esrf.fr:5000]: read bytes=4 b'\x00\x01\x00\x00'
DEBUG 2021-03-30 18:52:09,869 Socket[gpibid11b.esrf.fr:5000]: received bytes=16 b'\x00\x00\x00\x0c!\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00+'
DEBUG 2021-03-30 18:52:09,869 Socket[gpibid11b.esrf.fr:5000]: read bytes=4 b'\x00\x00\x00\x0c'
DEBUG 2021-03-30 18:52:09,869 Socket[gpibid11b.esrf.fr:5000]: read bytes=12 b'!\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00+'
DEBUG 2021-03-30 18:52:09,869 global.controllers.KeithleySCPI(SCPI(Gpib[enet://gpibid11b_esrf_fr:20])).SCPI(Gpib[enet://gpibid11b_esrf_fr:20]).Gpib[enet://gpibid11b_esrf_fr:20]: readline bytes=42 b'+9.864126E-05A,+5.297880E+05,+0.000000E+00'
DEBUG 2021-03-30 18:52:09,870 global.controllers.KeithleySCPI(SCPI(Gpib[enet://gpibid11b_esrf_fr:20])).SCPI(Gpib[enet://gpibid11b_esrf_fr:20]): [ end ] read bytes=1 ['+9.864126E-05A,+5.297880E+05,+0.000000E+00']
DEBUG 2021-03-30 18:52:09,870 bliss.scans: Start scan.events.channel
DEBUG 2021-03-30 18:52:09,871 bliss.scans: End scan.events.channel Took 0.000305s
DEBUG 2021-03-30 18:52:09,871 bliss.scans: End keithley.wait_ready Took 0.032638s
DEBUG 2021-03-30 18:52:09,871 Socket[gpibid11b.esrf.fr:5000]: received bytes=16 b'\x00\x00\x00\x0c\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
DEBUG 2021-03-30 18:52:09,871 Socket[gpibid11b.esrf.fr:5000]: read bytes=4 b'\x00\x00\x00\x0c'
DEBUG 2021-03-30 18:52:09,871 Socket[gpibid11b.esrf.fr:5000]: read bytes=12 b'\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
DEBUG 2021-03-30 18:52:09,874 Socket[gpibid11b.esrf.fr:5000]: received bytes=47 b'\x00\x00\x00++6.270886E-06A,+5.297956E+05,+0.000000E+00\n'
DEBUG 2021-03-30 18:52:09,874 Socket[gpibid11b.esrf.fr:5000]: read bytes=4 b'\x00\x00\x00+'
DEBUG 2021-03-30 18:52:09,875 Socket[gpibid11b.esrf.fr:5000]: read bytes=43 b'+6.270886E-06A,+5.297956E+05,+0.000000E+00\n'
DEBUG 2021-03-30 18:52:09,875 Socket[gpibid11b.esrf.fr:5000]: received bytes=4 b'\x00\x01\x00\x00'
DEBUG 2021-03-30 18:52:09,875 Socket[gpibid11b.esrf.fr:5000]: read bytes=4 b'\x00\x01\x00\x00'
DEBUG 2021-03-30 18:52:09,876 Socket[gpibid11b.esrf.fr:5000]: received bytes=16 b'\x00\x00\x00\x0c!\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00+'
DEBUG 2021-03-30 18:52:09,876 Socket[gpibid11b.esrf.fr:5000]: read bytes=4 b'\x00\x00\x00\x0c'
DEBUG 2021-03-30 18:52:09,876 Socket[gpibid11b.esrf.fr:5000]: read bytes=12 b'!\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00+'
DEBUG 2021-03-30 18:52:09,876 global.controllers.KeithleySCPI(SCPI(Gpib[enet://gpibid11b_esrf_fr:21])).SCPI(Gpib[enet://gpibid11b_esrf_fr:21]).Gpib[enet://gpibid11b_esrf_fr:21]: readline bytes=42 b'+6.270886E-06A,+5.297956E+05,+0.000000E+00'
DEBUG 2021-03-30 18:52:09,876 global.controllers.KeithleySCPI(SCPI(Gpib[enet://gpibid11b_esrf_fr:21])).SCPI(Gpib[enet://gpibid11b_esrf_fr:21]): [ end ] read bytes=1 ['+6.270886E-06A,+5.297956E+05,+0.000000E+00']
DEBUG 2021-03-30 18:52:09,877 bliss.scans: Start scan.events.channel
DEBUG 2021-03-30 18:52:09,877 bliss.scans: End scan.events.channel Took 0.000439s
DEBUG 2021-03-30 18:52:09,878 bliss.scans: End keithley.wait_ready Took 0.039801s
DEBUG 2021-03-30 18:52:09,878 bliss.scans: Start ct2_counters_controller.wait_ready
DEBUG 2021-03-30 18:52:09,878 bliss.scans: End ct2_counters_controller.wait_ready Took 0.000287s
DEBUG 2021-03-30 18:52:09,879 bliss.scans: Start timer.wait_slaves
DEBUG 2021-03-30 18:52:09,879 bliss.scans: End timer.wait_slaves Took 0.000254s
DEBUG 2021-03-30 18:52:09,879 bliss.scans: Start scan.events.device
pico5 = 6.27089e+06 ( 6.27089e+08 /s) keithley
pico4 = 9.86413e+07 ( 9.86413e+09 /s) keithley
fpico4 = 99313.0 ( 9.93130e+06 /s) p201_20
fpico5 = 62682.0 ( 6.26820e+06 /s) p201_20
sec = 0.0100001 ( 1.00001 /s) p201_20
fpico3 = 2308.00 ( 230800. /s) p201_20
DEBUG 2021-03-30 18:52:09,885 bliss.scans: End scan.events.device Took 0.005407s
DEBUG 2021-03-30 18:52:09,885 bliss.scans: Start keithley.wait_reading
DEBUG 2021-03-30 18:52:09,885 bliss.scans: End keithley.wait_reading Took 0.000154s
DEBUG 2021-03-30 18:52:09,885 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,885 bliss.scans: End scan.events.device Took 0.000190s
DEBUG 2021-03-30 18:52:09,886 bliss.scans: Start keithley.wait_reading
DEBUG 2021-03-30 18:52:09,886 bliss.scans: End keithley.wait_reading Took 0.000155s
DEBUG 2021-03-30 18:52:09,886 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,886 bliss.scans: End scan.events.device Took 0.000156s
DEBUG 2021-03-30 18:52:09,886 bliss.scans: Start p201_20.wait_slaves
DEBUG 2021-03-30 18:52:09,886 bliss.scans: End p201_20.wait_slaves Took 0.000168s
DEBUG 2021-03-30 18:52:09,887 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,887 bliss.scans: End scan.events.device Took 0.000166s
DEBUG 2021-03-30 18:52:09,887 bliss.scans: Start ct2_counters_controller.wait_reading
DEBUG 2021-03-30 18:52:09,887 bliss.scans: End ct2_counters_controller.wait_reading Took 0.000123s
DEBUG 2021-03-30 18:52:09,887 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,887 bliss.scans: End scan.events.device Took 0.000164s
DEBUG 2021-03-30 18:52:09,888 bliss.scans: Start timer.stop
DEBUG 2021-03-30 18:52:09,888 bliss.scans: End timer.stop Took 0.000150s
DEBUG 2021-03-30 18:52:09,888 bliss.scans: Start keithley.stop
DEBUG 2021-03-30 18:52:09,888 bliss.scans: End keithley.stop Took 0.000139s
DEBUG 2021-03-30 18:52:09,889 bliss.scans: Start keithley.stop
DEBUG 2021-03-30 18:52:09,889 bliss.scans: End keithley.stop Took 0.000137s
DEBUG 2021-03-30 18:52:09,889 bliss.scans: Start p201_20.stop
DEBUG 2021-03-30 18:52:09,889 global.controllers.p201_20.CT2: rpc client (tcp://lid112:8909): 'call' args=['stop_acq']
DEBUG 2021-03-30 18:52:09,890 bliss.scans: End p201_20.stop Took 0.001007s
DEBUG 2021-03-30 18:52:09,890 bliss.scans: Start ct2_counters_controller.stop
DEBUG 2021-03-30 18:52:09,890 bliss.scans: End ct2_counters_controller.stop Took 0.000180s
DEBUG 2021-03-30 18:52:09,891 bliss.scans: Start timer.wait_slaves
DEBUG 2021-03-30 18:52:09,891 bliss.scans: End timer.wait_slaves Took 0.000171s
DEBUG 2021-03-30 18:52:09,891 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,891 bliss.scans: End scan.events.device Took 0.000153s
DEBUG 2021-03-30 18:52:09,891 bliss.scans: Start keithley.wait_reading
DEBUG 2021-03-30 18:52:09,891 bliss.scans: End keithley.wait_reading Took 0.000158s
DEBUG 2021-03-30 18:52:09,892 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,892 bliss.scans: End scan.events.device Took 0.000157s
DEBUG 2021-03-30 18:52:09,892 bliss.scans: Start keithley.wait_reading
DEBUG 2021-03-30 18:52:09,892 bliss.scans: End keithley.wait_reading Took 0.000124s
DEBUG 2021-03-30 18:52:09,892 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,892 bliss.scans: End scan.events.device Took 0.000145s
DEBUG 2021-03-30 18:52:09,892 bliss.scans: Start p201_20.wait_slaves
DEBUG 2021-03-30 18:52:09,893 bliss.scans: End p201_20.wait_slaves Took 0.000145s
DEBUG 2021-03-30 18:52:09,893 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,893 bliss.scans: End scan.events.device Took 0.000147s
DEBUG 2021-03-30 18:52:09,893 bliss.scans: Start ct2_counters_controller.wait_reading
DEBUG 2021-03-30 18:52:09,893 bliss.scans: End ct2_counters_controller.wait_reading Took 0.000120s
DEBUG 2021-03-30 18:52:09,893 bliss.scans: Start scan.events.device
DEBUG 2021-03-30 18:52:09,894 bliss.scans: End scan.events.device Took 0.000149s
DEBUG 2021-03-30 18:52:09,894 global.controllers.multiplexer:mux_tdxrd: Multiplexer.getOutputStat SHUTTER_SESSION
DEBUG 2021-03-30 18:52:09,894 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=5 b'?IM\r\n'
DEBUG 2021-03-30 18:52:09,894 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'?IM\r\n'),)
DEBUG 2021-03-30 18:52:09,895 id11/serial/lid112_16: returned: 5
DEBUG 2021-03-30 18:52:09,896 id11/serial/lid112_16: call DevSerReadChar(2,)
DEBUG 2021-03-30 18:52:09,913 id11/serial/lid112_16: returned: [ 48 120 56 49 13 10]
DEBUG 2021-03-30 18:52:09,914 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: readline bytes=5 b'0x81\r'
DEBUG 2021-03-30 18:52:09,915 global.controllers.multiplexer:mux_tdxrd.opiom:opiom_tdxrd: Read b'0x81'
DEBUG 2021-03-30 18:52:09,915 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=6 b'?IMA\r\n'
DEBUG 2021-03-30 18:52:09,915 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'?IMA\r\n'),)
DEBUG 2021-03-30 18:52:09,917 id11/serial/lid112_16: returned: 6
DEBUG 2021-03-30 18:52:09,917 id11/serial/lid112_16: call DevSerReadChar(2,)
DEBUG 2021-03-30 18:52:09,937 id11/serial/lid112_16: returned: [ 48 120 49 68 13 10]
DEBUG 2021-03-30 18:52:09,938 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: readline bytes=5 b'0x1D\r'
DEBUG 2021-03-30 18:52:09,938 global.controllers.multiplexer:mux_tdxrd.opiom:opiom_tdxrd: Read b'0x1D'
DEBUG 2021-03-30 18:52:09,939 global.controllers.multiplexer:mux_tdxrd: Multiplexer.switch SHUTTER to CLOSE
DEBUG 2021-03-30 18:52:09,939 global.controllers.opiom:opiom_tdxrd.Serial[tango://id11/serial/lid112_16]: write bytes=12 b'IM 0x0 0x7\r\n'
DEBUG 2021-03-30 18:52:09,939 id11/serial/lid112_16: call DevSerWriteChar(bytearray(b'IM 0x0 0x7\r\n'),)
DEBUG 2021-03-30 18:52:09,941 id11/serial/lid112_16: returned: 12
DEBUG 2021-03-30 18:52:09,941 bliss.scans: Start scan.fill_metadata
DEBUG 2021-03-30 18:52:09,941 bliss.scans: End scan.fill_metadata Took 0.000350s
DEBUG 2021-03-30 18:52:09,943 bliss.scans: Start scan.finalize.node
DEBUG 2021-03-30 18:52:09,944 bliss.scans: Start scan.finalize.set_ttl
DEBUG 2021-03-30 18:52:09,952 bliss.scans: End scan.finalize.set_ttl Took 0.007823s
DEBUG 2021-03-30 18:52:09,952 bliss.scans: End scan.finalize.node Took 0.009223s
DEBUG 2021-03-30 18:52:09,952 bliss.scans: Start scan.preset._stop
DEBUG 2021-03-30 18:52:09,952 bliss.scans: End scan.preset._stop Took 0.000170s
Took 0:00:00.284513[s]
DEBUG 2021-03-30 18:52:09,953 bliss.scans: Start scan.finalize.writer
DEBUG 2021-03-30 18:52:09,953 bliss.scans: End scan.finalize.writer Took 0.000248s
DEBUG 2021-03-30 18:52:09,954 bliss.scans: Start scan.finalize.caching
DEBUG 2021-03-30 18:52:09,954 bliss.scans: End scan.finalize.caching Took 0.000734s
Out [16]: Scan(name=ct, path='not saved')