Exception when counting area detector

[prjemian]

RunEngine raises exception from RE(bp.count([adsimdet])): ValueError: 'resource' is not a valid DocumentNames

setup (without the imports):

class MyHDF5Plugin(HDF5Plugin, FileStoreHDF5IterativeWrite):
    """
    """

class MySingleTriggerHdf5SimDetector(SingleTrigger, SimDetector): 
    image = Component(ImagePlugin, suffix="image1:")
    hdf1 = Component(
        MyHDF5Plugin,
        suffix='HDF1:', 
        root='/',                               # for databroker
        write_path_template="/tmp/simdet/%Y/%m/%d/",    # for EPICS AD
    )

_ad_prefix = "13SIM1:"
adsimdet = MySingleTriggerHdf5SimDetector(_ad_prefix, name='adsimdet')
adsimdet.read_attrs.append("hdf1")

RE(bp.count([det]))

Session trace:

mintadmin@mint-vm ~/.../profile_bluesky/startup $ use_bluesky.sh 
BlueSky executable path: /home/mintadmin/Apps/BlueSky/bin
Python 3.6.3 :: Anaconda custom (64-bit)
conda 4.5.4
pip 9.0.1 from /home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages (python 3.6)
starting ipython with profile: bluesky
Python 3.6.3 |Anaconda custom (64-bit)| (default, Oct 13 2017, 12:02:49) 
Type "copyright", "credits" or "license" for more information.

IPython 5.3.0 -- An enhanced Interactive Python.
?         -> Introduction and overview of IPython's features.
%quickref -> Quick reference.
help      -> Python's own help system.
object?   -> Details about 'object', use 'object??' for extra details.

IPython profile: bluesky
/home/mintadmin/.ipython/profile_bluesky/startup/00-0-checks.py
BlueSky version: 1.3.2
Ophyd version: 1.2.0
/home/mintadmin/.ipython/profile_bluesky/startup/00-startup.py
Loading metadata history from /home/mintadmin/.config/bluesky/bluesky_history.db
/home/mintadmin/.ipython/profile_bluesky/startup/01-databroker.py
/home/mintadmin/.ipython/profile_bluesky/startup/02-pyepics.py
/home/mintadmin/.ipython/profile_bluesky/startup/10-devices.py
/home/mintadmin/.ipython/profile_bluesky/startup/11-motors.py
/home/mintadmin/.ipython/profile_bluesky/startup/20-detectors.py
/home/mintadmin/.ipython/profile_bluesky/startup/20-signals.py
/home/mintadmin/.ipython/profile_bluesky/startup/25-simdetector.py
/home/mintadmin/.ipython/profile_bluesky/startup/60-metadata.py
Metadata dictionary:
RE.md['APS_BlueSky_tools_VERSION'] = 0.0.20
RE.md['BLUESKY_VERSION'] = 1.3.2
RE.md['OPHYD_VERSION'] = 1.2.0
RE.md['SESSION_START'] = 2018-06-15 12:00:55.097663
RE.md['beamline_id'] = developer
RE.md['ipython_session_start'] = 2018-02-14 12:54:06.447450
RE.md['login_id'] = mintadmin@mint-vm
RE.md['owner'] = Pete
RE.md['pid'] = 6199
RE.md['proposal_id'] = None
RE.md['scan_id'] = 938
/home/mintadmin/.ipython/profile_bluesky/startup/70-busy_flyer.py
/home/mintadmin/.ipython/profile_bluesky/startup/80-callbacks.py

In [1]: RE(bp.count([adsimdet]))
---------------------------------------------------------------------------
ValueError                                Traceback (most recent call last)
<ipython-input-1-ce70e8a47dae> in <module>()
----> 1 RE(bp.count([adsimdet]))

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/run_engine.py in __call__(self, *args, **metadata_kw)
    742                     # it (unless it is a canceled error)
    743                     if exc is not None:
--> 744                         raise exc
    745 
    746             if self._interrupted:

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/run_engine.py in _run(self)
   1251             self.log.error("Run aborted")
   1252             self.log.error("%r", err)
-> 1253             raise err
   1254         finally:
   1255             # Some done_callbacks may still be alive in other threads.

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/run_engine.py in _run(self)
   1138                     else:
   1139                         try:
-> 1140                             msg = self._plan_stack[-1].send(resp)
   1141                         # We have exhausted the top generator
   1142                         except StopIteration:

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in __call__(self, plan)
   1292         plan = monitor_during_wrapper(plan, self.monitors)
   1293         plan = baseline_wrapper(plan, self.baseline)
-> 1294         return (yield from plan)

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in baseline_wrapper(plan, devices, name)
   1145     if not devices:
   1146         # no-op
