Report generation takes a lot of time since update

[HannesMorre]

Please verify that this bug has NOT been raised before.

• [X] I checked and didn't find a similar issue

Describe the bug*

Since we updated to 0.14.4, the report generation takes a redicilous long time to load.

Steps to Reproduce

1. update inventree to 0.14.4 from 0.12.7
2. generate a build order report

Expected behaviour

Reports were generated almost instantly on 0.12.7, but since we updated to 0.14.4 it takes almost a minute to load a single report with 6 lines on it.

Deployment Method

• [X] Docker
• [ ] Package
• [ ] Bare metal
• [X] Other - added info in Steps to Reproduce

Version Information

Version Information:

InvenTree-Version: 0.14.4 Django Version: 4.2.11 Commit Hash: 35fc954 Commit Date: 2024-03-22

Database: postgresql Debug-Mode: False Deployed using Docker: True Platform: Linux-5.4.0-167-generic-x86_64-with Installer: DOC

Active plugins: [{'name': 'InvenTreeBarcode', 'slug': 'inventreebarcode', 'version': '2.0.0'}, {'name': 'InvenTreeCoreNotificationsPlugin', 'slug': 'inventreecorenotificationsplugin', 'version': '1.0.0'}, {'name': 'InvenTreeCurrencyExchange', 'slug': 'inventreecurrencyexchange', 'version': '1.0.0'}, {'name': 'InvenTreeLabel', 'slug': 'inventreelabel', 'version': '1.0.0'}, {'name': 'InvenTreeLabelMachine', 'slug': 'inventreelabelmachine', 'version': '1.0.0'}, {'name': 'InvenTreeLabelSheet', 'slug': 'inventreelabelsheet', 'version': '1.0.0'}, {'name': 'DigiKeyPlugin', 'slug': 'digikeyplugin', 'version': '1.0.0'}, {'name': 'LCSCPlugin', 'slug': 'lcscplugin', 'version': '1.0.0'}, {'name': 'MouserPlugin', 'slug': 'mouserplugin', 'version': '1.0.0'}, {'name': 'TMEPlugin', 'slug': 'tmeplugin', 'version': '1.0.0'}, {'name': 'SupplierCart', 'slug': 'suppliercart', 'version': '0.4.0'}]

Please verify if you can reproduce this bug on the demo site.

• [ ] I can reproduce this bug on the demo site.

Relevant log output

No response

[SchrodingersGat]

but since we updated to 0.14.4 it takes almost a minute to load a single report with 6 lines on it.

That is significantly more than I have ever seen, and I print multiple (complex) reports every day with it.

Can you share some further information:

• What sort of report are you generating?
• Can you share the template you are using?
• Do you see any error messages?

[HannesMorre]

* What sort of report are you generating?

Build report (a picking list)

* Can you share the template you are using?

{% extends "report/inventree_report_base.html" %}

{% load i18n %}
{% load report %}
{% load inventree_extras %}

{% block page_margin %}
margin-left: 2cm;
margin-right: 1cm;
margin-top: 4cm;
{% endblock %}

{% block bottom_left %}
content: "v{{report_revision}} - {{ date.isoformat }}";
{% endblock %}

{% block bottom_center %}
content: "InvenTree v{% inventree_version %}";
{% endblock %}

{% block style %}
.header-left {
    text-align: left;
    float: left;
}
table {
    border: 1px solid #eee;
    border-radius: 3px;
    border-collapse: collapse;
    width: 100%;
    font-size: 80%;
}
table td {
    border: 1px solid #eee;
}
{% endblock %}

{% block header_content %}
    <div class='header-left'>
        <h3>{% trans "Picking list" %}</h3>
    </div>
{% endblock %}

{% block page_content %}
<table>
  <tr> <td>Article</td><td>{{ part.IPN }}</td>  </tr>
  <tr> <td>Description</td><td>{{ part.description }}</td> </tr>
  <tr> <td>Date</td><td>{{ date }}</td> </tr>
  <tr> <td>Quantity</td><td>{{ build.quantity|floatformat:0 }}</td> </tr>
  <tr> <td>Build Order</td><td> {{ build }}</td> </tr>
</table>
<br>
<table class='changes-table'>
  <thead>
    <tr>
	  <th>ID</th>
	  <th>Name</th>
	  <th>MPN</th>
      <th>Location</th>
      <th>Qty Needed</th>
	  <th>Item Qty</th>
    </tr>
  </thead>
  <tbody>
  {% for line in build.allocated_stock.all %}
    <tr>
	{% if line.stock_item.location.pathstring != "Page"%}
	{% if line.stock_item.location.pathstring != "LHM"%}
	  <td> {{ line.stock_item.pk }} </td>
	  <td> {{ line.bom_item.sub_part.name }} </td>
	  <td> {{ line.stock_item.supplier_part.manufacturer_part.MPN }} </td>
      <td> {{ line.stock_item.location.pathstring }} </td>
      <td> {{ line.quantity|floatformat:0 }} </td>
	  <td> {{ line.stock_item.quantity|floatformat:0 }} </td>
	{% endif %}
	{% endif %}
    </tr>
  {% endfor %}
  </tbody>
</table>

{% endblock %}

* Do you see any error messages?

No errors

