Comments (13)
klauer
commented on June 3, 2024
Can you share your IOC code (or provide more details on what it does and how) so that we can suggest how to avoid subscriptions being dropped?
from caproto.
tkurita
commented on June 3, 2024
My simplified code is as follows.
30 PVs are just defined.
import numpy as np
import caproto
from caproto.server import pvproperty, PVGroup, ioc_arg_parser, run, SubGroup
from caproto import config_caproto_logging
#import caproto.server.common
class SupportIOC(PVGroup):
@subgroup(prefix="BPMFB:")
class BPMFBGroup(PVGroup):
@subgroup(prefix="MIRROR:")
class MIRROR(PVGroup):
BPM_P_GAIN_DP_CNST = pvproperty(value=0,
dtype=caproto.ChannelType.INT,
read_only=True)
BPM_P_SHIFT_DP = pvproperty(value=0,
dtype=caproto.ChannelType.INT,
read_only=True)
BPM_P_GAIN_DR_CNST = pvproperty(value=0,
dtype=caproto.ChannelType.INT,
read_only=True)
BPM_P_SHIFT_DR = pvproperty(value=0,
dtype=caproto.ChannelType.INT,
read_only=True)
BPM_I_GAIN_DR_CNST = pvproperty(value=0,
dtype=caproto.ChannelType.INT,
read_only=True)
BPM_I_SHIFT_DR = pvproperty(value=0,
dtype=caproto.ChannelType.INT,
read_only=True)
BPM_PERIOD_IACC_DR_SET = pvproperty(value=0,
dtype=caproto.ChannelType.INT,
read_only=True)
BPM_GAIN_2FS_CNST = pvproperty(value=0,
dtype=caproto.ChannelType.INT,
read_only=True)
BPM_GN_SHIFT_2FS = pvproperty(value=0,
dtype=caproto.ChannelType.INT,
read_only=True)
@SubGroup(prefix="RB:")
class RB(PVGroup):
BPM_P_GAIN_DP_FLOAT = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
BPM_P_GAIN_DR_FLOAT = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
BPM_I_GAIN_DR_FLOAT = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
BPM_GAIN_2FS_FLOAT = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
@SubGroup(prefix="SET:")
class SET(PVGroup):
BPM_P_GAIN_DP_FLOAT = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
BPM_P_GAIN_DR_FLOAT = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
BPM_I_GAIN_DR_FLOAT = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
BPM_GAIN_2FS_FLOAT = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
BPM_P_GAIN_DP_FLOAT_CHANGE = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
BPM_P_GAIN_DR_FLOAT_CHANGE = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
BPM_I_GAIN_DR_FLOAT_CHANGE = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
BPM_GAIN_2FS_FLOAT_CHANGE = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
@SubGroup(prefix="DR_PTN:")
class DelRPatternGroup(PVGroup):
PTN_LENGTH = 65536
MON_LENGTH = 40960
GEN_REFERENCE = pvproperty(value=0,
dtype=caproto.ChannelType.INT)
FB = pvproperty(value=0,
dtype=caproto.ChannelType.DOUBLE)
EXT = pvproperty(value=20,
dtype=caproto.ChannelType.DOUBLE)
TIMMING_RISE = pvproperty(value=400.0,
dtype=caproto.ChannelType.DOUBLE)
REFERENCE_PTN = pvproperty(value=np.zeros(PTN_LENGTH), # length 65536
dtype=caproto.ChannelType.INT) # short
REFERENCE_PTN_A = pvproperty(value=np.zeros(MON_LENGTH),
dtype=caproto.ChannelType.DOUBLE)
WAVE_SPAN = pvproperty(value=2000.0,
dtype=caproto.ChannelType.DOUBLE)
WAVE_DELAY = pvproperty(value=0.0,
dtype=caproto.ChannelType.DOUBLE)
XAXIS_MON = pvproperty(value=np.arange(0, MON_LENGTH),
dtype=caproto.ChannelType.DOUBLE)
if name == 'main':
config_caproto_logging(level='INFO')
ioc_options, run_options = ioc_arg_parser(
default_prefix='SUPPORT:',
desc='Run an Support IOC.',
supported_async_libs=('asyncio',)
)
ioc = SupportIOC(**ioc_options)
run_options["log_pv_names"] = True
run(ioc.pvdb, **run_options)
from caproto.
klauer
commented on June 3, 2024
The above all looks normal enough. I see that you didn't include any functionality in your snippet - just the 30 PVs themselves. Do you have any code that does .write()? Startup, scan, put handlers, etc.?
Unless something strange is happening, high load-based subscription-dropping usually happens if you don't use asyncio properly (e.g., calling time.sleep() where you should be using await asyncio.sleep() - blocking the task accidentally). It can also happen if updates really are happening too quickly for the server to keep up within its default threshold (
caproto/caproto/server/common.py
Lines 17 to 22 in 41ffe0b
for _ in range(10000): await self.BPM_P_GAIN_DP_FLOAT_CHANGE.write(1000))from caproto.
tkurita
commented on June 3, 2024
The code I posted is simplified to confirm the problem I met.
Many put and startup handlers in the actual code are removed.
Even if the code is simplified, I confirmed the messages of "High load. Dropped n responses" appear.
Also, I tried to change HIGH_LOAD_TIMEOUT as follows:
caproto.server.common.HIGH_LOAD_TIMEOUT = 0.1
It looks changing HIGH_LOAD_TIMEOUT does not have no effects.
The message "High load. Dropped 7 responses." appears.
from caproto.
klauer
commented on June 3, 2024
I'm afraid I can't help debug the issue without more complete code. If you don't wish to provide the code, you'll have to dig deeper into what I suggested above. The problem is very likely in how you are implementing the handlers and not in the core of caproto.
from caproto.
tacaswell
commented on June 3, 2024
I suggest setting the high load timeout to something silly like 10_000_000 which will make sure that we never drop messages due to high load.
It is plausible that if you slam the iOC with 30 channel creation and subscription requests all at once it has issues keeping up, but I agree with @klauer , I suspect one of your tasks is not being a fully cooperative team player and blocking the event loop.
from caproto.
tkurita
commented on June 3, 2024
My code is not small then, I afraid showing all code masks the problem.
I attach all code, but above simplified code can represent the problem.
from caproto.
klauer
commented on June 3, 2024
Thanks for providing more details, @tkurita.
Let's see...
-
Most of what I see looks okay, and it appears you've largely followed the intended use of the server library
-
The
dfbcalls appear to not be asyncio-friendly and could be blocking in parts of the code.a. There are a few places where you are doing
ca_get()in aputter. If these are CA calls through an external library, you should consider changing those to the asyncio client as you've already done inCAVFBGroup.pyb. If it's not a CA client call but it's a general operation which may take more than a few milliseconds, you should consider putting it in a background executor
-
The same goes for things like
PatternChannels.put_all- if these block for any significant time, they need to go in a background executor (thread) -
You might be able to narrow in on the problematic code by way of caproto's verbose logging. Try running your IOC with
python support-ioc.py -vvvand inspecting where any slowdowns seem to happen. The output may be difficult to interpret, however.
I'll take a step back from my earlier assertion - it's still possible you're hitting a caproto bug/bad default setting as @tacaswell notes above.
If you can use the simplified code you provided to reproduce the high load message with the verbose logging enabled, we'd be happy to take a look.
from caproto.
tkurita
commented on June 3, 2024
Thanks for many advices.
I will improve my code with following your suggestions.
I present the verbose log of simplified code.
This log include a message "High load. Dropped 7 responses.".
[D 21:19:28.411 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 16B VersionRequest(priority=1, version=13)
[D 21:19:28.411 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='SUPPORT:DR_PTN:XAXIS_MON', cid=5159, version=13, reply=5)
[D 21:19:28.412 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:MON:MMON_BPM_BUNCH_A', cid=5160, version=13, reply=5)
[D 21:19:28.412 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 40B SearchRequest(name='RFAC:DFB:MON:MMON_CAV_A', cid=5161, version=13, reply=5)
[D 21:19:28.412 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='SUPPORT:DR_PTN:REFERENCE_PTN_A', cid=5162, version=13, reply=5)
[D 21:19:28.412 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:MON:MMON_BPM_FB_DP_A', cid=5163, version=13, reply=5)
[D 21:19:28.412 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:MON:MMON_BPM_FB_DR_A', cid=5164, version=13, reply=5)
[D 21:19:28.412 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:MON:MMON_BPM_FB_2FS_A', cid=5165, version=13, reply=5)
[D 21:19:28.413 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 40B SearchRequest(name='SUPPORT:DR_PTN:EXT', cid=5168, version=13, reply=5)
[D 21:19:28.413 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='SUPPORT:DR_PTN:GEN_REFERENCE', cid=5166, version=13, reply=5)
[D 21:19:28.413 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 56B SearchRequest(name='SUPPORT:BPMFB:RB:BPM_P_GAIN_DP_FLOAT', cid=5174, version=13, reply=5)
[D 21:19:28.413 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_GAIN_2FS_CNST', cid=5175, version=13, reply=5)
[D 21:19:28.413 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:PERIOD_UPDATE', cid=5167, version=13, reply=5)
[D 21:19:28.414 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 64B SearchRequest(name='SUPPORT:BPMFB:SET:BPM_I_GAIN_DR_FLOAT_CHANGE', cid=5176, version=13, reply=5)
[D 21:19:28.414 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_I_GAIN_DR_CNST', cid=5177, version=13, reply=5)
[D 21:19:28.414 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='SUPPORT:DR_PTN:TIMMING_RISE', cid=5169, version=13, reply=5)
[D 21:19:28.414 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 40B SearchRequest(name='RFAC:DFB:SET:BPM_FB_ON', cid=5178, version=13, reply=5)
[D 21:19:28.414 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 56B SearchRequest(name='SUPPORT:BPMFB:SET:BPM_P_GAIN_DR_FLOAT', cid=5179, version=13, reply=5)
[D 21:19:28.415 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_PERIOD_IACC_DR', cid=5180, version=13, reply=5)
[D 21:19:28.415 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 64B SearchRequest(name='SUPPORT:BPMFB:SET:BPM_GAIN_2FS_FLOAT_CHANGE', cid=5181, version=13, reply=5)
[D 21:19:28.415 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 40B SearchRequest(name='SUPPORT:DR_PTN:FB', cid=5170, version=13, reply=5)
[D 21:19:28.415 _broadcaster: 94] (1 of 11) VersionResponse(version=13)
[D 21:19:28.416 _broadcaster: 92] (2 of 11) SearchResponse(port=5064, ip='255.255.255.255', cid=5159, version=13)
[D 21:19:28.416 _broadcaster: 92] (3 of 11) SearchResponse(port=5064, ip='255.255.255.255', cid=5162, version=13)
[D 21:19:28.416 _broadcaster: 92] (4 of 11) SearchResponse(port=5064, ip='255.255.255.255', cid=5168, version=13)
[D 21:19:28.416 _broadcaster: 92] (5 of 11) SearchResponse(port=5064, ip='255.255.255.255', cid=5166, version=13)
[D 21:19:28.416 _broadcaster: 92] (6 of 11) SearchResponse(port=5064, ip='255.255.255.255', cid=5174, version=13)
[D 21:19:28.417 _broadcaster: 92] (7 of 11) SearchResponse(port=5064, ip='255.255.255.255', cid=5176, version=13)
[D 21:19:28.417 _broadcaster: 92] (8 of 11) SearchResponse(port=5064, ip='255.255.255.255', cid=5169, version=13)
[D 21:19:28.417 _broadcaster: 92] (9 of 11) SearchResponse(port=5064, ip='255.255.255.255', cid=5179, version=13)
[D 21:19:28.417 _broadcaster: 92] (10 of 11) SearchResponse(port=5064, ip='255.255.255.255', cid=5181, version=13)
[D 21:19:28.417 _broadcaster: 92] (11 of 11) SearchResponse(port=5064, ip='255.255.255.255', cid=5170, version=13)
[D 21:19:28.418 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 16B VersionRequest(priority=1, version=13)
[D 21:19:28.418 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='SUPPORT:DR_PTN:WAVE_SPAN', cid=5171, version=13, reply=5)
[D 21:19:28.418 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='SUPPORT:DR_PTN:WAVE_DELAY', cid=5172, version=13, reply=5)
[D 21:19:28.419 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 64B SearchRequest(name='SUPPORT:BPMFB:SET:BPM_P_GAIN_DR_FLOAT_CHANGE', cid=5173, version=13, reply=5)
[D 21:19:28.419 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 56B SearchRequest(name='SUPPORT:BPMFB:RB:BPM_I_GAIN_DR_FLOAT', cid=5182, version=13, reply=5)
[D 21:19:28.419 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_FB_START_B', cid=5191, version=13, reply=5)
[D 21:19:28.419 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_FB_END_A', cid=5190, version=13, reply=5)
[D 21:19:28.419 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_P_SHIFT_DP', cid=5183, version=13, reply=5)
[D 21:19:28.419 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 56B SearchRequest(name='SUPPORT:BPMFB:RB:BPM_GAIN_2FS_FLOAT', cid=5184, version=13, reply=5)
[D 21:19:28.419 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 56B SearchRequest(name='SUPPORT:BPMFB:SET:BPM_P_GAIN_DP_FLOAT', cid=5185, version=13, reply=5)
[D 21:19:28.420 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_FB_END_B', cid=5186, version=13, reply=5)
[D 21:19:28.420 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 64B SearchRequest(name='SUPPORT:BPMFB:SET:BPM_P_GAIN_DP_FLOAT_CHANGE', cid=5187, version=13, reply=5)
[D 21:19:28.420 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_FB_START_A', cid=5188, version=13, reply=5)
[D 21:19:28.420 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_P_GAIN_DP_CNST', cid=5189, version=13, reply=5)
[D 21:19:28.420 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_I_SHIFT_DR', cid=5192, version=13, reply=5)
[D 21:19:28.420 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_P_SHIFT_DR', cid=5193, version=13, reply=5)
[D 21:19:28.420 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_P_GAIN_DR_CNST', cid=5194, version=13, reply=5)
[D 21:19:28.421 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 56B SearchRequest(name='SUPPORT:BPMFB:SET:BPM_I_GAIN_DR_FLOAT', cid=5195, version=13, reply=5)
[D 21:19:28.421 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 48B SearchRequest(name='RFAC:DFB:SET:BPM_GN_SHIFT_2FS', cid=5196, version=13, reply=5)
[D 21:19:28.421 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 56B SearchRequest(name='SUPPORT:BPMFB:SET:BPM_GAIN_2FS_FLOAT', cid=5197, version=13, reply=5)
[D 21:19:28.421 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 16B VersionRequest(priority=1, version=13)
[D 21:19:28.421 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 56B SearchRequest(name='SUPPORT:BPMFB:RB:BPM_P_GAIN_DR_FLOAT', cid=5198, version=13, reply=5)
[D 21:19:28.421 _broadcaster: 136] 219.30.54.37:5064 <<<--- 219.30.54.37:59311 40B SearchRequest(name='RFAC:DFB:MON:MMON_VALID', cid=5199, version=13, reply=5)
[D 21:19:28.422 _broadcaster: 94] (1 of 10) VersionResponse(version=13)
[D 21:19:28.422 _broadcaster: 92] (2 of 10) SearchResponse(port=5064, ip='255.255.255.255', cid=5171, version=13)
[D 21:19:28.422 _broadcaster: 92] (3 of 10) SearchResponse(port=5064, ip='255.255.255.255', cid=5172, version=13)
[D 21:19:28.422 _broadcaster: 92] (4 of 10) SearchResponse(port=5064, ip='255.255.255.255', cid=5173, version=13)
[D 21:19:28.422 _broadcaster: 92] (5 of 10) SearchResponse(port=5064, ip='255.255.255.255', cid=5182, version=13)
[D 21:19:28.422 _broadcaster: 92] (6 of 10) SearchResponse(port=5064, ip='255.255.255.255', cid=5184, version=13)
[D 21:19:28.422 _broadcaster: 92] (7 of 10) SearchResponse(port=5064, ip='255.255.255.255', cid=5185, version=13)
[D 21:19:28.423 _broadcaster: 92] (8 of 10) SearchResponse(port=5064, ip='255.255.255.255', cid=5187, version=13)
[D 21:19:28.423 _broadcaster: 92] (9 of 10) SearchResponse(port=5064, ip='255.255.255.255', cid=5195, version=13)
[D 21:19:28.423 _broadcaster: 92] (10 of 10) SearchResponse(port=5064, ip='255.255.255.255', cid=5197, version=13)
[D 21:19:28.423 _broadcaster: 94] (1 of 2) VersionResponse(version=13)
[D 21:19:28.423 _broadcaster: 92] (2 of 2) SearchResponse(port=5064, ip='255.255.255.255', cid=5198, version=13)
[I 21:19:28.424 common: 1089] Connected to new client at 219.30.54.37:56123 (total: 1).
[D 21:19:28.424 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B VersionRequest(priority=1, version=13)
[D 21:19:28.424 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B VersionResponse(version=13)
[D 21:19:28.425 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 24B ClientNameRequest(name='FPGA')
[D 21:19:28.425 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 24B HostNameRequest(name='RFDFB')
[D 21:19:28.425 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 48B CreateChanRequest(name='SUPPORT:DR_PTN:XAXIS_MON', cid=5159, version=13)
[D 21:19:28.425 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5159, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.425 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=40960, cid=5159, sid=0)
[D 21:19:28.426 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 48B CreateChanRequest(name='SUPPORT:DR_PTN:REFERENCE_PTN_A', cid=5162, version=13)
[D 21:19:28.426 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5162, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.426 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=40960, cid=5162, sid=1)
[D 21:19:28.426 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 40B CreateChanRequest(name='SUPPORT:DR_PTN:EXT', cid=5168, version=13)
[D 21:19:28.427 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5168, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.427 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5168, sid=2)
[D 21:19:28.427 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 48B CreateChanRequest(name='SUPPORT:DR_PTN:GEN_REFERENCE', cid=5166, version=13)
[D 21:19:28.427 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5166, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.427 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.INT: 1>, data_count=1, cid=5166, sid=3)
[D 21:19:28.427 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 56B CreateChanRequest(name='SUPPORT:BPMFB:RB:BPM_P_GAIN_DP_FLOAT', cid=5174, version=13)
[D 21:19:28.428 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5174, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.428 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5174, sid=4)
[D 21:19:28.428 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 64B CreateChanRequest(name='SUPPORT:BPMFB:SET:BPM_I_GAIN_DR_FLOAT_CHANGE', cid=5176, version=13)
[D 21:19:28.428 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5176, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.428 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5176, sid=5)
[D 21:19:28.429 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 48B CreateChanRequest(name='SUPPORT:DR_PTN:TIMMING_RISE', cid=5169, version=13)
[D 21:19:28.429 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5169, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.429 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5169, sid=6)
[D 21:19:28.429 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 56B CreateChanRequest(name='SUPPORT:BPMFB:SET:BPM_P_GAIN_DR_FLOAT', cid=5179, version=13)
[D 21:19:28.429 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5179, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.430 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5179, sid=7)
[D 21:19:28.430 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 64B CreateChanRequest(name='SUPPORT:BPMFB:SET:BPM_GAIN_2FS_FLOAT_CHANGE', cid=5181, version=13)
[D 21:19:28.430 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5181, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.430 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5181, sid=8)
[D 21:19:28.430 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 40B CreateChanRequest(name='SUPPORT:DR_PTN:FB', cid=5170, version=13)
[D 21:19:28.430 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5170, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.431 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5170, sid=9)
[D 21:19:28.431 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 48B CreateChanRequest(name='SUPPORT:DR_PTN:WAVE_SPAN', cid=5171, version=13)
[D 21:19:28.431 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5171, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.431 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5171, sid=10)
[D 21:19:28.431 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 48B CreateChanRequest(name='SUPPORT:DR_PTN:WAVE_DELAY', cid=5172, version=13)
[D 21:19:28.431 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5172, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.432 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5172, sid=11)
[D 21:19:28.432 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 64B CreateChanRequest(name='SUPPORT:BPMFB:SET:BPM_P_GAIN_DR_FLOAT_CHANGE', cid=5173, version=13)
[D 21:19:28.432 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5173, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.432 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5173, sid=12)
[D 21:19:28.432 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 56B CreateChanRequest(name='SUPPORT:BPMFB:RB:BPM_I_GAIN_DR_FLOAT', cid=5182, version=13)
[D 21:19:28.432 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5182, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.433 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5182, sid=13)
[D 21:19:28.433 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 56B CreateChanRequest(name='SUPPORT:BPMFB:RB:BPM_GAIN_2FS_FLOAT', cid=5184, version=13)
[D 21:19:28.433 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5184, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.433 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5184, sid=14)
[D 21:19:28.433 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 56B CreateChanRequest(name='SUPPORT:BPMFB:SET:BPM_P_GAIN_DP_FLOAT', cid=5185, version=13)
[D 21:19:28.434 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5185, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.434 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5185, sid=15)
[D 21:19:28.434 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 64B CreateChanRequest(name='SUPPORT:BPMFB:SET:BPM_P_GAIN_DP_FLOAT_CHANGE', cid=5187, version=13)
[D 21:19:28.434 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5187, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.434 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5187, sid=16)
[D 21:19:28.435 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 56B CreateChanRequest(name='SUPPORT:BPMFB:SET:BPM_I_GAIN_DR_FLOAT', cid=5195, version=13)
[D 21:19:28.435 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5195, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.435 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5195, sid=17)
[D 21:19:28.435 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 56B CreateChanRequest(name='SUPPORT:BPMFB:SET:BPM_GAIN_2FS_FLOAT', cid=5197, version=13)
[D 21:19:28.435 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5197, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.436 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5197, sid=18)
[D 21:19:28.436 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 56B CreateChanRequest(name='SUPPORT:BPMFB:RB:BPM_P_GAIN_DR_FLOAT', cid=5198, version=13)
[D 21:19:28.436 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B AccessRightsResponse(cid=5198, access_rights=<AccessRights.WRITE|READ: 3>)
[D 21:19:28.436 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 16B CreateChanResponse(data_type=<ChannelType.DOUBLE: 6>, data_count=1, cid=5198, sid=19)
[D 21:19:28.438 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=0, ioid=23639)
[D 21:19:28.438 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23639, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.439 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=0, sid=0, subscriptionid=23640, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.440 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 327720B EventAddResponse(data=array([0.0000e+00, 1.0000e+00, 2.0000e+00, ..., 4.0957e+04, 4.0958e+04,
4.0959e+04]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=40960, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23640, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.441 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=1, ioid=23641)
[D 21:19:28.441 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23641, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.442 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=0, sid=1, subscriptionid=23642, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.443 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=3, ioid=23643)
[D 21:19:28.443 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23643, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.444 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_INT: 15>, data_count=1, sid=3, subscriptionid=23644, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.444 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 327720B EventAddResponse(data=array([0., 0., 0., ..., 0., 0., 0.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=40960, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23642, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.445 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=8, ioid=23645)
[D 21:19:28.445 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23645, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.445 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=8, subscriptionid=23646, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.446 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=11, ioid=23647)
[D 21:19:28.446 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23647, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.447 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=11, subscriptionid=23648, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.447 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=6, ioid=23649)
[D 21:19:28.448 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([400.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23649, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.448 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=6, subscriptionid=23650, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.449 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=10, ioid=23651)
[D 21:19:28.449 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([2000.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23651, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.450 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=10, subscriptionid=23652, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.450 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=5, ioid=23653)
[D 21:19:28.451 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23653, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.451 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=5, subscriptionid=23654, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.452 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=13, ioid=23655)
[D 21:19:28.452 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23655, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.452 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=13, subscriptionid=23656, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.453 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=4, ioid=23657)
[D 21:19:28.453 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23657, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.454 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=4, subscriptionid=23658, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.454 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=7, ioid=23659)
[D 21:19:28.454 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23659, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.455 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=7, subscriptionid=23660, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.455 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=14, ioid=23661)
[D 21:19:28.456 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23661, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.456 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=14, subscriptionid=23662, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.457 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=2, ioid=23663)
[D 21:19:28.457 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([20.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23663, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.457 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=2, subscriptionid=23664, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.458 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=9, ioid=23665)
[D 21:19:28.458 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23665, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.458 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=9, subscriptionid=23666, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.459 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=15, ioid=23667)
[D 21:19:28.459 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23667, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.460 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=15, subscriptionid=23668, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.460 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=19, ioid=23669)
[D 21:19:28.460 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23669, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.461 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=19, subscriptionid=23670, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.461 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=12, ioid=23671)
[D 21:19:28.461 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23671, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.462 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=12, subscriptionid=23672, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.462 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=16, ioid=23673)
[D 21:19:28.462 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23673, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.463 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=16, subscriptionid=23674, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.464 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=18, ioid=23675)
[D 21:19:28.464 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23675, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.464 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=18, subscriptionid=23676, low=0.0, high=0.0, to=0.0, mask=5)
[D 21:19:28.465 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B ReadNotifyRequest(data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, sid=17, ioid=23677)
[D 21:19:28.465 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 104B ReadNotifyResponse(data=array([0.]), data_type=<ChannelType.CTRL_DOUBLE: 34>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), ioid=23677, metadata=DBR_CTRL_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, upper_disp_limit=0.0, lower_disp_limit=0.0, upper_alarm_limit=0.0, upper_warning_limit=0.0, lower_warning_limit=0.0, lower_alarm_limit=0.0, upper_ctrl_limit=0.0, lower_ctrl_limit=0.0, precision=0, units=b''))
[D 21:19:28.466 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 32B EventAddRequest(data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, sid=17, subscriptionid=23678, low=0.0, high=0.0, to=0.0, mask=5)
[I 21:19:28.466 common: 671] Client at 219.30.54.37:56123 has turned events off.
[D 21:19:28.466 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B EventsOffRequest()
[I 21:19:28.466 common: 661] Client at 219.30.54.37:56123 has turned events on.
[D 21:19:28.467 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B EventsOnRequest()
[I 21:19:28.467 common: 671] Client at 219.30.54.37:56123 has turned events off.
[D 21:19:28.467 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B EventsOffRequest()
[I 21:19:28.467 common: 661] Client at 219.30.54.37:56123 has turned events on.
[D 21:19:28.467 common: 684] 219.30.54.37:5064 <<<--- 219.30.54.37:56123 16B EventsOnRequest()
[W 21:19:28.583 common: 385] High load. Dropped 7 responses.
[I 21:19:28.583 common: 387] High load. Batched 11 commands (432B) with 0.0310s latency.
[D 21:19:28.583 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 32B EventAddResponse(data=array([0], dtype=int16), data_type=<ChannelType.TIME_INT: 15>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23644, metadata=DBR_TIME_INT(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.584 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 40B EventAddResponse(data=array([0.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23646, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.584 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 40B EventAddResponse(data=array([0.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23648, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.584 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 40B EventAddResponse(data=array([400.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23650, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.585 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 40B EventAddResponse(data=array([2000.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23652, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.585 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 40B EventAddResponse(data=array([0.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23654, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.585 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 40B EventAddResponse(data=array([0.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23656, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.586 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 40B EventAddResponse(data=array([0.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23658, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.586 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 40B EventAddResponse(data=array([0.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23660, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.586 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 40B EventAddResponse(data=array([0.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23662, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
[D 21:19:28.587 _circuit: 166] 219.30.54.37:5064 --->>> 219.30.54.37:56123 40B EventAddResponse(data=array([0.]), data_type=<ChannelType.TIME_DOUBLE: 20>, data_count=1, status=CAStatusCode(name='ECA_NORMAL', code=0, code_with_severity=1, severity=<CASeverity.SUCCESS: 1>, success=1, defunct=False, description='Normal successful completion'), subscriptionid=23678, metadata=DBR_TIME_DOUBLE(status=<AlarmStatus.NO_ALARM: 0>, severity=<AlarmSeverity.NO_ALARM: 0>, timestamp=1657282751.8598))
from caproto.
danielballan
commented on June 3, 2024
I believe someone raised the issue before that we might shift into "high load" mode, where we drop responses to keep up, a little too eagerly. Reviewing that code, I think you might try increasing this constant:
caproto/_constants.py:MAX_TOTAL_SUBSCRIPTION_BACKLOG = 10000 # total per circuit not per subscription
from caproto.
klauer
commented on June 3, 2024
Looking over the log, it seems to me like the CSS EPICS client library, with its repeated toggling of EventsOffRequest and EventsOnRequest, could be making caproto dump out too many messages at once according to its thresholds:
https://github.com/klauer/caproto/blob/57e0c564e1463e8a19d7ab6da5d1b9735d04f48f/caproto/server/common.py#L651-L663
I'm not sure how this could be rectified, or if these should actually count toward the high load detection. Interesting... If that's the case, I believe you may have hit a real bug here, @tkurita (and sorry for the initial doubt!)
from caproto.
klauer
commented on June 3, 2024
Working on semi-related subscription bugs (as in #814), I was hoping to tackle this as well before the next caproto tag.
I've reproduced the issue thanks to your verbose log above (almost a year later - sorry, such is the nature of these open source projects). Next will be digging into potential fixes... Hoping Dan/Tom may also have some ideas here.
$ python support-ioc.py
[I 09:01:33.084 common: 1117] Connected to new client at 192.168.2.110:50519 (total: 1).
[I 09:01:33.084 common: 1117] Connected to new client at 192.168.2.110:50519 (total: 1).
[I 09:01:33.214 common: 676] Client at 192.168.2.110:50519 has turned events off.
[I 09:01:33.215 common: 666] Client at 192.168.2.110:50519 has turned events on.
[I 09:01:33.216 common: 676] Client at 192.168.2.110:50519 has turned events off.
[I 09:01:33.216 common: 666] Client at 192.168.2.110:50519 has turned events on.
[W 09:01:33.228 common: 390] High load. Dropped 7 responses.
[I 09:01:33.228 common: 392] High load. Batched 9 commands (352B) with 0.0026s latency.
[I 09:01:38.222 common: 1139] Disconnected from client at 192.168.2.110:50519 (total: 0).
[I 09:01:38.222 common: 1139] Disconnected from client at 192.168.2.110:50519 (total: 0).$ python client_issue_797.pyRepo: https://github.com/klauer/issue_797_caproto_subs/blob/master/client_issue_797.py
from caproto.
klauer
commented on June 3, 2024
Closed by #817. Sorry that it took almost a year.
from caproto.
Related Issues (20)
- caproto without wifi\ethernet HOT 1
- BUG: Using lower-level PVSpec with kwarg `read_only=True` results in a PV that is not read only. HOT 1
- Run multiple, soft and caproto, IOCs on same host HOT 4
- Looking for maintainers / developers HOT 13
- Error [WinError 10054] HOT 12
- Subscription backlog memory usage too high for PVs storing large arrays HOT 2
- Writing a C++ CA client that communicates with caproto-based server HOT 2
- Threading client sometimes fails to reconnect a disconnected PV
- Python 3.10: asyncio `loop` parameter was removed HOT 3
- Review performance testing HOT 3
- Duplication of PV writes seen by camonitor HOT 6
- Strict typing and Caproto HOT 3
- Pyepics Compat Layer: caget_many ignores timeout HOT 6
- Caproto incompatibility with Python 3.11 HOT 4
- add_callback failed with error HOT 2
- Deprecate/remove/fix examples which have getters
- Array slice channel filter works intermittently when used with camonitor HOT 2
- Repository links for Caproto-written IOCs? HOT 6
- CI: deprecated GHA usage of `set-output` needs resolving in docs workflow
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from caproto.