-> 1147         return (yield from plan)
   1148     else:
   1149         return (yield from plan_mutator(plan, insert_baseline))

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in monitor_during_wrapper(plan, signals)
    788     plan1 = plan_mutator(plan, insert_after_open)
    789     plan2 = plan_mutator(plan1, insert_before_close)
--> 790     return (yield from plan2)
    791 
    792 

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    167                     continue
    168                 else:
--> 169                     raise ex
    170         # if inserting / mutating, put new generator on the stack
    171         # and replace the current msg with the first element from the

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    120             ret = result_stack.pop()
    121             try:
--> 122                 msg = plan_stack[-1].send(ret)
    123             except StopIteration as e:
    124                 # discard the exhausted generator

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    167                     continue
    168                 else:
--> 169                     raise ex
    170         # if inserting / mutating, put new generator on the stack
    171         # and replace the current msg with the first element from the

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    120             ret = result_stack.pop()
    121             try:
--> 122                 msg = plan_stack[-1].send(ret)
    123             except StopIteration as e:
    124                 # discard the exhausted generator

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in fly_during_wrapper(plan, flyers)
    846     plan1 = plan_mutator(plan, insert_after_open)
    847     plan2 = plan_mutator(plan1, insert_before_close)
--> 848     return (yield from plan2)
    849 
    850 

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    167                     continue
    168                 else:
--> 169                     raise ex
    170         # if inserting / mutating, put new generator on the stack
    171         # and replace the current msg with the first element from the

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    120             ret = result_stack.pop()
    121             try:
--> 122                 msg = plan_stack[-1].send(ret)
    123             except StopIteration as e:
    124                 # discard the exhausted generator

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    167                     continue
    168                 else:
--> 169                     raise ex
    170         # if inserting / mutating, put new generator on the stack
    171         # and replace the current msg with the first element from the

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    120             ret = result_stack.pop()
    121             try:
--> 122                 msg = plan_stack[-1].send(ret)
    123             except StopIteration as e:
    124                 # discard the exhausted generator

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/plans.py in count(detectors, num, delay, md)
     65                                       num=num, delay=delay))
     66 
---> 67     return (yield from inner_count())
     68 
     69 

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/utils.py in dec_inner(*inner_args, **inner_kwargs)
   1011                 plan = gen_func(*inner_args, **inner_kwargs)
   1012                 plan = wrapper(plan, *args, **kwargs)
-> 1013                 return (yield from plan)
   1014             return dec_inner
   1015         return dec

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in stage_wrapper(plan, devices)
    937         return (yield from plan)
    938 
--> 939     return (yield from finalize_wrapper(inner(), unstage_devices()))
    940 
    941 

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in finalize_wrapper(plan, final_plan, pause_for_debug)
    498     cleanup = True
    499     try:
--> 500         ret = yield from plan
    501     except GeneratorExit:
    502         cleanup = False

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in inner()
    935     def inner():
    936         yield from stage_devices()
--> 937         return (yield from plan)
    938 
    939     return (yield from finalize_wrapper(inner(), unstage_devices()))

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/utils.py in dec_inner(*inner_args, **inner_kwargs)
   1011                 plan = gen_func(*inner_args, **inner_kwargs)
   1012                 plan = wrapper(plan, *args, **kwargs)
-> 1013                 return (yield from plan)
   1014             return dec_inner
   1015         return dec

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in run_wrapper(plan, md)
    324     yield from contingency_wrapper(plan,
    325                                    except_plan=except_plan,
--> 326                                    else_plan=close_run)
    327     return rs_uid
    328 

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in contingency_wrapper(plan, except_plan, else_plan, final_plan, pause_for_debug)
    560     cleanup = True
    561     try:
--> 562         ret = yield from plan
    563     except GeneratorExit:
    564         cleanup = False

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/plans.py in inner_count()
     63     def inner_count():
     64         return (yield from bps.repeat(partial(bps.trigger_and_read, detectors),
---> 65                                       num=num, delay=delay))
     66 
     67     return (yield from inner_count())

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/plan_stubs.py in repeat(plan, num, delay)
   1007                     yield Msg('sleep', None, d)
   1008 
-> 1009     return (yield from repeated_plan())

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/plan_stubs.py in repeated_plan()
    990             now = time.time()  # Intercept the flow in its earliest moment.
    991             yield Msg('checkpoint')
--> 992             yield from ensure_generator(plan())
    993             try:
    994                 d = next(delay)

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/plan_stubs.py in trigger_and_read(devices, name)
    800     from .preprocessors import rewindable_wrapper
    801     return (yield from rewindable_wrapper(inner_trigger_and_read(),
--> 802                                           rewindable))
    803 
    804 

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in rewindable_wrapper(plan, rewindable)
    678                                             restore_rewindable()))
    679     else:
