email.message import time

@loewis

BPO	11454
Nosy	@loewis, @warsaw, @orsenthil, @ezio-melotti, @bitdancer, @serhiy-storchaka
Files	issue11454.diff issue11454_benchmarks.py email_import_speedup.patch

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2013-06-26.16:09:07.209>
created_at = <Date 2011-03-09.20:07:16.685>
labels = ['library', 'performance']
title = 'email.message import time'
updated_at = <Date 2013-06-26.16:09:07.207>
user = 'https://bugs.python.org/rosslagerwall'

bugs.python.org fields:

activity = <Date 2013-06-26.16:09:07.207>
actor = 'r.david.murray'
assignee = 'none'
closed = True
closed_date = <Date 2013-06-26.16:09:07.209>
closer = 'r.david.murray'
components = ['Library (Lib)']
creation = <Date 2011-03-09.20:07:16.685>
creator = 'rosslagerwall'
dependencies = []
files = ['27201', '27225', '27226']
hgrepos = []
issue_num = 11454
keywords = ['patch']
message_count = 29.0
messages = ['130461', '130483', '130487', '130505', '170545', '170546', '170549', '170553', '170697', '170712', '170713', '170714', '170715', '170718', '170761', '170762', '170763', '170765', '170767', '170768', '170770', '170772', '171073', '171074', '171075', '171076', '171077', '191910', '191911']
nosy_count = 10.0
nosy_names = ['loewis', 'barry', 'orsenthil', 'nadeem.vawda', 'ezio.melotti', 'Arfrever', 'r.david.murray', 'rosslagerwall', 'python-dev', 'serhiy.storchaka']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'resource usage'
url = 'https://bugs.python.org/issue11454'
versions = ['Python 3.4']

While importing most modules has little effect on the start up time,
importing urllib.request seems to take a considerable time.

E.g.: without importing urllib.request:
real 0m0.072s
user 0m0.070s
sys 0m0.000s

with importing urllib.request:
real	0m0.127s
user	0m0.120s
sys	0m0.010s

What operating system is that on?

Ubuntu 10.10.

I haven't investigated whether it is actually urllib.request that is causing the long import time or a module that it is dependent on.

OK, running this:
import base64
import bisect
import hashlib
import io
import os
import posixpath
import random
import re
import socket
import sys
import time
import collections

import io
import os
import socket
import collections
import warnings

import warnings
from io import StringIO, TextIOWrapper

import re
import uu
import base64
import binascii
import warnings
from io import BytesIO, StringIO

which is most of the imports that are generated when importing urllib.request takes about 0.62s.

Running this:
import email.message
import email.parser
import email
from email.feedparser import FeedParser
from email.message import Message
from email import utils
from email import errors
from email import header
from email import charset as _charset

which is the rest of the imports generated takes 0.105s.

It seems like importing the email module adds considerable time, affecting a bunch of other modules like urllib.request and http.client.

When looking at the code, it seems like a fair number of regular expressions are compiled when the email module is imported, causing the long import time. I wonder if this could be improved somehow?

