Issue while testing of the server with IPython-based worker

[dmgav]

The issue while running an autonomous experiment with IPython-based worker. The issue must be reproduced in simulated environment.

Transient Scan ID: 1061657     Time: 2023-05-24 00:14:32
Persistent Unique Scan ID: 'b5bc4e57-93d2-4ce0-9270-9a9725ab4a3e'
schi [In progress. No progress bar available.]
[I 2023-05-24 00:14:32,846 bluesky_queueserver.manager.manager] Returning the list of runs for the running New stream: 'primary'
+-----------+------------+------------+------------+------------+------------------------+------------------------+------------------------+----------------+----------------+-----------------+---------------------+---------------------------+---------------------+-----------------------+------------------------+------------+------------+------------+
|   seq_num |       time |        sth |       schi |     laserx | pilatus2M_stats2_total | pilatus2M_stats3_total | pilatus2M_stats4_total | laser_width_rb | laser_delay_rb | laser_pulses_rb | laser_pv_bitmask_rb | laser_physical_bitmank_rb | laser_pv_trigger_rb | laser_trigger_mode_rb | laser_manual_button_rb |        smx |     lasery |        smy |
+-----------+------------+------------+------------+------------+------------------------+------------------------+------------------------+----------------+----------------+-----------------+---------------------+---------------------------+---------------------+-----------------------+------------------------+------------+------------+------------+
[I 2023-05-24 00:14:34,352 bluesky_queueserver.manager.plan_monitoring] Run was closed: 'b5bc4e57-93d2-4ce0-9270-9a9725ab4a3e'
|         1 | 00:14:34.2 |     1.1894 |     1.0000 |  -20.12450 |                    197 |                      0 |                      1 |          10000 |              0 |               5 |                 ENA |                       ENA |                   0 |                   DIS |                     ON |   48.78000 |    0.00000 |    25.6822 |
+-----------+------------+------------+------------+------------+------------------------+------------------------+------------------------+----------------+----------------+-----------------+---------------------+---------------------------+---------------------+-----------------------+------------------------+------------+------------+------------+
generator count ['b5bc4e57'] (scan num: 1061657)
  Data saved to: /nsls2/data/cms/legacy/xf11bm/Pilatus2M/2023/05/24/d5ed19cf-930b-42b7-a210_000000.tiff
  Data linked as: /nsls2/data/cms/legacy/xf11bm/data/2023_2/PTA///saxs/raw/C67_0HP_Tb50C_LP17w_run3_Tc156.83_7156.7s_x48.780_th0.088_1.00s_1061657_saxs.tiff
Shutter is CLOSED.
[I 2023-05-24 00:14:34,578 bluesky_queueserver.manager.worker] The plan was exited. Plan state: completed
[I 2023-05-24 00:14:34,796 bluesky_queueserver.manager.manager] No items are left in the queue.
[I 2023-05-24 00:14:34,796 bluesky_queueserver.manager.manager] Queue is empty.
[I 2023-05-24 00:14:34,857 bluesky_queueserver.manager.manager] Returning current queue and running plan ...
[I 2023-05-24 00:14:34,859 bluesky_queueserver.manager.manager] Returning the list of runs for the running plan ...
[I 2023-05-24 00:14:34,861 bluesky_queueserver.manager.manager] Returning plan history ...
[I 2023-05-24 00:14:34,877 bluesky_queueserver.manager.manager] Adding new item to the queue ...
[I 2023-05-24 00:14:34,879 bluesky_queueserver.manager.manager] Item added: success=True item_type='plan' name='agent_feedback_time_plan' item_uid='564589af-85ef-483a-84a5-976769ba4764' qsize=1.
[I 2023-05-24 00:14:35,899 bluesky_queueserver.manager.manager] Returning current queue and running plan ...
[I 2023-05-24 00:15:05,115 bluesky_queueserver.manager.manager] Adding new item to the queue ...
[I 2023-05-24 00:15:05,119 bluesky_queueserver.manager.manager] Item added: success=True item_type='plan' name='agent_feedback_time_plan' item_uid='66fcf37d-de53-4d4c-bd4a-7f5197b04b76' qsize=2.
[I 2023-05-24 00:15:06,010 bluesky_queueserver.manager.manager] Returning current queue and running plan ...
[IPKernelApp] ERROR | Error in message handler
Traceback (most recent call last):
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/site-packages/ipykernel/kernelbase.py", line 513, in dispatch_queue
    await self.process_one()
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/site-packages/ipykernel/kernelbase.py", line 502, in process_one
    await dispatch(*args)
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/site-packages/ipykernel/kernelbase.py", line 366, in dispatch_shell
    idents, msg = self.session.feed_identities(msg, copy=False)
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/site-packages/jupyter_client/session.py", line 990, in feed_identities
    raise ValueError(msg)
ValueError: DELIM not in msg_list
[IPKernelApp] ERROR | Error in message handler
Traceback (most recent call last):
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/site-packages/ipykernel/kernelbase.py", line 513, in dispatch_queue
    await self.process_one()
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/site-packages/ipykernel/kernelbase.py", line 502, in process_one
    await dispatch(*args)
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/site-packages/ipykernel/kernelbase.py", line 366, in dispatch_shell
    idents, msg = self.session.feed_identities(msg, copy=False)
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/site-packages/jupyter_client/session.py", line 990, in feed_identities
    raise ValueError(msg)
ValueError: DELIM not in msg_list
[E 2023-05-24 03:32:39,064 bluesky_queueserver.manager.manager] Exiting RE Manager with exception Operation cannot be accomplished in current state
Traceback (most recent call last):
  File "/nsls2/data/cms/shared/config/bluesky_overlay/2023-2.0-py310-tiled/lib/python3.10/site-packages/bluesky_queueserver/manager/manager.py", line 3623, in run
    asyncio.run(self.zmq_server_comm())
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete
    return future.result()
  File "/nsls2/data/cms/shared/config/bluesky_overlay/2023-2.0-py310-tiled/lib/python3.10/site-packages/bluesky_queueserver/manager/manager.py", line 3582, in zmq_server_comm
    await self._zmq_send(msg_out)
  File "/nsls2/data/cms/shared/config/bluesky_overlay/2023-2.0-py310-tiled/lib/python3.10/site-packages/bluesky_queueserver/manager/manager.py", line 3413, in _zmq_send
    await self._zmq_socket.send_json(msg)
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/site-packages/zmq/_future.py", line 512, in _add_send_event
    r = send(msg, **nowait_kwargs)
  File "/nsls2/conda/envs/2023-2.0-py310-tiled/lib/python3.10/site-packages/zmq/sugar/socket.py", line 688, in send
    return super().send(data, flags=flags, copy=copy, track=track)
  File "zmq/backend/cython/socket.pyx", line 742, in zmq.backend.cython.socket.Socket.send
  File "zmq/backend/cython/socket.pyx", line 789, in zmq.backend.cython.socket.Socket.send
  File "zmq/backend/cython/socket.pyx", line 255, in zmq.backend.cython.socket._send_copy
  File "zmq/backend/cython/socket.pyx", line 250, in zmq.backend.cython.socket._send_copy
  File "zmq/backend/cython/checkrc.pxd", line 28, in zmq.backend.cython.checkrc._check_rc
zmq.error.ZMQError: Operation cannot be accomplished in current state\

Expected Behavior

Current Behavior

Possible Solution

Steps to Reproduce (for bugs)

Context

Your Environment