OTP crash while changing menu 6-11 or 6-12 #89

tonyc · 2022-07-03T14:36:34Z

The low/high bandscope edge frequencies seem to be missing. Where'd they go?

Tyrbiter · 2022-07-03T15:32:03Z

I see them in hi/lo-cut mode, the display switches when I change it in menu 6-11 in either direction.

And the bandscope edges are showing for me too ;-)

I'm using Firefox 102.

tonyc · 2022-07-03T17:59:39Z

I'm not sure what caused me to see this, but I'm actually getting them now that I've changed branches locally a couple times. On the radar, at least.

tonyc · 2022-07-04T15:16:25Z

There seems to be a crash+restart when switching from CW to SSB, and then adjusting menu 6-11 from High & Low Cut to Shift & Width:

[info] TIMER: Update cloudlog
[info] Pinging cloudlog: 14314730, :cw
[info] [DN] "OM02"
[info] [DN] "RL104"
[debug] Dispatch: unknown message: "RL104"
[info] [DN] "SH0022"
[info] [DN] "SH1022"
[debug] Dispatch: unknown message: "SH1022"
[info] [DN] "SL003"
[info] [DN] "SL103"
[debug] Dispatch: unknown message: "SL103"
[info] [DN] "TF12"
[debug] Dispatch: unknown message: "TF12"
[info] [DN] "TF24"
[debug] Dispatch: unknown message: "TF24"
[info] [DN] "BSA1"
[info] [DN] "EQT00"
[debug] Dispatch: unknown message: "EQT00"
[info] [DN] "EQT15"
[debug] Dispatch: unknown message: "EQT15"
[info] [DN] "FB00014314030"
[info] [DN] "FL1000270"
[info] [DN] "FL210"
[debug] Dispatch: unknown message: "FL210"
[info] [DN] "FL222"
[debug] Dispatch: unknown message: "FL222"
[info] [DN] "FL310"
[debug] Dispatch: unknown message: "FL310"
[info] [DN] "FL322"
[debug] Dispatch: unknown message: "FL322"
[info] [DN] "GT161105"
[debug] Dispatch: unknown message: "GT161105"
[debug] Cloudlog response: %{"status" => "success"}
[info] TIMER: Update cloudlog
[info] Pinging cloudlog: 14314030, :usb
[debug] Cloudlog response: %{"status" => "success"}
[info] [DN] "SH0029"
[error] GenServer {:radio_connection_registry, {:tcp, "903e7dd4-38b7-4466-b48a-6b95b144ae44"}} terminating
** (ArgumentError) argument error
    :erlang.element(30, {600, 700, 800, 900, 1000, 1100, 1200, 1300, 1400, 1500, 1600, 1700, 1800, 1900, 2000, 2100, 2200, 2300, 2400, 2500, 2600, 2700, 2800, 2900, 3000, 3400, 4000, 5000})
    (open890 0.1.0) lib/open890/extract.ex:546: Open890.Extract.get_ssb_hi_cut/1
    (open890 0.1.0) lib/open890/radio_state.ex:573: Open890.RadioState.dispatch/2
    (open890 0.1.0) lib/open890/tcp_client.ex:307: Open890.TCPClient.handle_msg/2
    (elixir 1.12.3) lib/enum.ex:2385: Enum."-reduce/3-lists^foldl/2-0-"/3
    (open890 0.1.0) lib/open890/tcp_client.ex:76: Open890.TCPClient.handle_info/2
    (stdlib 3.14.2.2) gen_server.erl:689: :gen_server.try_dispatch/4
    (stdlib 3.14.2.2) gen_server.erl:765: :gen_server.handle_msg/6
    (stdlib 3.14.2.2) proc_lib.erl:226: :proc_lib.init_p_do_apply/3