I tried to remove a few unused regex and inline some of the others (the re module has its own caching anyway and they don't seem to be documented), but it didn't get so much faster (see attached patch).

I then put the second list of email imports of the previous message in a file and run it with cprofile and these are the results:

=== Without patch ===

$ time ./python -m issue11454_imp2
[69308 refs]

real 0m0.337s
user 0m0.312s
sys 0m0.020s

$ ./python -m cProfile -s time issue11454_imp2.py
         15130 function calls (14543 primitive calls) in 0.191 seconds

Ordered by: internal time

ncalls tottime percall cumtime percall filename:lineno(function)
26 0.029 0.001 0.029 0.001 {built-in method loads}
1248 0.015 0.000 0.018 0.000 sre_parse.py:184(__next)
3 0.010 0.003 0.015 0.005 sre_compile.py:301(optimize_unicode)
48/17 0.009 0.000 0.037 0.002 sre_parse.py:418(parse)
30/1 0.008 0.000 0.191 0.191 {built-in method exec}
82 0.007 0.000 0.024 0.000 {built-in method __build_class}
25 0.006 0.000 0.024 0.001 sre_compile.py:207(_optimize_charset)
8 0.005 0.001 0.005 0.001 {built-in method load_dynamic}
1122 0.005 0.000 0.022 0.000 sre_parse.py:209(get)
177 0.005 0.000 0.005 0.000 {built-in method stat}
107 0.005 0.000 0.012 0.000 <frozen importlib._bootstrap>:1350(find_loader)
2944/2919 0.004 0.000 0.004 0.000 {built-in method len}
69/15 0.003 0.000 0.028 0.002 sre_compile.py:32(_compile)
9 0.003 0.000 0.003 0.000 sre_compile.py:258(_mk_bitmap)
94 0.002 0.000 0.003 0.000 <frozen importlib._bootstrap>:74(_path_join)

=== With patch ===

$ time ./python -m issue11454_imp2
[69117 refs]

real 0m0.319s
user 0m0.304s
sys 0m0.012s

$ ./python -m cProfile -s time issue11454_imp2.py
         11281 function calls (10762 primitive calls) in 0.162 seconds

Ordered by: internal time

ncalls tottime percall cumtime percall filename:lineno(function)
21 0.022 0.001 0.022 0.001 {built-in method loads}
3 0.011 0.004 0.015 0.005 sre_compile.py:301(_optimize_unicode)
708 0.008 0.000 0.010 0.000 sre_parse.py:184(next)
30/1 0.008 0.000 0.238 0.238 {built-in method exec}
82 0.007 0.000 0.023 0.000 {built-in method __build_class}
187 0.005 0.000 0.005 0.000 {built-in method stat}
8 0.005 0.001 0.005 0.001 {built-in method load_dynamic}
107 0.005 0.000 0.012 0.000 <frozen importlib._bootstrap>:1350(find_loader)
29/8 0.005 0.000 0.020 0.002 sre_parse.py:418(_parse)
11 0.004 0.000 0.020 0.002 sre_compile.py:207(_optimize_charset)
643 0.003 0.000 0.012 0.000 sre_parse.py:209(get)
5 0.003 0.001 0.003 0.001 {built-in method dumps}
94 0.002 0.000 0.003 0.000 <frozen importlib._bootstrap>:74(_path_join)
257 0.002 0.000 0.002 0.000 quoprimime.py:56(<genexpr>)
26 0.002 0.000 0.116 0.004 <frozen importlib._bootstrap>:938(get_code)
1689/1676 0.002 0.000 0.002 0.000 {built-in method len}
31 0.002 0.000 0.003 0.000 <frozen importlib._bootstrap>:1034(get_data)
256 0.002 0.000 0.002 0.000 {method 'setdefault' of 'dict' objects}
119 0.002 0.000 0.003 0.000 <frozen importlib._bootstrap>:86(_path_split)
35 0.002 0.000 0.019 0.001 <frozen importlib._bootstrap>:1468(_find_module)
34 0.002 0.000 0.015 0.000 <frozen importlib._bootstrap>:1278(_get_loader)
39/6 0.002 0.000 0.023 0.004 sre_compile.py:32(_compile)
26/3 0.001 0.000 0.235 0.078 <frozen importlib._bootstrap>:853(_load_module)

The time spent in sre_compile.py:301(_optimize_unicode) most likely comes from email.utils._has_surrogates (there's a further speedup when it's commented away):
_has_surrogates = re.compile('([^\\ud800-\\udbff]|\A)\udc00-\udfff').search

This is used in a number of places, so it can't be inlined.  I wanted to optimize it but I'm not sure what it's supposed to do.  It matches lone low surrogates, but not lone high ones, and matches some invalid sequences, but not others:
>>> _has_surrogates('\ud800')  # lone high
>>> _has_surrogates('\udc00')  # lone low
<_sre.SRE_Match object at 0x9ae00e8>
>>> _has_surrogates('\ud800\udc00')  # valid pair (high+low)
>>> _has_surrogates('\ud800\ud800\udc00')  # invalid sequence (lone high, valid high+low)
>>> _has_surrogates('\udc00\ud800\ud800\udc00')  # invalid sequence (lone low, lone high, valid high+low)
<_sre.SRE_Match object at 0x9ae0028>

FWIW this was introduced in email.message in 1a041f364916 and then moved to email.util in 9388c671d52d.

It detects whether a string contains any characters have been surrogate escaped by the surrogate escape handler. I disliked using it, but I didn't know of any better way to do that detection. It's on my long list of things to come back to eventually and try to improve :)

