search

greghesp / ha-bambulab

A Home Assistant Integration for Bambu Lab Printers
698 stars 59 forks source link

[Bug] P1P usage hours are being incorrectly (double?) counted some of the time #467

Closed AdrianGarside closed 4 months ago

AdrianGarside commented 4 months ago

Describe the bug

Not sure what the repro case is yet but I'm seeing the integration appearing to double count some print hours. But it's not consistently doing so. The X1 usage hours appear to be relatively reliably tracked with only minor drift so likely still something related to the way we have to simulate start times on the P1 devices since it doesn't provide them in the mqtt payload.

To Reproduce

.

Expected Behaviour

.

What device are you using?

P1P

Diagnostic Output

.

Log Extracts

No response

Other Information

No response

AdrianGarside commented 4 months ago

One of the incorrect jumps was a 24 hour jump and I think that was probably due to a print I started and then immediately cancelled.

AdrianGarside commented 4 months ago

Yes, I think that 24 hour was an immediately cancelled print as there's nothing in my print history other than the prints either side of that 24 hour jump.

AdrianGarside commented 4 months ago

Looks like maybe a slight difference between the cloud provide times and the local times:

2024-02-19 00:07:32.427 GCODE_STATE: IDLE -> PREPARE 2024-02-19 00:07:32.427 GCODE_STATE: IDLE -> PREPARE 2024-02-19 00:07:32.427 GENERATED START TIME: P1P 2024-02-19 00:07:00 2024-02-19 00:07:32.843 CLOUD PRINT STATUS: 4 2024-02-19 00:07:32.843 CLOUD START TIME1: P1P 2024-02-19 00:07:00 2024-02-19 00:07:32.845 CLOUD START TIME2: P1P 2024-02-19 00:07:25 2024-02-19 00:07:32.849 CLOUD END TIME1: P1P None 2024-02-19 00:07:32.849 CLOUD END TIME2: P1P 2024-02-19 00:07:29 2024-02-19 00:07:39.957 GCODE_STATE: PREPARE -> RUNNING 2024-02-19 00:07:39.957 GCODE_STATE: PREPARE -> RUNNING 2024-02-19 00:07:50.829 GCODE_STATE: RUNNING -> FAILED 2024-02-19 00:07:50.829 GCODE_STATE: RUNNING -> FAILED 2024-02-19 00:07:50.829 NEW USAGE HOURS: P1P 23.99

The last start time we had was 2024-02-19 00:07:25 and then we subtract it from a rounded current time: duration = get_end_time(0) - self.start_time w/ get_end_time doing: def get_end_time(remaining_time): end_time = round_minute(datetime.now() + timedelta(minutes=remaining_time))

So the rounded end time can end up a few seconds before the current time which leads to -1 days (which seems to be a bug in Python):

end - start datetime.timedelta(days=-1, seconds=86397, microseconds=752664) And that generates an incorrect almost 24 hours of usage: new_hours = round((duration.seconds / 60 / 60) * 100) / 100

Changing code to: duration = datetime.now() - self.start_time instead of: duration = get_end_time(0) - self.start_time

Is probably sufficient to fix the bug but there might still be an issue if the start_time we got from the cloud servers is slightly in the past as far as the local time is concerned. Not sure if that's actually possible though.