Closed cmazzoli closed 8 years ago
Might it be related with the flyers (containing both diag6 and fccd)?
Anyway, I had to restart BS as it was then impossible to repeat a previous scan () performed identical just before the ct command above. This is the output
In [379]: asc(pgm_en,690,710,40)
Run aborted
Device is already staged. Unstage it first.
^C^C---------------------------------------------------------------------------
RuntimeError Traceback (most recent call last)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
731 logger.error("%s", err)
--> 732 raise err
733 finally:
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
705 except Exception as e:
--> 706 self._genstack[-1].throw(e)
707 self.log.debug("Response: %r", response)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in __iter__(self)
58 # the RunStart is generated by open_run, below.
---> 59 yield from self._pre()
60
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in _pre(self)
98 if obj not in staged:
---> 99 yield Msg('stage', obj)
100 staged.append(obj)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
701 self.log.debug("Processing %r", msg)
--> 702 response = yield from coro(msg)
703 except KeyboardInterrupt:
/home/xf23id1/conda_envs/collection/lib/python3.4/asyncio/coroutines.py in coro(*args, **kw)
205 def coro(*args, **kw):
--> 206 res = func(*args, **kw)
207 if isinstance(res, futures.Future) or inspect.isgenerator(res):
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _stage(self, msg)
1163 return
-> 1164 result = obj.stage()
1165 self._staged.add(obj) # add first in case of failure below
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/device.py in stage(self)
354 elif self._staged == Staged.yes:
--> 355 raise RuntimeError("Device is already staged. Unstage it first.")
356 elif self._staged == Staged.partially:
RuntimeError: Device is already staged. Unstage it first.
During handling of the above exception, another exception occurred:
KeyboardInterrupt Traceback (most recent call last)
/home/xf23id1/Users/2016_02_Porro/2016_02_26_overnight.py in <module>()
----> 1 asc(pgm_en,690,710,40)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/simple_scans.py in __call__(self, motor, start, finish, intervals, time, subs, **kwargs)
286 original_times = _set_acquire_time(time)
287 result = super().__call__(motor, start, finish, intervals + 1,
--> 288 subs=subs, **kwargs)
289 _unset_acquire_time(original_times)
290 return result
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/simple_scans.py in __call__(self, subs, sub_factories, *args, **kwargs)
182 # Any remainging kwargs go the RE. To be safe, no args are passed
183 # to RE; RE args effectively become keyword-only arguments.
--> 184 return gs.RE(self.scan, _subs, **kwargs)
185
186
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in __call__(self, plan, subs, **metadata_kw)
558 with SignalHandler(signal.SIGINT) as self._sigint_handler: # ^C
559 self._task = loop.create_task(self._run())
--> 560 loop.run_forever()
561 if self._task.done() and not self._task.cancelled():
562 exc = self._task.exception()
/home/xf23id1/conda_envs/collection/lib/python3.4/asyncio/base_events.py in run_forever(self)
293 try:
294 while True:
--> 295 self._run_once()
296 if self._stopping:
297 break
/home/xf23id1/conda_envs/collection/lib/python3.4/asyncio/base_events.py in _run_once(self)
1252 self._current_handle = None
1253 else:
-> 1254 handle._run()
1255 handle = None # Needed to break cycles when an exception occurs.
1256
/home/xf23id1/conda_envs/collection/lib/python3.4/asyncio/events.py in _run(self)
123 def _run(self):
124 try:
--> 125 self._callback(*self._args)
126 except Exception as exc:
127 cb = _format_callback_source(self._callback, self._args)
/home/xf23id1/conda_envs/collection/lib/python3.4/asyncio/tasks.py in _wakeup(self, future)
299 # instead of `__next__()`, which is slower for futures
300 # that return non-generator iterators from their `__iter__`.
--> 301 self._step()
302 self = None # Needed to break cycles when an exception occurs.
303
/home/xf23id1/conda_envs/collection/lib/python3.4/asyncio/tasks.py in _step(***failed resolving arguments***)
237 # We use the `send` method directly, because coroutines
238 # don't have `__iter__` and `__next__` methods.
--> 239 result = coro.send(None)
240 else:
241 result = coro.throw(exc)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
743 for obj in list(self._uncollected):
744 try:
--> 745 yield from self._collect(Msg('collect', obj))
746 except Exception:
747 logger.error("Failed to collect %r", obj)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _collect(self, msg)
1051 bulk_data[descriptor_uid].append(ev)
1052
-> 1053 yield from self.emit(DocumentNames.bulk_events, bulk_data)
1054 self.log.debug("Emitted bulk events")
1055
/home/xf23id1/conda_envs/collection/lib/python3.4/asyncio/coroutines.py in coro(*args, **kw)
204 @functools.wraps(func)
205 def coro(*args, **kw):
--> 206 res = func(*args, **kw)
207 if isinstance(res, futures.Future) or inspect.isgenerator(res):
208 res = yield from res
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in emit(self, name, doc)
1209 "Process blocking callbacks and schedule non-blocking callbacks."
1210 jsonschema.validate(doc, schemas[name])
-> 1211 self._lossless_dispatcher.process(name, doc)
1212 if name != DocumentNames.event:
1213 self.dispatcher.process(name, doc)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in process(self, name, doc)
1227
1228 def process(self, name, doc):
-> 1229 exceptions = self.cb_registry.process(name, name.name, doc)
1230 for exc, traceback in exceptions:
1231 warn("A %r was raised during the processing of a %s "
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/utils.py in process(self, sig, *args, **kwargs)
149 for cid, func in list(self.callbacks[sig].items()):
150 try:
--> 151 func(*args, **kwargs)
152 except ReferenceError:
153 self._remove_proxy(func)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/utils.py in __call__(self, *args, **kwargs)
230 mtd = self.func
231 # invoke the callable and return the result
--> 232 return mtd(*args, **kwargs)
233
234 def __eq__(self, other):
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/register_mds.py in _insert_bulk_events(name, doc)
46 # if events is empty, mongo chokes
47 if events:
---> 48 mds.bulk_insert_events(desc_uid, events)
49
50 insert_funcs = {DocumentNames.event: _make_insert_func(mds.insert_event),
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/metadatastore/commands.py in inner(*args, **kwargs)
118 port = int(conf.connection_config['port'])
119 db_connect(database=database, host=host, port=port)
--> 120 return func(*args, **kwargs)
121 return inner
122
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/metadatastore/commands.py in bulk_insert_events(event_descriptor, events, validate)
829 bulk.insert(ev)
830
--> 831 return bulk.execute()
832
833
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/pymongo/bulk.py in execute(self, write_concern)
580 if write_concern is not None:
581 validate_is_mapping("write_concern", write_concern)
--> 582 return self.__bulk.execute(write_concern)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/pymongo/bulk.py in execute(self, write_concern)
434 return self.execute_command(sock_info, generator, write_concern)
435 else:
--> 436 return self.execute_legacy(sock_info, generator, write_concern)
437
438
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/pymongo/bulk.py in execute_legacy(self, sock_info, generator, write_concern)
361 coll._insert(sock_info,
362 operation,
--> 363 write_concern=write_concern)
364 result = {}
365 elif run.op_type == _UPDATE:
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/pymongo/collection.py in _insert(self, sock_info, docs, ordered, check_keys, manipulate, write_concern)
434 message._do_batched_insert(self.__full_name, gen(), check_keys,
435 safe, concern, not ordered,
--> 436 self.codec_options, sock_info)
437 if return_one:
438 return ids[0]
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/pymongo/pool.py in legacy_write(self, request_id, msg, max_doc_size, with_last_error)
234 self.send_message(msg, max_doc_size)
235 if with_last_error:
--> 236 response = self.receive_message(1, request_id)
237 return helpers._check_gle_response(response)
238
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/pymongo/pool.py in receive_message(self, operation, request_id)
214 return receive_message(self.sock, operation, request_id)
215 except BaseException as error:
--> 216 self._raise_connection_failure(error)
217
218 def legacy_write(self, request_id, msg, max_doc_size, with_last_error):
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/pymongo/pool.py in _raise_connection_failure(self, error)
314 _raise_connection_failure(self.address, error)
315 else:
--> 316 raise error
317
318 def __eq__(self, other):
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/pymongo/pool.py in receive_message(self, operation, request_id)
212 """
213 try:
--> 214 return receive_message(self.sock, operation, request_id)
215 except BaseException as error:
216 self._raise_connection_failure(error)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/pymongo/network.py in receive_message(sock, operation, request_id)
58 def receive_message(sock, operation, request_id):
59 """Receive a raw BSON message or raise socket.error."""
---> 60 header = _receive_data_on_socket(sock, 16)
61 length = _UNPACK_INT(header[:4])[0]
62
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/pymongo/network.py in _receive_data_on_socket(sock, length)
80 msg = b""
81 while length:
---> 82 chunk = sock.recv(length)
83 if chunk == b"":
84 raise AutoReconnect("connection closed")
KeyboardInterrupt:
In [380]:
KeyboardInterrupt
In [380]: gs.DETS
Out[380]:
[EpicsMotor(prefix='XF:23ID1-ES{Dif-Ax:Th}Mtr', name='theta', egu='', timeout=0.0, read_attrs=['user_readback', 'user_setpoint'], configuration_attrs=['motor_egu'], monitor_attrs=[], settle_time=0.05),
EpicsMotor(prefix='XF:23ID1-ES{Dif-Ax:Del}Mtr', name='delta', egu='', timeout=0.0, read_attrs=['user_readback', 'user_setpoint'], configuration_attrs=['motor_egu'], monitor_attrs=[], settle_time=0.05),
EpicsMotor(prefix='XF:23ID1-ES{Dif-Ax:Gam}Mtr', name='gamma', egu='', timeout=0.0, read_attrs=['user_readback', 'user_setpoint'], configuration_attrs=['motor_egu'], monitor_attrs=[], settle_time=0.05),
EpicsMotor(prefix='XF:23ID1-ES{Dif-Ax:X}Mtr', name='sx', egu='', timeout=0.0, read_attrs=['user_readback', 'user_setpoint'], configuration_attrs=['motor_egu'], monitor_attrs=[], settle_time=0.05),
EpicsMotor(prefix='XF:23ID1-ES{Dif-Ax:Y}Mtr', name='say', egu='', timeout=0.0, read_attrs=['user_readback', 'user_setpoint'], configuration_attrs=['motor_egu'], monitor_attrs=[], settle_time=0.05),
EpicsMotor(prefix='XF:23ID1-ES{Dif-Ax:Z}Mtr', name='saz', egu='', timeout=0.0, read_attrs=['user_readback', 'user_setpoint'], configuration_attrs=['motor_egu'], monitor_attrs=[], settle_time=0.05),
Cryoangle(prefix='', name='cryoangle', egu='', timeout=0.0, read_attrs=['setpoint', 'readback'], configuration_attrs=[], monitor_attrs=[], settle_time=0.05, limits=None),
Temperature(prefix='XF:23ID1-ES{TCtrl:1', name='temp', read_attrs=['a', 'b'], configuration_attrs=[], monitor_attrs=[]),
PGMEnergy(prefix='XF:23ID1-OP{Mono', name='pgm_en', parent='pgm', egu='', timeout=0.0, read_attrs=['setpoint', 'readback', 'stop_signal'], configuration_attrs=[], monitor_attrs=[], settle_time=0.05, limits=None),
EPU1(prefix='XF:23ID-ID{EPU:1', name='epu1', read_attrs=['gap', 'phase'], configuration_attrs=[], monitor_attrs=[]),
EPU2(prefix='XF:23ID-ID{EPU:2', name='epu2', read_attrs=['gap', 'phase'], configuration_attrs=[], monitor_attrs=[]),
SlitsGapCenter(prefix='XF:23ID1-OP{Slt:1', name='slt1', read_attrs=['xg', 'xc', 'yg', 'yc'], configuration_attrs=[], monitor_attrs=[]),
SlitsGapCenter(prefix='XF:23ID1-OP{Slt:2', name='slt2', read_attrs=['xg', 'xc', 'yg', 'yc'], configuration_attrs=[], monitor_attrs=[]),
SlitsXY(prefix='XF:23ID1-OP{Slt:3', name='slt3', read_attrs=['x', 'y'], configuration_attrs=[], monitor_attrs=[]),
Mirror(prefix='XF:23IDA-OP:1{Mir:1', name='m1a', read_attrs=['z', 'y', 'x', 'pit', 'yaw', 'rol'], configuration_attrs=[], monitor_attrs=[]),
MotorMirror(prefix='XF:23ID1-OP{Mir:3', name='m3a', read_attrs=['x', 'pit', 'bdr'], configuration_attrs=[], monitor_attrs=[]),
EpicsSignal(read_pv='XF:23ID-SR{}I-I', name='ring_curr', value=149.92159610000002, timestamp=1456439832.239723, pv_kw={}, auto_monitor=False, string=False, write_pv='XF:23ID-SR{}I-I', limits=False, put_complete=False),
EpicsScaler(prefix='XF:23ID1-ES{Sclr:1}', name='sclr', read_attrs=['channels', 'time'], configuration_attrs=['preset_time', 'presets', 'gates'], monitor_attrs=[])]
In [381]: asc(pgm_en,690,710,40)
Run aborted
Device is already staged. Unstage it first.
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/numpy/core/_methods.py:59: RuntimeWarning: Mean of empty slice.
warnings.warn("Mean of empty slice.", RuntimeWarning)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py:1235: UserWarning: A AttributeError("'LiveTable' object has no attribute 'table'",) was raised during the processing of a stop Document. The error will be ignored to avoid interrupting data collection. To investigate, set RunEngine.ignore_callback_exceptions = False and run again.
"and run again." % (exc, name.name))
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py:1235: UserWarning: A ValueError('attempt to get argmax of an empty sequence',) was raised during the processing of a stop Document. The error will be ignored to avoid interrupting data collection. To investigate, set RunEngine.ignore_callback_exceptions = False and run again.
"and run again." % (exc, name.name))
---------------------------------------------------------------------------
RuntimeError Traceback (most recent call last)
/home/xf23id1/Users/2016_02_Porro/2016_02_26_overnight.py in <module>()
----> 1 asc(pgm_en,690,710,40)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/simple_scans.py in __call__(self, motor, start, finish, intervals, time, subs, **kwargs)
286 original_times = _set_acquire_time(time)
287 result = super().__call__(motor, start, finish, intervals + 1,
--> 288 subs=subs, **kwargs)
289 _unset_acquire_time(original_times)
290 return result
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/simple_scans.py in __call__(self, subs, sub_factories, *args, **kwargs)
182 # Any remainging kwargs go the RE. To be safe, no args are passed
183 # to RE; RE args effectively become keyword-only arguments.
--> 184 return gs.RE(self.scan, _subs, **kwargs)
185
186
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in __call__(self, plan, subs, **metadata_kw)
562 exc = self._task.exception()
563 if exc is not None:
--> 564 raise exc
565
566 return self._run_start_uids
/home/xf23id1/conda_envs/collection/lib/python3.4/asyncio/tasks.py in _step(***failed resolving arguments***)
237 # We use the `send` method directly, because coroutines
238 # don't have `__iter__` and `__next__` methods.
--> 239 result = coro.send(None)
240 else:
241 result = coro.throw(exc)
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
730 logger.error("Run aborted")
731 logger.error("%s", err)
--> 732 raise err
733 finally:
734 self.state = 'idle'
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
704 raise
705 except Exception as e:
--> 706 self._genstack[-1].throw(e)
707 self.log.debug("Response: %r", response)
708 except KeyboardInterrupt:
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in __iter__(self)
57 # Some metadata is compute in _pre, so it must be done before
58 # the RunStart is generated by open_run, below.
---> 59 yield from self._pre()
60
61 # If the plan has a 'subs' attribute, yield a 'subscribe' Msg for
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in _pre(self)
97 for obj in objs:
98 if obj not in staged:
---> 99 yield Msg('stage', obj)
100 staged.append(obj)
101
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
700 coro = self._command_registry[msg.command]
701 self.log.debug("Processing %r", msg)
--> 702 response = yield from coro(msg)
703 except KeyboardInterrupt:
704 raise
/home/xf23id1/conda_envs/collection/lib/python3.4/asyncio/coroutines.py in coro(*args, **kw)
204 @functools.wraps(func)
205 def coro(*args, **kw):
--> 206 res = func(*args, **kw)
207 if isinstance(res, futures.Future) or inspect.isgenerator(res):
208 res = yield from res
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _stage(self, msg)
1162 if not hasattr(obj, 'stage'):
1163 return
-> 1164 result = obj.stage()
1165 self._staged.add(obj) # add first in case of failure below
1166 return result
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/device.py in stage(self)
353 pass # to short-circuit checking individual cases
354 elif self._staged == Staged.yes:
--> 355 raise RuntimeError("Device is already staged. Unstage it first.")
356 elif self._staged == Staged.partially:
357 raise RuntimeError("Device has been partially staged. Maybe the "
RuntimeError: Device is already staged. Unstage it first.
In [382]:
Do you really want to exit ([y]/n)?
...
Performed another ct(num=None) [i.e. you need to ctrl+C to stop it..] and then ctrl+C and stop() after ~30'. It took ages (~2 min) to close the scan but did it successfully. So above, I wasn't patient enough. Now done the third of the same scan type after having removed all the flyers from ct.flyers (none defined in gs.FLYERS). Once ctrl+C and stop(), the scan was successfully closed immediately.
It looks like the first time you hit C^c
while we were not managing it, it went down and killed pymongo while it was writing your flyer events into the data base. Because of this the runengine did not get a chance to properly clean it self up.
The two things we should do
Stopping flyers on pause is a possibility, although some special application might benefit of keeping them running. Actually, I believe that the problem was generated because I thought the program was stalled. It would be nice, I believe, to print some information on what it is happening when possibly long operations in the background are executed (like writing flyers). Ideally, a progress indicator would help a lot.. Anyway, if you kill an operation it is important to know:
Sorry, the last point it should have been something like:
@cmazzoli The (partial) solution is to forbid you from canceling during the clean up phase of the run-engine. Not ideal, but it will prevent the above trace back and ensure that your RE is always in a good state when you get control back.
Why is giving an error on area detector if none is defined in my current gs.DETS?? Thanks!