Bug 1925164

Summary: Online backup restarting tarballs even 12 hours after start of process without logging to stdout/console
Product: Red Hat Satellite Reporter: mithun kalyat <mkalyat>
Component: Satellite MaintainAssignee: satellite6-bugs <satellite6-bugs>
Status: CLOSED WONTFIX QA Contact: Satellite QE Team <sat-qe-bz-list>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.8.0CC: apatel, aupadhye, iballou, kgaikwad, peter.vreman, saydas
Target Milestone: UnspecifiedKeywords: Reopened, Triaged
Target Release: Unused   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2023-04-06 17:10:05 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description mithun kalyat 2021-02-04 14:09:47 UTC
Without creating any output to the logging, process list that the tar command to create the pulp_data.tar is starting 12 hours after the online backup process is started.Log output of the backup process does not show anything:

--------
Creating backup folder /backup/satellite-backup-2021-01-25-01-00-04   ESC[32mESC[1m[OK]ESC[0m
--------------------------------------------------------------------------------
Check if the directory exists and is writable:                        ESC[32mESC[1m[OK]ESC[0m
--------------------------------------------------------------------------------
Generate metadata:

Collecting metadata
Collecting system release info
Collecting list of plugins
Collecting list of proxy features
Collecting installed RPMs
Saving metadata to metadata.yml                                       ESC[32mESC[1m[OK]ESC[0m
--------------------------------------------------------------------------------
Backup config files:

Collecting config files to backup                                     ESC[32mESC[1m[OK]ESC[0m
--------------------------------------------------------------------------------
Backup Pulp data:

Collecting Pulp data
(END)


From /var/log/foreman-maintain/foreman-maintain.log, it looks like retry is not limited to just a few (e.g. 3) times. With the pulp data tarball easily can take a few hours to create it quickly sums up in the time. See e.g. the 2021-01-09 where it retries for the 8x at 23:48UTC for a backup that was started at 01:00UTC. And the next backup would almost be starting again:
--------
root@satellite:/usr/share/gems/gems/foreman_maintain-0.6.14# grep 'Retrying...' /var/log/foreman-maintain/foreman-maintain.log
I, [2021-01-07 04:05:52+0000 #15496]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-07 07:09:33+0000 #15496]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-07 10:15:07+0000 #15496]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-07 13:20:38+0000 #15496]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-07 16:23:02+0000 #15496]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-07 18:58:16+0000 #15496]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-07 22:09:45+0000 #15496]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-08 03:52:20+0000 #24538]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-08 06:53:22+0000 #24538]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-08 10:14:38+0000 #24538]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-08 13:20:34+0000 #24538]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-08 16:16:09+0000 #24538]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-08 19:11:48+0000 #24538]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-08 22:10:59+0000 #24538]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-08 23:45:44+0000 #24538]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-09 04:11:53+0000 #17694]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-09 07:04:24+0000 #17694]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-09 10:10:33+0000 #17694]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-09 13:08:29+0000 #17694]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-09 16:04:53+0000 #17694]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-09 19:11:44+0000 #17694]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-09 22:10:59+0000 #17694]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-09 23:48:04+0000 #17694]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-10 04:17:16+0000 #10799]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-10 07:20:34+0000 #10799]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-10 10:23:16+0000 #10799]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-10 13:20:47+0000 #10799]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-10 16:16:36+0000 #10799]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-10 19:21:21+0000 #10799]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-11 03:57:31+0000 #22512]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-11 06:52:18+0000 #22512]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...
I, [2021-01-11 10:05:43+0000 #22512]  INFO -- : Data in /var/lib/pulp changed during backup. Retrying...


- Logging of the backup process is too less to analyze/troubleshoot why commands are failing/restart and/or taken that long.

- Restarting a command 12 Hours after backup is also not good anymore for predictability. It does not match the real scheduled backup time (01:00am UTC) I planned as user.

Comment 2 Amit Upadhye 2022-05-23 10:23:25 UTC
Hello,

From Satellite 6.10 onward there is newer qpid stack with Pulp 3 which should help to avoid this kind of situations. Accordingly I am closing this bugzilla.

If in case you see similar issue with newer Satellite versions then request to raise new bug for same.

Thank You,
Amit Upadhye.

Comment 4 Ian Ballou 2022-06-08 16:24:41 UTC
After chatting with folks from Pulp, they mentioned that they would like to write a new Pulpcore documentation section about filesystem changes in /var/lib/pulp.  There are numerous ways that file changes can occur, so having official documentation would be best.  Since the documentation will be published in Pulp terms, we can help translate it into Satellite (6.10+) terms once it's done.

I've linked the upstream Pulpcore issue requesting for the documentation.

Shall we reopen the issue for the documentation update?

Comment 5 Amit Upadhye 2022-06-08 17:54:25 UTC
Hello,

As per the discussion with Katello and Pulp team there could be occurrences of files getting modified however the situations will be lesser in number. We are working with Pulp team to get the details about when and how it happens.

I am reopening the bugzilla however its low priority and would be worked on as per general bugzilla prioritization process.

Regards,
Amit Upadhye.

Comment 6 Brad Buckingham 2023-03-06 11:37:55 UTC
Upon review of our valid but aging backlog the Satellite Team has concluded that this Bugzilla does not meet the criteria for a resolution in the near term, and are planning to close in a month. This message may be a repeat of a previous update and the bug is again being considered to be closed. If you have any concerns about this, please contact your Red Hat Account team.  Thank you.

Comment 7 Brad Buckingham 2023-04-06 17:10:05 UTC
Thank you for your interest in Red Hat Satellite. We have evaluated this request, and while we recognize that it is a valid request, we do not expect this to be implemented in the product in the foreseeable future. This is due to other priorities for the product, and not a reflection on the request itself. We are therefore closing this out as WONTFIX. If you have any concerns about this feel free to contact your Red Hat Account Team. Thank you.