For a simple build with 8 items in the bom list it took 45 seconds to load.

[SchrodingersGat]

@HannesMorre I have not been able to reproduce this. I used the same report template you have provided and printing was near instantaneous.

Are you able to perform any further testing with a copy or duplicated setup of your production setup?

[github-actions[bot]]

This issue seems stale. Please react to show this is still important.

[HannesMorre]

This is still happening and now the report is not printed anymore at all. For some parts I get this error after one minute of loading time: For other parts this report print is loaded instantly with equal or more data to be loaded

[HannesMorre]

@SchrodingersGat can this be reopened, since this is a big issue for our operations

[HannesMorre]

This is the version of inventree currently running:

# Version Information:
InvenTree-Version: 0.16.1
Django Version: 4.2.15
Commit Hash: 4c15e5c
Commit Date: 2024-08-30

Database: postgresql
Debug-Mode: False
Deployed using Docker: True
Platform: Linux-5.4.0-167-generic-x86_64-with
Installer: DOC

Active plugins: [{'name': 'InvenTreeBarcode', 'slug': 'inventreebarcode', 'version': '2.1.0'}, {'name': 'InvenTreeCoreNotificationsPlugin', 'slug': 'inventreecorenotificationsplugin', 'version': '1.0.0'}, {'name': 'InvenTreeCurrencyExchange', 'slug': 'inventreecurrencyexchange', 'version': '1.0.0'}, {'name': 'InvenTreeLabel', 'slug': 'inventreelabel', 'version': '1.1.0'}, {'name': 'InvenTreeLabelMachine', 'slug': 'inventreelabelmachine', 'version': '1.0.0'}, {'name': 'InvenTreeLabelSheet', 'slug': 'inventreelabelsheet', 'version': '1.0.0'}, {'name': 'DigiKeyPlugin', 'slug': 'digikeyplugin', 'version': '1.0.0'}, {'name': 'LCSCPlugin', 'slug': 'lcscplugin', 'version': '1.0.0'}, {'name': 'MouserPlugin', 'slug': 'mouserplugin', 'version': '1.0.0'}, {'name': 'TMEPlugin', 'slug': 'tmeplugin', 'version': '1.0.0'}, {'name': 'SupplierCart', 'slug': 'suppliercart', 'version': '0.4.0.dev'}]

[SchrodingersGat]

@HannesMorre you will have to provide some more information here to go on. The report printing has not slowed down to my eyes, perhaps there is something particular to your setup

[HannesMorre]

Are you able to perform any further testing with a copy or duplicated setup of your production setup?

I can confirm this issue persists on our staging environment as well.

Here are the worker logs when we try to create a report: worker.log

[SchrodingersGat]

Can you provide the inventree-server container logs? The worker does not handle report printing, it is run by the frontend worker

[HannesMorre]

Here are the logs of the inventree-server container: server2.log

As you can see, at 9:49 we tried to create a report. According to the logs, the api call results in a 200 OK, but in the inventree UI we get a 504 error code.

[SchrodingersGat]

Ok, thanks. Given that the server is responding 200, likely the proxy server is responsible for the 500. Can you provide a log from the proxy container?

Additionally, are you running any other proxies at a higher level?

[matmair]

I can not replicate this @HannesMorre have you tried to replicate this on the demo server?

[HannesMorre]

@SchrodingersGat We cannot see any errors in the inventree proxy log nor in any other proxy logs

@matmair I cannot even reporduce this on our own server. I duplicated one of the parts with this issue. Everything is exactly the same aside from the part number and with this copy I CAN create a report without error. However it still takes a while to load, 45s to be exact (timeout is at 1m).

[matmair]

@HannesMorre we are shipping tracing functionality based on the OpenTelemetry with InvenTree - you can plug that into nearly every observability / APM / monitoring solution out there. We could use that to diagnose. If you are allowed to use functions like this / share access to results of such tools feel free to reach out to [email protected] - I can send you sample setups for Datadog, Splunk, Grafana Cloud or Honeycomb if you have one of those or give you access to one of my tracing setups if that works for you.

[HannesMorre]

Thanks @matmair. I sent your reply to our system administrator and asked him to contact you here or through email. These reports are crucial for our daily workflow, so I would really like to find a solution for this issue.

[lqdmist]

Hi, @matmair we are currently using Zabbix for our server monitoring. Any example setups for this?

[matmair]

Zabbix does not have support for OpenTelemetry (yet https://support.zabbix.com/browse/ZBXNEXT-7617). If you want to self-host I can recommend uptrace or if you want to get up and running fast Grafana Cloud has a very generous and performant free tier that requires no credit card (https://grafana.com/pricing/)

[lqdmist]

I have install uptrace and configured inventree to send metrics to uptrace but I get an error 405 for exporting the values. However I am able to view the metric json in the inventree-server log using the INVENTREE_TRACING_CONSOLE environment parameter. It this enough for you? In case it is I will collect the logs and send them over to you through email.

[matmair]

405 sounds like it could be either a missing or added trailing slash or not using the intended protocol (HTTP/gRPC).

The metric json should be enough, I can ingest that into my tracer instance and look for anomalies.

[lqdmist]

Alright, I just have sent you an email containing the metrics json

[github-actions[bot]]

This issue seems stale. Please react to show this is still important.