[BUG] Filament Usage for Octoprint broken in multiple areas of code

[puterboy]

The current code in octoprint_messages.py as well as seemingly normalizers.js fails to retrieve either the live or predicted filament usage when using Octoprint.

The result is that filament usage is NEVER CALCULATED (and hence never available for display) when using Octoprint, regardless of whether you are using the Obico Cloud Server or a private server.

Given that the "average" user is probably more likely to use Octoprint than Moonraker and that filament usage is a basic displayed feature of both the web and mobile apps, it seems like this is a critical bug that should be prioritized and fixed.

The basic problem is that the Obico code assumes that filament usage shows up under the progress data structure/api under the label filamentUsed which seems to be true for Moonraker but not for Octoprint.

For example, the code in octoprint_messages.py says:
filament_used = printer_status.get('progress', {}).get('filamentUsed')

Rather, as clearly documented in https://docs.octoprint.org/en/master/api/job.html#retrieve-information-about-the-current-job, the API for Octoprint uses the following data structure with filament usage listed by tool# under the job structure.

  "job": {
    "file": {
      "name": "whistle_v2.gcode",
      "origin": "local",
      "size": 1468987,
      "date": 1378847754
    },
    "estimatedPrintTime": 8811,
    "filament": {
      "tool0": {
        "length": 810,
        "volume": 5.36
      }
    }
  },
  "progress": {
    "completion": 0.2298468264184775,
    "filepos": 337942,
    "printTime": 276,
    "printTimeLeft": 912
  },
  "state": "Printing"
}

I was able to fix this problem by adding the following several lines just after the above quoted line that works for Moonraker. The added code sums the filament usage listed by tool under 'job'

+++ ./api/octoprint_messages.py   2023-09-11 20:04:35.431958890 -0400
@@ -138,6 +138,11 @@

         completion = printer_status.get('progress', {}).get('completion')
         filament_used = printer_status.get('progress', {}).get('filamentUsed')
+        if filament_used is None: #Try Octoprint
+            for key in printer_status.get('job', {}).get('filament'):
+                tool_used =  printer_status.get('job', {}).get('filament').get(key).get('length')
+                if tool_used is not None:
+                    filament_used = (filament_used or 0) + tool_used

         if filament_used is None and completion is not None and _print.g_code_file and _print.g_code_file.filament_total:
             if completion == 0 and print_time and _print.g_code_file.estimated_time: # Old moonraker-obico version sends completion: 0.0 when print ends. We estimate it using print time

See the following Pull request for more details #817

However, there are other issues in the octoprint_messages.py code.
Specifically, the fallback estimation code fails:

                completion = print_time / _print.g_code_file.estimated_time
            filament_used = _print.g_code_file.filament_total * completion / 100.0

It seems like filament_total is never calculated though it should be available and retrievable from the .metadata.json files stored in Octoprint under the .octoprint/uploads tree as well as from the current uploaded gcode itself. This may be due to issues with the corresponding code in normalizers.js where it seems like none of the methods succeed in returning the estimated filament total (but I'm not sure how this code is called so I can't be 100% certain).

Regardless, the above errors assuredly mean that filament usage is totally broken for Octoprint independent of whether you use Obico Cloud or your own private server.

The patch I suggested works fine for me and is quite simple so feel free to use it for now until a formal fix for all the above issues is implemented.

[puterboy]

If you are using the private server, you can also retrospectively add back historical estimated filament usage for both completed prints as well as prints that were canceled but have a recoverable print time, using the following perl code that I hacked together (use at your own risk).
This code attempts to recover/reconstruct the missing filament_used field as well as other missing, reconstructable print time fields present in the app_time table of the db.sqlite3 database found in obico_server/backend.

