+++ This bug was initially created as a clone of Bug #2223567 +++

Description of problem:
This seems to be regression of BZ 2139545.

During registration violation of unique constraint is hit as below

PG::UniqueViolation: ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"

It seems like previous bugzilla just removed the log from /var/log/foreman/production, but postgresql still reflects same issue as below:

2023-07-18 13:31:36 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-18 13:31:36 CEST DETAIL: Key (name, stream, context)=(python36, 3.6, 683b2e54) already exists.
2023-07-18 13:31:36 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-18 13:31:36 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-18 13:31:36 CEST DETAIL: Key (name, stream, context)=(ruby, 2.5, ad008a3a) already exists.
2023-07-18 13:31:36 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"

Version-Release number of selected component (if applicable):
Satellite 6.13.2

How reproducible:
Always

Steps to Reproduce:
1. re-register RHEL8 host

Actual results:
/var/log/foreman/production.log
2023-07-18T13:31:36 [I|app|9ba09d93] Processing by Katello::Api::Rhsm::CandlepinDynflowProxyController#upload_profiles as JSON
2023-07-18T13:31:36 [I|app|9ba09d93] Parameters:

{"id"=>"1b137c1f-62d0-440b-acb7-9a55c342dd45"}
2023-07-18T13:31:36 [I|app|9ba09d93] Completed 200 OK in 167ms (Views: 6.1ms | ActiveRecord: 56.7ms | Allocations: 52327)

/var/lib/pgsql/data/log/postgresql-Tue.log
2023-07-18 13:31:36 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-18 13:31:36 CEST DETAIL: Key (name, stream, context)=(python36, 3.6, 683b2e54) already exists.
2023-07-18 13:31:36 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-18 13:31:36 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-18 13:31:36 CEST DETAIL: Key (name, stream, context)=(ruby, 2.5, ad008a3a) already exists.
2023-07-18 13:31:36 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"

Expected results:
No index violation.

Additional info:
Reported by customer but also reproduced locally, i will share reproducer details.

— Additional comment from on 2023-07-18T09:46:32Z

Reproducer

jjansat613.usersys.redhat.com (10.37.195.73)
ssh: root/redhat
webui: admin/admin

host used for re-registration jjansky-rhel8.sat613.jjansky.lan (use satellite as jumphost during ssh)
jjansky-rhel8.sat613.jjansky.lan (192.168.13.7)
ssh: root/RedHat1!

logs from reproducer

/var/log/foreman/production.log
2023-07-18T13:31:36 [I|app|9ba09d93] Processing by Katello::Api::Rhsm::CandlepinDynflowProxyController#upload_profiles as JSON
2023-07-18T13:31:36 [I|app|9ba09d93] Parameters: {"id"=>"1b137c1f-62d0-440b-acb7-9a55c342dd45"}

2023-07-18T13:31:36 [I|app|9ba09d93] Completed 200 OK in 167ms (Views: 6.1ms | ActiveRecord: 56.7ms | Allocations: 52327)

/var/lib/pgsql/data/log/postgresql-Tue.log
2023-07-18 13:31:36 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-18 13:31:36 CEST DETAIL: Key (name, stream, context)=(python36, 3.6, 683b2e54) already exists.
2023-07-18 13:31:36 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-18 13:31:36 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-18 13:31:36 CEST DETAIL: Key (name, stream, context)=(ruby, 2.5, ad008a3a) already exists.
2023-07-18 13:31:36 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"

logs from customer

/var/log/foreman/production.log
2023-07-16T13:01:44 [I|app|466e2f80] Started PUT "/rhsm/consumers/ac382152-d1f5-4ffe-836e-1e368a4d8390/profiles" for 10.178.3.150 at 2023-07-16 13:01:44 +0200
2023-07-16T13:01:44 [I|app|466e2f80] Processing by Katello::Api::Rhsm::CandlepinDynflowProxyController#upload_profiles as JSON
2023-07-16T13:01:44 [I|app|466e2f80] Parameters:

{"id"=>"ac382152-d1f5-4ffe-836e-1e368a4d8390"}

2023-07-16T13:01:44 [I|app|466e2f80] Completed 200 OK in 593ms (Views: 4.8ms | ActiveRecord: 74.9ms | Allocations: 61097)

/var/lib/pgsql/data/log/postgresql-Sun.log
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(maven, 3.8, 470dcefd) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(nginx, 1.22, 9) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(nodejs, 18, rhel9) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(nodejs, 18, rhel9) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(nodejs, 18, rhel9) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(nodejs, 18, rhel9) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(php, 8.1, 9) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(php, 8.1, 9) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(postgresql, 15, rhel9) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(ruby, 3.1, 9) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"
2023-07-16 13:01:44 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
2023-07-16 13:01:44 CEST DETAIL: Key (name, stream, context)=(maven, 3.8, 470dcefd) already exists.
2023-07-16 13:01:44 CEST STATEMENT: INSERT INTO "katello_available_module_streams" ("name", "stream", "context") VALUES ($1, $2, $3) RETURNING "id"

— Additional comment from on 2023-08-08T07:15:18Z

@satellite6-bugs <satellite6-bugs@redhat.com>
Do we have any updates here? This is still escalated.

Kind Regards,
Kuunal Rathod
Critical Situation Manager

— Additional comment from on 2023-08-14T13:48:04Z

We'll be looking into this soon.

Also, for the future, I'm not sure if anyone monitors needinfos on satellite6-bugs@redhat.com.

— Additional comment from on 2023-08-24T19:19:41Z

Hello Jan

The previous BZ dealt with concurrent registrations (several hosts being registered at once). The fix would hopefully prevent the race condition that created the error, but would not clean up anything in the database.

