refactor: Improved logger usage #1373

Venefilyn · 2024-09-10T15:05:38Z

This refactor of the usage of our logging is to get away from custom
functions that causes attribute errors in editors and IDEs. This will
also standarize the usage of logger and the loglevels.

In future PRs we can include changes to include prepare, rollback, and
final specific message styles.

Jira Issues:

Depends on

[RHELC-1732] refactor: Improved logger usage #1327

Checklist

PR has been tested manually in a VM (either author or reviewer)
Jira issue has been made public if possible
[RHELC-] or [HMS-] is part of the PR title
GitHub label has been added to help with Release notes
PR title explains the change from the user's point of view
Code and tests are documented properly
The commits are squashed to as few commits as possible (without losing data)
When merged: Jira issue has been updated to Release Pending if relevant

convert2rhel/logger.py

r0x0d · 2024-09-11T18:27:04Z

convert2rhel/main.py

@@ -136,6 +136,7 @@ def main_locked():
    initialize_file_logging("convert2rhel.log", logger_module.LOG_DIR)

    try:
+        logger_module.ConversionStage.set_stage("prepare")


What about using ConversionPhase for this? I think it could be really good to map the phases in that class to the ConversionStage you created

@r0x0d That's a good point. Though that made me dig down a rabbit hole of refactoring to be a bit nicer to use for more scenarios. What do you think of this?

class ConversionPhase: """Conversion phase to hold name and logging-friendly name. """ def __init__(self, name, log_name=None): # type: (str, str|None) -> None self.name = name self.log_name = log_name def __str__(self): return self.log_name def __repr__(self): return self.name def __hash__(self) -> int: return hash(self.name) class ConversionPhases(dict): """During conversion we will be in different states depending on where we are in the execution. This class establishes the different phases that we have as well as what the current phase is set to. """ _phases = [ ConversionPhase(name="POST_CLI", log_name="Prepare"), ConversionPhase(name="PRE_PONR_CHANGES", log_name="Prepare") ] current_phase = None # type: ConversionPhase|None def __getitem__(self, key): # type: (str) -> ConversionPhase|None return next(phase for phase in self._phases if phase.name == key ) @classmethod def set_stage(cls, phase): # type: (str) -> None if phase is None or phase in cls._phases: cls.current_phase = cls._phases[phase] raise NotImplementedError("The stage {} is not implemented in the ConversionStage class".format(phase)) test = ConversionPhases() print(test["POST_CLI"].__repr__)

$ python test.py <bound method ConversionPhase.__repr__ of POST_CLI>

Hmmm, this work as well, but it is easy to introduce an error if we miss the correct naming in other parts of the code or introduce a new phase and forget about it.

I was thinking in something more simple, like this:

class ConversionPhase: POST_CLI = 1 # PONR means Point Of No Return PRE_PONR_CHANGES = 2 # Phase to exit the Analyze SubCommand early ANALYZE_EXIT = 3 POST_PONR_CHANGES = 4 class ConversionStage: stages = { ConversionPhase.PRE_PONR_CHANGES: "Prepare", ConversionPhase.POST_PONR_CHANGES: "Final", ... } current = None # type: str|None @classmethod def set_stage(cls, stage): # type: (str) -> None if stage == None or stage in cls.stages: cls.current = cls.stages[stage] raise NotImplementedError("The stage {} is not implemented in the ConversionStage class".format(stage))

Then, when we initialize the ConversionStage, we could just simply:

logger_module.ConversionStage.set_stage(ConversionPhase.PRE_PONR_CHANGES)

And then we have it mapped everywhere that PRE_PONR_CHANGES matches the Prepare or something else. The interface will still look clean enough in the new class, and we will make sure that if someone changes the meaning for any of those phases, we will catch somewhere as well.

Since our use case is so small for now, I think that reusing the phases from ConversionPhase should be good enough.

I think our ConversionPhase class should hold the information where we are in the process at all times, being our source of truth for many different operations. It is true that logging phases may differ from execution phases, but if that's really the case, then we could come up with an intermediate class that will hold the logging phases for us, tied to the conversion phase if necessary.

Ah I didn't see this as I got hyperfocused on overcomplicating the solution... but anyhow I did change it now to be a bit safer but in a way that means we still rely on strings. But given exceptions being raised we should catch it in tests if we do a mistake

convert2rhel/utils/phase.py

r0x0d · 2024-09-12T15:14:30Z

convert2rhel/utils/phase.py