Given that high surrogates are U+D800..U+DBFF, and low ones are U+DC00..U+DFFF, '([^\\ud800-\\udbff]|\A)\udc00-\udfff' means "a low surrogates, preceded by either an high one or line beginning, and followed by another low one or line end".

PEP-838 says "With this PEP, non-decodable bytes >= 128 will be represented as lone surrogate codes U+DC80..U+DCFF".

If I change the regex to _has_surrogates = re.compile('[\udc80-\udcff]').search, the tests still pass but there's no improvement on startup time (note: the previous regex was matching all the surrogates in this range too, however I'm not sure how well this is tested).

If I change the implementation with
_pep383_surrogates = set(map(chr, range(0xDC80, 0xDCFF+1)))
def _has_surrogates(s):
return any(c in _pep383_surrogates for c in s)

the tests still pass and the startup is ~15ms faster here:

$ time ./python -m issue11454_imp2
[68837 refs]

real 0m0.305s
user 0m0.288s
sys 0m0.012s

However using this function instead of the regex is ~10x slower at runtime. Using the shorter regex is about ~7x faster, but there are no improvements on the startup time.
Assuming the shorter regex is correct, it can still be called inside a function or used with functools.partial. This will result in a improved startup time and a ~2x improvement on runtime (so it's a win-win).
See attached patch for benchmarks.

This is a sample result:
17.01 usec/pass <- re.compile(current_regex).search
2.20 usec/pass <- re.compile(short_regex).search
148.18 usec/pass <- return any(c in surrogates for c in s)
106.35 usec/pass <- for c in s: if c in surrogates: return True
8.40 usec/pass <- return re.search(short_regex, s)
8.20 usec/pass <- functools.partial(re.search, short_regex)

Considering how often that test is done, I would consider the compiled version of the short regex the clear winner based on your numbers. I wonder if we could precompile the regex and load it from a pickle.

re.compile seems twice as fast as pickle.loads:

import re
import pickle
import timeit

N = 100000
s = "r = re.compile('[\\udc80-\\udcff]')"
t = timeit.Timer(s, 'import re')
print("%6.2f <- re.compile" % t.timeit(number=N))

s = "r = pickle.loads(p)"
p = pickle.dumps(re.compile('[\udc80-\udcff]'))
t = timeit.Timer(s, 'import pickle; from __main__ import p')
print("%6.2f <- pickle.loads" % t.timeit(number=N))

Result:
5.59 <- re.compile
11.04 <- pickle.loads

See also bpo-2679.

If I change the regex to _has_surrogates = re.compile('[\udc80-\udcff]').search, the tests still pass but there's no improvement on startup time (note: the previous regex was matching all the surrogates in this range too, however I'm not sure how well this is tested).

What about

  _has_surrogates = re.compile('[^\udc80-\udcff]*\Z').match

?

What about _has_surrogates = re.compile('[^\\udc80-\\udcff]*\Z').match ?

The runtime is a bit slower than re.compile('[\udc80-\udcff]').search, but otherwise it's faster than all the other alternatives. I haven't checked the startup-time, but I suspect it won't be better -- maybe even worse.

I haven't checked the startup-time, but I suspect it won't be better -- maybe even worse.

I suppose it will be much better.

Yes, however it has a startup cost that the function that returns re.search(short_regex, s) and the one with functool.partial don't have, because with these the compilation happens at the first call.

If we use one of these two, the startup time will be reduced a lot, and the runtime will be ~2x faster.
If we use re.compile(short_regex).search the startup time won't be reduced as much, but the runtime will be ~8x faster.

Given that here we are trying to reduce the startup time and not the runtime, I think using one of those two functions is better.

Another possible solution to improve the startup time is trying to optimize _optimize_unicode -- not sure how much can be done there though.

This issue may be about reducing the startup time, but this function is a hot spot in the email package so I would prefer to sacrifice startup time optimization for an increase in speed.

However, given the improvements to import locking in 3.3, what about a self replacing function?

def _has_surrogates(s):
    import email.utils
    f = re.compile('[\udc80-\udcff]').search
    email.utils._has_surrogates = f
    return f(s)

That might work.

To avoid the overhead of the cache lookup I was thinking about something like

regex = None
def _has_surrogates(s):
    global regex
    if regex is None:
        regex = re.compile(short_regex)
    return regex.search(s)

but I have discarded it because it's not very pretty and still has the overhead of the function and an additional if. Your version solves both the problems in a more elegant way.

