inventree / InvenTree

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

[BUG] Internal Server Error #3355

Closed luwol03 closed 2 years ago

luwol03 commented 2 years ago

Describe the bug I get an Internal Server error after start and don't know why.

Steps to Reproduce

Steps to reproduce the behavior:

  1. Start the server
  2. Watch logs
  3. Navigate to /admin
  4. See error

Expected behavior Should show the Django admin

Deployment Method

Version Information

# Version Information:
InvenTree-Version: 0.7.5
Django Version: 3.2.13

Database: postgresql
Debug-Mode: False
Deployed using Docker: True

Log: https://gist.github.com/luwol03/45794e822bfd00730f9edcb259028915

matmair commented 2 years ago

I can not reproduce this with a fresh install @luwol03 anything else you changed? Do you have any custom plugins activated?

SchrodingersGat commented 2 years ago

@luwol03 this is a new one for me too. Looks like the postgres database container is having some issues. Please let us know if you made any changes to the docker-compose or .env files

luwol03 commented 2 years ago

Hello, the first lines until line 826 are cannons connect to database, because the database is not listening, but then the connection is successful but an SQL statement is executed 3 times concurrently which causes an error. And I guess this has something to to with that the 500 on /admin. I more and more think, that this is caused because I run it via macos docker. (Also the git safepermissions error). I try to export the database and try on Linux. Thank you for taking a look.

SchrodingersGat commented 2 years ago

@luwol03 please let us know if you find anything further :)

luwol03 commented 2 years ago

@SchrodingersGat I now copied everything to a linux machine and started the containers, open /admin in browser and see error. I have no idea why. I would appreciate if you could take a look. I bundled everything into a targz archive:inventree-mac.tar.zip

Steps to reproduce:

  1. extract the tar from the zip (gh only allowed me to upload zip)
  2. tar xfzv inventree-mac.tar
  3. cd inventree-mac
  4. docker-compose up -d && docker-compose logs -f
  5. wait for start and see error
  6. browse http://localhost:8000/admin (if login is needed, there is an admin user: admin with password: Passw0rd)
luwol03 commented 2 years ago

Hey @SchrodingersGat, I analyzed it a bit further and I did the following:

  1. Running the inventree_data volume with a clean database -> OK
  2. Running my db -> ERROR
  3. Comparing the dbs table by table
  4. After trying to modify one by one of my corrupted db to fit the working (fresh) db I found the "Übeltäter". If simpleactionplugin is enabled, I get the error described in this issue. Removing the checkmark and restarting the docker container results with no error before: image after: image

Excact descibed Error:

