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

New formats for the logging instances #3639

Merged
merged 1 commit into from
Oct 16, 2020

Conversation

ferdnyc
Copy link
Contributor

@ferdnyc ferdnyc commented Aug 2, 2020

The fixed-width component of our logging format, with the first 12 characters being devoted to the module name, was fine when the module names were all short, like most of openshot_qt.classes. It meant that everything would line up nicely in the output.

But now that most of our module names are longer than 12 characters (like basically every other name except export), it's just silly. Nothing really lines up anyway, and the indentation just means that the few modules with short names are wasting space at the start of their log lines.

So, this PR proposes to change the format to place the log level before the module name, with everything taking only the space it requires. I tried a couple of different formats:

LEVEL[module_name]: message
LEVEL module_name: message

and decided I found the second one more readable and less "busy".

It also sets a separate formatter for the logfile output, turning on HH:MM:SS timestamps only for the logs written to disk (not the runtime console output).

With this change, starting up OpenShot on my system goes from this:

Loaded modules from: /home/ferd/rpmbuild/REPOS/openshot-qt/worktree-develop/src
         app:INFO ------------------------------------------------
         app:INFO             Sat Aug  1 23:17:04 2020            
         app:INFO               Starting new session              
         app:INFO ------------------------------------------------
         app:INFO          OpenShot (version 2.5.1-dev2)          
         app:INFO ------------------------------------------------
         app:INFO openshot-qt version: 2.5.1-dev2
         app:INFO libopenshot version: 0.2.5-dev2
         app:INFO platform: Linux-5.7.10-201.fc32.x86_64-x86_64-with-glibc2.2.5
         app:INFO processor: x86_64
         app:INFO machine: x86_64
         app:INFO python version: 3.8.5
         app:INFO qt5 version: 5.14.2
         app:INFO pyqt5 version: 5.14.2
     metrics:ERROR Error determining OS version in metrics.py: 
Traceback (most recent call last):
  File "/home/ferd/rpmbuild/REPOS/openshot-qt/worktree-develop/src/classes/metrics.py", line 65, in <module>
    linux_distro = "-".join(platform.linux_distribution())
AttributeError: module 'platform' has no attribute 'linux_distribution'
    language:INFO Qt Detected Languages: ['en-US']
    language:INFO LANG Environment Variable: en_US.utf8
    language:INFO LOCALE Environment Variable: 
    language:INFO OpenShot Preference Language: Default
project_data:INFO Loaded user project defaults from /home/ferd/.openshot_qt/default.project
project_data:INFO Setting default profile to HD 1080p 30 fps
         app:INFO Setting font to /home/ferd/rpmbuild/REPOS/openshot-qt/worktree-develop/src/images/fonts/Ubuntu-R.ttf
logger_libopenshot:INFO Connecting to libopenshot with debug port: 5556
         app:INFO Setting custom dark theme
     ui_util:INFO Initializing UI for MainWindow
 files_model:INFO updating files model.
 files_model:INFO updating files model.
transition_model:INFO updating transitions model.
     version:INFO Found current version: {"openshot_version": "2.5.1"}
transition_model:INFO updating transitions model.
effects_model:INFO updating effects model.
effects_model:INFO updating effects model.
 emoji_model:INFO updating emoji model.
properties_model:INFO updating clip properties model.
 main_window:INFO InitCacheSettings
 main_window:INFO cache-mode: CacheMemory
 main_window:INFO cache-limit-mb: 2500
 main_window:INFO Creating CacheMemory object with 2621440000 byte limit
 main_window:INFO Clear all thumbnails: /home/ferd/.openshot_qt/thumbnail
preview_thread:INFO QThread Start Method Invoked
preview_thread:INFO initPlayer
 main_window:INFO Clear all animations: /home/ferd/.openshot_qt/blender
 main_window:INFO Clear all titles: /home/ferd/.openshot_qt/title
 main_window:INFO updateStatusChanged
 main_window:INFO updateStatusChanged
         app:INFO Process command-line arguments: ['./launch.py']
 main_window:INFO recover_backup
