NSLS-II / Bug-Reports

Unified issue-tracker for bugs in the data acquisition, management, and analysis software at NSLS-II
BSD 3-Clause "New" or "Revised" License
2 stars 5 forks source link

Repetead script crash on CSX #132

Open cmazzoli opened 8 years ago

cmazzoli commented 8 years ago

The last one of a series over the weekend...


Macro crashed after scan 68057. Error message below:

FailedStatus Traceback (most recent call last)
/home/xf23id1/Beamline/Commissioning/2016_08_11/2016_08_14_dinner.py in <module>()
53 
54 # T cycle ~4h
---> 55 TcycleTH2TH(Tanneal=300,annealtime=1800,Tcool=30)
56 
57 # current cycle ~6h

/home/xf23id1/Beamline/Commissioning/2016_08_11/2016_08_14_dinner.py in TcycleTH2TH(Tanneal, annealtime, Tcool)
9 while temp.a.value < Tanneal-5:
10 #oneIplan(my_E = my_E_off,short002=0,scan002=1,fine001=0)
---> 11 oneIplan(my_E = my_E_on,short002=0,scan002=0,fine001=0)
12 sleep(annealtime)
13 caput('XF:23ID1-ES{TCtrl:1-Out:1}T-SP', Tcool);

/home/xf23id1/Beamline/Commissioning/2016_08_11/2016_08_14_dinner.py in oneIplan(my_E, short002, scan002, fine001)
27 if fine001==0:
28 OlogTH2th()
---> 29 RE(d2scan(theta,-3.,3., delta,-6.0,6.0,30))
30 shclose()
31 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in __call__(self, plan, subs, raise_if_interrupted, **metadata_kw)
601 exc = self._task.exception()
602 if exc is not None:
--> 603 raise exc
604 if raise_if_interrupted and self._interrupted:
605 raise RunEngineInterrupted("RunEngine was interrupted.")

