'ETA' is always 'now' - Githubissues

tedder commented 5 years ago

Let me know what info you need to reproduce, but here are some examples.

sent at 12:02:

[12:02 AM] :heavy_minus_sign: Print progress 45% :horse_racing: File Stand_wMotorMount_0.2mm_PLA_MK3MMU2.gcode (18.6MB via OctoPrint) Elapsed 05:11:39 Remaining 05:30:25 ETA 00:02 today

sent at 12:33:

[12:02 AM] :heavy_minus_sign: Print progress 50% :horse_racing: File Stand_wMotorMount_0.2mm_PLA_MK3MMU2.gcode (18.6MB via OctoPrint) Elapsed 05:42:54 Remaining 05:00:27 ETA 00:33 today

fraschetti commented 5 years ago

Hi @tedder

Can you confirm the time zone the machine running Octoprint is configured to use as well as the time zone (if any) you've configured for Octoslack to use (via Octoslack's ETA timestamp time zone setting)? It'd be helpful to see the progress output as well the output of timedatectl (assuming you're on linux) for that same time period.

tedder commented 5 years ago

Hi there. Octoprint is from the Octopi distro, running on a pi3. The Pi is running on UTC:

$ timedatectl
      Local time: Wed 2019-01-09 16:09:36 UTC
  Universal time: Wed 2019-01-09 16:09:36 UTC
        RTC time: n/a
       Time zone: Etc/UTC (UTC, +0000)
 Network time on: yes
NTP synchronized: yes
 RTC in local TZ: no

Octoslack is set to America/Los_Angeles, "ETA date/time format" is "HH:mm ".

You said you want to see the 'progress output', not sure what you mean. I pasted some of the Slack progress messages above. Do you just want me to show you how those match to reality? If so, here's a message from 10 minutes ago:

:heavy_minus_sign: Print progress 15% :horse_racing: File 2x-hevo-base-spacer-v1_0.2mm_MK3MMU2.gcode (2.4MB via OctoPrint) Elapsed 01:06:54 Remaining 04:09:31 ETA 08:03 today

It's currently 1613 UTC, 0813 in the America/Los_Angeles time zone. (obviously that was posted at 1603 UTC). So the ETA is the current time of the correct time zone, not [current time] + [remaining].

In reality I have two pis for two printers, they both give the same behavior.

tedder commented 5 years ago

Reading through the code now. I'm using this in addition to PrintTimeGenius, I wonder if it is setting the estimated time to zero. I'll look at the data being returned in the API.

tedder commented 5 years ago

Here's the 'job' and 'progress' data from the API:

  "job": {
    "averagePrintTime": null,
    "estimatedPrintTime": 19190.361678324804,
    "filament": {
      "tool0": {
        "length": 24028.141858068713,
        "volume": 169.84493109299032
      }
    },
....
  "progress": {
    "completion": 21.851433145071,
    "filepos": 561310,
    "printTime": 5268,
    "printTimeLeft": 13721,
    "printTimeLeftOrigin": "genius"
  },
  "state": "Printing"

tedder commented 5 years ago

found it. For cases where the TZ is specified, you are grabbing 'now' and converting the TZ. You never add on the estimated print time.

fraschetti commented 5 years ago

Thanks for hunting this down @tedder

fraschetti / Octoslack

'ETA' is always 'now' #41