+    # Phase to exit the Analyze SubCommand early
+    ANALYZE_EXIT = ConversionPhase(name="ANALYZE_EXIT")
+    POST_PONR_CHANGES = ConversionPhase(name="POST_PONR_CHANGES", log_name="Convert")
+    ROLLBACK = (ConversionPhase(name="ROLLBACK", log_name="Rollback"),)


Suggested change

ROLLBACK = (ConversionPhase(name="ROLLBACK", log_name="Rollback"),)

ROLLBACK = ConversionPhase(name="ROLLBACK", log_name="Rollback")

codecov · 2024-09-18T15:25:32Z

Codecov Report

Attention: Patch coverage is 79.72973% with 30 lines in your changes missing coverage. Please review.

Project coverage is 96.09%. Comparing base (d603f04) to head (943cec0).
Report is 2 commits behind head on main.

Files with missing lines	Patch %	Lines
convert2rhel/phase.py	57.69%	18 Missing and 4 partials ⚠️
convert2rhel/main.py	82.35%	2 Missing and 4 partials ⚠️
convert2rhel/logger.py	66.66%	1 Missing and 1 partial ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #1373      +/-   ##
==========================================
- Coverage   96.59%   96.09%   -0.51%     
==========================================
  Files          71       72       +1     
  Lines        5113     5174      +61     
  Branches      883      896      +13     
==========================================
+ Hits         4939     4972      +33     
- Misses         98      119      +21     
- Partials       76       83       +7

Flag	Coverage Δ
centos-linux-7	`91.61% <78.47%> (-0.46%)`	⬇️
centos-linux-8	`92.46% <79.16%> (-0.47%)`	⬇️
centos-linux-9	`92.59% <79.72%> (-0.46%)`	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

has-bot · 2024-09-19T12:20:59Z

/packit test --labels sanity

Comment generated by an automation.

Log | Bot Usage

Venefilyn · 2024-09-19T15:39:45Z

/packit test --labels sanity

Venefilyn · 2024-09-20T12:19:04Z

/packit test --labels sanity

Venefilyn · 2024-09-20T13:41:02Z

/packit test --labels sanity

Venefilyn · 2024-09-20T14:52:53Z

/packit test --labels sanity

Venefilyn · 2024-09-20T14:54:49Z

/packit build

Venefilyn · 2024-09-20T15:02:05Z

/packit test --labels sanity

Venefilyn · 2024-09-23T09:33:14Z

/packit test --labels sanity

hosekadam · 2024-09-24T09:39:54Z

convert2rhel/phase.py

