[JimmXinu]

I was unable to run using CALIBRE_DEVELOP_FROM pointing to the current GitHub master. Unrelated to the issue I'm having, but thought you'd want to know. Details:

Spoiler:

I got a popup telling me there was an error and no GUI:

ERROR: Startup error: There was an error during calibre startup. Parts of calibre may not function. Click Show details to learn more.

Traceback (most recent call last):
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\gui2\main.py", line 289, in initialize_db_stage2
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\gui2\main.py", line 233, in start_gui
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\gui2\ui.py", line 247, in initialize
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\gui2\layout.py", line 332, in init_main_window_mixin
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\gui2\actions\fetch_news.py", line 32, in init_scheduler
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\gui2\dialogs\scheduler.py", line 586, in __init__
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\web\feeds\recipes\model.py", line 157, in __init__
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\web\feeds\recipes\model.py", line 226, in do_refresh
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\web\feeds\recipes\model.py", line 218, in factory
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\web\feeds\recipes\model.py", line 66, in __init__
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\utils\localization.py", line 379, in get_language
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\utils\localization.py", line 359, in get_iso_language
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\utils\localization.py", line 352, in _load_iso639
  File "C:\Users\jimm\Desktop\nook\calibre\src\calibre\utils\resources.py", line 75, in get_path
IOError: [Errno 2] No such file or directory: 'C:\\Users\\jimm\\Desktop\\nook\\calibre\\resources\\localization\\iso639.calibre_msgpack'

Going back to the v3.31.0 tag worked. I turned on cProfile around sync_booklists:

Spoiler:

import cProfile

def do_cprofile(func):
    def profiled_func(*args, **kwargs):
        profile = cProfile.Profile()
        try:
            profile.enable()
            result = func(*args, **kwargs)
            profile.disable()
            return result
        finally:
            profile.print_stats()
    return profiled_func
...
    @do_cprofile
    def sync_booklists(self, booklists, end_session=True):
        debug_print('USBMS: starting sync_booklists')
...

Results with new Kindle:

Spoiler:

DEBUG:   81.1 USBMS: starting sync_booklists
Job: 4 Upload one book to the device: Chimaera finished
No details available.
DEBUG:  345.5 USBMS: finished sync_booklists
         64872424 function calls (49010574 primitive calls) in 264.343 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        2    0.000    0.000    0.000    0.000 Queue.py:107(put)
        2    0.000    0.000    0.000    0.000 Queue.py:204(_put)
        2    0.000    0.000    0.000    0.000 __init__.py:178(prints)
        1    0.086    0.086    7.213    7.213 __init__.py:193(dumps)
   396501    0.095    0.000    0.156    0.000 __init__.py:640(isbytestring)
        1    0.000    0.000    0.030    0.030 __init__.py:720(fsync)
        1    0.000    0.000    0.000    0.000 _abcoll.py:548(update)
        1    0.000    0.000    0.000    0.000 _weakrefset.py:70(__contains__)
        1    0.000    0.000    0.000    0.000 abc.py:148(__subclasscheck__)
   473569    0.288    0.000    0.319    0.000 base.py:124(__getattribute__)
     5321    0.026    0.000    0.031    0.000 base.py:161(__setattr__)
   154309    0.074    0.000    0.268    0.000 base.py:213(get)
     5321    0.105    0.000    6.179    0.001 base.py:360(get_all_user_metadata)
     5318    0.457    0.000    1.145    0.000 base64.py:43(b64encode)
        1    0.000    0.000    0.000    0.000 collections.py:50(__init__)
       26    0.000    0.000    0.000    0.000 collections.py:71(__setitem__)
2742536/58498    2.833    0.000    6.074    0.000 copy.py:145(deepcopy)
  2261447    0.167    0.000    0.167    0.000 copy.py:198(_deepcopy_atomic)
    63816    0.064    0.000    0.180    0.000 copy.py:226(_deepcopy_list)
10076/5038    0.042    0.000    0.212    0.000 copy.py:234(_deepcopy_tuple)
233702/58498    0.887    0.000    5.952    0.000 copy.py:253(_deepcopy_dict)
  2579117    1.061    0.000    1.403    0.000 copy.py:267(_keep_alive)
