Performance becoming an issue

[AustinScola]

Hi @yukinarit,

I've been loving using pyserde the last 2ish years, however recently I noticed that the import time for a lot of modules in a repo is quite slow. Using python's -X importtime I narrowed it down to modules that have a lot of pyserde decorated dataclasses. We are up to between 5-10 seconds of import time being due to pyserde :(

Here is an example of how long some very simple dataclasses take to decorate:

from dataclasses import dataclass
import time

from serde import serde

@dataclass
class Foo:
    bar: int

start = time.time()
serde(Foo)
end = time.time()
print(end - start) # 0.019263029098510742


@dataclass
class Wobble:
    wham: int

@dataclass
class Wibble:
    wobble: Wobble

start = time.time()
serde(Wibble)
end = time.time()
print(end - start) # 0.033370018005371094

[yukinarit]

That is a problem. Let me take a look.

[yukinarit]

Looks like jinja2 is slow

Sat May 11 21:24:41 2024    profile_results.prof

         50295 function calls (47272 primitive calls) in 0.031 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     2863    0.003    0.000    0.005    0.000 /home/yukinari/.cache/pypoetry/virtualenvs/pyserde-3viUZWFG-py3.10/lib/python3.10/site-packages/jinja2/nodes.py:167(iter_child_nodes)
        5    0.002    0.000    0.002    0.000 {built-in method builtins.compile}
      400    0.002    0.000    0.003    0.000 /home/yukinari/.cache/pypoetry/virtualenvs/pyserde-3viUZWFG-py3.10/lib/python3.10/site-packages/jinja2/lexer.py:667(tokeniter)
    10803    0.002    0.000    0.002    0.000 {built-in method builtins.isinstance}
     5167    0.002    0.000    0.002    0.000 /home/yukinari/.cache/pypoetry/virtualenvs/pyserde-3viUZWFG-py3.10/lib/python3.10/site-packages/jinja2/nodes.py:145(iter_fields)
    860/5    0.001    0.000    0.013    0.003 /home/yukinari/.cache/pypoetry/virtualenvs/pyserde-3viUZWFG-py3.10/lib/python3.10/site-packages/jinja2/visitor.py:35(visit)
   845/62    0.001    0.000    0.004    0.000 /home/yukinari/.cache/pypoetry/virtualenvs/pyserde-3viUZWFG-py3.10/lib/python3.10/site-packages/jinja2/nodes.py:193(find_all)
     4634    0.001    0.000    0.001    0.000 {built-in method builtins.getattr}
   486/76    0.001    0.000    0.004    0.000 /home/yukinari/.cache/pypoetry/virtualenvs/pyserde-3viUZWFG-py3.10/lib/python3.10/site-packages/jinja2/visitor.py:44(generic_visit)
     1160    0.001    0.000    0.001    0.000 {method 'match' of 're.Pattern' objects}
      196    0.001    0.000    0.001    0.000 {built-in method builtins.min}
      325    0.001    0.000    0.004    0.000 /home/yukinari/.cache/pypoetry/virtualenvs/pyserde-3viUZWFG-py3.10/lib/python3.10/site-packages/jinja2/lexer.py:613(wrap)
      189    0.001    0.000    0.001    0.000 /home/yukinari/.cache/pypoetry/virtualenvs/pyserde-3viUZWFG-py3.10/lib/python3.10/site-packages/jinja2/nodes.py:127(__init__)
     11/1    0.001    0.000    0.032    0.032 {built-in method builtins.exec}
      459    0.001    0.000    0.001    0.000 /home/yukinari/.cache/pypoetry/virtualenvs/pyserde-3viUZWFG-py3.10/lib/python3.10/site-packages/jinja2/compiler.py:453(write)

[AustinScola]

What are you thinking in terms of changes to pyserde (if any)?

[yukinarit]

I will look into where those jinja functions are used and see if we can optimize.

[yukinarit]

Hi @AustinScola
Can you measure module load time of your code with this branch? #528

[AustinScola]

Not too much of a difference with that branch. If I look at one module in particular which has 7 serde decorated classes here is what I see with -X importtime:

before:

import time: self [us] | cumulative | imported package
import time:    138455 |     171981 | XXXXX

after:

import time: self [us] | cumulative | imported package
import time:    131310 |     163527 | XXXXX

And I remove the serde decorators:

import time: self [us] | cumulative | imported package
import time:      8433 |      41325 | XXXXX

[yukinarit]

Added more optimization to #528
Can you try again?

[AustinScola]

Definitely an improvement this time:

import time: self [us] | cumulative | imported package
import time:     49394 |      68187 | XXXXX

[yukinarit]

Awesome! I will finish up the PR and hopefully merge within this week.

[yukinarit]

Published v0.18.0 🚀

[yukinarit]

@AustinScola Can this issue be closed?

FYI: I've added further performance improvements in v0.19.0,