Signing up can be very slow

[vorpal-buildbot]

Exceeded slow_page limit (11.3 > 10) in fetch: /signup/ (slow_page, 11.3, fetch)

Reported on fetch by perf

[bakert]

Can't repro this on local. I wonder what we do on signup page sometimes but not always.

[bakert]

Oh, I wonder if this is submission not load.

[bakert]

On local submission takes 4.2s with a very simple decklist (60 Swamp) so I'm sure that's what this is.

Exceeded slow_page limit (4.2 > 2) in decksite: /signup/ (slow_page, 4.2, decksite)

Profiler reveals that the db is at fault:

  ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       26    4.132    0.159    4.132    0.159 /opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/MySQLdb/connections.py:261(query)
    13186    0.015    0.000    0.015    0.000 /opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/site-packages/munch/__init__.py:98(__getattr__)
        2    0.012    0.006    0.027    0.014 /Users/bakert/pd/magic/legality.py:11(legal_formats)
 2244/132    0.004    0.000    0.005    0.000 /opt/local/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/copy.py:137(deepcopy)
        2    0.001    0.001    0.001    0.001 {method 'commit' of '_mysql.connection' objects}

[bakert]

The two longest queries (>1s on local) performed during sign up are:

... big long standard card query ...
HAVING name_ascii LIKE %s OR names LIKE %s
    ORDER BY pd_legal DESC, name
; ['%swamp%', '%swamp%'] (slow_query, 1.4, mysql)

And a very similar looking card query:

   ... big long standard card query ...
    HAVING LOWER(
    CASE
    WHEN layout = 'double-faced' OR layout = 'flip' THEN
        GROUP_CONCAT(CASE WHEN `u`.position = 1 THEN face_name ELSE '' END SEPARATOR '')
    WHEN layout = 'meld' THEN
        GROUP_CONCAT(CASE WHEN `u`.position = 1 OR `u`.position = 2 THEN face_name ELSE '' END SEPARATOR '')
    ELSE
        GROUP_CONCAT(face_name SEPARATOR ' // ' )
    END
) IN ('swamp')

[bakert]

The first is oracle.search being passed 'swamp'. The second is oracle.load_cards after being passed 'swamp'.

Both these things seem pretty unnecessary as we already have oracle.LEGAL_CARDS and oracle.CARDS_BY_NAME in memory.

[bakert]

The culprit is decklist.vivify because it calls oracle.valid_name for each card in the decklist and also oracle.load_cards for all the validated card names.

The call to valid_name will be fast if the exact card name is used but slow if it is not an exact match, including case sensitivity. ("swamp" does a 1.5s db query, "Swamp" does not.) It's also called once for each entry in the decklist.