10076/5038    0.035    0.000    0.239    0.000 copy.py:306(_reconstruct)
     5038    0.003    0.000    0.005    0.000 copy_reg.py:92(__newobj__)
        1    0.000    0.000    0.000    0.000 cp1252.py:14(decode)
    20974    0.037    0.000    0.117    0.000 date.py:187(isoformat)
        1    0.000    0.000    0.000    0.000 device.py:80(report_progress)
        2    0.000    0.000    0.000    0.000 driver.py:40(debug_print)
        1    0.003    0.003  264.343  264.343 driver.py:446(sync_booklists)
        3    0.008    0.003  264.308   88.103 driver.py:454(write_prefix)
        2    0.000    0.000    0.000    0.000 driver.py:481(path_to_unicode)
        2    0.000    0.000    0.000    0.000 driver.py:487(normalize_path)
        1    0.000    0.000    0.000    0.000 encoder.py:101(__init__)
        1    0.610    0.610    7.127    7.127 encoder.py:186(encode)
        1    0.000    0.000    0.000    0.000 encoder.py:212(iterencode)
     1067    0.001    0.000    0.002    0.000 encoder.py:236(floatstr)
        1    0.000    0.000    0.000    0.000 encoder.py:272(_make_iterencode)
7018795/6653880    1.009    0.000    5.599    0.000 encoder.py:288(_iterencode_list)
19207551/6653877    3.575    0.000    4.802    0.000 encoder.py:341(_iterencode_dict)
  6653880    0.780    0.000    6.379    0.000 encoder.py:417(_iterencode)
        1    0.000    0.000    0.000    0.000 field_metadata.py:30(_builtin_field_metadata)
        1    0.000    0.000    0.000    0.000 field_metadata.py:386(__init__)
    95778    0.032    0.000    0.032    0.000 field_metadata.py:409(__getitem__)
   154309    0.046    0.000    0.046    0.000 field_metadata.py:424(__contains__)
       26    0.000    0.000    0.000    0.000 field_metadata.py:660(_add_search_terms_to_map)
        2    0.000    0.000    0.000    0.000 genericpath.py:23(exists)
       21    0.000    0.000    0.000    0.000 gettext.py:219(ugettext)
        1    0.000    0.000    0.000    0.000 gettext.py:224(ungettext)
        1    0.000    0.000    0.000    0.000 json_codec.py:129(__init__)
        1    0.226    0.226  262.665  262.665 json_codec.py:132(encode_to_file)
        1    0.006    0.006    8.968    8.968 json_codec.py:136(encode_booklist_metadata)
     5321    0.067    0.000    8.960    0.002 json_codec.py:142(encode_book_metadata)
   159630    0.349    0.000    8.893    0.000 json_codec.py:148(encode_metadata_attr)
    21281    0.109    0.000    0.233    0.000 json_codec.py:30(datetime_to_string)
     5321    0.026    0.000    1.172    0.000 json_codec.py:43(encode_thumbnail)