#============================================================= -*-perl-*-
#
# add_time_filament.pl
#
# DESCRIPTION
#   Fill-in missing db.sqlite3 print_time.app_print fields using,
#   where possible the following other fields:
#      1. finished_at - started_at (from app_print)
#      2. canceled_at - started_at (from app_print)
#      3. "filename".analysis.estimatedPrintTime (from Octoprint .metadata.json)
#          or "filename".analysis.analysisPrintTime (added by Print Time Genius if exists)     
#      4. Estimated print time encoded in gcode "filename" (from app_print)
#   Change print_times that differ significantly from estimatedPrintTime
#   to estimatedPrintTime
#
#   Fill-in missing db.sqlite3 filament_used.app_print fields using, 
#   where possible the .metadata.jso data stored in the ~/.octoprint/uploads
#   tree:
#      "filename".analysis.filament.<tool#>.length
#   If canceled, pro-rate by:
#      printTime/"filename".analysis.estimatedPrintTime
#
# USAGE
#     add_time_filament.pl.pl <db.sqlite3> <.metadata.json> [<.metadata.json> <.metadata.json> ...]
#
#  Specifically, to include the entire ~/.octoprint/uploads tree,
#     add_time_filament.pl.pl $(find ~/.octoprint/uploads/ -type f -name ".metadata.json")
#
# AUTHOR
#   Jeff Kosowsky
#
# COPYRIGHT
#   Copyright (C) 2023 Jeff Kosowsky
#
#========================================================================
#
# Version 0.3, released September 2023
#
#========================================================================

use strict;
use warnings;
use DBI;
use JSON;
use Data::Dumper;
use DateTime::Format::Strptime;

my $max_est_err_low = 0.25; #Smaller error when using: "filename".analysis.estimatedPrintTime
my $max_est_err_hi = 0.40; #Larger error when using print time estimate encoded in gcode filename

#Load .metadata.json files listed on the command line into the %jsonH hash
my $json = JSON->new;
my $json_text;
my %jsonH = ();

die <<EOF
Usage: 
    $0 <db.sqlite3> <.metadata.json> [<.metadata.json> <.metadata.json> ...]

Alternatively, to include all 'metadata.json' files, consider something like:
    $0 <db.sqlite3> \$(find ~/.octoprint/uploads/ -type f -name ".metadata.json")
    
EOF
    unless $#ARGV >0;

my $DB = $ARGV[0];
die "Error: sqlite3 database file '$DB' does not exist...\n"
    unless -e $DB;
shift @ARGV;
foreach(@ARGV) {
    open(FH, '<', $_)
	or die("Can't open metadata.json file\"$_\": $!\n");
    $json_text = do {
	local $/;
	<FH>;
    };
	close(FH);
    
    %jsonH = (%jsonH, %{$json->decode($json_text)});
}

#print Dumper %jsonH; exit; #JJKDEBUG
#foreach(keys %jsonH){ printf("%s\t%f\n", $_, $jsonH{$_}{analysis}{filament}{tool0}{length} || 0);}; exit; #JJKDEBUG

#Load in the obico-server database, db.sqlite3, into the $DbH hash
my $TABLE = "app_print";
my $dsn = "DBI:SQLite:dbname=$DB";
my $userid = "";
my $password = "";

my $dbh = DBI->connect($dsn, $userid, $password, { RaiseError => 1 })
    or die $DBI::errstr;
print STDERR "Database opened successfully\n";

my ($stmt, $sth, $res);
$stmt = qq(SELECT id, filename, cancelled_at, filament_used, print_time, started_at, finished_at FROM $TABLE);
$sth = $dbh->prepare($stmt);
$res = $sth->execute() or die $DBI::errstr;

my %DbH; #Hash of hashes to store values from obico-server database
while(my @row = $sth->fetchrow_array()) { #Add selected columns from each row of the database
    $DbH{$row[0]} = { #Key = id
	filename => $row[1],
	cancelled_at => $row[2],
	filament_used => $row[3],
	print_time => $row[4],
	started_at => $row[5],
	finished_at => $row[6],	
    };
}
#print Dumper %DbH; exit; #JJKDEBUG

my $dt_parser = DateTime::Format::Strptime->new(
    pattern => '%Y-%m-%d %H:%M:%S.%6N',
    on_error => 'croak',
    );
	       