![image](https://user-images.githubusercontent.com/60048565/179844366-43caa70f-6d23-47c1-803d-41b539cd1470.png) ```bash Environment: Request Method: GET Request URL: http://localhost:8000/admin/ Django Version: 3.2.13 Python Version: 3.9.5 Installed Applications: ['build.apps.BuildConfig', 'common.apps.CommonConfig', 'company.apps.CompanyConfig', 'label.apps.LabelConfig', 'order.apps.OrderConfig', 'part.apps.PartConfig', 'report.apps.ReportConfig', 'stock.apps.StockConfig', 'users.apps.UsersConfig', 'plugin.apps.PluginAppConfig', 'InvenTree.apps.InvenTreeConfig', 'django.contrib.admin', 'django.contrib.auth', 'django.contrib.contenttypes', 'user_sessions', 'django.contrib.messages', 'django.contrib.staticfiles', 'django.contrib.sites', 'maintenance_mode', 'django_filters', 'rest_framework', 'rest_framework.authtoken', 'corsheaders', 'crispy_forms', 'import_export', 'django_cleanup.apps.CleanupConfig', 'mptt', 'markdownx', 'markdownify', 'django_admin_shell', 'djmoney', 'djmoney.contrib.exchange', 'error_report', 'django_q', 'formtools', 'allauth', 'allauth.account', 'allauth.socialaccount', 'django_otp', 'django_otp.plugins.otp_totp', 'django_otp.plugins.otp_static', 'allauth_2fa', 'sslserver'] Installed Middleware: ['django.middleware.security.SecurityMiddleware', 'x_forwarded_for.middleware.XForwardedForMiddleware', 'user_sessions.middleware.SessionMiddleware', 'django.middleware.locale.LocaleMiddleware', 'django.middleware.common.CommonMiddleware', 'django.middleware.csrf.CsrfViewMiddleware', 'corsheaders.middleware.CorsMiddleware', 'django.contrib.auth.middleware.AuthenticationMiddleware', 'InvenTree.middleware.InvenTreeRemoteUserMiddleware', 'django_otp.middleware.OTPMiddleware', 'InvenTree.middleware.CustomAllauthTwoFactorMiddleware', 'django.contrib.messages.middleware.MessageMiddleware', 'django.middleware.clickjacking.XFrameOptionsMiddleware', 'InvenTree.middleware.AuthRequiredMiddleware', 'InvenTree.middleware.Check2FAMiddleware', 'maintenance_mode.middleware.MaintenanceModeMiddleware', 'error_report.middleware.ExceptionProcessor'] Traceback (most recent call last): File "/home/inventree/.local/lib/python3.9/site-packages/django/core/handlers/exception.py", line 47, in inner response = get_response(request) File "/home/inventree/.local/lib/python3.9/site-packages/django/core/handlers/base.py", line 181, in _get_response response = wrapped_callback(request, *callback_args, **callback_kwargs) File "/home/inventree/.local/lib/python3.9/site-packages/django/contrib/admin/sites.py", line 250, in wrapper return self.admin_view(view, cacheable)(*args, **kwargs) File "/home/inventree/.local/lib/python3.9/site-packages/django/utils/decorators.py", line 130, in _wrapped_view response = view_func(request, *args, **kwargs) File "/home/inventree/.local/lib/python3.9/site-packages/django/views/decorators/cache.py", line 44, in _wrapped_view_func response = view_func(request, *args, **kwargs) File "/home/inventree/.local/lib/python3.9/site-packages/django/contrib/admin/sites.py", line 232, in inner return view(request, *args, **kwargs) File "/home/inventree/.local/lib/python3.9/site-packages/django/views/decorators/cache.py", line 44, in _wrapped_view_func response = view_func(request, *args, **kwargs) File "/home/inventree/.local/lib/python3.9/site-packages/django/contrib/admin/sites.py", line 522, in index app_list = self.get_app_list(request) File "/home/inventree/.local/lib/python3.9/site-packages/django/contrib/admin/sites.py", line 505, in get_app_list app_dict = self._build_app_dict(request) File "/home/inventree/.local/lib/python3.9/site-packages/django/contrib/admin/sites.py", line 487, in _build_app_dict 'app_url': reverse( File "/home/inventree/.local/lib/python3.9/site-packages/django/urls/base.py", line 86, in reverse return resolver._reverse_with_prefix(view, prefix, *args, **kwargs) File "/home/inventree/.local/lib/python3.9/site-packages/django/urls/resolvers.py", line 698, in _reverse_with_prefix raise NoReverseMatch(msg) Exception Type: NoReverseMatch at /admin/ Exception Value: Reverse for 'app_list' with keyword arguments '{'app_label': 'common'}' not found. 1 pattern(s) tried: ['admin/(?Ppart|build|order|stock)/$'] ```

Now my log looks like that (this time debug mode and DEBUG log level enabled) (take care to look at the right file, just appended that to the gist): https://gist.github.com/luwol03/45794e822bfd00730f9edcb259028915#file-new_log-log

As you can see, the main error is gone, but the concurrent update is still there. I think this should be tracked in a new issue, because this is unrelated to the 5XX error.

Hopefully you have an idea why an enabled simpleactionplugin causes that 5XX error.

Can you please also explain what the plugin is doing/where I can find it in code?

luwol03

SchrodingersGat commented 2 years ago

As you can see, the main error is gone, but the concurrent update is still there. I think this should be tracked in a new issue, because this is unrelated to the 5XX error.

This has actually been addressed for 0.8.0 - https://github.com/inventree/InvenTree/pull/3268

SchrodingersGat commented 2 years ago

There are some strange issues popping up with javascript URLs also

image

SchrodingersGat commented 2 years ago

@luwol03 I have managed to reproduce the 500 error when navigating to the admin page, with the zip you provided. Will look into it further.

Dropping your database and starting afresh also "fixes" the issue on my end...

luwol03 commented 2 years ago

@SchrodingersGat Have you read that I found out, that one single flag in the db is causing that?

SchrodingersGat commented 2 years ago

Have you read that I found out, that one single flag in the db is causing that?

I did read that, I am very confused as to why that would lead to all these errors..

SchrodingersGat commented 2 years ago

Is it otherwise working well for you now?

luwol03 commented 2 years ago

Is it otherwise working well for you now?

Yes, inventree rocks, why do I don't discovered that before. I was a long time searching for a free storage tracking solution but didn't found inventree via google. It was a randomness, that inventree was on my gh explore page. Good job.

How do you actually finance this project and the investigated time?

(I only had this 500 on my experimental instance hosted on my pc to test the plugins and write my own first plugin. Only thought this may be an error which could occur in someone else production instance and would be good to fix.)

SchrodingersGat commented 2 years ago

@luwol03 I think this may have been specific to your particular setup, it is not something we have seen previously. I'm going to close this out for now, but if you see it again, please comment back here.

matmair commented 2 years ago

@SchrodingersGat not sure what do make of this but this is at least the second user having problems with plugins in this kind of setup. Maybe there is something systematic. Still trying to reproduce #3287

@luwol03 feel free to spread the word ;-) . We are not really getting financed, this project is more held up by its users right now.