project_data:INFO Loaded user project defaults from /home/ferd/.openshot_qt/default.project
project_data:INFO Setting default profile to HD 1080p 30 fps
preview_thread:INFO refreshFrame
preview_thread:INFO self.player.Position(): 1
 files_model:INFO updating files model.
video_widget:INFO Load: Set video widget display aspect ratio to: 1.7777777910232544
video_widget:INFO Set video widget pixel aspect ratio to: 1.0
 main_window:INFO updateStatusChanged
 main_window:INFO foundCurrentVersion: Found the latest version: 2.5.1
preview_thread:INFO onModeChanged
properties_model:INFO Update item: 
properties_model:INFO updating clip properties model.
preview_thread:INFO refreshFrame
preview_thread:INFO self.player.Position(): 1
    timeline:INFO Adjusting max size of preview image: PyQt5.QtCore.QSize(396, 223)
preview_thread:INFO refreshFrame
preview_thread:INFO self.player.Position(): 1
timeline_webview:INFO Qt Found!
timeline_webview:INFO $scope.Qt = true;
timeline_webview:INFO setThumbAddress: http://127.0.0.1:47297/thumbnails/
timeline_webview:INFO updateLayerIndex
timeline_webview:INFO sortItems
timeline_webview:INFO updateLayerIndex
timeline_webview:INFO updateLayerIndex

To this:

Loaded modules from: /home/ferd/rpmbuild/REPOS/openshot-qt/worktree-develop/src
INFO app: ------------------------------------------------
INFO app:             Sat Aug  1 23:17:41 2020            
INFO app:               Starting new session              
INFO app: ------------------------------------------------
INFO app:          OpenShot (version 2.5.1-dev2)          
INFO app: ------------------------------------------------
INFO app: openshot-qt version: 2.5.1-dev2
INFO app: libopenshot version: 0.2.5-dev2
INFO app: platform: Linux-5.7.10-201.fc32.x86_64-x86_64-with-glibc2.2.5
INFO app: processor: x86_64
INFO app: machine: x86_64
INFO app: python version: 3.8.5
INFO app: qt5 version: 5.14.2
INFO app: pyqt5 version: 5.14.2
ERROR metrics: Error determining OS version in metrics.py: 
Traceback (most recent call last):
  File "/home/ferd/rpmbuild/REPOS/openshot-qt/worktree-develop/src/classes/metrics.py", line 65, in <module>
    linux_distro = "-".join(platform.linux_distribution())
