Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Quality-of-Life 0: Logging (log-to-file, color in cli, formatting, other minor changes) #148

Open
wants to merge 12 commits into
base: rewrite
Choose a base branch
from

Conversation

bilditup1
Copy link
Contributor

@bilditup1 bilditup1 commented Nov 26, 2023

This PR does a few things on the server side, not to the core functionality at all but mainly consists of what I think are enhancements to the logging; my hope is you agree. I tried not to change the look of the UI and nor did I refactor any code out. I also tried to adhere to the existing naming conventions of variables and functions--point is I'm not trying to step on your toes, but think this might be nice.

Anyway, here's what this does:

  • Enables logging to a file named "nxdt_host_DATE_TIME.log" located in target root. This is toggleable from the CLI using the new flag "-l" and in the GUI from a new checkbox (which is enabled by default).
  • Enables logging in color in console mode, if the console can handle ANSI command codes, corresponding to the colors already chosen for the UI.
  • Prepends the ISO-8601ish date and square-bracketed loglevel to each line of the log during CLI and file logging.
    • Leading and trailing newlines are taken into consideration and processed appropriately by the prepending logic. Other newlines are not (they weren't used at all and arguably shouldn't be) but push comes to shove this should be tractable.
    • This can be made optional from the command-line easily enough, but would begin to clutter up the GUI, so I decided not to implement this until I had a clearer idea of what you wanted out of the GUI/how you wanted to go about it/how acceptable this PR is, etc.
  • Logs some basic environmental and configuration information on script start and on successful connection.
  • Beginning and end of transfer session now logged now appear more prominently.
  • Some basic info listed at the beginning of each transfer:
    • Either the source partition (in case of extracted FS) or the path (in every other case)
    • The total size of the transfer in human-readable format.
      • In verbose/debug mode, these are omitted.
  • During NSP and extracted FS transfers, the path of each constituent file followed by its human-readable size in parentheses appears slightly indented and without the redundant (to the user) target directory, which should give a good idea of both the directory tree and some granular idea of transfer progress generally, especially during extracted FS transfers.
  • At the end of each session, the total size of the transfer and the time it took (in seconds if it took less than 60, in formatted [h:mm:ss] if it took longer) is listed.
    • If the transfer took at least two seconds, the average transfer rate is listed as well.

Other minor changes:
-The bottom padding of elements at the bottom of the GUI are now tied to the font size; this is slightly cleaner-looking.
-The choose-directory prompt, instead of being seeded with the same root directory each time, will start from the last directory that was successfully submitted to it since the beginning of the program. If that directory was moved or deleted, then it will revert back to the default behavior.
-Refactored my earlier path-fixing code on Windows, removed it from one spot entirely (it was redundant, and so, prepended the magic string twice) and added references. Also, the paths aren't '32-bit' as I wrote earlier, but rather ~32,767 2-byte characters long.

I will also add logs and screenshots momentarily.

Limitations and possible pitfalls:

  • I may have screwed up some variable scoping, which I'm not totally confident in.
  • Some of my comments are long. Maybe should use docstrings?
  • Probably there is more refactoring that can be done, mainly around the end-of-transfer log stuff, since this has to be done in three different places (individual files, NSP, and extracted FS) and what is done is broadly similar with only some differences, but maybe other places.
  • Timestamp prepending I thought wasn't too ugly and generally I am glad to have not had to resort to any regexes, but maybe you have a better way of handling this?
  • I have only been able to test with my personal machine running Windows 11 and Python 3.11 and 3.12. I don't expect major issues but of course that's the entire point of testing...ETA: I basically assumed that any modern *nix terminal can handle ANSI control characters and color output, and have no idea if this is actually true.