206968/133025    0.206    0.000    0.370    0.000 json_codec.py:70(object_to_unicode)
        1    0.000    0.000    0.000    0.000 json_codec.py:72(dec)
    58498    0.042    0.000    0.056    0.000 json_codec.py:89(encode_is_multiple)
        2    0.000    0.000    0.000    0.000 mbcs.py:20(decode)
        1    0.000    0.000    0.000    0.000 ntpath.py:63(join)
        2    0.000    0.000    0.000    0.000 ntpath.py:96(splitdrive)
        2    0.000    0.000    0.000    0.000 os.py:444(__contains__)
        1    0.000    0.000    1.605    1.605 startup.py:114(local_open)
        2    0.000    0.000    0.000    0.000 threading.py:300(_is_owned)
        2    0.000    0.000    0.000    0.000 threading.py:373(notify)
    41138    0.005    0.000    0.005    0.000 tz.py:33(utcoffset)
    10082    0.001    0.000    0.001    0.000 tz.py:36(dst)
        1    0.000    0.000    0.000    0.000 {_codecs.charmap_decode}
        2    0.000    0.000    0.000    0.000 {_codecs.mbcs_decode}
  2299871    0.426    0.000    0.426    0.000 {_json.encode_basestring_ascii}
     5318    0.688    0.000    0.688    0.000 {binascii.b2a_base64}
     5038    0.002    0.000    0.002    0.000 {built-in method __new__ of type object at 0x000000006C515330}
    20152    0.019    0.000    0.019    0.000 {getattr}
    46986    0.012    0.000    0.012    0.000 {hasattr}
  5926181    0.319    0.000    0.319    0.000 {id}
  5294237    0.688    0.000    0.688    0.000 {isinstance}
    10076    0.003    0.000    0.003    0.000 {issubclass}
    20169    0.002    0.000    0.002    0.000 {len}
    10076    0.048    0.000    0.048    0.000 {method '__reduce_ex__' of 'object' objects}
        4    0.000    0.000    0.000    0.000 {method 'acquire' of 'thread.lock' objects}
        2    0.000    0.000    0.000    0.000 {method 'append' of 'collections.deque' objects}
  2599700    0.212    0.000    0.212    0.000 {method 'append' of 'list' objects}
    20974    0.013    0.000    0.015    0.000 {method 'astimezone' of 'datetime.datetime' objects}
        3    0.000    0.000    0.000    0.000 {method 'decode' of 'str' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        1    0.000    0.000    0.000    0.000 {method 'fileno' of 'file' objects}
        1    0.004    0.004    0.004    0.004 {method 'flush' of 'file' objects}
  5555180    0.399    0.000    0.399    0.000 {method 'get' of 'dict' objects}
    20974    0.060    0.000    0.063    0.000 {method 'isoformat' of 'datetime.datetime' objects}
    21285    0.009    0.000    0.009    0.000 {method 'items' of 'dict' objects}
   382483    0.033    0.000    0.033    0.000 {method 'iteritems' of 'dict' objects}
     5321    0.000    0.000    0.000    0.000 {method 'iterkeys' of 'dict' objects}
     5321    0.001    0.000    0.001    0.000 {method 'itervalues' of 'dict' objects}
        1    0.139    0.139    0.139    0.139 {method 'join' of 'str' objects}
        2    0.000    0.000    0.000    0.000 {method 'release' of 'thread.lock' objects}
        4    0.000    0.000    0.000    0.000 {method 'replace' of 'str' objects}
     5038    0.002    0.000    0.002    0.000 {method 'update' of 'dict' objects}
        2    0.000    0.000    0.000    0.000 {method 'upper' of 'str' objects}
        9  246.259   27.362  246.259   27.362 {method 'write' of 'file' objects}
        1    0.026    0.026    0.026    0.026 {nt.fsync}
        2    0.000    0.000    0.000    0.000 {nt.stat}
        1    1.605    1.605    1.605    1.605 {open}
    10076    0.007    0.000    0.007    0.000 {range}
     1067    0.001    0.000    0.001    0.000 {repr}
        2    0.000    0.000    0.000    0.000 {time.time}


DeviceJob: 5 Send metadata to device done, calling callback
DeviceJob: 5 Send metadata to device callback returned
Job: 5 Send metadata to device finished
No details available.

It looks like the lion's share of the time is in method 'write' of 'file' objects.

By contrast, here's the same for the old Kindle:

Spoiler:

DEBUG: 1358.7 USBMS: starting sync_booklists
Job: 11 Upload one book to the device: Chimaera finished
No details available.
DEBUG: 1370.9 USBMS: finished sync_booklists
         8534666 function calls (7605838 primitive calls) in 12.186 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        2    0.000    0.000    0.000    0.000 Queue.py:107(put)
        2    0.000    0.000    0.000    0.000 Queue.py:204(_put)
        2    0.000    0.000    0.000    0.000 __init__.py:178(prints)
        1    0.032    0.032    1.081    1.081 __init__.py:193(dumps)
   375708    0.077    0.000    0.130    0.000 __init__.py:640(isbytestring)
        1    0.000    0.000    0.140    0.140 __init__.py:720(fsync)
        1    0.000    0.000    0.000    0.000 _abcoll.py:548(update)
        1    0.000    0.000    0.000    0.000 _weakrefset.py:70(__contains__)
        1    0.000    0.000    0.000    0.000 abc.py:148(__subclasscheck__)
   473480    0.250    0.000    0.282    0.000 base.py:124(__getattribute__)
     5320    0.013    0.000    0.019    0.000 base.py:161(__setattr__)
   154280    0.068    0.000    0.249    0.000 base.py:213(get)
     5320    0.012    0.000    0.288    0.000 base.py:360(get_all_user_metadata)
      238    0.045    0.000    0.101    0.000 base64.py:43(b64encode)
        1    0.000    0.000    0.000    0.000 collections.py:50(__init__)
       26    0.000    0.000    0.000    0.000 collections.py:71(__setitem__)
123215/2618    0.126    0.000    0.276    0.000 copy.py:145(deepcopy)
   101830    0.007    0.000    0.007    0.000 copy.py:198(_deepcopy_atomic)
     2856    0.004    0.000    0.010    0.000 copy.py:226(_deepcopy_list)
  462/231    0.002    0.000    0.010    0.000 copy.py:234(_deepcopy_tuple)
10455/2618    0.041    0.000    0.270    0.000 copy.py:253(_deepcopy_dict)
   116065    0.048    0.000    0.064    0.000 copy.py:267(_keep_alive)
  462/231    0.002    0.000    0.011    0.000 copy.py:306(_reconstruct)
      231    0.000    0.000    0.000    0.000 copy_reg.py:92(__newobj__)
        1    0.000    0.000    0.000    0.000 cp1252.py:14(decode)
     6005    0.010    0.000    0.030    0.000 date.py:187(isoformat)
        1    0.000    0.000    0.000    0.000 device.py:80(report_progress)
        2    0.000    0.000    0.000    0.000 driver.py:40(debug_print)
        1    0.003    0.003   12.186   12.186 driver.py:446(sync_booklists)
        3    0.018    0.006   12.164    4.055 driver.py:454(write_prefix)
        2    0.000    0.000    0.000    0.000 driver.py:481(path_to_unicode)
        2    0.000    0.000    0.000    0.000 driver.py:487(normalize_path)
        1    0.000    0.000    0.000    0.000 encoder.py:101(__init__)
        1    0.104    0.104    1.049    1.049 encoder.py:186(encode)
        1    0.000    0.000    0.000    0.000 encoder.py:212(iterencode)
       30    0.000    0.000    0.000    0.000 encoder.py:236(floatstr)
        1    0.000    0.000    0.000    0.000 encoder.py:272(_make_iterencode)
1115953/1014151    0.218    0.000    0.802    0.000 encoder.py:288(_iterencode_list)
1659392/1014148    0.358    0.000    0.668    0.000 encoder.py:341(_iterencode_dict)
  1014151    0.120    0.000    0.923    0.000 encoder.py:417(_iterencode)
        1    0.000    0.000    0.000    0.000 field_metadata.py:30(_builtin_field_metadata)
        1    0.000    0.000    0.000    0.000 field_metadata.py:386(__init__)
    95760    0.026    0.000    0.026    0.000 field_metadata.py:409(__getitem__)
   154280    0.039    0.000    0.039    0.000 field_metadata.py:424(__contains__)
       26    0.000    0.000    0.000    0.000 field_metadata.py:660(_add_search_terms_to_map)
        2    0.000    0.000    0.000    0.000 genericpath.py:23(exists)
       21    0.000    0.000    0.000    0.000 gettext.py:219(ugettext)
        1    0.000    0.000    0.000    0.000 gettext.py:224(ungettext)
        3    0.000    0.000    0.000    0.000 iso8601.py:19(_isdst)
        1    0.000    0.000    0.000    0.000 json_codec.py:129(__init__)
        1    0.038    0.038   11.346   11.346 json_codec.py:132(encode_to_file)
        1    0.004    0.004    1.631    1.631 json_codec.py:136(encode_booklist_metadata)
     5320    0.086    0.000    1.625    0.000 json_codec.py:142(encode_book_metadata)
   159600    0.272    0.000    1.538    0.000 json_codec.py:148(encode_metadata_attr)
    16198    0.054    0.000    0.085    0.000 json_codec.py:30(datetime_to_string)
     5320    0.014    0.000    0.115    0.000 json_codec.py:43(encode_thumbnail)
185886/133000    0.171    0.000    0.309    0.000 json_codec.py:70(object_to_unicode)
        1    0.000    0.000    0.000    0.000 json_codec.py:72(dec)
     2618    0.002    0.000    0.003    0.000 json_codec.py:89(encode_is_multiple)
        2    0.000    0.000    0.000    0.000 mbcs.py:20(decode)
        1    0.000    0.000    0.000    0.000 ntpath.py:63(join)
        2    0.000    0.000    0.000    0.000 ntpath.py:96(splitdrive)
        2    0.000    0.000    0.000    0.000 os.py:444(__contains__)
        1    0.000    0.000    0.661    0.661 startup.py:114(local_open)
        2    0.000    0.000    0.000    0.000 threading.py:300(_is_owned)
        2    0.000    0.000    0.000    0.000 threading.py:373(notify)
        3    0.000    0.000    0.000    0.000 tz.py:114(_isdst)
     6940    0.001    0.000    0.001    0.000 tz.py:33(utcoffset)
      468    0.000    0.000    0.000    0.000 tz.py:36(dst)
        3    0.000    0.000    0.000    0.000 tz.py:95(utcoffset)
        1    0.000    0.000    0.000    0.000 {_codecs.charmap_decode}
        2    0.000    0.000    0.000    0.000 {_codecs.mbcs_decode}
   361686    0.129    0.000    0.129    0.000 {_json.encode_basestring_ascii}
      238    0.056    0.000    0.056    0.000 {binascii.b2a_base64}
      231    0.000    0.000    0.000    0.000 {built-in method __new__ of type object at 0x000000006C515330}
      924    0.001    0.000    0.001    0.000 {getattr}
    12241    0.002    0.000    0.002    0.000 {hasattr}
   291992    0.016    0.000    0.016    0.000 {id}
  1475865    0.204    0.000    0.204    0.000 {isinstance}
      462    0.000    0.000    0.000    0.000 {issubclass}
      941    0.000    0.000    0.000    0.000 {len}
      462    0.002    0.000    0.002    0.000 {method '__reduce_ex__' of 'object' objects}
        4    0.000    0.000    0.000    0.000 {method 'acquire' of 'thread.lock' objects}
        2    0.000    0.000    0.000    0.000 {method 'append' of 'collections.deque' objects}
   122547    0.013    0.000    0.013    0.000 {method 'append' of 'list' objects}
     6005    0.001    0.000    0.001    0.000 {method 'astimezone' of 'datetime.datetime' objects}
        3    0.000    0.000    0.000    0.000 {method 'decode' of 'str' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        1    0.000    0.000    0.000    0.000 {method 'fileno' of 'file' objects}
        1    0.002    0.002    0.002    0.002 {method 'flush' of 'file' objects}
   397124    0.049    0.000    0.049    0.000 {method 'get' of 'dict' objects}
     6005    0.017    0.000    0.018    0.000 {method 'isoformat' of 'datetime.datetime' objects}
    21281    0.006    0.000    0.006    0.000 {method 'items' of 'dict' objects}
    27280    0.004    0.000    0.004    0.000 {method 'iteritems' of 'dict' objects}
     5320    0.000    0.000    0.000    0.000 {method 'iterkeys' of 'dict' objects}
     5320    0.001    0.000    0.001    0.000 {method 'itervalues' of 'dict' objects}
        1    0.023    0.023    0.023    0.023 {method 'join' of 'str' objects}
        2    0.000    0.000    0.000    0.000 {method 'release' of 'thread.lock' objects}
        4    0.000    0.000    0.000    0.000 {method 'replace' of 'str' objects}
        3    0.000    0.000    0.000    0.000 {method 'toordinal' of 'datetime.date' objects}
      231    0.000    0.000    0.000    0.000 {method 'update' of 'dict' objects}
        2    0.000    0.000    0.000    0.000 {method 'upper' of 'str' objects}
        9    8.595    0.955    8.595    0.955 {method 'write' of 'file' objects}
        1    0.137    0.137    0.137    0.137 {nt.fsync}
        2    0.000    0.000    0.000    0.000 {nt.stat}
        1    0.661    0.661    0.661    0.661 {open}
      462    0.000    0.000    0.000    0.000 {range}
       30    0.000    0.000    0.000    0.000 {repr}
        3    0.000    0.000    0.000    0.000 {time.localtime}
        2    0.000    0.000    0.000    0.000 {time.time}


DeviceJob: 12 Send metadata to device done, calling callback
DeviceJob: 12 Send metadata to device callback returned
Job: 12 Send metadata to device finished

The number of writes is the same (only 9), but the time length is radically different.

It does not look like it's the same processing between the two. For example method 'get' of 'dict' objects is called ~400k times on the old Kindle and 5.5m times on the new one.