my $time_cnt = 0;
my $filament_cnt = 0;
foreach (keys %DbH) {
    my $print_time = $DbH{$_}{print_time};
    my $print_time_orig = $print_time;

    my $max_est_err = $max_est_err_low;
    my $print_time_est = $jsonH{$DbH{$_}{filename}}{analysis}{analysisPrintTime} || #From "Print Time Genius" if exists
	$jsonH{$DbH{$_}{filename}}{analysis}{estimatedPrintTime};
    if(!defined($print_time_est)) { #Try to recover print_time_est from gcode file name
	$DbH{$_}{filename} =~ /.*_((\d*)d)?((\d*)h)?((\d*)m)?\.gcode$/;
	$print_time_est = ((( ($2||0) * 24 + ($4||0)) * 60) + ($6||0)) * 60;
	$print_time_est = undef if $print_time_est == 0;
#	printf("%s\t%f\n", $DbH{$_}{filename}, $print_time_est); #JJKDEBUG
	$max_est_err = $max_est_err_hi;	#Use larger error since this estimate is likely less accurate
    }

    #If missing print_time, Try to calculate from 'finished_at - started_at' or 'canceled_at - started_at'
    if(!defined($print_time) && defined($DbH{$_}{started_at}) &&
       (defined($DbH{$_}{finished_at}) || defined($DbH{$_}{canceled_at}))){
	my $dt_start = $dt_parser->parse_datetime($DbH{$_}{started_at});
	my $dt_end = $dt_parser->parse_datetime(defined($DbH{$_}{finished_at}) ? 
						$DbH{$_}{finished_at} : $DbH{$_}{canceled_at});
	$print_time = $dt_end->hires_epoch - $dt_start->hires_epoch;
#	printf("%s\t%s %s\t%s %s\t%f\n", $DbH{$_}{filename}, $dt_start->ymd, $dt_start->hms, $dt_end->ymd, $dt_end->hms, $print_time); #JJKDEBUG	
    }

    #Set to print_time_est if still not defined
    if(!defined($print_time) && defined($print_time_est)) {  
#	printf("%s\t%f\n", $DbH{$_}{filename}, $print_time_est); #JJKDEBUG	
	$print_time = $print_time_est;
       }
    
    #Replace print_time with print_time_est if values too far off (but not if undershoots & canceled)
    if(defined($print_time_est) && defined($print_time) && #If print_time too far off from estimate, replace with print_time_est
	   ($print_time/$print_time_est > 1 + $max_est_err || #Overshoots
	    !defined($DbH{$_}{cancelled_at}) && $print_time/$print_time_est < 1 - $max_est_err)) { #Undershoots but not canceled
#	    printf("%s\t%f\t%f\n", $DbH{$_}{filename}, $print_time, $print_time_est); #JJKDEBUG
	    $print_time = $print_time_est;
    }

    #Write changed 'print_time' back out to obico database
    if(defined($print_time) && (!defined($print_time_orig) ||  $print_time != $print_time_orig)) { 
	$stmt = qq(UPDATE $TABLE SET print_time = $print_time WHERE id = $_;);
	$res = $dbh->do($stmt) or die $DBI::errstr;	
	$time_cnt++;
    }

    #Add filament_length if not present and if calculable
    if(!defined($DbH{$_}{filament_used}) &&  
       defined(my $FilamentHref = $jsonH{$DbH{$_}{filename}}{analysis}{filament})) {
	my $filament_length = 0;
	foreach(keys %$FilamentHref) { #Calculate cumulative sum in case multiple 'tools'
	    $filament_length += $FilamentHref->{$_}{length};
	}
	next unless $filament_length >0;

	#Correct filament used if canceled by pro-rating actual against estimate
	if(defined($DbH{$_}{cancelled_at}) && defined($print_time) &&
	   defined($print_time_est) && $print_time < $print_time_est) {
	    $filament_length *= $print_time/$print_time_est;
	}

	#Write 'filament_used' back out to obico database
	$stmt = qq(UPDATE $TABLE SET filament_used = $filament_length WHERE id = $_;);
	$res = $dbh->do($stmt) or die $DBI::errstr;
#	printf("%s\t%f\n", $_, $filament_length) if defined($filament_length); #JJKDEBUG
	$filament_cnt++;
    }
};
printf("Added %d 'print_time' and %d 'filament_length'\n", $time_cnt, $filament_cnt);
exit