Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Fix: thread-safety and dynamic memory for MessageOutput #567

Merged
merged 1 commit into from
Dec 30, 2023
Merged

Fix: thread-safety and dynamic memory for MessageOutput #567

merged 1 commit into from
Dec 30, 2023

Conversation

schlimmchen
Copy link
Member

this commit re-introduces the changes from #418, which were effectively reverted with d494810 (merge commit introducing TaskScheduler).

these adjustments are important to guarantee unmangled log messages and more importantly, to guarantee that all messages from a particular component are printed to the web console, which most people use to copy messages from when reporting issues.

  • use dynamic memory to allow handling of arbitrary message lenghts.
  • keep a message buffer for every task so no task ever mangles the message of another task.
  • every complete line is written to the serial console and moved to a line buffer for sending them through the websocket.
  • the websocket is always fed complete lines.
  • make sure to feed only as many lines as possible to the websocket handler, so that no lines are dropped.
  • lock all MessageOutput state against concurrent access.
  • respect HardwareSerial buffer size: the MessageOutput class buffers whole lines of output printed by any task in order to avoid mangling of text. that means we hand over full lines to the HardwareSerial instance, which might be too much in one call to write(buffer, size). we now check the return value of write(buffer, size) and call the function again with the part of the message that could not yet be written by HardwareSerial.

Web console output before this change (interleaved lines of logs and very limited buffer which drops a lot of information):

12:10:23.606 > Fetch inverter: 116183125666
12:10:23.606 > JK BMS Dummy Serial: write(20 Bytes)
12:10:23.606 > [ 833813.815] JK BMS: request for data sent
12:10:23.709 > TX RealTimeRunData Channel: 61 --> 15 83 12 56 66 80 16 72 56 80 0B 00 65 8E A9 1F 00 00 00 00 00 00 00 00 F1 EA CB 
12:10:23.709 > [ 833813.863] JK BMS: a whole frame was received
12:10:23.709 > [ 833813.864] JK BMS: raw data (291 Bytes):
12:10:23.709 > [ 833813.864] JK BMS: 4e 57 01 21 00 00 00 00 06 00 01 79 30 01 0c c0
12:10:23.709 > [ 833813.864] JK BMS: 02 0c c1 03 0c c0 04 0c c4 05 0c c4 06 0c c2 07
12:10:23.709 > [ 833813.864] JK BMS: 0c c2 08 0c c1 09 0c ba 0a 0c c1 0b 0c c2 0c 0c
12:10:23.709 > [ 833813.864] JK BMS: c2 0d 0c c2 0e 0c c4 0f 0c c2 10 0c c1 80 00 1b 81Interrupt received
12:10:23.724 > RX Channel: 40 --> 95 83 12 56 66 83 12 56 66 01 00 01 01 E6 00 6A 00 67 02 02 01 F6 00 04 24 8A 22 | -80 dBm
12:10:23.734 > Interrupt received

Web console output if this PR is applied:

