furlongm / patchman

Patchman is a Linux Patch Status Monitoring System
http://patchman.openbytes.ie
GNU General Public License v3.0
357 stars 77 forks source link

Error while processing report from centos 8, "Module matching query does not exist" #546

Closed Pavel077 closed 7 months ago

Pavel077 commented 9 months ago

Hello.

I've been using Patchman successfully for ubuntu 20.04,22.04 and centos 7, however after sending report from centos 8 I see these errors in celery log:

Dec 21 14:20:12 patchman.local celery-patchman[9424]: [2023-12-21 14:20:12,481: ERROR/ForkPoolWorker-2] Task reports.tasks.process_report[2b1d97e9-70b8-499b-94d8-e5c077124cab] raised unexpected: DoesNotExist('Module matching query does not exist.')
Dec 21 14:20:12 patchman.local celery-patchman[9424]: Traceback (most recent call last):
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 581, in get_or_create
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return self.get(**kwargs), False
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 435, in get
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     raise self.model.DoesNotExist(
Dec 21 14:20:12 patchman.local celery-patchman[9424]: modules.models.Module.DoesNotExist: Module matching query does not exist.
Dec 21 14:20:12 patchman.local celery-patchman[9424]: During handling of the above exception, another exception occurred:
Dec 21 14:20:12 patchman.local celery-patchman[9424]: Traceback (most recent call last):
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/backends/mysql/base.py", line 73, in execute
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return self.cursor.execute(query, args)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/MySQLdb/cursors.py", line 209, in execute
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     res = self._query(query)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/MySQLdb/cursors.py", line 315, in _query
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     db.query(q)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/MySQLdb/connections.py", line 239, in query
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     _mysql.connection.query(self, query)
Dec 21 14:20:12 patchman.local celery-patchman[9424]: MySQLdb._exceptions.OperationalError: (1048, "Column 'repo_id' cannot be null")
Dec 21 14:20:12 patchman.local celery-patchman[9424]: During handling of the above exception, another exception occurred:
Dec 21 14:20:12 patchman.local celery-patchman[9424]: Traceback (most recent call last):
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/reports/utils.py", line 346, in process_module
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     module, c = modules.get_or_create(name=m_name,
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 588, in get_or_create
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return self.create(**params), True
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 453, in create
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     obj.save(force_insert=True, using=self.db)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 739, in save
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     self.save_base(using=using, force_insert=force_insert,
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 776, in save_base
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     updated = self._save_table(
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 881, in _save_table
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     results = self._do_insert(cls._base_manager, using, fields, returning_fields, raw)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 919, in _do_insert
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return manager._insert(
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/manager.py", line 85, in manager_method
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return getattr(self.get_queryset(), name)(*args, **kwargs)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 1270, in _insert
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return query.get_compiler(using=using).execute_sql(returning_fields)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/sql/compiler.py", line 1416, in execute_sql
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     cursor.execute(sql, params)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 98, in execute
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return super().execute(sql, params)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 66, in execute
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 75, in _execute_with_wrappers
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return executor(sql, params, many, context)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 84, in _execute
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return self.cursor.execute(sql, params)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/backends/mysql/base.py", line 78, in execute
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     raise IntegrityError(*tuple(e.args))
Dec 21 14:20:12 patchman.local celery-patchman[9424]: django.db.utils.IntegrityError: (1048, "Column 'repo_id' cannot be null")
Dec 21 14:20:12 patchman.local celery-patchman[9424]: During handling of the above exception, another exception occurred:
Dec 21 14:20:12 patchman.local celery-patchman[9424]: Traceback (most recent call last):
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/celery/app/trace.py", line 451, in trace_task
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     R = retval = fun(*args, **kwargs)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/celery/app/trace.py", line 734, in __protected_call__
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     return self.run(*args, **kwargs)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/reports/tasks.py", line 29, in process_report
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     report.process(verbose=True)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/reports/models.py", line 168, in process
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     process_modules(report=self, host=host)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/reports/utils.py", line 80, in process_modules
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     module = process_module(module_str)
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/reports/utils.py", line 354, in process_module
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     module = modules.get(name=m_name,
Dec 21 14:20:12 patchman.local celery-patchman[9424]:   File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 435, in get
Dec 21 14:20:12 patchman.local celery-patchman[9424]:     raise self.model.DoesNotExist(
Dec 21 14:20:12 patchman.local celery-patchman[9424]: modules.models.Module.DoesNotExist: Module matching query does not exist.

I guess the root cause is "MySQLdb._exceptions.OperationalError: (1048, "Column 'repo_id' cannot be null")" but how can I debug further what is causing this error? Is it specific repo? Thank you for awesome software!

furlongm commented 9 months ago

Can you provide a sample report that causes this issue?

Pavel077 commented 9 months ago

How can i save report for sending it to you? Should I send file(s) from /tmp folder which are left if I run patchman-client with -d flag?

I guess the problem is in "modules". Reports from centos 8 are the only reports that had "modules" section present, reports from other distros had only Details, Repositories and Packages sections. So for now i replaced modularity=true to modularity=false inside the check_for_modularity() procedure and now reports from centos 8 are processed without errors.

UPD: No, it's not that easy :) Although report is uploaded without error, when patchman server tries to process Centos8 repository [CentOS Linux 8 - AppStream x86_64] it encounters error with module "389_ds" which is the first module in yum module list output

Refreshing metadata for Repo 71
Repository 71 : CentOS Linux 8 - AppStream x86_64
Checking http://vault.centos.org/centos/8/AppStream/x86_64/os/repodata/repomd.xml.xz
Checking http://vault.centos.org/centos/8/AppStream/x86_64/os/repodata/repomd.xml.bz2
Checking http://vault.centos.org/centos/8/AppStream/x86_64/os/repodata/repomd.xml.gz
Checking http://vault.centos.org/centos/8/AppStream/x86_64/os/repodata/repomd.xml
Found yum rpm repo - https://vault.centos.org/centos/8/AppStream/x86_64/os/repodata/repomd.xml
Downloading package info:          100%|##############################################################################################################################################################################|Time: 0:00:00
Downloading module info:           100%|##############################################################################################################################################################################|Time: 0:00:00
Extracting packages:               100%|##############################################################################################################################################################################|Time: 0:00:01
Adding 6533 new packages:          100%|##############################################################################################################################################################################|Time: 0:01:12

(1062, "Duplicate entry '389-ds' for key 'modules_module.name'")
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 581, in get_or_create
    return self.get(**kwargs), False
  File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 435, in get
    raise self.model.DoesNotExist(
modules.models.Module.DoesNotExist: Module matching query does not exist.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 84, in _execute
    return self.cursor.execute(sql, params)
  File "/usr/lib/python3/dist-packages/django/db/backends/mysql/base.py", line 73, in execute
    return self.cursor.execute(query, args)
  File "/usr/lib/python3/dist-packages/MySQLdb/cursors.py", line 209, in execute
    res = self._query(query)
  File "/usr/lib/python3/dist-packages/MySQLdb/cursors.py", line 315, in _query
    db.query(q)
  File "/usr/lib/python3/dist-packages/MySQLdb/connections.py", line 239, in query
    _mysql.connection.query(self, query)
MySQLdb._exceptions.IntegrityError: (1062, "Duplicate entry '389-ds' for key 'modules_module.name'")

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/repos/utils.py", line 329, in extract_module_metadata
    module, c = all_modules.get_or_create(name=m_name,
  File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 588, in get_or_create
    return self.create(**params), True
  File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 453, in create
    obj.save(force_insert=True, using=self.db)
  File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 739, in save
    self.save_base(using=using, force_insert=force_insert,
  File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 776, in save_base
    updated = self._save_table(
  File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 881, in _save_table
    results = self._do_insert(cls._base_manager, using, fields, returning_fields, raw)
  File "/usr/lib/python3/dist-packages/django/db/models/base.py", line 919, in _do_insert
    return manager._insert(
  File "/usr/lib/python3/dist-packages/django/db/models/manager.py", line 85, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 1270, in _insert
    return query.get_compiler(using=using).execute_sql(returning_fields)
  File "/usr/lib/python3/dist-packages/django/db/models/sql/compiler.py", line 1416, in execute_sql
    cursor.execute(sql, params)
  File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 98, in execute
    return super().execute(sql, params)
  File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 66, in execute
    return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
  File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 75, in _execute_with_wrappers
    return executor(sql, params, many, context)
  File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 79, in _execute
    with self.db.wrap_database_errors:
  File "/usr/lib/python3/dist-packages/django/db/utils.py", line 90, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 84, in _execute
    return self.cursor.execute(sql, params)
  File "/usr/lib/python3/dist-packages/django/db/backends/mysql/base.py", line 73, in execute
    return self.cursor.execute(query, args)
  File "/usr/lib/python3/dist-packages/MySQLdb/cursors.py", line 209, in execute
    res = self._query(query)
  File "/usr/lib/python3/dist-packages/MySQLdb/cursors.py", line 315, in _query
    db.query(q)
  File "/usr/lib/python3/dist-packages/MySQLdb/connections.py", line 239, in query
    _mysql.connection.query(self, query)
django.db.utils.IntegrityError: (1062, "Duplicate entry '389-ds' for key 'modules_module.name'")

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/patchman", line 705, in <module>
    main()
  File "/usr/bin/patchman", line 699, in main
    showhelp = process_args(args)
  File "/usr/bin/patchman", line 665, in process_args
    refresh_repos(args.repo, args.force)
  File "/usr/bin/patchman", line 122, in refresh_repos
    repo.refresh(force)
  File "/usr/lib/python3/dist-packages/repos/models.py", line 86, in refresh
    refresh_rpm_repo(self)
  File "/usr/lib/python3/dist-packages/repos/utils.py", line 716, in refresh_rpm_repo
    refresh_yum_repo(mirror, data, mirror_url, ts)
  File "/usr/lib/python3/dist-packages/repos/utils.py", line 586, in refresh_yum_repo
    extract_module_metadata(module_data, modules_url, mirror.repo)
  File "/usr/lib/python3/dist-packages/repos/utils.py", line 337, in extract_module_metadata
    module = all_modules.get(name=m_name,
  File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 435, in get
    raise self.model.DoesNotExist(
modules.models.Module.DoesNotExist: Module matching query does not exist.

And indeed there is a record present in db:

mysql> select * from modules_module;
+----+--------+--------+---------------------+----------+---------+---------+
| id | name   | stream | version             | context  | arch_id | repo_id |
+----+--------+--------+---------------------+----------+---------+---------+
|  8 | 389-ds | 1.4    | 8050020211110012652 | 1a75f91c |       3 |      71 |
+----+--------+--------+---------------------+----------+---------+---------+
1 row in set (0.00 sec)
furlongm commented 9 months ago

How can i save report for sending it to you? Should I send file(s) from /tmp folder which are left if I run patchman-client with -d flag?

Yes running with -d should leave some files in /tmp. Then we can compare the modules file with what is in the database.

And indeed there is a record present in db:

mysql> select * from modules_module;
+----+--------+--------+---------------------+----------+---------+---------+
| id | name   | stream | version             | context  | arch_id | repo_id |
+----+--------+--------+---------------------+----------+---------+---------+
|  8 | 389-ds | 1.4    | 8050020211110012652 | 1a75f91c |       3 |      71 |
+----+--------+--------+---------------------+----------+---------+---------+
1 row in set (0.00 sec)
Pavel077 commented 9 months ago

Hello. Sorry for the delay :(

This is file with module list tmp.zip

Database has one record about modules. which was inserted when patchman server tried to process initial report

mysql> select * from modules_module;
+----+--------+--------+---------------------+----------+---------+---------+
| id | name   | stream | version             | context  | arch_id | repo_id |
+----+--------+--------+---------------------+----------+---------+---------+
|  8 | 389-ds | 1.4    | 8050020211110012652 | 1a75f91c |       3 |      71 |
+----+--------+--------+---------------------+----------+---------+---------+
1 row in set (0.00 sec)

For now I've modified patchman-client on centos8 to ignore modules, and disabled "CentOS Linux 8 - AppStream x86_64" repository in patchman administrator's interface.

furlongm commented 8 months ago

Can you post the output of yum module list --enabled | grep "\[e\]" | grep -v ^Hint | awk {'print $1'} on one of the affected hosts?

furlongm commented 8 months ago

And can you try with 3.0.7 on both server and client?

lk6549 commented 8 months ago

Hi! I'm not the original poster but I am experiencing the same issue. I've run the requested command below along with a copy of the yum info command on the affected host and patchman server to demonstrate that they are running version 3.0.7-1.

Affected host

[root@nine ~]# cat /etc/os-release 
NAME="AlmaLinux"
VERSION="9.2 (Turquoise Kodkod)"
ID="almalinux"
ID_LIKE="rhel centos fedora"
VERSION_ID="9.2"
PLATFORM_ID="platform:el9"
PRETTY_NAME="AlmaLinux 9.2 (Turquoise Kodkod)"
ANSI_COLOR="0;34"
LOGO="fedora-logo-icon"
CPE_NAME="cpe:/o:almalinux:almalinux:9::baseos"
HOME_URL="https://almalinux.org/"
DOCUMENTATION_URL="https://wiki.almalinux.org/"
BUG_REPORT_URL="https://bugs.almalinux.org/"

ALMALINUX_MANTISBT_PROJECT="AlmaLinux-9"
ALMALINUX_MANTISBT_PROJECT_VERSION="9.2"
REDHAT_SUPPORT_PRODUCT="AlmaLinux"
REDHAT_SUPPORT_PRODUCT_VERSION="9.2"
[root@nine ~]# yum module list --enabled | grep "\[e\]" | grep -v ^Hint | awk {'print $1'}
[root@nine ~]# yum info patchman-client
Updating Subscription Management repositories.
Unable to read consumer identity

This system is not registered with an entitlement server. You can use subscription-manager to register.

Last metadata expiration check: 2:08:47 ago on Fri 26 Jan 2024 01:23:17 PM.
Installed Packages
Name         : patchman-client
Version      : 3.0.7
Release      : 1
Architecture : noarch
Size         : 22 k
Source       : patchman-client-3.0.7-1.src.rpm
Repository   : @System
From repo    : patchman
Summary      : patchman-client uploads reports to the patchman server
URL          : http://patchman.openbytes.ie
License      : GPLv3
Description  : patchman-client provides a client that uploads reports to a patchman server

[root@nine ~]# 

Patchman Server

sh-5.1# cat /etc/os-release 
NAME="AlmaLinux"
VERSION="9.3 (Shamrock Pampas Cat)"
ID="almalinux"
ID_LIKE="rhel centos fedora"
VERSION_ID="9.3"
PLATFORM_ID="platform:el9"
PRETTY_NAME="AlmaLinux 9.3 (Shamrock Pampas Cat)"
ANSI_COLOR="0;34"
LOGO="fedora-logo-icon"
CPE_NAME="cpe:/o:almalinux:almalinux:9::baseos"
HOME_URL="https://almalinux.org/"
DOCUMENTATION_URL="https://wiki.almalinux.org/"
BUG_REPORT_URL="https://bugs.almalinux.org/"

ALMALINUX_MANTISBT_PROJECT="AlmaLinux-9"
ALMALINUX_MANTISBT_PROJECT_VERSION="9.3"
REDHAT_SUPPORT_PRODUCT="AlmaLinux"
REDHAT_SUPPORT_PRODUCT_VERSION="9.3"
sh-5.1# yum info patchman
Last metadata expiration check: 23:47:09 ago on Thu Jan 25 15:45:41 2024.
Installed Packages
Name         : patchman
Version      : 3.0.7
Release      : 1
Architecture : noarch
Size         : 577 k
Source       : patchman-3.0.7-1.src.rpm
Repository   : @System
From repo    : openbytes
Summary      : Django based patch status monitoring tool for linux systems
URL          : http://patchman.openbytes.ie/
License      : GPLv3
lk6549 commented 7 months ago

After updating to patchman 3.0.8 and patchman-client 3.0.8 issue did not initially resolve. Ran patchman-manage migrate and received below output,

sh-5.1# patchman-manage migrate
Operations to perform:
  Apply all migrations: admin, arch, auth, contenttypes, domains, hosts, modules, operatingsystems, packages, reports, repos, sessions, sites, tagging
Running migrations:
  Applying modules.0002_auto_20240204_2214... OK
  Applying modules.0003_alter_module_options... OK

then issue resolved.

I'm running a containerised instance of patchman, so I'm not sure if this would be the solution should the app not be containerized.