/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)
982 self.log.error("Run aborted")
983 self.log.error("%r", err)
--> 984 raise err
985 finally:
986 # call stop() on every movable object we ever set()

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
859 try:
860 msg = self._plan_stack[-1].throw(
--> 861 self._exception)
862 except Exception as e:
863 # The current plan did not handle it,

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in wrapped(*args, **kwargs)
69 gen_stack = func(*args, **kwargs)
70 for g in gen_stack:
---> 71 yield from g
72 
73 return wrapped

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in configure_count_time_wrapper(plan, time)
1484 if time is None:
1485 # no-op
-> 1486 return (yield from plan)
1487 else:
1488 return (yield from finalize_wrapper(plan_mutator(plan, insert_set),

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in baseline_wrapper(plan, devices, name)
1526 return (yield from plan)
1527 else:
-> 1528 return (yield from plan_mutator(plan, insert_baseline))
1529 
1530 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in plan_mutator(plan, msg_proc)
192 inner_ret = yield msg
193 except Exception as ex:
--> 194 msg = plan.throw(ex)
195 plan_stack.append(single_gen(msg))
196 result_stack.append(None)

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in wrapped(*args, **kwargs)
69 gen_stack = func(*args, **kwargs)
70 for g in gen_stack:
---> 71 yield from g
72 
73 return wrapped

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in reset_positions_wrapper(plan, devices)
1436 
1437 return (yield from finalize_wrapper(plan_mutator(plan, insert_reads),
-> 1438 reset()))
1439 
1440 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in finalize_wrapper(plan, final_plan)
953 # https://docs.python.org/3/reference/expressions.html?#generator.close
954 if cleanup:
--> 955 yield from ensure_generator(final_plan)
956 return ret
957 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in reset()
1432 blk_grp = 'reset-{}'.format(str(uuid.uuid4())[:6])
1433 for k, v in initial_positions.items():
-> 1434 yield Msg('set', k, v, group=blk_grp)
1435 yield Msg('wait', None, group=blk_grp)
1436 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in plan_mutator(plan, msg_proc)
190 try:
191 # yield out the 'current message' and collect the return
--> 192 inner_ret = yield msg
193 except Exception as ex:
194 msg = plan.throw(ex)

FailedStatus: MoveStatus(done=True, pos=theta, elapsed=4.4, success=False, settle_time=0.0)
cmazzoli commented 8 years ago

Plagued over the whole time by timeout errors, never seen before to my memory. In the following, another one of the same kind but on a different subsystem... Any idea why? We cannot continue like this (essentially no possibility of writing overnight scripts..)


---------------------------------------------------------------------------
TimeoutError                              Traceback (most recent call last)
/home/xf23id1/Beamline/Commissioning/2016_08_11/2016_08_15_evening.py in <module>()
     13 
     14 # T cycle ~4h
---> 15 TcycleTH2TH(Tanneal=300,annealtime=1800,Tcool=20)
     16 
     17 

/home/xf23id1/Beamline/Commissioning/2016_08_11/2016_08_15_evening.py in TcycleTH2TH(Tanneal, annealtime, Tcool)
     91     while temp.a.value > Tcool+1:
     92         #oneIplan(my_E = my_E_off,short002=0,scan002=1,fine001=0)
---> 93         oneIplan(my_E = my_E_on,short002=0,scan002=0,fine001=0)
     94     # Extra scans at base T
     95     oneIplan(my_E = my_E_on,short002=0,scan002=0,fine001=0)

/home/xf23id1/Beamline/Commissioning/2016_08_11/2016_08_15_evening.py in oneIplan(my_E, short002, scan002, fine001)
     27         if fine001==0:
     28             OlogTH2th()
---> 29             RE(d2scan(theta,-3.,3., delta,-6.0,6.0,30))
     30     shclose()
     31 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in __call__(self, plan, subs, raise_if_interrupted, **metadata_kw)
    601                 exc = self._task.exception()
    602                 if exc is not None:
--> 603                     raise exc
    604             if raise_if_interrupted and self._interrupted:
    605                 raise RunEngineInterrupted("RunEngine was interrupted.")

/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)
    982             self.log.error("Run aborted")
    983             self.log.error("%r", err)
--> 984             raise err
    985         finally:
    986             # call stop() on every movable object we ever set()

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
    880                         resp = self._response_stack.pop()
    881                         try:
--> 882                             msg = self._plan_stack[-1].send(resp)
    883                         # We have exhausted the top generator
    884                         except StopIteration:

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in wrapped(*args, **kwargs)
     69         gen_stack = func(*args, **kwargs)
     70         for g in gen_stack:
---> 71             yield from g
     72 
     73     return wrapped

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in configure_count_time_wrapper(plan, time)
   1484     if time is None:
   1485         # no-op
-> 1486         return (yield from plan)
   1487     else:
   1488         return (yield from finalize_wrapper(plan_mutator(plan, insert_set),

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in baseline_wrapper(plan, devices, name)
   1526         return (yield from plan)
   1527     else:
-> 1528         return (yield from plan_mutator(plan, insert_baseline))
   1529 
   1530 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in plan_mutator(plan, msg_proc)
    164                 continue
    165             else:
--> 166                 raise ex
    167 
    168         # if inserting / mutating, put new generator on the stack

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in plan_mutator(plan, msg_proc)
    120             # send last result to the top most generator in the
    121             # stack this may raise StopIteration
--> 122             msg = plan_stack[-1].send(ret)
    123 
    124         except StopIteration:

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in wrapped(*args, **kwargs)
     69         gen_stack = func(*args, **kwargs)
     70         for g in gen_stack:
---> 71             yield from g
     72 
     73     return wrapped

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in reset_positions_wrapper(plan, devices)
   1436 
   1437     return (yield from finalize_wrapper(plan_mutator(plan, insert_reads),
-> 1438                                         reset()))
   1439 
   1440 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in finalize_wrapper(plan, final_plan)
    938     cleanup = True
    939     try:
--> 940         ret = yield from plan
    941     except GeneratorExit:
    942         cleanup = False

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in plan_mutator(plan, msg_proc)
    192             inner_ret = yield msg
    193         except Exception as ex:
--> 194             msg = plan.throw(ex)
    195             plan_stack.append(single_gen(msg))
    196             result_stack.append(None)

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in relative_set_wrapper(plan, devices)
   1386     plan = plan_mutator(plan, insert_reads)
   1387     plan = msg_mutator(plan, rewrite_pos)
-> 1388     return (yield from plan)
   1389 
   1390 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in msg_mutator(plan, msg_proc)
    233                 ret = None
    234                 continue
--> 235             ret = yield msg
    236         except StopIteration:
    237             break

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in plan_mutator(plan, msg_proc)
    190         try:
    191             # yield out the 'current message' and collect the return
--> 192             inner_ret = yield msg
    193         except Exception as ex:
    194             msg = plan.throw(ex)

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in plan_mutator(plan, msg_proc)
    190         try:
    191             # yield out the 'current message' and collect the return
--> 192             inner_ret = yield msg
    193         except Exception as ex:
    194             msg = plan.throw(ex)

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
    931                         # exceptions (coming in via throw) can be
    932                         # raised
--> 933                         response = yield from coro(msg)
    934                     # special case `CancelledError` and let the outer
    935                     # exception block deal with it.

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _stage(self, msg)
   1852         if not hasattr(obj, 'stage'):
   1853             return []
-> 1854         result = obj.stage()
   1855         self._staged.add(obj)  # add first in case of failure below
   1856         yield from self._reset_checkpoint_state_coro()

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/areadetector/trigger_mixins.py in stage(self)
     62     def stage(self):
     63         self._acquisition_signal.subscribe(self._acquire_changed)
---> 64         super().stage()
     65 
     66     def unstage(self):

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/areadetector/base.py in stage(self, *args, **kwargs)
    154     def stage(self, *args, **kwargs):
    155         self.validate_asyn_ports()
--> 156         return super().stage(*args, **kwargs)
    157 
    158     def get_plugin_by_asyn_port(self, port_name):

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/device.py in stage(self)
    438                 logger.debug("Setting %s to %r (original value: %r)", self.name,
    439                              val, original_vals[sig])
--> 440                 set_and_wait(sig, val)
    441                 # It worked -- now add it to this list of sigs to unstage.
    442                 self._original_vals[sig] = original_vals[sig]

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/utils/epics_pvs.py in set_and_wait(signal, val, poll_time, timeout, rtol, atol)
    401             raise TimeoutError("Attempted to set %r to value %r and timed "
    402                                "out after %r seconds. Current value is %r." %
--> 403                                (signal, val, timeout, current_value))
    404 
    405 

TimeoutError: Attempted to set EpicsSignalWithRBV(read_pv='XF:23ID1-ES{FCCD}cam1:ImageMode_RBV', name='fccd_cam_image_mode', parent='fccd_cam', value=1, timestamp=1471330600.815966, pv_kw={}, auto_monitor=False, string=False, write_pv='XF:23ID1-ES{FCCD}cam1:ImageMode', limits=False, put_complete=False) to value 1 and timed out after 10 seconds. Current value is 1.
tacaswell commented 8 years ago

It looks like your theta motor failed to complete it's move. We recently started to watch the alarm state of motors (which fixed the issue you were having when the energy scans stopped working with following errors, but the scan kept running anyway.

tacaswell commented 8 years ago

The second one looks unrelated.

stuwilkins commented 8 years ago

I think that these timeouts are not related to bluesky or problems with this. We have been experiencing network problems for a while with CA timeouts. This could also be due to the camera IOC being busy at high speed and we should probably increase those timeouts to about 120s because the areaDetector IOCs are not fully multithreaded and get stuck in mutex locks which prevents the CA returning if you are unfortunate to request a change at that moment. I do think that 10s is a very short timeout to then completely bomb a data collection.

AFIK, this is also an issue because bluesky is running on the workstation and not on a server in the rack. This adds an additional loop and also runs the CA over the same wire as viewing the images. To my mind this is not a good idea.

Also reviewing how things are setup at CSX, the CSX-1 and CSX-2 workstations are fed from the same switch and also from the same connections. It might pay to completely separate these and run the CSX-2 workstations from their switch, and the CSX-1 workstations from our switch. We have the infrastructure for that and it may pay to do that in the shutdown.

I would really like to run bluesky from one of the SVR or IOCs (IOC3?) because that may solve a lot of these problems. For starters we could do this with a simple $ ssh -Y

Lastly we may want to do some checking of the load on IOC2 when the camera is running very fast.

Thoughts?

On Aug 16, 2016, at 9:03 AM, Thomas A Caswell notifications@github.com<mailto:notifications@github.com> wrote:

The second one looks unrelated.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHubhttps://github.com/NSLS-II/Bug-Reports/issues/132#issuecomment-240094685, or mute the threadhttps://github.com/notifications/unsubscribe-auth/ABPOFf56_fZotlNOieRfWDBvS1l9yER-ks5qgbUUgaJpZM4Jkaz4.

ambarb commented 8 years ago

I was playing around in test mode on a shutdown day. I would expect the network to be less busy today. We also restarted the computer this morning. Using camera at 10Hz in stead of 50Hz in previous cases for @cmazzoli

In [19]: RE(ct())
Transient Scan ID: 68224
Persistent Unique Scan ID: '70a1bc9a-7c23-4308-a8e4-d23480491cbd'
/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py:1976: UserWarning: A ReadTimeout(ReadTimeoutError("HTTPSConnectionPool(host='xf23id1-log.cs.nsls2.local', port=8181): Read timed out. (read timeout=30)",),) was raised during the processing of a start 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))
+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+
|   seq_num |       time | fccd_stats1_total | fccd_stats2_total | fccd_stats3_total | fccd_stats4_total | fccd_stats5_total |
+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+
|         1 | 15:38:10.6 |        3626552410 |        7244959560 |        1407669240 |        4870097080 |       26394163200 |
+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+
generator ct ['70a1bc'] (scan num: 68224)
Out[19]: ['70a1bc9a-7c23-4308-a8e4-d23480491cbd']

In [20]: RE(ct())
Transient Scan ID: 68225
Persistent Unique Scan ID: '016559ed-0f31-4890-9f7f-10ae987a3f0d'
+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+
|   seq_num |       time | fccd_stats1_total | fccd_stats2_total | fccd_stats3_total | fccd_stats4_total | fccd_stats5_total |
+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+
|         1 | 15:41:47.0 |        3626552410 |        7244959560 |        1407669240 |        4870097080 |       26394163200 |
+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+
generator ct ['016559'] (scan num: 68225)
---------------------------------------------------------------------------
TimeoutError                              Traceback (most recent call last)
/home/xf23id1/Users/2016_08_Ricci/startup.py in <module>()
----> 1 RE(ct())

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in __call__(self, plan, subs, raise_if_interrupted, **metadata_kw)
    601                 exc = self._task.exception()
    602                 if exc is not None:
--> 603                     raise exc
    604             if raise_if_interrupted and self._interrupted:
    605                 raise RunEngineInterrupted("RunEngine was interrupted.")

/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)
    982             self.log.error("Run aborted")
    983             self.log.error("%r", err)