Last message: {:tcp, #Port<0.27>, "SH0029;SH1029;"}
State: %{connection: #Open890.RadioConnection<auto_start: "true", cloudlog_api_key: "REDACTED", cloudlog_enabled: "true", cloudlog_url: "REDACTED", id: "903e7dd4-38b7-4466-b48a-6b95b144ae44", ip_address: "REDACTED", name: "TS-890", tcp_port: "60000", type: :tcp, user_is_admin: "false", user_name: "REDACTED", ...>, kns_user: %Open890.KNS.User{is_admin: "false", password: "REDACTED!", username: "REDACTED"}, radio_state: %Open890.RadioState{vd_meter: 0, active_mode: :usb, id_meter: 0, filter_state: %Open890.FilterState{hi_passband_id: 22, hi_shift: 2800, lo_passband_id: 3, lo_width: 200}, active_frequency: 14314030, ssb_filter_mode: :hi_lo_cut, band_scope_mode: :auto_scroll, ssb_data_filter_mode: :shift_width, fine: false, roofing_filter_data: %{a: 2700, b: 2700, c: 2700}, active_receiver: :b, squelch: 10, vfo_a_frequency: 3913000, band_scope_span: 50, audio_gain: 0, band_scope_avg: 1, mic_gain: 53, voip_available: true, alc_meter: 0, split_enabled: false, temp_meter: 0, cw_delay: 0, rf_att: 0, noise_blank_state: %Open890.NoiseBlankState{nb_1_enabled: false, nb_2_enabled: false}, projected_active_receiver_location: "", filter_high_freq: 14317530, cw_key_speed: 18, active_if_filter: :a, power_level: 50, inactive_frequency: 3913000, band_scope_fixed_span: nil, data_speed: 1, rit_xit_offset: 0, agc: :med, ref_level: 49, band_scope_edges: {14290000, 14340000}, notch_state: %Open890.NotchState{enabled: false, frequency: 72, width: :narrow}, nr: :off, apf_enabled: false, tx_state: :off, active_frequency_delta: -700, inactive_mode: :lsb, xit_enabled: false, swr_meter: 0, comp_meter: 0, s_meter: 11, vfo_memory_state: :vfo, ...}, socket: #Port<0.27>}
[info] Established TCP socket with radio on port 60000
[info] [UP] "##CN;"
[debug] Bandscope LV: RX connection_state: :up
[info] [UP] "##ID[REDACTED];"
[info] signed in, scheduling first ping
[info] [DN] "##TI1"
[debug] Dispatch: unknown message: "##TI1"
[info] Enabling audio scope via LAN
[info] [UP] "DD11;"
[info] Enabling LAN bandscope
[info] [UP] "DD01;"
[info] [UP] "AI2;"
[info] [UP] "FR;"
[info] [UP] "FR;"
[info] [UP] "FA;"
[info] [UP] "FB;"
[info] [UP] "BU0;"
[info] [UP] "BU1;"
[info] [UP] "SM;"
[info] [UP] "EX00611;"
[info] [UP] "EX00612;"
[info] [UP] "OM0;"
[info] [UP] "OM1;"
[info] [UP] "SH0;"
[info] [UP] "SL0;"
[info] [UP] "FS;"
[info] [UP] "FL0;"
[info] [UP] "FL10;"
[info] [UP] "FL11;"
[info] [UP] "FL12;"
[info] [UP] "BSO;"
[info] [UP] "BS3;"
[info] [UP] "BS4;"
[info] [UP] "BSM0;"
[info] [UP] "BSA;"
[info] [UP] "BS8;"
[info] [UP] "DS1;"
[info] [UP] "PA;"
[info] [UP] "RA;"
[info] [UP] "BSC;"
[info] [UP] "MV;"
[info] [UP] "RM11;"
[info] [UP] "RM21;"
[info] [UP] "DD0;"
[info] [UP] "AG;"
[info] [UP] "RG;"
[info] [UP] "PC;"
[info] [UP] "NT;"
[info] [UP] "NW;"
[info] [UP] "BP;"
[info] [UP] "XV;"
[info] [UP] "XO;"
[info] [UP] "AN;"
[info] [UP] "KS;"
[info] [UP] "SD;"
[info] [UP] "GC;"
[info] [UP] "MG;"
[info] [UP] "NR;"
[info] [UP] "BC;"
[info] [UP] "NB1;"
[info] [UP] "NB2;"
[info] [UP] "SQ;"
[info] [UP] "TB;"
[info] [UP] "AP0;"
[info] [UP] "##KN2;"
[info] [UP] "##VP;"
[info] [UP] "RT;"
[info] [UP] "XT;"
[info] [UP] "RF;"
[info] [DN] "SL031"
[warn] Unknown passband_id 31 for mode: unknown (filter_mode: unknown)
[info] [DN] "##KN21"
[info] [DN] "##VP0"
[info] [DN] "SL131"
[debug] Dispatch: unknown message: "SL131"
[info] [DN] "FR1"
[info] [DN] "FR1"
[info] [DN] "FA00003913000"
[info] [DN] "FB00014314030"
[info] [DN] "BU02"
[info] [DN] "BU12"
[info] [DN] "EX00611 001"
[info] [DN] "EX00612 001"
[info] [DN] "OM02"
[info] [DN] "OM11"
[info] [DN] "SH0029"
[info] [DN] "SL031"
[info] JOINED radio:audio_stream in 32µs

Tyrbiter · 2022-07-04T15:21:03Z

I don't have Cloudlog, which may or may not be relevant.

If you don't find the cause then I can repeat your test sequence if you like and see what happens.

I have noticed some glitchiness when selecting Radio from the connections page, it often seems to hang and then either retries or times out followed by the radio page opening as expected. Not sure if this could be related.

tonyc · 2022-07-04T15:37:47Z

I think the band scope edges are actually working fine, but I encountered this while testing it out. So the title of this ticket might actually change.

The crash isn't related to cloudlog in any way -- it seems like the code is trying to figure out which passband "ID" to use, and something is getting mucked up since it doesn't know the filter mode. Once the mode has changed in the menu, then it all recovers and is fine, so I wonder if the radio is sending the passband ID before the filter mode change.

Tyrbiter · 2022-07-04T15:41:58Z

OK, I saw the Cloudlog debug outputs, wondered if it might affect things.

I'm going to defer to your knowledge, I just don't have enough understanding of how the various parameters are sent across and interpreted. But please shout if extra testing is needed and I can rebuild and try things pretty rapidly.

tonyc · 2022-07-04T17:12:23Z

The cause of the problem is really annoying: the radio sends the filter info (hi/shift, low/width) BEFORE sending the message that the menu item changed, so open890 doesn't yet realize that menu 6-11 (6-12) changed. The code uses indexed lookup tables based on the command reference, so I'll need to attempt to detect this.

References #91

Tyrbiter · 2022-07-04T18:38:16Z

I suppose the only way to deal with this is to keep the state of things that can do this so that you compare the will-change-to values it sends to the was-set-to values you already have.

But then I'm no programmer and I don't know much about web-based event-driven programming.

tonyc · 2022-07-15T14:36:03Z

Encountered another one today while working on UI stuff. Mostly just leaving here for my own records:

[error] GenServer {:radio_connection_registry, {:tcp, "903e7dd4-38b7-4466-b48a-6b95b144ae44"}} terminating
** (ArithmeticError) bad argument in arithmetic expression
    :erlang.-(14101670, nil)
    (open890 0.1.0) lib/open890_web/radio_view_helpers.ex:155: Open890Web.RadioViewHelpers.offset_frequency_reverse/3
    (open890 0.1.0) lib/open890/radio_state.ex:661: Open890.RadioState.update_filter_lo_edge/1
    (open890 0.1.0) lib/open890/tcp_client.ex:307: Open890.TCPClient.handle_msg/2
    (elixir 1.12.3) lib/enum.ex:2385: Enum."-reduce/3-lists^foldl/2-0-"/3
    (open890 0.1.0) lib/open890/tcp_client.ex:76: Open890.TCPClient.handle_info/2
    (stdlib 3.14.2.2) gen_server.erl:689: :gen_server.try_dispatch/4
    (stdlib 3.14.2.2) gen_server.erl:765: :gen_server.handle_msg/6
    (stdlib 3.14.2.2) proc_lib.erl:226: :proc_lib.init_p_do_apply/3
Last message: {:tcp, #Port<0.28>, "SL025;"}

Tyrbiter · 2022-07-15T18:36:55Z

I looked at the command reference, seems like they've made it easy to go beyond the effective filter cutoff frequency array bounds, which change with mode. It's not a clean interface.

tonyc · 2024-07-02T19:03:32Z

The problem here is that when the menu item changes (EX00611 001), the radio sends filter info down first, but not the reply that the menu item actually changed.

The solution may be to just "believe" that the menu item actually changed when sending the command, rather than when receiving the response from the radio.

Tyrbiter · 2024-07-02T23:12:55Z

Presumably it doesn't send the filter info unless the menu item has changed, so you can interpret the filter info as the confirmation of the change.

Only a problem if the same thing can happen in other situations, which I don't know.

tonyc · 2024-07-02T23:20:03Z

The problem is that you have to know what the menu setting is to properly interpret the "lo/width" and "hi/shift" messages.

So, here's what happens when sending the command to change the menu:

[up] change the menu item
[down] here's the low/width
[down] here's the high/shift
[down] ok, the menu item changed

What should happen:

[up] change the menu item
[down] ok, the menu item changed
[down] here's the low/width
[down] here's the high/shift

Anyway, I think I can get around it by just assuming the menu item changed when sending the command to change it, and then I'll know which filter mode the radio will be in, which then should cause the filter display to not crash :)

tonyc added the bug Something isn't working label Jul 3, 2022

tonyc added this to the 0.8 milestone Jul 3, 2022

tonyc self-assigned this Jul 3, 2022

tonyc changed the title ~~Band edge frequencies are missing~~ OTP crash while changing menu 6-11 or 6-12 Jul 4, 2022

tonyc modified the milestones: 0.8, 0.9 Jul 30, 2022

tonyc removed this from the 0.9 milestone Nov 5, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

OTP crash while changing menu 6-11 or 6-12 #89

OTP crash while changing menu 6-11 or 6-12 #89

tonyc commented Jul 3, 2022

Tyrbiter commented Jul 3, 2022 •

edited

Loading

tonyc commented Jul 3, 2022 •

edited

Loading

tonyc commented Jul 4, 2022 •

edited

Loading

Tyrbiter commented Jul 4, 2022 •

edited

Loading

tonyc commented Jul 4, 2022 •

edited

Loading

Tyrbiter commented Jul 4, 2022

tonyc commented Jul 4, 2022

Tyrbiter commented Jul 4, 2022

tonyc commented Jul 15, 2022

Tyrbiter commented Jul 15, 2022

tonyc commented Jul 2, 2024

Tyrbiter commented Jul 2, 2024

tonyc commented Jul 2, 2024

OTP crash while changing menu 6-11 or 6-12 #89

OTP crash while changing menu 6-11 or 6-12 #89

Comments

tonyc commented Jul 3, 2022

Tyrbiter commented Jul 3, 2022 • edited Loading

tonyc commented Jul 3, 2022 • edited Loading

tonyc commented Jul 4, 2022 • edited Loading

Tyrbiter commented Jul 4, 2022 • edited Loading

tonyc commented Jul 4, 2022 • edited Loading

Tyrbiter commented Jul 4, 2022

tonyc commented Jul 4, 2022

Tyrbiter commented Jul 4, 2022

tonyc commented Jul 15, 2022

Tyrbiter commented Jul 15, 2022

tonyc commented Jul 2, 2024

Tyrbiter commented Jul 2, 2024

tonyc commented Jul 2, 2024

Tyrbiter commented Jul 3, 2022 •

edited

Loading

tonyc commented Jul 3, 2022 •

edited

Loading

tonyc commented Jul 4, 2022 •

edited

Loading

Tyrbiter commented Jul 4, 2022 •

edited

Loading

tonyc commented Jul 4, 2022 •

edited

Loading