oracle.load_cards is called only once but always hits the db (probably because that's what CARDS_BY_NAME uses to populate itself initially and having it uses CARDS_BY_NAME too would be circular at times).

Ultimately we should have all card details in memory all the time so the only thing that should take time here is fuzzy matching. And case sensitivity seems like something we could take care of without hitting the db for fuzzy matching.

[bakert]

The valid_name part is the big deal because it's O(n) not O(1).

This decklist is reasonably fast:

1 About Face
1 Absolute Grace
1 Absolver Thrull
1 Absorb Vis
1 Abstruse Interference
1 Abuna Acolyte
1 Abuna's Chant
1 Abundant Maw
1 Abyssal Specter
1 Abzan Advantage
1 Abzan Ascendancy
1 Abzan Banner
1 Abzan Battle Priest
1 Abzan Beastmaster
1 Abzan Charm
1 Abzan Falconer
1 Abzan Guide
1 Abzan Kin-Guard
1 Abzan Runemark
1 Abzan Skycaptain
1 Academy Elite
1 Academy Raider
1 Academy Researchers
1 Accelerate
1 Accelerated Mutation
1 Acceptable Losses
1 Accomplished Automaton
1 Accorder Paladin
1 Accorder's Shield
1 Accursed Horde
1 Accursed Spirit
1 Accursed Witch
1 Acid Web Spider
1 Acid-Spewer Dragon
1 Acidic Sliver
1 Acolyte of Xathrid
1 Acolyte of the Inferno
1 Acolyte's Reward
1 Acrobatic Maneuver
1 Act of Aggression
1 Act of Heroism
1 Act of Treason
1 Act on Impulse
1 Adanto Vanguard
1 Adaptive Snapjaw
1 Adarkar Sentinel
1 Adarkar Valkyrie
1 Adarkar Windform
1 Adder-Staff Boggart
1 Adriana, Captain of the Guard
1 Advance Scout
1 Advanced Hoverguard
1 Advanced Stitchwing
1 Advent of the Wurm
1 Adventuring Gear
1 Adverse Conditions
1 Advice from the Fae
1 Advocate of the Beast
1 Aegis Angel
1 Aegis Automaton
1 Aeolipile
1 Aeon Chronicler
1 Aerial Formation
1 Aerial Guide
1 Aerial Maneuver
1 Aerial Modification
1 Aerial Predation
1 Aerial Responder
1 Aerial Volley
1 Aerie Bowmasters
1 Aerie Mystics
1 Aerie Ouphes
1 Aerie Worshippers
1 Aeronaut Admiral
1 Aeronaut Tinkerer
1 Aesthir Glider
1 Aether Adept
1 Aether Charge
1 Aether Chaser
1 Aether Figment
1 Aether Herder
1 Aether Inspector
1 Aether Membrane
1 Aether Mutation
1 Aether Poisoner
1 Aether Rift
1 Aether Shockwave
1 Aether Snap
1 Aether Spellbomb
1 Aether Sting
1 Aether Storm
1 Aether Swooper
1 Aether Theorist
1 Aether Tide
1 Aether Tradewinds
1 Aether Web
1 Aetherborn Marauder
1 Aethermage's Touch
1 Aetherplasm
1 Aethersnipe
1 Aetherspouts
1 Aethersquall Ancient
1 Aetherstorm Roc
1 Aetherstream Leopard
1 Aethertide Whale
1 Aethertorch Renegade
1 Aethertow
1 Affa Guard Hound
1 Affa Protector
1 Afflict
1 Afflicted Deserter

but this decklist is terrifyingly slow (a few minutes?):

1 about face
1 absolute grace
1 absolver thrull
1 absorb vis
1 abstruse interference
1 abuna acolyte
1 abuna's chant
1 abundant maw
1 abyssal specter
1 abzan advantage
1 abzan ascendancy
1 abzan banner
1 abzan battle priest
1 abzan beastmaster
1 abzan charm
1 abzan falconer
1 abzan guide
1 abzan kin-guard
1 abzan runemark
1 abzan skycaptain
1 academy elite
1 academy raider
1 academy researchers
1 accelerate
1 accelerated mutation
1 acceptable losses
1 accomplished automaton
1 accorder paladin
1 accorder's shield
1 accursed horde
1 accursed spirit
1 accursed witch
1 acid web spider
1 acid-spewer dragon
1 acidic sliver
1 acolyte of xathrid
1 acolyte of the inferno
1 acolyte's reward
1 acrobatic maneuver
1 act of aggression
1 act of heroism
1 act of treason
1 act on impulse
1 adanto vanguard
1 adaptive snapjaw
1 adarkar sentinel
1 adarkar valkyrie
1 adarkar windform
1 adder-staff boggart
1 adriana, captain of the guard
1 advance scout
1 advanced hoverguard
1 advanced stitchwing
1 advent of the wurm
1 adventuring gear
1 adverse conditions
1 advice from the fae
1 advocate of the beast
1 aegis angel
1 aegis automaton
1 aeolipile
1 aeon chronicler
1 aerial formation
1 aerial guide
1 aerial maneuver
1 aerial modification
1 aerial predation
1 aerial responder
1 aerial volley
1 aerie bowmasters
1 aerie mystics
1 aerie ouphes
1 aerie worshippers
1 aeronaut admiral
1 aeronaut tinkerer
1 aesthir glider
1 aether adept
1 aether charge
1 aether chaser
1 aether figment
1 aether herder
1 aether inspector
1 aether membrane
1 aether mutation
1 aether poisoner
1 aether rift
1 aether shockwave
1 aether snap
1 aether spellbomb
1 aether sting
1 aether storm
1 aether swooper
1 aether theorist
1 aether tide
1 aether tradewinds
1 aether web
1 aetherborn marauder
1 aethermage's touch
1 aetherplasm
1 aethersnipe
1 aetherspouts
1 aethersquall ancient
1 aetherstorm roc
1 aetherstream leopard
1 aethertide whale
1 aethertorch renegade
1 aethertow
1 affa guard hound
1 affa protector
1 afflict
1 afflicted deserter

[silasary]

We should probably normalize the case of CARDS_BY_NAME (or the lookups) then.

[bakert]

Some 45-90s sign ups seen in prod.

[bakert]

oracle.valid_name does a couple of good things for us in the signup code – lowercase names and Far/Away type split cards. I don't think we want to start rejecting those. We could reject minor misspellings and aliases but I think it's kinda nice to accept those too. We use a much tighter threshold here than we do when checking for misspellings via the bot (20 v 260).

[bakert]

canonicalize does the split card thing and the case thing and unaccent so that should cover 99% of cases.

[bakert]

I added this for a disappointing 300ms per fuzzy match. Better than the 1s+ we had before. Will revisit when this is the slowest page on the site again.

59bd7ded.