I re-registered the host you provided with subscription-manager register --force, but did not get any errors. Are you still able to reproduce this?

— Additional comment from on 2023-08-25T09:48:35Z

Hello Jeremy,
not sure where you looked, but you reproduced it as well according to logs

1. grep -ri "duplicate key value violates unique constraint \"katello_available_module_streams_name_stream_context\"" /var/lib/pgsql/data/log/
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
   /var/lib/pgsql/data/log/postgresql-Thu.log:2023-08-24 21:15:50 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"

Just to be sure i tried to reproduce again

/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"
/var/lib/pgsql/data/log/postgresql-Fri.log:2023-08-25 11:46:48 CEST ERROR: duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"

— Additional comment from on 2023-08-25T13:57:09Z

I see what's happening now.

In the previous fix we switched to using Active Record `create_or_find_by` to avoid the race condition in concurrent registrations.

According to [1], the way that create_or_find_by works is

"If a row already exists with one or several of these unique constraints, the exception such an insertion would normally raise is caught, and the existing record with those attributes is found using #find_by!."

Therefore, the errors in Postgres are expected, and should not cause any harm.

[1] https://apidock.com/rails/v6.0.0/ActiveRecord/Relation/create_or_find_by

— Additional comment from on 2023-08-25T13:57:48Z

Based on https://bugzilla.redhat.com/show_bug.cgi?id=2223567#c6, I propose closing this as NOTABUG.

— Additional comment from on 2023-09-18T13:24:04Z

Closing as NOTABUG; see https://bugzilla.redhat.com/show_bug.cgi?id=2223567#c6

— Additional comment from on 2024-01-17T13:18:50Z

//Internal

I have 2 customers with me who are using Satellite version 6.13 and I confirmed that the fix available in https://bugzilla.redhat.com/show_bug.cgi?id=2139545 is already present on their Satellite 6.13. Still they are facing the same error reported in this BugZilla. I explained them the reason behind this and conveyed them that it is harmless. Though the error is harmless, still they want to get rid of the observed error? How we can get rid of the observed error?

• Customer is getting same error in his postgres logs for 300 times in a day!

Below are the support case for reference already attached to this bug:

• 03709965 : https://access.redhat.com/support/cases/#/case/03709965

• 03707963 : https://access.redhat.com/support/cases/#/case/03707963

— Additional comment from on 2024-01-17T15:34:12Z

It's a choice between dealing with logs which can be ignored, or dealing with the error raised before this BZ which cannot be ignored.

I'm not sure if there's a way to tune what is put into the Postgres logs, or to have Postgresql ignore this specific error..

— Additional comment from on 2024-01-17T16:59:50Z

//Internal

Can we have a public update from Red Hat Engineering in this regard? Telling customer that we cannot get rid of a harmless error message that they see in the logs 300 times a day will not give a good user experience and will neither convince the customer. If we can have a public detailed response from Engineering on it, that might help to tackle the customer!

Currently there are only 2 customers who have reported the issue, but there are more customer who will surely raise the concern on it in coming days.

Disabling the package profile upload on each client system ( rhsm.conf ) can be an option to get rid of the observed error message but it will have other consequences and cannot be suggested to customer.

— Additional comment from on 2024-01-17T17:10:05Z

We will investigate this and see if there is a better technical solution.

— Additional comment from on 2024-01-17T17:29:45Z

Target Milestone is set to Unspecified, since this bug has Target Milestone set to 6.15.0 and approved release flag is not sat-6.15.0+

Once the bug has been granted the sat-6.15.0+ flag, the Target Milestone can be set to the desired value.

— Additional comment from on 2024-01-18T10:10:54Z

Do we know which tasks/actions can cause this apart from system registration?

Customer from case #03709965 sees around 200k of these errors logged each day. This includes weekends where the user activity is low/non-existent:

1. grep 'duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"' var/lib/pgsql/data/log/postgresql-Fri.log | wc -l
   —
   227950
   —

— Additional comment from on 2024-01-18T10:12:20Z

1. grep 'duplicate key value violates unique constraint "katello_available_module_streams_name_stream_context"' var/lib/pgsql/data/log/postgresql-Sun.log | wc -l
   —
   198114
   —

— Additional comment from on 2024-01-30T18:19:36Z

I think these logs are also caused by package profile uploads, which happen for every host every 4 hours.

If we keep the current status quo (postgresql logs) during registration, but prevent them for package profile uploads, would that be acceptable? It should cut down on the logs significantly.

— Additional comment from on 2024-01-31T00:41:08Z

There are mostly all customers who rely on the details of Applicable and Installable Errata displayed on Satellite WebUI for registered content hosts. Disabling Package Profile Upload could lead to many other consequences and might not be acceptable by the customers.

There are customers who reports that the Applicable and Installable Errata count displayed on Satellite WebUI mismatch or is not correct. If preventing the postgres logs during package profile uploads does not hinder the troubleshooting of such mismatch scenarios, it should not be an issue.

— Additional comment from on 2024-01-31T08:15:52Z

If we can suppress this log message during package profile upload will it not also solve the registration? From my understanding of your comments this kind of violation message is cause by profile package upload and that is also done during registration.

— Additional comment from on 2024-01-31T14:30:18Z

The previous method of creating records avoided the postgresql logs but sometimes caused race conditions during concurrent registrations that would cause registrations to fail.

My thinking for the solution to this BZ is to return to the previous method, but only for package profile uploads.

— Additional comment from on 2024-02-01T22:03:14Z

Created redmine issue https://projects.theforeman.org/issues/37137 from this bug

QE Tracker for https://issues.redhat.com/browse/SAT-23586
Bugzilla: https://bugzilla.redhat.com/show_bug.cgi?id=2266147