search

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

RE abort throws too verbose message #199

Open zhernenkov opened 5 years ago

zhernenkov commented 5 years ago

when aborted, RE spills tons of different messages, which are quite annoying for users. How can we trim the amount of lines users see when abort the RE?

Versions of DAMA software:

    - Bluesky    : v1.5.2
    - Ophyd      : v1.3.2
    - Databroker : v0.12.2

Links to Bluesky and Databroker tutorials:

    - http://nsls-ii.github.io/bluesky/tutorial.html
    - http://nsls-ii.github.io/databroker/tutorial.html

If you get lost or confused, then we want to know! We have a friendly chat channel:

    https://gitter.im/NSLS-II/DAMA

or you can file a bug to let us know where our documentation could be made more clear:

    https://github.com/NSLS-II/Bug-Reports/issues

bsui is running these commands now to start an interactive computing environment for data acquisition:
    $ conda activate collection-2019-2.0-smi
    $ ipython --profile=collection --IPCompleter.use_jedi=False

.......
RunEngineInterrupted:
Your RunEngine is entering a paused state. These are your options for changing
the state of the RunEngine:

RE.resume()    Resume the plan.
RE.abort()     Perform cleanup, then kill plan. Mark exit_stats='aborted'.
RE.stop()      Perform cleanup, then kill plan. Mark exit_status='success'.
RE.halt()      Emergency Stop: Do not perform cleanup --- just stop.

In [6]: RE.abort()
Aborting: running cleanup and marking exit_status as 'abort'...
+-----------+------------+------------+--------------------+
generator scan ['93ee65ce'] (scan num: 124197)
End-of-run baseline readings:
+--------------------------------+--------------------------------+
|                  energy_energy | 13900.003972283106             |
|                   energy_bragg | 8.193663939469207              |
|         energy_ivugap_readback | 25000.08                       |
|                        stage_x | -0.002                         |
|                        stage_y | -6.0                           |
|                        stage_z | -0.002                         |
|                       stage_th | 0.0                            |
|                       stage_ph | 4.0                            |
|                       stage_ch | 0.0                            |
|                            prs | 3.999                          |
|                        piezo_x | -879.9190000000017             |
|                        piezo_y | 2899.509                       |
|                        piezo_z | 3499.772000000001              |
|                       piezo_th | -0.000159                      |
|                       piezo_ch | -0.249683                      |
+--------------------------------+--------------------------------+

[E 21:27:16.824 run_engine:1260] Run aborted
    Traceback (most recent call last):
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/run_engine.py", line 1153, in _run
        msg = self._plan_stack[-1].send(resp)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 1294, in __call__
        return (yield from plan)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 1149, in baseline_wrapper
        return (yield from plan_mutator(plan, insert_baseline))
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 169, in plan_mutator
        raise ex
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 122, in plan_mutator
        msg = plan_stack[-1].send(ret)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 790, in monitor_during_wrapper
        return (yield from plan2)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 169, in plan_mutator
        raise ex
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 122, in plan_mutator
        msg = plan_stack[-1].send(ret)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 169, in plan_mutator
        raise ex
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 122, in plan_mutator
        msg = plan_stack[-1].send(ret)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 848, in fly_during_wrapper
        return (yield from plan2)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 169, in plan_mutator
        raise ex
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 122, in plan_mutator
        msg = plan_stack[-1].send(ret)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 169, in plan_mutator
        raise ex
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 122, in plan_mutator
        msg = plan_stack[-1].send(ret)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/plans.py", line 849, in scan
        per_step=per_step, md=_md))
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/plans.py", line 750, in scan_nd
        return (yield from inner_scan_nd())
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/utils.py", line 1011, in dec_inner
        return (yield from plan)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 939, in stage_wrapper
        return (yield from finalize_wrapper(inner(), unstage_devices()))
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 500, in finalize_wrapper
        ret = yield from plan
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 937, in inner
        return (yield from plan)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/utils.py", line 1011, in dec_inner
        return (yield from plan)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 326, in run_wrapper
        else_plan=close_run)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 562, in contingency_wrapper
        ret = yield from plan
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/plans.py", line 748, in inner_scan_nd
        yield from per_step(detectors, step, pos_cache)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/plan_stubs.py", line 951, in one_nd_step
        yield from move_per_step(step, pos_cache)
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/plan_stubs.py", line 924, in move_per_step
        yield Msg('checkpoint')
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 194, in plan_mutator
        inner_ret = yield msg
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 194, in plan_mutator
        inner_ret = yield msg
      File "/opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/site-packages/bluesky/preprocessors.py", line 194, in plan_mutator
        inner_ret = yield msg
      [Previous line repeated 1 more times]
    bluesky.utils.RequestAbort
Task was destroyed but it is pending!
task: <Task pending coro=<Event.wait() running at /opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/asyncio/locks.py:283> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7fe1620a0e28>()]> cb=[_wait.<locals>._on_completion() at /opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/asyncio/tasks.py:380]>
Task was destroyed but it is pending!
task: <Task pending coro=<Event.wait() running at /opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/asyncio/locks.py:283> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7fe1620a0738>()]> cb=[_wait.<locals>._on_completion() at /opt/conda_envs/collection-2019-2.0-smi/lib/python3.6/asyncio/tasks.py:380]>
Out[6]: ['93ee65ce-efd0-4565-9296-2c8741a8b41d']
danielballan commented 5 years ago

This is relatively recent problem, an unintended side-effect of adding logging by default. Likely fix will last in July along with other logging-related improvements.