17:09:03.210 > All missing
17:09:03.213 > Nothing received, resend whole request
17:09:03.215 > TX RealTimeRunData Channel: 61 --> 15 83 12 56 66 80 16 72 56 80 0B 00 65 8E EF 1D 00 00 00 00 00 00 00 00 5A 11 DF 
17:09:03.293 > JK BMS Dummy Serial: write(20 Bytes)
17:09:03.297 > [     20.007] JK BMS: request for data sent
17:09:03.536 > [     20.012] JK BMS: a whole frame was received
17:09:03.538 > [     20.013] JK BMS: raw data (291 Bytes):
17:09:03.545 > [     20.013] JK BMS: 4e 57 01 21 00 00 00 00 06 00 01 79 30 01 0c fb
17:09:03.548 > [     20.013] JK BMS: 02 0c fb 03 0c fb 04 0c fb 05 0c fb 06 0c fb 07
17:09:03.549 > [     20.013] JK BMS: 0c fb 08 0c f7 09 0d 01 0a 0c f9 0b 0c fb 0c 0c
17:09:03.552 > [     20.013] JK BMS: fb 0d 0c fb 0e 0c f8 0f 0c f9 10 0c fb 80 00 1a
17:09:03.555 > [     20.013] JK BMS: 81 00 12 82 00 12 83 14 c3 84 83 f4 85 2e 86 02
17:09:03.556 > [     20.013] JK BMS: 87 00 15 89 00 00 13 52 8a 00 10 8b 00 00 8c 00
17:09:03.558 > [     20.013] JK BMS: 03 8e 16 80 8f 12 c0 90 0e 10 91 0c da 92 00 05
17:09:03.563 > [     20.013] JK BMS: 93 0b b8 94 0c 80 95 00 05 96 01 2c 97 00 28 98
17:09:03.567 > [     20.013] JK BMS: 01 2c 99 00 28 9a 00 1e 9b 0b b8 9c 00 0a 9d 01
17:09:03.570 > [     20.013] JK BMS: 9e 00 64 9f 00 50 a0 00 64 a1 00 64 a2 00 14 a3
17:09:03.571 > [     20.013] JK BMS: 00 46 a4 00 46 a5 00 00 a6 00 02 a7 ff ec a8 ff
17:09:03.572 > [     20.013] JK BMS: f6 a9 10 aa 00 00 00 e6 ab 01 ac 01 ad 04 4d ae
17:09:03.577 > [     20.013] JK BMS: 01 af 00 b0 00 0a b1 14 b2 32 32 31 31 38 37 00
17:09:03.580 > [     20.013] JK BMS: 00 00 00 b3 00 b4 62 65 6b 69 00 00 00 00 b5 32
17:09:03.581 > [     20.013] JK BMS: 33 30 36 b6 00 01 4a c3 b7 31 31 2e 58 57 5f 53
17:09:03.582 > [     20.013] JK BMS: 31 31 2e 32 36 32 48 5f b8 00 b9 00 00 00 e6 ba
17:09:03.583 > [     20.013] JK BMS: 62 65 6b 69 00 00 00 00 00 00 00 00 4a 4b 5f 42
17:09:03.586 > [     20.013] JK BMS: 31 41 32 34 53 31 35 50 c0 01 00 00 00 00 68 00
17:09:03.589 > [     20.013] JK BMS: 00 53 bb
17:09:03.592 > [     20.129] JK BMS: ProtocolVersion: 1
17:09:03.593 > [     20.129] JK BMS: ProductId: beki        JK_B1A24S15P
17:09:03.596 > [     20.129] JK BMS: ActualBatteryCapacityAmpHours: 230Ah
17:09:03.602 > [     20.129] JK BMS: CurrentCalibration: no
17:09:03.604 > [     20.129] JK BMS: BmsSoftwareVersion: 11.XW_S11.262H_
17:09:03.605 > [     20.128] JK BMS: BmsHourMeterMinutes: 84675min
17:09:03.606 > [     20.128] JK BMS: DateOfManufacturing: 2306
17:09:03.607 > [     20.128] JK BMS: EquipmentId: beki
17:09:03.607 > [     20.128] JK BMS: DedicatedChargerSwitch: no
17:09:03.608 > [     20.128] JK BMS: ModificationPassword: 221187
17:09:03.610 > [     20.128] JK BMS: LowCapacityAlarmThresholdPercent: 20%
17:09:03.634 > [     20.128] JK BMS: SleepWaitTime: 10s
17:09:03.638 > [     20.128] JK BMS: BatteryType: 0
17:09:03.641 > [     20.128] JK BMS: BmsAddress: 1
17:09:03.645 > [     20.128] JK BMS: CurrentCalibrationMilliAmps: 1101mA
17:09:03.648 > [     20.128] JK BMS: BatteryDischargeEnabled: yes
17:09:03.651 > [     20.128] JK BMS: BatteryChargeEnabled: yes
17:09:03.653 > [     20.127] JK BMS: BatteryCapacitySettingAmpHours: 230Ah
17:09:03.654 > [     20.127] JK BMS: CellAmountSetting: 16
17:09:03.656 > [     20.127] JK BMS: DischargeLowTempRecoveryCelsius: -10°C
17:09:03.662 > [     20.127] JK BMS: DischargeLowTempThresholdCelsius: -20°C
17:09:03.665 > [     20.127] JK BMS: ChargeLowTempRecoveryCelsius: 2°C
17:09:03.666 > [     20.127] JK BMS: ChargeLowTempThresholdCelsius: 0°C
17:09:03.669 > [     20.125] JK BMS: CellOvervoltageThresholdMilliVolt: 3600mV
17:09:03.669 > [     20.125] JK BMS: TotalUndervoltageThresholdMilliVolt: 48000mV
17:09:03.672 > [     20.125] JK BMS: TotalOvervoltageThresholdMilliVolt: 57600mV
17:09:03.673 > [     20.125] JK BMS: StatusBitmask: 3
17:09:03.676 > [     20.125] JK BMS: AlarmsBitmask: 0
17:09:03.681 > [     20.124] JK BMS: BatteryCycleCapacity: 4946Ah
17:09:03.681 > [     20.124] JK BMS: BatteryCycles: 21
17:09:03.685 > [     20.124] JK BMS: BatteryTemperatureSensorAmount: 2
17:09:03.686 > [     20.124] JK BMS: BatterySoCPercent: 46%
17:09:03.688 > [     20.124] JK BMS: BmsTempCelsius: 26°C
17:09:03.689 > [     20.124] JK BMS: BatteryCellAmount: 16
17:09:03.691 > [     20.123] JK BMS: CellsMilliVolt: (1=3323, 2=3323, 3=3323, 4=3323, 5=3323, 6=3323, 7=3323, 8=3319, 9=3329, 10=3321, 11=3323, 12=3323, 13=3323, 14=3320, 15=3321, 16=3323)mV
17:09:03.694 > [     20.126] JK BMS: BmsTempProtectionThresholdCelsius: 100°C
17:09:03.698 > [     20.124] JK BMS: BatteryTempOneCelsius: 18°C
17:09:03.701 > [     20.124] JK BMS: BatteryTempTwoCelsius: 18°C
17:09:03.704 > [     20.124] JK BMS: BatteryVoltageMilliVolt: 53150mV
17:09:03.704 > [     20.124] JK BMS: BatteryCurrentMilliAmps: 10120mA
17:09:03.707 > [     20.125] JK BMS: CellOvervoltageRecoveryMilliVolt: 3290mV
17:09:03.709 > [     20.125] JK BMS: CellOvervoltageProtectionDelaySeconds: 5s
17:09:03.713 > [     20.125] JK BMS: CellUndervoltageThresholdMilliVolt: 3000mV
17:09:03.716 > [     20.125] JK BMS: CellUndervoltageRecoveryMilliVolt: 3200mV
17:09:03.717 > [     20.125] JK BMS: CellUndervoltageProtectionDelaySeconds: 5s
17:09:03.719 > [     20.125] JK BMS: CellVoltageDiffThresholdMilliVolt: 300mV
17:09:03.735 > [     20.126] JK BMS: DischargeOvercurrentThresholdAmperes: 40A
17:09:03.739 > [     20.126] JK BMS: DischargeOvercurrentDelaySeconds: 300s
17:09:03.742 > [     20.126] JK BMS: ChargeOvercurrentThresholdAmps: 40A
17:09:03.747 > [     20.126] JK BMS: ChargeOvercurrentDelaySeconds: 30s
17:09:03.751 > [     20.126] JK BMS: BalanceCellVoltageThresholdMilliVolt: 3000mV
17:09:03.751 > [     20.126] JK BMS: BalanceVoltageDiffThresholdMilliVolt: 10mV
17:09:03.752 > [     20.126] JK BMS: BalancingEnabled: yes
17:09:03.755 > [     20.126] JK BMS: BmsTempRecoveryThresholdCelsius: 80°C
17:09:03.758 > [     20.126] JK BMS: BatteryTempProtectionThresholdCelsius: 100°C
17:09:03.761 > [     20.127] JK BMS: BatteryTempRecoveryThresholdCelsius: 100°C
17:09:03.765 > [     20.127] JK BMS: BatteryTempDiffThresholdCelsius: 20°C
17:09:03.768 > [     20.127] JK BMS: ChargeHighTempThresholdCelsius: 70°C
17:09:03.768 > [     20.127] JK BMS: DischargeHighTempThresholdCelsius: 70°C
17:09:03.771 > [     20.251] JK BMS: waiting for poll interval to elapse
17:09:03.771 > RX Period End
17:09:03.774 > All missing