--> 984             raise err
    985         finally:
    986             # call stop() on every movable object we ever set()

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
    859                         try:
    860                             msg = self._plan_stack[-1].throw(
--> 861                                 self._exception)
    862                         except Exception as e:
    863                             # The current plan did not handle it,

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in wrapped(*args, **kwargs)
     69         gen_stack = func(*args, **kwargs)
     70         for g in gen_stack:
---> 71             yield from g
     72 
     73     return wrapped

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in configure_count_time_wrapper(plan, time)
   1484     if time is None:
   1485         # no-op
-> 1486         return (yield from plan)
   1487     else:
   1488         return (yield from finalize_wrapper(plan_mutator(plan, insert_set),

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in baseline_wrapper(plan, devices, name)
   1524     if not devices:
   1525         # no-op
-> 1526         return (yield from plan)
   1527     else:
   1528         return (yield from plan_mutator(plan, insert_baseline))

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in wrapped(*args, **kwargs)
     69         gen_stack = func(*args, **kwargs)
     70         for g in gen_stack:
---> 71             yield from g
     72 
     73     return wrapped

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in unstage()
   1324     def unstage():
   1325         # unstage devices explicitly passed to 'devices' argument
-> 1326         yield from broadcast_msg('unstage', reversed(devices))
   1327 
   1328     plan_stack.append(stage())

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in broadcast_msg(command, objs, *args, **kwargs)
   1652     return_vals = []
   1653     for o in objs:
-> 1654         ret = yield Msg(command, o, *args, **kwargs)
   1655         return_vals.append(ret)
   1656 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)
    931                         # exceptions (coming in via throw) can be
    932                         # raised
--> 933                         response = yield from coro(msg)
    934                     # special case `CancelledError` and let the outer
    935                     # exception block deal with it.

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _unstage(self, msg)
   1869         if not hasattr(obj, 'unstage'):
   1870             return []
-> 1871         result = obj.unstage()
   1872         # use `discard()` to ignore objects that are not in the staged set.
   1873         self._staged.discard(obj)

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/areadetector/trigger_mixins.py in unstage(self)
     65 
     66     def unstage(self):
---> 67         super().unstage()
     68         self._acquisition_signal.clear_sub(self._acquire_changed)
     69 

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/device.py in unstage(self)
    486             logger.debug("Setting %s back to its original value: %r)", self.name,
    487                          val)
--> 488             set_and_wait(sig, val)
    489             self._original_vals.pop(sig)
    490         devices_unstaged.append(self)

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/utils/epics_pvs.py in set_and_wait(signal, val, poll_time, timeout, rtol, atol)
    401             raise TimeoutError("Attempted to set %r to value %r and timed "
    402                                "out after %r seconds. Current value is %r." %
--> 403                                (signal, val, timeout, current_value))
    404 
    405 

TimeoutError: Attempted to set EpicsSignalWithRBV(read_pv='XF:23ID1-ES{FCCD}cam1:Acquire_RBV', name='fccd_cam_acquire', parent='fccd_cam', value=1, timestamp=1471462915.600884, pv_kw={}, auto_monitor=False, string=False, write_pv='XF:23ID1-ES{FCCD}cam1:Acquire', limits=False, put_complete=False) to value 1 and timed out after 10 seconds. Current value is 1.
stuwilkins commented 8 years ago

Thanks Andi,

Do you still get this problem if you turn off the polling of the FastCCD status (there is an interval timer, just set it to 1 Day) ? Also, can we set these timeouts to 120s somehow?

S

From: ambarb notifications@github.com Reply-To: NSLS-II/Bug-Reports reply@reply.github.com Date: Thursday, August 18, 2016 at 3:46 AM To: NSLS-II/Bug-Reports Bug-Reports@noreply.github.com Cc: Stuart Wilkins swilkins@bnl.gov, Comment comment@noreply.github.com Subject: Re: [NSLS-II/Bug-Reports] Repetead script crash on CSX (#132)

I was playing around in test mode on a shutdown day. I would expect the network to be less busy today. We also restarted the computer this morning. Using camera at 10Hz in stead of 50Hz in previous cases for @cmazzolihttps://github.com/cmazzoli

In [19]: RE(ct())

Transient Scan ID: 68224

Persistent Unique Scan ID: '70a1bc9a-7c23-4308-a8e4-d23480491cbd'

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py:1976: UserWarning: A ReadTimeout(ReadTimeoutError("HTTPSConnectionPool(host='xf23id1-log.cs.nsls2.local', port=8181): Read timed out. (read timeout=30)",),) was raised during the processing of a start 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))