AttributeError: module 'platform' has no attribute 'linux_distribution'
INFO language: Qt Detected Languages: ['en-US']
INFO language: LANG Environment Variable: en_US.utf8
INFO language: LOCALE Environment Variable: 
INFO language: OpenShot Preference Language: Default
INFO project_data: Loaded user project defaults from /home/ferd/.openshot_qt/default.project
INFO project_data: Setting default profile to HD 1080p 30 fps
INFO app: Setting font to /home/ferd/rpmbuild/REPOS/openshot-qt/worktree-develop/src/images/fonts/Ubuntu-R.ttf
INFO logger_libopenshot: Connecting to libopenshot with debug port: 5556
INFO app: Setting custom dark theme
INFO ui_util: Initializing UI for MainWindow
INFO files_model: updating files model.
INFO files_model: updating files model.
INFO transition_model: updating transitions model.
INFO version: Found current version: {"openshot_version": "2.5.1"}
INFO transition_model: updating transitions model.
INFO effects_model: updating effects model.
INFO effects_model: updating effects model.
INFO emoji_model: updating emoji model.
INFO properties_model: updating clip properties model.
INFO main_window: InitCacheSettings
INFO main_window: cache-mode: CacheMemory
INFO main_window: cache-limit-mb: 2500
INFO main_window: Creating CacheMemory object with 2621440000 byte limit
INFO main_window: Clear all thumbnails: /home/ferd/.openshot_qt/thumbnail
INFO preview_thread: QThread Start Method Invoked
INFO preview_thread: initPlayer
INFO main_window: Clear all animations: /home/ferd/.openshot_qt/blender
INFO main_window: Clear all titles: /home/ferd/.openshot_qt/title
INFO main_window: updateStatusChanged
INFO main_window: updateStatusChanged
INFO app: Process command-line arguments: ['./launch.py']
INFO main_window: recover_backup
INFO project_data: Loaded user project defaults from /home/ferd/.openshot_qt/default.project
INFO project_data: Setting default profile to HD 1080p 30 fps
INFO preview_thread: refreshFrame
INFO preview_thread: self.player.Position(): 1
INFO files_model: updating files model.
INFO video_widget: Load: Set video widget display aspect ratio to: 1.7777777910232544
INFO video_widget: Set video widget pixel aspect ratio to: 1.0
INFO main_window: updateStatusChanged
INFO main_window: foundCurrentVersion: Found the latest version: 2.5.1
INFO preview_thread: onModeChanged
INFO properties_model: Update item: 
INFO properties_model: updating clip properties model.
INFO preview_thread: refreshFrame
INFO preview_thread: self.player.Position(): 1
INFO timeline: Adjusting max size of preview image: PyQt5.QtCore.QSize(396, 223)
INFO preview_thread: refreshFrame
INFO preview_thread: self.player.Position(): 1
INFO timeline_webview: Qt Found!
INFO timeline_webview: $scope.Qt = true;
INFO timeline_webview: setThumbAddress: http://127.0.0.1:39577/thumbnails/
INFO timeline_webview: updateLayerIndex
INFO timeline_webview: sortItems
INFO timeline_webview: updateLayerIndex
INFO timeline_webview: updateLayerIndex

With the logfile containing, for the same period:

23:17:41 INFO app: ------------------------------------------------
23:17:41 INFO app:             Sat Aug  1 23:17:41 2020            
23:17:41 INFO app:               Starting new session              
23:17:41 INFO app: ------------------------------------------------
23:17:41 INFO app:          OpenShot (version 2.5.1-dev2)          
23:17:41 INFO app: ------------------------------------------------
23:17:41 INFO app: openshot-qt version: 2.5.1-dev2
23:17:41 INFO app: libopenshot version: 0.2.5-dev2
23:17:41 INFO app: platform: Linux-5.7.10-201.fc32.x86_64-x86_64-with-glibc2.2.5
23:17:41 INFO app: processor: x86_64
23:17:41 INFO app: machine: x86_64
23:17:41 INFO app: python version: 3.8.5
23:17:41 INFO app: qt5 version: 5.14.2
23:17:41 INFO app: pyqt5 version: 5.14.2
23:17:41 ERROR metrics: Error determining OS version in metrics.py: 
Traceback (most recent call last):
  File "/home/ferd/rpmbuild/REPOS/openshot-qt/worktree-develop/src/classes/metrics.py", line 65, in <module>
    linux_distro = "-".join(platform.linux_distribution())
