Thread: Slow switching of Views - Long thread
View Single Post
Old 03-05-2022, 03:32 PM   #23
nikosan
Connoisseur
nikosan doesn't litternikosan doesn't litter
 
Posts: 61
Karma: 198
Join Date: Feb 2022
Device: Kobo Sage (prev. Kindle PW5)
Quote:
Originally Posted by BetterRed View Post
One other suggestion, have you tried running calibre in Windows Safe Mode. I can't imagine how, but maybe a 3rd party gadget/extension/add-on is sticking its spoon into the pudding
Good suggestion. I tried this, but got an error. It said my database is corrupt... so I couldn't access that library. It doesn't do that when I'm not in Safe Mode... Is this something I need to look into?? =/

Code:
Traceback (most recent call last):
  File "calibre\gui2\ui.py", line 853, in library_moved
  File "calibre\db\legacy.py", line 187, in __init__
  File "calibre\db\legacy.py", line 44, in create_backend
  File "calibre\db\backend.py", line 461, in __init__
  File "calibre\db\backend.py", line 1213, in user_version
  File "calibre\db\backend.py", line 926, in conn
  File "calibre\db\backend.py", line 339, in __init__
apsw.CantOpenError: CantOpenError: unable to open database file


Quote:
Originally Posted by JimmXinu View Post
I don't know if it will actually help any, but here's a quick and dirty version of VM that spits out some times between different events.

You have to run in debug to see the output and look at the code to see what it means, but it should pinpoint exactly where the time is going.

From VM's point of view that is.

I have every expectation that the longest time for basically everyone will be where I see it: "7.4" self.gui.library_view.apply_state(...) which sets the viewable columns and sorts.

Look for the self.print_timediff(...) calls in action.py.
Okay wow, thank you SO MUCH for doing this! I installed, manually CTRL+Tabbed through my VM views with no VL open, then clicked though my VL tabs (which have Action Chains associated w/ them), to compare the speeds between two. It actually does look like maybe the Action Chain switches have the biggest lag? I could have sworn there wasn’t much difference, but if I’m reading this right, it looks like there is. Maybe I've been looking for the cause of the lag in entirely the wrong place...

Code:
calibre Debug log
calibre 5.38 [64bit]  embedded-python: True is64bit: True
Windows-10-10.0.22000 Windows ('64bit', 'WindowsPE')
('Windows', '10', '10.0.22000')
Python 3.8.5
Windows: ('10', '10.0.22000', '', 'Multiprocessor Free')
Interface language: None
Successfully initialized third party plugins: Gather KFX-ZIP (from KFX Input) (1, 47, 0) && DeDRM (10, 0, 2) && Package KFX (from KFX Input) (1, 47, 0) && Action Chains (1, 16, 3) && Annotations (1, 16, 0) && Count Pages (1, 11, 2) && FanFicFare (4, 10, 0) && Generate Cover (2, 1, 0) && KFX metadata reader (from KFX Input) (1, 47, 0) && KFX Input (1, 47, 0) && Set KFX metadata (from KFX Output) (1, 59, 0) && KFX Output (1, 59, 0) && KindleUnpack - The Plugin (0, 83, 1) && Obok DeDRM (10, 0, 0) && Reading List (1, 8, 0) && SmartEject (2, 4, 0) && View Manager (1, 7, 0) && WordDumb (3, 18, 4)
calibre 5.38 [64bit]  embedded-python: True is64bit: True
Windows-10-10.0.22000 Windows ('64bit', 'WindowsPE')
('Windows', '10', '10.0.22000')
Python 3.8.5
Windows: ('10', '10.0.22000', '', 'Multiprocessor Free')
Interface language: None
Successfully initialized third party plugins: Gather KFX-ZIP (from KFX Input) (1, 47, 0) && DeDRM (10, 0, 2) && Package KFX (from KFX Input) (1, 47, 0) && Action Chains (1, 16, 3) && Annotations (1, 16, 0) && Count Pages (1, 11, 2) && FanFicFare (4, 10, 0) && Generate Cover (2, 1, 0) && KFX metadata reader (from KFX Input) (1, 47, 0) && KFX Input (1, 47, 0) && Set KFX metadata (from KFX Output) (1, 59, 0) && KFX Output (1, 59, 0) && KindleUnpack - The Plugin (0, 83, 1) && Obok DeDRM (10, 0, 0) && Reading List (1, 8, 0) && SmartEject (2, 4, 0) && View Manager (1, 7, 0) && WordDumb (3, 18, 4)
Turning on automatic hidpi scaling
devicePixelRatio: 1.0
logicalDpi: 96.0 x 96.0
physicalDpi: 95.81139489194499 x 95.9160839160839
Using calibre Qt style: True
[0.00] Starting up...
[0.01] Showing splash screen...
[0.44] splash screen shown
[0.44] Initializing db...
[0.47] db initialized
[0.47] Constructing main UI...
DEBUG:    0.0 Annotations plugin: Error loading libiMobileDevice. This hasn't worked for a while, and is blacklisted in calibre v3.
DEBUG:    0.0 Annotations plugin: Error is:  No module named 'calibre.devices.idevice'
DEBUG:    0.0 Annotations::reader_app_support.py - loading translations
DEBUG:    0.0 Annotations::common_utils.py - loading translations
DEBUG:    0.0 Annotations::appearance.py - loading translations
DEBUG:    0.0 Annotations::config.py - loading translations
DEBUG:    0.0 Annotations::annotated_books.py - loading translations
DEBUG:    0.0 Annotations::action.py - loading translations
DEBUG:    0.0 obok::utilities.py - loading translations
DEBUG:    0.0 obok::dialogs.py - loading translations
DEBUG:    0.0 obok::config.py - loading translations
DEBUG:    0.0 obok::action_err.py - loading translations
[2.41] main UI initialized...
[2.41] Hiding splash screen
Action chains: _call_plugins_action_chains_resources(): start
Action Chains: _call_plugins_action_chains_resources(): finished
Action chains: formulas: running on_templates_update()
Action chains: _call_plugins_on_modules_update(): start
Action Chains: _call_plugins_on_modules_update(): finished
Starting QuickView
[3.98] splash screen hidden
[3.98] Started up in 3.98 seconds with 227 books
switch_view(All Books)
1:0.0
2:0.0
3:0.0
4:0.0
5:0.0
6:0.0
7.1:0.0
7.2:0.0
7.3:0.0
7.4:0.0
7.5:0.0
7.6:0.0
7.10:0.0
7:0.0
8:0.03127121925354004
9:0.0
10:0.0
switch_view(Fanfic)
1:0.0
2:0.015655994415283203
3:0.06296420097351074
4:0.0
5:0.0
6:0.0
7.1:0.0
7.2:0.0
7.3:0.0
7.4:1.192173957824707
7.5:0.07853269577026367
7.6:0.0
7.10:0.0
7:0.0
8:0.031271934509277344
9:0.0
10:0.0
switch_view(Manga)
1:0.0
2:0.0
3:0.10957932472229004
4:0.0
5:0.0
6:0.0
7.1:0.0
7.2:0.0
7.3:0.0
7.4:1.117962121963501
7.5:0.0
7.6:0.0
7.10:0.0
7:0.0
8:0.03127408027648926
9:0.0
10:0.0
switch_view(Prose)
1:0.0010290145874023438
2:0.0
3:0.06935787200927734
4:0.0
5:0.0
6:0.0
7.1:0.0
7.2:0.0
7.3:0.0
7.4:0.12209963798522949
7.5:0.015333890914916992
7.6:0.0
7.10:0.0
7:0.0
8:0.031244516372680664
9:0.0
10:0.0
switch_view(All Books)
1:0.0
2:0.0
3:0.11008644104003906
4:0.0
5:0.0
6:0.0
7.1:0.0
7.2:0.0
7.3:0.0
7.4:0.7217462062835693
7.5:0.0
7.6:0.0
7.10:0.0
7:0.0
8:0.03124237060546875
9:0.0
10:0.0
switch_view(Manga)
1:0.0
2:0.0
3:0.09266543388366699
4:0.0
5:0.0
6:0.0
7.1:0.0
7.2:0.0
7.3:0.0
7.4:0.8940434455871582
7.5:0.0
7.6:0.0
7.10:0.0
7:0.0
8:0.03124237060546875
9:0.0
10:0.0
switch_view(Fanfic)
1:0.0
2:0.0
3:0.07855987548828125
4:0.0
5:0.0
6:0.0
7.1:0.0
7.2:0.0
7.3:0.0
7.4:1.535933256149292
7.5:0.0
7.6:0.0
7.10:0.0
7:0.0
8:0.03168678283691406
9:0.0
10:0.0
switch_view(Prose)
1:0.0
2:0.0
3:0.15700888633728027
4:0.0
5:0.0
6:0.0
7.1:0.0
7.2:0.0
7.3:0.0
7.4:1.6943953037261963
7.5:0.015617609024047852
7.6:0.0
7.10:0.0
7:0.0
8:0.03121209144592285
9:0.0
10:0.005539655685424805
switch_view(All Books)
1:0.0
2:0.0
3:0.09420442581176758
4:0.0
5:0.0
6:0.0
7.1:0.0
7.2:0.0
7.3:0.0
7.4:0.7216336727142334
7.5:0.0
7.6:0.0
7.10:0.0
7:0.0
8:0.03173184394836426
9:0.0
10:0.0
Action Chains: Starting event: VL Tab Changed
Action chains: formulas: running on_templates_update()
calling method (init_cache) of obj (selection_count)
Action chains: formulas: running on_templates_update()
calling method (flush_cache) of obj (selection_count)
Action Chains: Starting chain: VL View
Action Chains: VL View: starting action No. 1: Switch To VL View
debug1: vl: Fanfiction
debug2: view: Fanfic
7.1:5.5109899044036865
7.2:0.0
7.3:0.0
7.4:2.2270941734313965
7.5:0.0
7.6:0.0
7.10:0.0
Action Chains: chain (VL View) finished in: 0:00:02.496662
Action Chains: Is db modified by event: True
Action Chains: event (VL Tab Changed) finished in: 0:00:02.513281
Action Chains: Signal vl_tab_changed emitted
Action Chains: Starting event: VL Tab Changed
Action chains: formulas: running on_templates_update()
calling method (init_cache) of obj (selection_count)
Action chains: formulas: running on_templates_update()
calling method (flush_cache) of obj (selection_count)
Action Chains: Starting chain: VL View
Action Chains: VL View: starting action No. 1: Switch To VL View
debug1: vl: Manga
debug2: view: Manga
7.1:2.437694787979126
7.2:0.0
7.3:0.0
7.4:1.8519632816314697
7.5:0.0
7.6:0.0
7.10:0.0
Action Chains: chain (VL View) finished in: 0:00:02.040398
Action Chains: Is db modified by event: True
Action Chains: event (VL Tab Changed) finished in: 0:00:02.056019
Action Chains: Signal vl_tab_changed emitted
Action Chains: Starting event: VL Tab Changed
Action chains: formulas: running on_templates_update()
calling method (init_cache) of obj (selection_count)
Action chains: formulas: running on_templates_update()
calling method (flush_cache) of obj (selection_count)
Action Chains: Starting chain: VL View
Action Chains: VL View: starting action No. 1: Switch To VL View
debug1: vl: Prose
debug2: view: Prose
7.1:3.3334391117095947
7.2:0.0
7.3:0.0
7.4:0.21960043907165527
7.5:0.0
7.6:0.0
7.10:0.0
Action Chains: chain (VL View) finished in: 0:00:00.423471
Action Chains: Is db modified by event: True
Action Chains: event (VL Tab Changed) finished in: 0:00:00.439093
Action Chains: Signal vl_tab_changed emitted
Action Chains: Starting event: VL Tab Changed
Action chains: formulas: running on_templates_update()
calling method (init_cache) of obj (selection_count)
Action chains: formulas: running on_templates_update()
calling method (flush_cache) of obj (selection_count)
Action Chains: Starting chain: VL View
Action Chains: VL View: starting action No. 1: Switch To VL View
debug1: vl: _ALL_BOOKS
debug2: view: All Books
7.1:3.4159934520721436
7.2:0.0
7.3:0.0
7.4:0.7062489986419678
7.5:0.0
7.6:0.0
7.10:0.0
Action Chains: chain (VL View) finished in: 0:00:01.015570
Action Chains: Is db modified by event: True
Action Chains: event (VL Tab Changed) finished in: 0:00:01.033187
Action Chains: Signal vl_tab_changed emitted
Action Chains: Starting event: VL Tab Changed
Action chains: formulas: running on_templates_update()
calling method (init_cache) of obj (selection_count)
Action chains: formulas: running on_templates_update()
calling method (flush_cache) of obj (selection_count)
Action Chains: Starting chain: VL View
Action Chains: VL View: starting action No. 1: Switch To VL View
debug1: vl: Manga
debug2: view: Manga
7.1:6.749933481216431
7.2:0.0
7.3:0.0
7.4:1.3303160667419434
7.5:0.015621662139892578
7.6:0.0
7.10:0.0
Action Chains: chain (VL View) finished in: 0:00:01.506669
Action Chains: Is db modified by event: True
Action Chains: event (VL Tab Changed) finished in: 0:00:01.526304
Action Chains: Signal vl_tab_changed emitted
Action Chains: Starting event: VL Tab Changed
Action chains: formulas: running on_templates_update()
calling method (init_cache) of obj (selection_count)
Action chains: formulas: running on_templates_update()
calling method (flush_cache) of obj (selection_count)
Action Chains: Starting chain: VL View
Action Chains: VL View: starting action No. 1: Switch To VL View
debug1: vl: _ALL_BOOKS
debug2: view: All Books
7.1:2.164708375930786
7.2:0.0
7.3:0.0
7.4:0.9017114639282227
7.5:0.007542610168457031
7.6:0.0
7.10:0.0
Action Chains: chain (VL View) finished in: 0:00:01.199462
Action Chains: Is db modified by event: True
Action Chains: event (VL Tab Changed) finished in: 0:00:01.217078
Action Chains: Signal vl_tab_changed emitted
Action Chains: Starting event: VL Tab Changed
Action chains: formulas: running on_templates_update()
calling method (init_cache) of obj (selection_count)
Action chains: formulas: running on_templates_update()
calling method (flush_cache) of obj (selection_count)
Action Chains: Starting chain: VL View
Action Chains: VL View: starting action No. 1: Switch To VL View
debug1: vl: Prose
debug2: view: Prose
7.1:2.987982988357544
7.2:0.0
7.3:0.0
7.4:1.4749689102172852
7.5:0.0
7.6:0.0
7.10:0.0
Action Chains: chain (VL View) finished in: 0:00:01.695132
Action Chains: Is db modified by event: True
Action Chains: event (VL Tab Changed) finished in: 0:00:01.710650
Action Chains: Signal vl_tab_changed emitted
Action Chains: Starting event: VL Tab Changed
Action chains: formulas: running on_templates_update()
calling method (init_cache) of obj (selection_count)
Action chains: formulas: running on_templates_update()
calling method (flush_cache) of obj (selection_count)
Action Chains: Starting chain: VL View
Action Chains: VL View: starting action No. 1: Switch To VL View
debug1: vl: Fanfiction
debug2: view: Fanfic
7.1:2.9287922382354736
7.2:0.0
7.3:0.0
7.4:2.2907092571258545
7.5:0.012963533401489258
7.6:0.0
7.10:0.0
Action Chains: chain (VL View) finished in: 0:00:02.619679
Action Chains: Is db modified by event: True
Action Chains: event (VL Tab Changed) finished in: 0:00:02.641620
Action Chains: Signal vl_tab_changed emitted
Action Chains: Starting event: VL Tab Changed
Action chains: formulas: running on_templates_update()
calling method (init_cache) of obj (selection_count)
Action chains: formulas: running on_templates_update()
calling method (flush_cache) of obj (selection_count)
Action Chains: Starting chain: VL View
Action Chains: VL View: starting action No. 1: Switch To VL ViewTraceback (most recent call last):
  File "calibre\gui2\ui.py", line 135, in __init__
  File "calibre\gui2\ui.py", line 153, in init_iaction
  File "calibre_plugins.fanficfare_plugin.__init__", line 121, in load_actual_plugin
  File "calibre\customize\__init__.py", line 624, in load_actual_plugin
  File "importlib\__init__.py", line 127, in import_module
  File "<frozen importlib._bootstrap>", line 1014, in _gcd_import
  File "<frozen importlib._bootstrap>", line 991, in _find_and_load
  File "<frozen importlib._bootstrap>", line 975, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 671, in _load_unlocked
  File "calibre\customize\zipplugin.py", line 191, in exec_module
  File "calibre_plugins.fanficfare_plugin.fff_plugin", line 80, in <module>
  File "<frozen importlib._bootstrap>", line 991, in _find_and_load
  File "<frozen importlib._bootstrap>", line 975, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 655, in _load_unlocked
  File "<frozen importlib._bootstrap>", line 618, in _load_backward_compatible
  File "zipimport.py", line 259, in load_module
  File "C:\Users\jnikk\AppData\Roaming\calibre\plugins\FanFicFare.zip\fanficfare\adapters\__init__.py", line 132, in <module>
  File "<frozen importlib._bootstrap>", line 991, in _find_and_load
  File "<frozen importlib._bootstrap>", line 971, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 914, in _find_spec
  File "<frozen importlib._bootstrap_external>", line 1342, in find_spec
  File "<frozen importlib._bootstrap_external>", line 1316, in _get_spec
  File "<frozen importlib._bootstrap_external>", line 1297, in _legacy_get_spec
  File "<frozen importlib._bootstrap>", line 414, in spec_from_loader
  File "<frozen importlib._bootstrap_external>", line 649, in spec_from_file_location
  File "zipimport.py", line 191, in get_filename
  File "zipimport.py", line 709, in _get_module_code
  File "zipimport.py", line 536, in _get_data
PermissionError: [Errno 13] Permission denied: 'C:\\Users\\jnikk\\AppData\\Roaming\\calibre\\plugins\\FanFicFare.zip'

debug1: vl: Prose
debug2: view: Prose
7.1:2.425004005432129
7.2:0.0
7.3:0.0
7.4:2.5235352516174316
7.5:0.0
7.6:0.0
7.10:0.0
Action Chains: chain (VL View) finished in: 0:00:02.805604
Action Chains: Is db modified by event: True
Action Chains: event (VL Tab Changed) finished in: 0:00:02.821227
Action Chains: Signal vl_tab_changed emitted
nikosan is offline   Reply With Quote