+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+

| seq_num | time | fccd_stats1_total | fccd_stats2_total | fccd_stats3_total | fccd_stats4_total | fccd_stats5_total |

+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+

| 1 | 15:38:10.6 | 3626552410 | 7244959560 | 1407669240 | 4870097080 | 26394163200 |

+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+

generator ct ['70a1bc'](scan num: 68224)

Out[19]: ['70a1bc9a-7c23-4308-a8e4-d23480491cbd']

In [20]: RE(ct())

Transient Scan ID: 68225

Persistent Unique Scan ID: '016559ed-0f31-4890-9f7f-10ae987a3f0d'

+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+

| seq_num | time | fccd_stats1_total | fccd_stats2_total | fccd_stats3_total | fccd_stats4_total | fccd_stats5_total |

+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+

| 1 | 15:41:47.0 | 3626552410 | 7244959560 | 1407669240 | 4870097080 | 26394163200 |

+-----------+------------+-------------------+-------------------+-------------------+-------------------+-------------------+

generator ct ['016559'](scan num: 68225)


TimeoutError Traceback (most recent call last)

/home/xf23id1/Users/2016_08_Ricci/startup.py in ()

----> 1 RE(ct())

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in call(self, plan, subs, raise_if_interrupted, **metadata_kw)

601                 exc = self._task.exception()