It passed the email test suite. Patch attached.

It would be better to add/improve the _has_surrogates tests before committing.
The patch I attached is also still valid if you want a further speed up improvement.

def _has_surrogates(s):
    try:
        s.encode()
        return False
    except UnicodeEncodeError:
        return True

Results:
0.26 <- re.compile(short_regex).search
0.06 <- try encode

I'm really not willing to inline any of those pre-compiled regular expressions. They are precompiled because for a program processing lots of email, they are hot spots. We could use the same "compile on demand" dodge on them, though.

Can you explain your changes to the

Woops.

Can you explain your changes to the ecre regex (keeping in mind that I don't know much about regex syntax).

Oh, yeah, and the encode benchmark is very instructive, thanks Serhiy :)

They are precompiled because for a program processing lots of email,
they are hot spots.

OK, I didn't know they were hot spots. Note that the regex are not recompiled everytime: they are compiled the first time and then taken from the cache (assuming they don't fall out from the bottom of the cache). This still has a small overhead though.

Can you explain your changes to the ecre regex (keeping in mind
that I don't know much about regex syntax).

-  (?P<charset>[^?]*?)   # non-greedy up to the next ? is the charset
+  (?P<charset>[^?]*)    # up to the next ? is the charset
   \?                    # literal ?
   (?P<encoding>[qb])    # either a "q" or a "b", case insensitive
   \?                    # literal ?
-  (?P<encoded>.*?)      # non-greedy up to the next ?= is the encoded string
+  (?P<encoded>[^?]*)    # up to the next ?= is the encoded string
   \?=                   # literal ?=

At the beginning, the non-greedy *? is unnecessary because [^?]* already stops at the first ? found.
The second change might actually be wrong if <encoded> is allowed to contain lone '?'s. The original regex used '.*?\?=', which means "match everything (including lone '?'s) until the first '?=')", mine means "match everything until the first '?'" which works fine as long as lone '?'s are not allowed.

Serhiy's suggestion is semantically different, but it might be still suitable if having _has_surrogate return True even for surrogates not in range \udc80-\udcff is OK.

Well, "other" surrogates will cause a different error later than with the current _has_surrogates logic, but it won't be any more mysterious than what would happen now, I think. Normally, if I understand correctly, other surrogates should never occur, so I don't think it is a real issue.

Yes, lone '?'s should not stop the pattern match in an encoded string. Even though I don't think they are normally supposed to occur, they do occur when encoded words are encoded incorrectly, and we get a better error recovery result if we look for ?= as the end.

New changeset 520490c4c388 by R David Murray in branch 'default':
bpo-11454: Reduce email module load time, improve surrogate check efficiency.
http://hg.python.org/cpython/rev/520490c4c388

I've checked in the encode version of the method. I'm going to pass on doing the other inlines, given that the improvement isn't that large. I will, however, keep the issue in mind as I make other changes to the code, and there will be a general performance review phase when I get done with the API additions/bug fixing in the email6 project.

Navigation Menu

Repository navigation

email.message import time #55663

4 remaining items

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

email.message import time #55663

Description

Activity

rosslagerwall commented on Mar 9, 2011

loewis commented on Mar 10, 2011

rosslagerwall commented on Mar 10, 2011

rosslagerwall commented on Mar 10, 2011

ezio-melotti commented on Sep 16, 2012

bitdancer commented on Sep 16, 2012

ezio-melotti commented on Sep 16, 2012

bitdancer commented on Sep 16, 2012

ezio-melotti commented on Sep 19, 2012

serhiy-storchaka commented on Sep 19, 2012

ezio-melotti commented on Sep 19, 2012

serhiy-storchaka commented on Sep 19, 2012

4 remaining items

ezio-melotti commented on Sep 19, 2012

bitdancer commented on Sep 19, 2012

ezio-melotti commented on Sep 19, 2012

bitdancer commented on Sep 19, 2012

ezio-melotti commented on Sep 19, 2012

serhiy-storchaka commented on Sep 19, 2012

bitdancer commented on Sep 23, 2012

bitdancer commented on Sep 23, 2012

bitdancer commented on Sep 23, 2012

ezio-melotti commented on Sep 23, 2012

bitdancer commented on Sep 23, 2012

python-dev commented on Jun 26, 2013

bitdancer commented on Jun 26, 2013

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions