redis walking high CPU time
CPU-time profiling (not wall time) of Redis walker listening to demo session (see below) shows:
- XREAD takes all CPU time
- XREAD is called 2x the number of points in the scan
Redis walk profiling: https://gitlab.esrf.fr/-/snippets/236
loopscan(1000,1e-6,diode1,diode2,save=False)
demo_session:tmp:scans:inhouse:id002011:sample:sample_wdn5:_1_loopscan
1115525 function calls (1116038 primitive calls) in 7.921 seconds
Ordered by: cumulative time
List reduced from 453 to 30 due to restriction <30>
ncalls tottime percall cumtime percall filename:lineno(function)
2020 0.030 0.000 7.475 0.004 .../bliss/config/streaming.py:565(DataStreamReader._read_active_streams)
2020 0.037 0.000 7.344 0.004 .../redis/client.py:2547(Redis.xread)
2104 0.021 0.000 7.305 0.003 .../redis/client.py:894(Redis.execute_command)
2020 0.013 0.000 3.744 0.002 .../redis/client.py:912(Redis.parse_response)
2733 0.018 0.000 3.493 0.001 .../redis/connection.py:727(UnixDomainSocketConnection.read_response)
4615 0.021 0.000 3.492 0.001 .../redis/connection.py:414(HiredisParser.read_from_socket)
2733 0.015 0.000 3.475 0.001 .../redis/connection.py:452(HiredisParser.read_response)
4615 0.012 0.000 3.457 0.001 .../redis/_compat.py:74(recv_into)
4615 3.396 0.001 3.445 0.001 .../gevent/_socket3.py:502(socket.recv_into)
2105 0.015 0.000 3.286 0.002 .../redis/connection.py:714(UnixDomainSocketConnection.send_command)
2733 0.928 0.000 3.029 0.001 .../redis/connection.py:750(UnixDomainSocketConnection.pack_command)
4049 0.001 0.000 2.342 0.001 .../bliss/data/node.py:733(DataNodeContainer.walk_on_new_events)
4049 0.009 0.000 2.341 0.001 .../bliss/data/node.py:708(DataNodeContainer.walk_events)
4049 0.028 0.000 2.332 0.001 .../bliss/data/node.py:741(DataNodeContainer._iter_reader)
8064 0.040 0.000 1.901 0.000 .../bliss/data/node.py:817(ChannelDataNode._iter_data_stream_events)
4032 0.038 0.000 1.765 0.000 .../bliss/data/nodes/channel.py:331(ChannelDataNode.decode_raw_events)
4032 0.246 0.000 1.632 0.000 .../bliss/data/events/channel.py:109(merge)
95088 0.917 0.000 1.442 0.000 .../redis/connection.py:103(Encoder.encode)
48893 0.065 0.000 1.253 0.000 .../bliss/config/streaming_events.py:197(ChannelDataEvent.__init__)
44861 0.051 0.000 1.110 0.000 .../bliss/config/streaming_events.py:219(ChannelDataEvent.decode)
44844 0.209 0.000 1.059 0.000 .../bliss/data/events/channel.py:99(ChannelDataEvent._decode)
89706 0.138 0.000 0.445 0.000 .../bliss/config/streaming_events.py:244(generic_decode)
2204 0.022 0.000 0.284 0.000 .../redis/connection.py:686(UnixDomainSocketConnection.send_packed_command)
2020 0.005 0.000 0.259 0.000 .../redis/client.py:342(parse_xread)
2020 0.008 0.000 0.254 0.000 .../redis/client.py:345(<listcomp>)
4062 0.093 0.000 0.246 0.000 .../redis/client.py:305(parse_stream_list)
2213 0.025 0.000 0.237 0.000 .../redis/_compat.py:8(sendall)
44861 0.077 0.000 0.225 0.000 .../bliss/config/streaming_events.py:232(ChannelDataEvent._decode)
2213 0.032 0.000 0.211 0.000 .../gevent/_socket3.py:527(socket.sendall)
2203 0.039 0.000 0.186 0.000 .../redis/connection.py:1171(GreenletSafeConnectionPool.get_connection)
loopscan(2000,1e-6,diode1,diode2,save=False)
demo_session:tmp:scans:inhouse:id002011:sample:sample_wdn7:_1_loopscan
1849254 function calls (1849893 primitive calls) in 15.019 seconds
Ordered by: cumulative time
List reduced from 453 to 30 due to restriction <30>
ncalls tottime percall cumtime percall filename:lineno(function)
4020 0.018 0.000 15.556 0.004 .../bliss/config/streaming.py:565(DataStreamReader._read_active_streams)
4020 0.067 0.000 15.353 0.004 .../redis/client.py:2547(Redis.xread)
4127 0.053 0.000 15.279 0.004 .../redis/client.py:894(Redis.execute_command)
4020 0.017 0.000 7.801 0.002 .../redis/client.py:912(Redis.parse_response)
4913 0.021 0.000 7.491 0.002 .../redis/connection.py:727(UnixDomainSocketConnection.read_response)
4913 0.045 0.000 7.470 0.002 .../redis/connection.py:452(HiredisParser.read_response)
8777 0.069 0.000 7.465 0.001 .../redis/connection.py:414(HiredisParser.read_from_socket)
8777 0.029 0.000 7.369 0.001 .../redis/_compat.py:74(recv_into)
8777 7.261 0.001 7.339 0.001 .../gevent/_socket3.py:502(socket.recv_into)
4128 0.039 0.000 7.084 0.002 .../redis/connection.py:714(UnixDomainSocketConnection.send_command)
4913 2.094 0.000 6.599 0.001 .../redis/connection.py:750(UnixDomainSocketConnection.pack_command)
8059 0.013 0.000 3.266 0.000 .../bliss/data/node.py:733(DataNodeContainer.walk_on_new_events)
8059 0.007 0.000 3.253 0.000 .../bliss/data/node.py:708(DataNodeContainer.walk_events)
8059 0.060 0.000 3.246 0.000 .../bliss/data/node.py:741(DataNodeContainer._iter_reader)
203782 1.740 0.000 3.051 0.000 .../redis/connection.py:103(Encoder.encode)
16080 0.069 0.000 2.562 0.000 .../bliss/data/node.py:817(ChannelDataNode._iter_data_stream_events)
8040 0.060 0.000 2.307 0.000 .../bliss/data/nodes/channel.py:331(ChannelDataNode.decode_raw_events)
8040 0.358 0.000 2.095 0.000 .../bliss/data/events/channel.py:109(merge)
68903 0.095 0.000 1.573 0.000 .../bliss/config/streaming_events.py:197(ChannelDataEvent.__init__)
60863 0.079 0.000 1.396 0.000 .../bliss/config/streaming_events.py:219(ChannelDataEvent.decode)
60844 0.230 0.000 1.317 0.000 .../bliss/data/events/channel.py:99(ChannelDataEvent._decode)
121710 0.152 0.000 0.561 0.000 .../bliss/config/streaming_events.py:244(generic_decode)
4251 0.054 0.000 0.472 0.000 .../redis/connection.py:686(UnixDomainSocketConnection.send_packed_command)
4262 0.020 0.000 0.415 0.000 .../redis/_compat.py:8(sendall)
4262 0.029 0.000 0.395 0.000 .../gevent/_socket3.py:527(socket.sendall)
4262 0.116 0.000 0.365 0.000 .../gevent/_socketcommon.py:337(_sendall)
4020 0.004 0.000 0.325 0.000 .../redis/client.py:342(parse_xread)
4020 0.010 0.000 0.321 0.000 .../redis/client.py:345(<listcomp>)
8075 0.086 0.000 0.311 0.000 .../redis/client.py:305(parse_stream_list)
60863 0.100 0.000 0.306 0.000 .../bliss/config/streaming_events.py:232(ChannelDataEvent._decode)