--> 680         return (yield from plan)
    681 
    682 

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/plan_stubs.py in inner_trigger_and_read()
    796             if reading is not None:
    797                 ret.update(reading)
--> 798         yield from save()
    799         return ret
    800     from .preprocessors import rewindable_wrapper

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/plan_stubs.py in save()
     55     :func:`bluesky.plan_stubs.create`
     56     """
---> 57     return (yield Msg('save'))
     58 
     59 

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    192         try:
    193             # yield out the 'current message' and collect the return
--> 194             inner_ret = yield msg
    195         except GeneratorExit:
    196             # special case GeneratorExit.  We must clean up all of our plans

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    192         try:
    193             # yield out the 'current message' and collect the return
--> 194             inner_ret = yield msg
    195         except GeneratorExit:
    196             # special case GeneratorExit.  We must clean up all of our plans

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    192         try:
    193             # yield out the 'current message' and collect the return
--> 194             inner_ret = yield msg
    195         except GeneratorExit:
    196             # special case GeneratorExit.  We must clean up all of our plans

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/preprocessors.py in plan_mutator(plan, msg_proc)
    192         try:
    193             # yield out the 'current message' and collect the return
--> 194             inner_ret = yield msg
    195         except GeneratorExit:
    196             # special case GeneratorExit.  We must clean up all of our plans

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/run_engine.py in _run(self)
   1195                         # exceptions (coming in via throw) can be
   1196                         # raised
-> 1197                         new_response = yield from coro(msg)
   1198 
   1199                     # special case `CancelledError` and let the outer

/home/mintadmin/Apps/BlueSky/lib/python3.6/site-packages/bluesky/run_engine.py in _save(self, msg)
   1685             if name == 'resource':
   1686                 doc['run_start'] = self._run_start_uid
-> 1687             yield from self.emit(DocumentNames(name), doc)
   1688 
   1689         # Event documents

/home/mintadmin/Apps/BlueSky/lib/python3.6/enum.py in __call__(cls, value, names, module, qualname, type, start)
    289         """
    290         if names is None:  # simple value lookup
--> 291             return cls.__new__(cls, value)
    292         # otherwise, functional API: we're creating a new Enum type
    293         return cls._create_(value, names, module=module, qualname=qualname, type=type, start=start)

/home/mintadmin/Apps/BlueSky/lib/python3.6/enum.py in __new__(cls, value)
    531                     return member
    532         # still not found -- try _missing_ hook
--> 533         return cls._missing_(value)
    534 
    535     def _generate_next_value_(name, start, count, last_values):

/home/mintadmin/Apps/BlueSky/lib/python3.6/enum.py in _missing_(cls, value)
    544     @classmethod
    545     def _missing_(cls, value):
--> 546         raise ValueError("%r is not a valid %s" % (value, cls.__name__))
    547 
    548     def __repr__(self):

ValueError: 'resource' is not a valid DocumentNames

[prjemian]

The doc is this:

ipdb> doc
{'spec': 'AD_HDF5',
 'root': '/',
 'resource_path': 'tmp/simdet/2018/06/15/545d3744-f571-481e-9810_000000.h5',
 'resource_kwargs': {
     'frame_per_point': 0},
     'path_semantics': 'posix',
     'uid': 'da48d242-b8eb-4867-a511-17d11b5afacc',
     'run_start': '0b29af03-94e9-40a8-9b52-1a943957cb1e'
 }

All simple data types: str, int dict of str & int

[prjemian]

The word resource does not appear in the AD's attributes XML file nor in the ipython's startup files. AND, this only happens on one of two workstations. I'm giving up early on this one. The workstation where this happens is a development VM, not for production use. It can always be rebuilt better.

[prjemian]

Epilogue: Rebuilt installation and problem does not recur. Conclusion: Transient, unresolved installation conflict.

[tacaswell]

doh, I read this too fast yesterday. The issues was an out-dated event_model installation.

[prjemian]

Right. Confirmed by restoring the old installation, and updating:

(base) mintadmin@mint-vm ~/Apps $ conda update -c lightsource2-tag event-model
Solving environment: done

## Package Plan ##

  environment location: /home/mintadmin/Apps/BlueSky

  added / updated specs: 
    - event-model

The following packages will be downloaded:

    package                    |            build
    ---------------------------|-----------------
    event-model-1.5.0          |           py36_1          15 KB  lightsource2-tag

The following packages will be UPDATED:

    event-model: 1.4.0-py36_0 conda-forge --> 1.5.0-py36_1 lightsource2-tag

Proceed ([y]/n)? y

Downloading and Extracting Packages
event-model-1.5.0    |   15 KB | ############################################################################### | 100% 
Preparing transaction: done
Verifying transaction: done
Executing transaction: done