+    """
+
+    POST_CLI = ConversionPhase(name="POST_CLI")
+    PREPARE = ConversionPhase(name="PREPARE", log_name="Prepare")


I just wonder, when we are changing the logging and the final is renamed to convert (which makes sense to me) - what about changing the Prepare to Analysis (or something like that)? I think it would be nice to have it matching the subcommands (analyze and convert).

Agreed and I had that before, but I wanted minimal changes in this PR to the actual logs so wanted it to remain the same. We can change it in a follow-up PR but requires a bit more discussion IMO

Okay. Maybe if we want minimal changes, then I would change the name of the post_conversion to the Final to be consistent

hosekadam · 2024-09-24T09:40:17Z

/packit test --labels sanity

hosekadam

Looks good, just wait till the infrastructure problems are resolved and try the sanity tests.

hosekadam · 2024-09-24T12:21:16Z

/packit test --labels sanity

Venefilyn · 2024-10-18T22:21:20Z

/packit test

Venefilyn · 2024-10-19T18:21:24Z

/packit test

Venefilyn · 2024-10-20T00:34:21Z

/packit test

SerCantus

The changes look great!
I see the integration tests are failing and some of them related to the expected messages, maybe something got messed up? I can't see it. For example in integration tests in CentOS7 it expects to see CUSTOM_REPOSITORIES_ARE_VALID::UNABLE_TO_ACCESS_REPOSITORIES but instead C2R fails with:

convert2rhel("-y --no-rhsm --enablerepo fake-rhel-8-for-x86_64-baseos-rpms --debug", unregister=True)

(ERROR) REMOVE_SPECIAL_PACKAGES::SPECIAL_PACKAGE_REMOVAL_FAILED - Failed to
remove some packages necessary for the conversion.
Description: The cause of this error is unknown, please look at the
diagnosis for more information.
Diagnosis: Couldn't download the centos-
release-7-9.2009.2.el7.centos.x86_64 package. This means we will not be able to
do a complete rollback and may put the system in a broken state.
Check to make sure that the CentOS Linux repositories are enabled and the
package is updated to its latest version.

Venefilyn · 2024-10-22T12:53:20Z

The changes look great! I see the integration tests are failing and some of them related to the expected messages, maybe something got messed up? I can't see it. For example in integration tests in CentOS7 it expects to see CUSTOM_REPOSITORIES_ARE_VALID::UNABLE_TO_ACCESS_REPOSITORIES but instead C2R fails with:

convert2rhel("-y --no-rhsm --enablerepo fake-rhel-8-for-x86_64-baseos-rpms --debug", unregister=True)

(ERROR) REMOVE_SPECIAL_PACKAGES::SPECIAL_PACKAGE_REMOVAL_FAILED - Failed to
remove some packages necessary for the conversion.
Description: The cause of this error is unknown, please look at the
diagnosis for more information.
Diagnosis: Couldn't download the centos-
release-7-9.2009.2.el7.centos.x86_64 package. This means we will not be able to
do a complete rollback and may put the system in a broken state.
Check to make sure that the CentOS Linux repositories are enabled and the
package is updated to its latest version.

@SerCantus is it occurring in other PRs or in main?

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

This refactors the logging stages that we output when we log in specific files depending on what we are doing. Meaning that any changes that has to do with preparing or rollback will now output the stage within the logger formatter rather than leaving it up to each class E.g. any logs with "Prepare: text" or "Rollback: text" will now be handled at the log-level Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

This removes all the different task log calls that include the stage it should be in and instead relies on the logger to take care of it e.g. `.task("Convert: ...")` will now have `Convert:` removed Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

ConversionPhases is now moved outside of utils module so that it doesn't cause a circular import with logger module Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Signed-off-by: Freya Gustavsson <freya@spytec.se> Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

We didn't know what phase we were on before going into rollback. With this change it now keeps a (soft) linear history where each phase points to the previous one

Venefilyn · 2024-10-22T14:21:13Z

/packit test

SerCantus · 2024-10-24T09:02:31Z

@SerCantus is it occurring in other PRs or in main?

@Venefilyn I commented after reviewing this PR checks but I see other PRs have similar failures so it might not be caused by this one. After discussing, it might be related to some infra.

Venefilyn · 2024-10-24T11:25:29Z

Ack, feel free to approve and merge with squash

danmyway

Test failures unrelated.
There is a regression caused by #1288 reported under RHELC-1753

github-advanced-security bot found potential problems Sep 10, 2024

View reviewed changes

convert2rhel/logger.py Fixed Show fixed Hide fixed

r0x0d mentioned this pull request Sep 10, 2024

[RHELC-1507] Port environment variables to config file #1272

Merged

8 tasks

r0x0d force-pushed the refactor/logger-stages branch from 8d7ce2b to b48acf3 Compare September 11, 2024 18:21

r0x0d reviewed Sep 11, 2024

View reviewed changes

Venefilyn force-pushed the refactor/logger-stages branch from b48acf3 to 8002f6a Compare September 12, 2024 14:03

github-advanced-security bot found potential problems Sep 12, 2024

View reviewed changes

convert2rhel/utils/phase.py Fixed Show fixed Hide fixed

Venefilyn force-pushed the refactor/logger-stages branch from 8002f6a to 034d54a Compare September 12, 2024 14:07

github-advanced-security bot found potential problems Sep 12, 2024

View reviewed changes

convert2rhel/utils/phase.py Fixed Show fixed Hide fixed

Venefilyn force-pushed the refactor/logger-stages branch from 034d54a to ba181c1 Compare September 12, 2024 14:21

r0x0d reviewed Sep 12, 2024

View reviewed changes

Venefilyn force-pushed the refactor/logger-stages branch from ba181c1 to 183d94a Compare September 18, 2024 11:39

Venefilyn force-pushed the refactor/logger-stages branch from e272c18 to 3c97895 Compare September 19, 2024 11:32

Venefilyn added the tests/sanity PR ready to run the sanity test suit. Equivalent to `/packit test --labels sanity`. label Sep 19, 2024

Venefilyn force-pushed the refactor/logger-stages branch 2 times, most recently from 00ec140 to e7f77f1 Compare September 20, 2024 14:32

Venefilyn marked this pull request as ready for review September 23, 2024 09:31

Venefilyn requested a review from a team as a code owner September 23, 2024 09:31

hosekadam reviewed Sep 24, 2024

View reviewed changes

hosekadam approved these changes Sep 24, 2024

View reviewed changes

Venefilyn requested a review from a team as a code owner October 19, 2024 18:12

Venefilyn requested a review from SerCantus October 19, 2024 18:12

SerCantus reviewed Oct 21, 2024

View reviewed changes

Venefilyn added 17 commits October 22, 2024 15:30

refactor: move codebase to new logging syntax

2278430

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Change format to use new stages style

a04f4f4

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Fixed failing unit tests

b0829a1

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Added log phase to logger task output

57c8544

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

chore: Move phases to prevent circular import

9a375db

ConversionPhases is now moved outside of utils module so that it doesn't cause a circular import with logger module Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Removed convert2rhel logger from conftest

38e8481

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Set rollback phase on rollback

2289a93

Signed-off-by: Freya Gustavsson <freya@spytec.se> Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Log phases correctly

58c9146

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Set log_name to Prepare for pre PONR changes

cb0ef66

Signed-off-by: Freya Gustavsson <freya@venefilyn.se>

Remove leftover text task stage

9963858

feat: add phase name for analyze

bb04cee

fix: changed post PONR phase to 'final'

64b5df1

fix: handle rollback phases in messages

07c915c

We didn't know what phase we were on before going into rollback. With this change it now keeps a (soft) linear history where each phase points to the previous one

fix: Correctly get the stage we were at

82edefa

fix: Update phase from Final to Convert

943cec0

Venefilyn force-pushed the refactor/logger-stages branch from 03f291c to 943cec0 Compare October 22, 2024 13:30

danmyway approved these changes Oct 24, 2024

View reviewed changes

danmyway merged commit 261d533 into oamg:main Oct 24, 2024
45 of 53 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

refactor: Improved logger usage #1373

refactor: Improved logger usage #1373

Venefilyn commented Sep 10, 2024

r0x0d Sep 11, 2024

Venefilyn Sep 12, 2024 •

edited

Loading

r0x0d Sep 12, 2024

r0x0d Sep 12, 2024

Venefilyn Sep 12, 2024

r0x0d Sep 12, 2024

codecov bot commented Sep 18, 2024 •

edited

Loading

has-bot commented Sep 19, 2024

Venefilyn commented Sep 19, 2024

Venefilyn commented Sep 20, 2024

Venefilyn commented Sep 20, 2024

Venefilyn commented Sep 20, 2024

Venefilyn commented Sep 20, 2024

Venefilyn commented Sep 20, 2024

Venefilyn commented Sep 23, 2024

hosekadam Sep 24, 2024

Venefilyn Sep 24, 2024

hosekadam Sep 24, 2024

hosekadam commented Sep 24, 2024

hosekadam left a comment

hosekadam commented Sep 24, 2024

Venefilyn commented Oct 18, 2024

Venefilyn commented Oct 19, 2024

Venefilyn commented Oct 20, 2024

SerCantus left a comment

Venefilyn commented Oct 22, 2024

Venefilyn commented Oct 22, 2024

SerCantus commented Oct 24, 2024 •

edited

Loading

Venefilyn commented Oct 24, 2024

danmyway left a comment

	ROLLBACK = (ConversionPhase(name="ROLLBACK", log_name="Rollback"),)
	ROLLBACK = ConversionPhase(name="ROLLBACK", log_name="Rollback")

refactor: Improved logger usage #1373

refactor: Improved logger usage #1373

Conversation

Venefilyn commented Sep 10, 2024

Choose a reason for hiding this comment

Venefilyn Sep 12, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

codecov bot commented Sep 18, 2024 • edited Loading

Codecov Report

has-bot commented Sep 19, 2024

Venefilyn commented Sep 19, 2024

Venefilyn commented Sep 20, 2024

Venefilyn commented Sep 20, 2024

Venefilyn commented Sep 20, 2024

Venefilyn commented Sep 20, 2024

Venefilyn commented Sep 20, 2024

Venefilyn commented Sep 23, 2024

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

hosekadam commented Sep 24, 2024

hosekadam left a comment

Choose a reason for hiding this comment

hosekadam commented Sep 24, 2024

Venefilyn commented Oct 18, 2024

Venefilyn commented Oct 19, 2024

Venefilyn commented Oct 20, 2024

SerCantus left a comment

Choose a reason for hiding this comment

Venefilyn commented Oct 22, 2024

Venefilyn commented Oct 22, 2024

SerCantus commented Oct 24, 2024 • edited Loading

Venefilyn commented Oct 24, 2024

danmyway left a comment

Choose a reason for hiding this comment

Venefilyn Sep 12, 2024 •

edited

Loading

codecov bot commented Sep 18, 2024 •

edited

Loading

SerCantus commented Oct 24, 2024 •

edited

Loading