@schlimmchen
Fix: thread-safety and dynamic memory for MessageOutput
7d58c35 
this commit re-introduces the changes from hoylabs#418, which were effectively
reverted with d494810 (merge commit introducing TaskScheduler).

these adjustments are important to guarantee unmangled log messages and
more importantly, to guarantee that all messages from a particular
component are printed to the web console, which most people use to copy
messages from when reporting issues.

* use dynamic memory to allow handling of arbitrary message lenghts.
* keep a message buffer for every task so no task ever mangles the
  message of another task.
* every complete line is written to the serial console and moved to
  a line buffer for sending them through the websocket.
* the websocket is always fed complete lines.
* make sure to feed only as many lines as possible to the websocket
  handler, so that no lines are dropped.
* lock all MessageOutput state against concurrent access.
* respect HardwareSerial buffer size: the MessageOutput class buffers
  whole lines of output printed by any task in order to avoid mangling
  of text. that means we hand over full lines to the HardwareSerial
  instance, which might be too much in one call to write(buffer, size).
  we now check the return value of write(buffer, size) and call the
  function again with the part of the message that could not yet be
  written by HardwareSerial.
@schlimmchen schlimmchen mentioned this pull request Dec 29, 2023
Closed
@helgeerbe helgeerbe merged commit c7098b6 into hoylabs:development Dec 30, 2023
8 checks passed
@schlimmchen schlimmchen deleted the message-output-improvements branch December 30, 2023 15:50
@github-actions GitHub Actions
Copy link

github-actions bot commented Apr 4, 2024

This pull request has been automatically locked since there has not been any recent activity after it was closed. Please open a new discussion or issue for related concerns.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Apr 4, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Reviewers
No reviews
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
2 participants
@schlimmchen @helgeerbe