602                 if exc is not None:

--> 603 raise exc

604             if raise_if_interrupted and self._interrupted:

605                 raise RunEngineInterrupted("RunEngine was interrupted.")

/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)

982             self.log.error("Run aborted")

983             self.log.error("%r", err)

--> 984 raise err

985         finally:

986             # call stop() on every movable object we ever set()

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)

859                         try:

860                             msg = self._plan_stack[-1].throw(

--> 861 self._exception)

862                         except Exception as e:

863                             # The current plan did not handle it,

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in wrapped(_args, *_kwargs)

 69         gen_stack = func(*args, **kwargs)

 70         for g in gen_stack:

---> 71 yield from g

 72

 73     return wrapped

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in configure_count_time_wrapper(plan, time)

1484 if time is None:

1485 # no-op

-> 1486 return (yield from plan)

1487 else:

1488 return (yield from finalize_wrapper(plan_mutator(plan, insert_set),

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in baseline_wrapper(plan, devices, name)

1524 if not devices:

1525 # no-op

-> 1526 return (yield from plan)

1527 else:

1528 return (yield from plan_mutator(plan, insert_baseline))

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in wrapped(_args, *_kwargs)

 69         gen_stack = func(*args, **kwargs)

 70         for g in gen_stack:

---> 71 yield from g

 72

 73     return wrapped

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in unstage()

1324 def unstage():

1325 # unstage devices explicitly passed to 'devices' argument

-> 1326 yield from broadcast_msg('unstage', reversed(devices))

1327

1328 plan_stack.append(stage())

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/plans.py in broadcast_msg(command, objs, _args, *_kwargs)

1652 return_vals = []

1653 for o in objs:

-> 1654 ret = yield Msg(command, o, _args, *_kwargs)

1655 return_vals.append(ret)

1656

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _run(self)

931                         # exceptions (coming in via throw) can be

932                         # raised

--> 933 response = yield from coro(msg)

934                     # special case `CancelledError` and let the outer

935                     # exception block deal with it.

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/bluesky/run_engine.py in _unstage(self, msg)

1869 if not hasattr(obj, 'unstage'):

1870 return []

-> 1871 result = obj.unstage()

1872 # use discard() to ignore objects that are not in the staged set.

1873 self._staged.discard(obj)

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/areadetector/trigger_mixins.py in unstage(self)

 65

 66     def unstage(self):

---> 67 super().unstage()

 68         self._acquisition_signal.clear_sub(self._acquire_changed)

 69

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/device.py in unstage(self)

486             logger.debug("Setting %s back to its original value: %r)", self.name,

487                          val)

--> 488 set_and_wait(sig, val)

489             self._original_vals.pop(sig)

490         devices_unstaged.append(self)

/home/xf23id1/conda_envs/collection/lib/python3.4/site-packages/ophyd/utils/epics_pvs.py in set_and_wait(signal, val, poll_time, timeout, rtol, atol)

401             raise TimeoutError("Attempted to set %r to value %r and timed "

402                                "out after %r seconds. Current value is %r." %

--> 403 (signal, val, timeout, current_value))

404

405

TimeoutError: Attempted to set EpicsSignalWithRBV(read_pv='XF:23ID1-ES{FCCD}cam1:Acquire_RBV', name='fccd_cam_acquire', parent='fccd_cam', value=1, timestamp=1471462915.600884, pv_kw={}, auto_monitor=False, string=False, write_pv='XF:23ID1-ES{FCCD}cam1:Acquire', limits=False, put_complete=False) to value 1 and timed out after 10 seconds. Current value is 1.

— You are receiving this because you commented. Reply to this email directly, view it on GitHubhttps://github.com/NSLS-II/Bug-Reports/issues/132#issuecomment-240525378, or mute the threadhttps://github.com/notifications/unsubscribe-auth/ABPOFV-SdXeWnPEqwa2Qol3BwiDuU0pIks5qg2UEgaJpZM4Jkaz4.