Zontex commented 2 years ago

My issue #3476 seems to be duplicated. I also had this issue now after upgrading but after reading @luwol03 notes I disabled plugins and now it's working. is there any fix to enable plugins back? I suggest to re-open this ticket.

I modified the sample active plugin to 0 via MySQL and activated plugins back and it seems to be working. Something seems to be broken with the plugin / plugin system that prevents accessing the admin dashboard.

SchrodingersGat commented 2 years ago

Huh, maybe one of the plugins is broken? Does the error come back if you re-enable plugins?

Zontex commented 2 years ago

Huh, maybe one of the plugins is broken? Does the error come back if you re-enable plugins?

I disabled the default simpleactionplugin via MySQL by running "UPDATE plugin_pluginconfig SET active=0 WHERE id=1;" then re-enabled the plugins and it works

Zontex commented 2 years ago

So let's summarize it to enable understand better what's going on. @luwol03 didn't provide much information on how the problem occurs but he did find the solution which is related to the plugin. In #3476 I provided a more detailed log that could shed some light on what's going on.

He was running a Docker while I was running bare-metal - which affects both.

For me, it happened after the 0.7.4 to 0.8.0 upgrade. I had plugins enabled in 0.7.4 but I never used them so the only plugin that was activated was "simpleactionplugin", by disabling it manually I was able to solve the issue.

Update: I enabled inventreebarcode to see if this issue affects all plugins, doesn't seem to be a problem. The plugin is activated and admin/ dashboard works. Seems to be related directly to simpleactionplugin.

TODO

matmair commented 2 years ago

@Zontex I had problems reproducing this last time - maybe because of the plugin settings. We might need to include plugin info in the version information stuff.

SchrodingersGat commented 2 years ago

@Zontex are you able to provide a bit more detail here - at what exact point do you see the error?

Is it during the update process? e.g. running invoke update or similar command?

Or is it after a successful update procedure when you navigate to the website

Zontex commented 2 years ago

After successful installation once you try to access "admin/" page. Exactly the same thing happened to OP

On Sat, Aug 6, 2022, 2:26 AM Oliver @.***> wrote:

@Zontex https://github.com/Zontex are you able to provide a bit more detail here - at what exact point do you see the error?

Is it during the update process? e.g. running invoke update or similar command?

Or is it after a successful update procedure when you navigate to the website

— Reply to this email directly, view it on GitHub https://github.com/inventree/InvenTree/issues/3355#issuecomment-1207086027, or unsubscribe https://github.com/notifications/unsubscribe-auth/AETSJRMJO4DJN7YVFHXH5X3VXWPJ5ANCNFSM535MJDAA . You are receiving this because you were mentioned.Message ID: @.***>

SchrodingersGat commented 2 years ago

@Zontex ah yep specific to the admin page. I had overlooked that detail. I can definitely recreate that.

SchrodingersGat commented 2 years ago

image

The /admin/common/ and /admin/plugin/ URL lookups are missing at least

Zontex commented 2 years ago

@SchrodingersGat after updating will the default plugin work or still the admin dashboard won't function?

SchrodingersGat commented 2 years ago

@Zontex after the patch in #3484 it should all work perfectly. If you are able to test on inventree:master please do. Otherwise 0.8.1 will be released soon.

SchrodingersGat commented 2 years ago

@luwol03 please note that finally I think I have found a solution to this one.