AttributeError: module 'platform' has no attribute 'linux_distribution'
23:17:41 INFO language: Qt Detected Languages: ['en-US']
23:17:41 INFO language: LANG Environment Variable: en_US.utf8
23:17:41 INFO language: LOCALE Environment Variable: 
23:17:41 INFO language: OpenShot Preference Language: Default
23:17:41 INFO project_data: Loaded user project defaults from /home/ferd/.openshot_qt/default.project
23:17:41 INFO project_data: Setting default profile to HD 1080p 30 fps
23:17:41 INFO app: Setting font to /home/ferd/rpmbuild/REPOS/openshot-qt/worktree-develop/src/images/fonts/Ubuntu-R.ttf
23:17:41 INFO logger_libopenshot: Connecting to libopenshot with debug port: 5556
23:17:41 INFO app: Setting custom dark theme
23:17:41 INFO ui_util: Initializing UI for MainWindow
23:17:42 INFO files_model: updating files model.
23:17:42 INFO files_model: updating files model.
23:17:42 INFO transition_model: updating transitions model.
23:17:42 INFO version: Found current version: {"openshot_version": "2.5.1"}
23:17:42 INFO transition_model: updating transitions model.
23:17:42 INFO effects_model: updating effects model.
23:17:42 INFO effects_model: updating effects model.
23:17:42 INFO emoji_model: updating emoji model.
23:17:42 INFO properties_model: updating clip properties model.
23:17:42 INFO main_window: InitCacheSettings
23:17:42 INFO main_window: cache-mode: CacheMemory
23:17:42 INFO main_window: cache-limit-mb: 2500
23:17:42 INFO main_window: Creating CacheMemory object with 2621440000 byte limit
23:17:42 INFO main_window: Clear all thumbnails: /home/ferd/.openshot_qt/thumbnail
23:17:42 INFO preview_thread: QThread Start Method Invoked
23:17:42 INFO preview_thread: initPlayer
23:17:43 INFO main_window: Clear all animations: /home/ferd/.openshot_qt/blender
23:17:43 INFO main_window: Clear all titles: /home/ferd/.openshot_qt/title
23:17:43 INFO main_window: updateStatusChanged
23:17:43 INFO main_window: updateStatusChanged
23:17:43 INFO app: Process command-line arguments: ['./launch.py']
23:17:43 INFO main_window: recover_backup
23:17:43 INFO project_data: Loaded user project defaults from /home/ferd/.openshot_qt/default.project
23:17:43 INFO project_data: Setting default profile to HD 1080p 30 fps
23:17:43 INFO preview_thread: refreshFrame
23:17:43 INFO preview_thread: self.player.Position(): 1
23:17:43 INFO files_model: updating files model.
23:17:43 INFO video_widget: Load: Set video widget display aspect ratio to: 1.7777777910232544
23:17:43 INFO video_widget: Set video widget pixel aspect ratio to: 1.0
23:17:43 INFO main_window: updateStatusChanged
23:17:43 INFO main_window: foundCurrentVersion: Found the latest version: 2.5.1
23:17:43 INFO preview_thread: onModeChanged
23:17:43 INFO properties_model: Update item: 
23:17:43 INFO properties_model: updating clip properties model.
23:17:43 INFO preview_thread: refreshFrame
23:17:43 INFO preview_thread: self.player.Position(): 1
23:17:43 INFO timeline: Adjusting max size of preview image: PyQt5.QtCore.QSize(396, 223)
23:17:43 INFO preview_thread: refreshFrame
23:17:43 INFO preview_thread: self.player.Position(): 1
23:17:43 INFO timeline_webview: Qt Found!
23:17:43 INFO timeline_webview: $scope.Qt = true;
23:17:43 INFO timeline_webview: setThumbAddress: http://127.0.0.1:39577/thumbnails/
23:17:43 INFO timeline_webview: updateLayerIndex
23:17:43 INFO timeline_webview: sortItems
23:17:43 INFO timeline_webview: updateLayerIndex
23:17:43 INFO timeline_webview: updateLayerIndex

I don't find the loss of (very occasional) alignment really detracts from readability, and being able to see the message severity at a glance is actually helpful.

- Move level name in front of module name
- Enable timestamps in the logfile (only)
@jonoomph
Copy link
Member

No complains here, other than I hope it doesn't break some regex we use for parsing log files. No big deal though, let's merge it!

@jonoomph
Copy link
Member

Thanks!

@jonoomph jonoomph merged commit a07d24f into OpenShot:develop Oct 16, 2020
@ferdnyc ferdnyc deleted the reformat-log branch January 7, 2022 02:28
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants