akka / akka-edge-rs

Akka Edge support in Rust
https://doc.akka.io/docs/akka-edge/current/
Other
9 stars 1 forks source link

Emitting filtered event once per second #48

Closed patriknw closed 1 year ago

patriknw commented 1 year ago

When leaving it running it seems to emit a filtered event once per second.

select persistence_id, seq_nr, db_timestamp, event_ser_id, event_ser_manifest, event_payload from event_journal order by db_timestamp;
 persistence_id | seq_nr |         db_timestamp          | event_ser_id |            event_ser_manifest            |                event_payload
----------------+--------+-------------------------------+--------------+------------------------------------------+----------------------------------------------
 Registration|1 |      1 | 2023-10-18 08:58:26.807942+02 |           33 | iot.registration.Registration$Registered | \xbf66736563726574bf6576616c756563666f6fffff
 Sensor|1       |      1 | 2023-10-18 09:25:08.837427+02 |           34 | F                                        | \x
 Sensor|1       |      2 | 2023-10-18 09:25:11.831705+02 |           34 | F                                        | \x
 Sensor|1       |      3 | 2023-10-18 09:26:11.940911+02 |           34 | F                                        | \x
 Sensor|1       |      4 | 2023-10-18 09:26:56.254831+02 |            2 | iot.temperature.proto.TemperatureRead    | \x0802
 Sensor|1       |      5 | 2023-10-18 09:27:12.22157+02  |           34 | F                                        | \x
 Sensor|1       |      6 | 2023-10-18 09:28:12.334963+02 |           34 | F                                        | \x
 Sensor|1       |      7 | 2023-10-18 09:29:12.451345+02 |           34 | F                                        | \x
 Sensor|1       |      8 | 2023-10-18 09:30:12.560615+02 |           34 | F                                        | \x
 Sensor|1       |      9 | 2023-10-18 09:31:12.659421+02 |           34 | F                                        | \x
 Sensor|1       |     10 | 2023-10-18 09:32:12.763068+02 |           34 | F                                        | \x
 Sensor|1       |     11 | 2023-10-18 09:33:12.869349+02 |           34 | F                                        | \x
 Sensor|1       |     12 | 2023-10-18 09:34:12.981261+02 |           34 | F                                        | \x
 Sensor|1       |     13 | 2023-10-18 09:35:13.090149+02 |           34 | F                                        | \x
 Sensor|1       |     14 | 2023-10-18 09:36:13.193917+02 |           34 | F                                        | \x
 Sensor|1       |     15 | 2023-10-18 09:37:13.296181+02 |           34 | F                                        | \x
 Sensor|1       |     16 | 2023-10-18 09:38:13.41136+02  |           34 | F                                        | \x
 Sensor|1       |     17 | 2023-10-18 09:39:14.519305+02 |           34 | F                                        | \x
 Sensor|1       |     18 | 2023-10-18 09:40:14.617701+02 |           34 | F                                        | \x
 Sensor|1       |     19 | 2023-10-18 09:41:14.722375+02 |           34 | F                                        | \x
 Sensor|1       |     20 | 2023-10-18 09:42:14.825526+02 |           34 | F                                        | \x
 Sensor|1       |     21 | 2023-10-18 09:43:14.933911+02 |           34 | F                                        | \x
 Sensor|1       |     22 | 2023-10-18 09:44:15.043617+02 |           34 | F                                        | \x
 Sensor|1       |     23 | 2023-10-18 09:45:15.156405+02 |           34 | F                                        | \x
 Sensor|1       |     24 | 2023-10-18 09:46:15.26491+02  |           34 | F                                        | \x
 Sensor|1       |     25 | 2023-10-18 09:47:15.386042+02 |           34 | F                                        | \x
 Sensor|1       |     26 | 2023-10-18 09:48:15.504482+02 |           34 | F                                        | \x
 Sensor|1       |     27 | 2023-10-18 09:49:15.613997+02 |           34 | F                                        | \x
 Sensor|1       |     28 | 2023-10-18 09:50:15.73658+02  |           34 | F                                        | \x
 Sensor|1       |     29 | 2023-10-18 09:51:15.852413+02 |           34 | F                                        | \x
 Sensor|1       |     30 | 2023-10-18 09:52:15.991798+02 |           34 | F                                        | \x
 Sensor|1       |     31 | 2023-10-18 09:53:16.112647+02 |           34 | F                                        | \x
 Sensor|1       |     32 | 2023-10-18 09:54:16.225129+02 |           34 | F                                        | \x
 Sensor|1       |     33 | 2023-10-18 09:55:16.338582+02 |           34 | F                                        | \x
 Sensor|1       |     34 | 2023-10-18 09:56:17.467419+02 |           34 | F                                        | \x
 Sensor|1       |     35 | 2023-10-18 09:57:17.576886+02 |           34 | F                                        | \x
 Sensor|1       |     36 | 2023-10-18 09:58:17.704509+02 |           34 | F                                        | \x
 Sensor|1       |     37 | 2023-10-18 09:59:17.829994+02 |           34 | F                                        | \x
 Sensor|1       |     38 | 2023-10-18 10:00:17.962988+02 |           34 | F                                        | \x
 Sensor|1       |     39 | 2023-10-18 10:01:18.084971+02 |           34 | F                                        | \x
 Sensor|1       |     40 | 2023-10-18 10:02:18.210927+02 |           34 | F                                        | \x
 Sensor|1       |     41 | 2023-10-18 10:03:18.341436+02 |           34 | F                                        | \x
 Sensor|1       |     42 | 2023-10-18 10:04:18.459105+02 |           34 | F                                        | \x
 Sensor|1       |     43 | 2023-10-18 10:05:18.588381+02 |           34 | F                                        | \x
 Sensor|1       |     44 | 2023-10-18 10:06:18.719669+02 |           34 | F                                        | \x
 Sensor|1       |     45 | 2023-10-18 10:07:18.850505+02 |           34 | F                                        | \x
 Sensor|1       |     46 | 2023-10-18 10:08:18.981718+02 |           34 | F                                        | \x
 Sensor|1       |     47 | 2023-10-18 10:09:19.104074+02 |           34 | F                                        | \x
 Sensor|1       |     48 | 2023-10-18 10:10:19.235849+02 |           34 | F                                        | \x
 Sensor|1       |     49 | 2023-10-18 10:11:19.371335+02 |           34 | F                                        | \x
 Sensor|1       |     50 | 2023-10-18 10:12:19.493649+02 |           34 | F                                        | \x
 Sensor|1       |     51 | 2023-10-18 10:13:19.61885+02  |           34 | F                                        | \x
 Sensor|1       |     52 | 2023-10-18 10:14:19.745095+02 |           34 | F                                        | \x
 Sensor|1       |     53 | 2023-10-18 10:14:51.814505+02 |            2 | iot.temperature.proto.TemperatureRead    | \x0803
 Sensor|1       |     54 | 2023-10-18 10:15:13.865504+02 |            2 | iot.temperature.proto.TemperatureRead    | \x0804
 Sensor|1       |     55 | 2023-10-18 10:22:54.964036+02 |           34 | F                                        | \x
 Sensor|1       |     56 | 2023-10-18 10:23:56.061048+02 |           34 | F                                        | \x
 Sensor|1       |     57 | 2023-10-18 10:24:56.187304+02 |           34 | F                                        | \x
 Sensor|1       |     58 | 2023-10-18 10:25:56.319631+02 |           34 | F                                        | \x
huntc commented 1 year ago

Can you confirm the network IO and log messages also?

huntc commented 1 year ago

Still investigating, but in terms of the frequency at least, connections are being reset by the JVM side once per minute... This is exacerbating the issue, but separately, we may want to re-consider why the JVM resets the connection every minute. Resetting will increase network IO and possible bandwidth costs, particularly over expensive LTE connections.

For evidence, using Wireshark, it looks as though the JVM side is resetting the connection:

image

This is occurring once per minute per wireshark:

image
patriknw commented 1 year ago

The filtered events are emitted once per minute, not once per second as I said. Seems likely that they are related to the idle connection reset.