inventree / InvenTree

Open Source Inventory Management System
https://docs.inventree.org
MIT License
4.22k stars 761 forks source link

Report generation takes a lot of time since update #7291

Open HannesMorre opened 5 months ago

HannesMorre commented 5 months ago

Please verify that this bug has NOT been raised before.

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

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.

Relevant log output

No response

SchrodingersGat commented 5 months ago

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:

HannesMorre commented 5 months ago
* 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 %}

{% trans "Picking list" %}

{% endblock %}

{% block page_content %}

Article{{ part.IPN }}
Description{{ part.description }}
Date{{ date }}
Quantity{{ build.quantity|floatformat:0 }}
Build Order {{ build }}


{% for line in build.allocated_stock.all %} {% if line.stock_item.location.pathstring != "Page"%} {% if line.stock_item.location.pathstring != "LHM"%} {% endif %} {% endif %} {% endfor %}
ID Name MPN Location Qty Needed Item Qty
{{ line.stock_item.pk }} {{ line.bom_item.sub_part.name }} {{ line.stock_item.supplier_part.manufacturer_part.MPN }} {{ line.stock_item.location.pathstring }} {{ line.quantity|floatformat:0 }} {{ line.stock_item.quantity|floatformat:0 }}

{% 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 commented 4 months ago

@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] commented 2 months ago

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

HannesMorre commented 2 weeks ago

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: Image For other parts this report print is loaded instantly with equal or more data to be loaded

HannesMorre commented 2 weeks ago

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

HannesMorre commented 2 weeks ago

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 commented 2 weeks ago

@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 commented 2 weeks ago

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 commented 2 weeks ago

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

HannesMorre commented 2 weeks ago

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 commented 2 weeks ago

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 commented 2 weeks ago

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

HannesMorre commented 2 weeks ago

@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 commented 2 weeks ago

@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 code@mjmair.com - 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 commented 2 weeks ago

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 commented 2 weeks ago

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

matmair commented 2 weeks ago

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 commented 2 weeks ago

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 commented 1 week ago

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 commented 1 week ago

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