Otherwise, my preference is, uh, not to maintain and sync a fork for the sake of these cosmetic changes, so if there is something unacceptable here (or hell, even if it's all trash), please let me know, and maybe I could make it right. Otherwise, thanks again for your time and your support of this project!

@bilditup1 bilditup1 changed the title Qo l0 server log Quality-of-Life 0: Logging (log-to-file, color in cli, formatting, other minor changes) Nov 26, 2023
@bilditup1
Copy link
Contributor Author

bilditup1 commented Nov 26, 2023

Failed to account for all cases of extracted FS (hard crashes); working on it but as of now this is no longer ready.
申し訳ありません

@DarkMatterCore DarkMatterCore added the enhancement New feature or request label Nov 26, 2023
@DarkMatterCore
Copy link
Owner

DarkMatterCore commented Nov 26, 2023

Thanks for the PR!

I'll take a better look at the changes over the course of the next week. For the time being, just making the minimum changes needed to resolve the current merge conflicts should be alright. If any additional changes are needed, I'll just submit a review.

I may have screwed up some variable scoping, which I'm not totally confident in.

Static analysis tools should tell you about it, and it's usually not that hard to fix. But as I said before, I'll take a better look at the changes at a later time.

Timestamp prepending I thought wasn't too ugly and generally I am glad to have not had to resort to any regexes, but maybe you have a better way of handling this?

Personally, I would stick to the timestamp format used by nxdumptool logfile entries, which encloses the timestamp itself between brackets followed by the uppercase log level name, also enclosed between brackets:

[2023-11-26 17:31:00.088721672] [INFO] /source/core/nxdt_utils.c:151:utilsInitializeResources -> nxdt_rw_poc v2.0.0 starting (rewrite-315a052-dirty). Built on 2023-11-11 20:53:37 UTC.
[2023-11-26 17:31:00.088764468] [INFO] /source/core/nxdt_utils.c:153:utilsInitializeResources -> Horizon OS version: 17.0.0.
[2023-11-26 17:31:00.088900240] [INFO] /source/core/services.c:258:servicesGetExosphereApiVersion -> Exosphère API version: 1.6.2.

I generally avoid using tab characters (\t) unless extremely necessary.

That being said, I'd probably use list comprehension for that part of the code:

    def format_message(self, record: logging.LogRecord) -> str:
        content = self.format(record)
        timestamp = datetime.now().strftime('%Y-%m-%d %H:%M:%S.%f')
        prepend = f'[{timestamp}] [{record.levelname}] '
        return '\n'.join([(prepend + part) for part in content.split('\n') if part.strip()])

This essentially generates a log entry with a format that mimics nxdumptool's logfile.

@bilditup1
Copy link
Contributor Author

Thanks for the PR!

Yeah!

I'll take a better look at the changes over the course of the next week. For the time being, just making the minimum changes needed to resolve the current merge conflicts should be alright. If any additional changes are needed, I'll just submit a review.

Yeah just glancing, looks like you turned on all the previously commented-out asserts, some changes in variable declarations, maybe some other things, not too bad

I may have screwed up some variable scoping, which I'm not totally confident in.

Static analysis tools should tell you about it, and it's usually not that hard to fix. But as I said before, I'll take a better look at the changes at a later time.

Aye aye cap'n.

Personally, I would stick to the timestamp format used by nxdumptool logfile entries, which encloses the timestamp itself between brackets followed by the uppercase log level name, also enclosed between brackets:

Ah! Yes I remember you mentioned that it also logged, somehow did not occur to me to look at how that worked...

[2023-11-26 17:31:00.088721672] [INFO] /source/core/nxdt_utils.c:151:utilsInitializeResources -> nxdt_rw_poc v2.0.0 starting (rewrite-315a052-dirty). Built on 2023-11-11 20:53:37 UTC.
[2023-11-26 17:31:00.088764468] [INFO] /source/core/nxdt_utils.c:153:utilsInitializeResources -> Horizon OS version: 17.0.0.
[2023-11-26 17:31:00.088900240] [INFO] /source/core/services.c:258:servicesGetExosphereApiVersion -> Exosphère API version: 1.6.2.

I generally avoid using tab characters (\t) unless extremely necessary.

Noted, noted. Don't have any particular thoughts about bracketing the timestamp but the extra five characters of precision for the second seems like a bit much for most users--maybe this can continue to be truncated, except e.g. in verbose/debug mode? As for the tabs, I think GUI mode especially benefits from their use--I wouldn't characterize it as 'extremely necessary' by any means but the whitespace does wonders for readability, I find. That said, try it, etc.

That being said, I'd probably use list comprehension for that part of the code:

    def format_message(self, record: logging.LogRecord) -> str:
        content = self.format(record)
        timestamp = datetime.now().strftime('%Y-%m-%d %H:%M:%S.%f')
        prepend = f'[{timestamp}] [{record.levelname}] '
        return '\n'.join([(prepend + part) for part in content.split('\n') if part.strip()])

This is so clean!!!!

Otherwise I fixed the issue with raw HFS dumps and will at least get that out now

@bilditup1
Copy link
Contributor Author

bilditup1 commented Dec 4, 2023

I've changed the way transfer logging works in the 'general case' (not extractedFS or NSP) and also attempted to reconcile with upstream, but upstream changed since last I looked so I'll have to do that again. There's also one assert, g_stopEvent is not None in usbGetDeviceEndpoints(), that prevents cli mode from working.
This also accounts for one case I had missed (because I didn't understand how to trigger it). While everything 'works' now, I think this part of the printing mechanism may be brittle and feels kind of ugly/hacky. That said, feels streamlinable too, so I will try to get on that as well. Apologies for not getting back to this sooner.

@bilditup1
Copy link
Contributor Author

Also: I am realizing that match/case is a Python 3.10+ feature. This will put nxdt out of reach of people with older systems, and the fact that you're checking for Vista and 7 (which only got official support up to 3.9 iirc) seems to suggest to me that this matters to you. If so I'll have to redo...a lot of things, I suppose

@bilditup1
Copy link
Contributor Author

bilditup1 commented Dec 5, 2023

While it now reports no conflicts, do not attempt to run yet. While some changes were of no consequence most need to now be reapplied.

@bilditup1
Copy link
Contributor Author

Added changes back without issue.

@bilditup1
Copy link
Contributor Author

After further testing, the approach taken of making the Windows path change as early instead of as late as possible has the consequence of every subsequent path set with g_outputDir as an input being mangled by os.path.abspath into a path that has all forward-slashes, including in the magic Windows prefix, when run in the MSYS2 environment CLI in Windows. I have reverted the behavior back and am testing again now. (I have also dispensed with removal of the Windows prefix when printing in verbose/debug mode as well, since that's precisely when we'd want to have that kind of information.)

@bilditup1
Copy link
Contributor Author

bilditup1 commented Dec 9, 2023

After further testing it appears that, longfile name syntax or not, MSYS2 or not, Windows appears to have the same 255 character/byte limit as other filesystems/operating systems do for the length of any individual file or folder in a given path. I didn't see official documentation of such a limitation but it's clear that it's there. While severely unlikely, sanitizing the user-entered path when entered from CLI would seem like a good idea for all systems; will try to get on this soon

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants