[Bottle] Routen- und Template-Dekoratoren

[glocke]

Hi,

ich habe eine ~2.000 Zeilen Datei die ca. 90 Funktionen, die ich mittels @route bzw. @post und teilweise mittels @view dekoriert habe. Starte ich mein Programm (welches die 2k-Zeilen-Datei importiert), dann dauert das Importieren davon ca. 80 Sekunden (auf meinem Netbook).

Meine Frage ist jetzt: ist das normal? Also ist die Zeit bei der Dateigröße zu erwarten? Oder habe ich irgendwelchen Quatsch gebastelt?

Ich habe zwischendrinnen mittels time.time() die Zeitstempel genommen und immer Zeitdifferenzen berechnet und ausgegeben. Dabei brauchen die hintersten Funktionen (5-10 Stück) an die 20-30 Sekunden. Tausche ich die Funktionen bzgl. ihrer Reihenfolge aus, so sind die Funktionen - die nun am Ende stehen - die jenigen, die sehr lange brauchen.

Prinzipiell ist eine Startzeit von ca. 80 Sekunden bei einem Webserver für mich nichts kritisches, aber dennoch unschön.

LG Glocke

/EDIT: ich verwende PasteServer

[jbs]

Eigentlich sollte es kein Problem sein.

Nur ist das ohne Codebeispiel schwierig zu analysieren.

[glocke]

Hi,

ja die gute alte Glaskugel ^^ Ich hoffe du kannst mit dem Code was anfangen, basiert auf von Entity abgeleiteten Klasse (ich verwende Elixir).

Code: Alles auswählen

@route(u'/support/player/:sid/')
@view(u'support/player/main')
def support_player(sid):
    supporter = Supporter.AuthRoute(sid)

    return dict(supporter=supporter, sid=sid, app_version=app_version)

@post(u'/support/account/:sid/')
@view(u'support/player/search')
def support_player_account(sid):
    supporter = Supporter.AuthPost(sid)

    return dict(sid=sid, supporter=supporter)

@route(u'/bans/')
@view(u'bans')
def bans():
    return dict(bans=Ban.query.order_by(desc(Ban.timestamp)).all(), timestring=timestring,
        app_version=app_version)

@post(u'/support/bans/:sid/')
@view(u'support/player/bans')
def support_player_bans(sid):
    if sid:
        supporter = Supporter.AuthPost(sid)

    return dict(sid=sid, bans=Ban.query.order_by(desc(Ban.timestamp)).all(), timestring=timestring)

@post(u'/support/player/:sid/account/')
@view(u'support/player/account')
def support_player_account(sid):
    supporter = Supporter.AuthPost(sid)

    ident = request.POST[u'ident']
    value = request.POST[u'value']

    if ident == u'mail':
        try:
            player = Player.query.filter_by(email=value).all()[0]
        except:
            return u'Nicht gefunden'
    elif ident == u'name':
        try:
            player = Player.query.filter_by(name=value).all()[0]
        except:
            return u'Nicht gefunden'
    else:
        return u'Fehler'

    return dict(sid=sid, player=player)

@post(u'/support/player/:sid/check/')
@view(u'support/player/check')
def support_player_account(sid):
    supporter = Supporter.AuthPost(sid)

    name = request.POST[u'name']

    try:
        player = Player.query.filter_by(name=name).all()[0]
        data = []
        # get all ips
        for a in Access.query.filter_by(account=player).all():
            # get other accesses with same ip at the same day
            for o in Access.query.filter(Access.account != player).filter(Access.ip == a.ip).all():
                # get dd.mm.yyyy
                day = timestring(o.time).split(u'-')[0]
                # check existance
                exists = False
                for d in data:
                    if d[1] == day:
                        exists = True
                        break
                if not exists:
                    # add access
                    if o.account:
                        name = o.account.name
                    else:
                        name = U'Anonym'
                    data.append([o.ip, day, name])
    except Exception as e:
        return unicode(e)

    return dict(sid=sid, player=player, data=data)

@post(u'/support/player/:sid/ban/')
@view(u'support/player/ban')
def support_player_account(sid):
    supporter = Supporter.AuthPost(sid)

    name = request.POST[u'name']

    return dict(sid=sid, supporter=supporter, name=name)

@post(u'/support/player/:sid/do_ban/')
def support_player_account(sid):
    supporter = Supporter.AuthPost(sid)

    name    = request.POST[u'name']
    reason  = request.POST[u'reason']
    timeout = request.POST[u'timeout'].replace(u' ', u'')

    if reason == u'':
        return u'Bitte Grund angeben!'

    if timeout == u'':
        return u'Bitte Dauer eingeben!'

    # convert timeout string to real timestamp
    try:
        i = int(timeout[:-1])
        if timeout[-1] == u'w':
            i *= 60 * 60 * 24 * 7
        elif timeout[-1] == u'd':
            i *= 60 * 60 * 24
        elif timeout[-1] == u'h':
            i *= 60 * 60
        else:
            raise Exception('Invalid time identifier')
        i += mktime(localtime())
    except:
        return u'Ungültige Dauer'

    try:
        player = Player.query.filter_by(name=name).all()[0]
    except Exception as e:
        return unicode(e)

    try:
        Ban(account=player, supporter=supporter, reason=reason, end=i)
        session.commit()
    except Exception as e:
        session.rollback()
        return u'Interner Fehler:<br />{0}'.format(e)

    return u'Abgeschlossen'

Diese Zeilen beim Start des Skripts abzuarbeiten, dauert ca. 23 Sekunden. Setze ich sie so wie sie sind an das Anfang des Skripts, dann dauert das nur 0.05 Sekunden, dafür aber ein anderer hinterer Part entsprechend länger.

[deets]

Ich sehe da jetzt nix, was das ausloesen koennte. Ich sehe ne Menge, das ich so nicht machen wuerde, vor allem was Fehlerbehandlung angeht. Aber das ist fuer den Moment ja nicht das Thema.

Also, entweder machst du noch was anderes auf Modulebene - dazu muessten wir den ganzen Code sehen. Oder die Dekoratoren machen Unfug, das liesse sich aber nur durch profiling klaeren. Das solltest du dann vielleicht mal machen.

[glocke]

Den gesamten Code zu posten würde über 100 KB mit sich ziehen.

Ich hab die Dekoratoren mal mit "sinnlosen" Funktionen getestet und keinerlei Performance-Probleme gehabt.

Hier mal das main-Skript, was die File (die die Routen enthält) importiert. Vielleicht ist da irgendwo unfug:

Code: Alles auswählen

import os

from setproctitle import setproctitle
# process title
setproctitle('pamyr_server')

from time import time, mktime, localtime
from models.core import timestring


try:
    from bottle import static_file, route, run, debug, default_app, TEMPLATE_PATH, PasteServer

    from models.config import server

    if os.environ.get('BOTTLE_CHILD'):
        import game # <-- enhält div. Routen etc. (vgl. oben)

    TMP = u'{0}/views'.format(server[u'dir'])
    TEMPLATE_PATH.append(TMP)

    @route('/static/:filename')
    def load_static(filename):
        return static_file(filename, root='{0}/statics'.format(TMP))

    if __name__ == '__main__':
        print u'[{0}] Running server'.format(timestring(mktime(localtime())))
        debug(server[u'debug'])
        run(server=PasteServer(host=server[u'ip'], port=server[u'port']), reloader=True)

except KeyboardInterrupt:
        print u'\n[{0}] Shutting down server'.format(timestring(mktime(localtime())))
        exit()

LG Glocke

[deets]

Dann benutz ein Pastebin. Und wie gesagt, profiling ist dein Freund...

[glocke]

profiling ist dein Freund...

Auffällig dabei:

Code: Alles auswählen

63135/1049   12.249    0.000   27.884    0.027 sre_compile.py:32(_compile)
    17763    0.461    0.000    0.971    0.000 sre_compile.py:354(_simple)
     1050    0.098    0.000    4.939    0.005 sre_compile.py:361(_compile_info)
     2100    0.044    0.000    0.072    0.000 sre_compile.py:474(isstring)
     1050    0.038    0.000   32.868    0.031 sre_compile.py:480(_code)
     1050    0.067    0.000   92.698    0.088 sre_compile.py:495(compile)
       18    0.000    0.000    0.000    0.000 sre_compile.py:51(fixup)
    73540    0.954    0.000    1.394    0.000 sre_parse.py:126(__len__)
       22    0.000    0.000    0.000    0.000 sre_parse.py:128(__delitem__)
   497035    7.269    0.000   11.164    0.000 sre_parse.py:130(__getitem__)
    17834    0.130    0.000    0.130    0.000 sre_parse.py:134(__setitem__)
   347312    4.753    0.000    6.941    0.000 sre_parse.py:138(append)
80988/18818    3.753    0.000    4.889    0.000 sre_parse.py:140(getwidth)
     1051    0.017    0.000    0.056    0.000 sre_parse.py:178(__init__)
   505042   11.885    0.000   17.956    0.000 sre_parse.py:182(__next)
   227833    2.477    0.000    5.964    0.000 sre_parse.py:195(match)
   406459    5.564    0.000   19.993    0.000 sre_parse.py:201(get)
        6    0.000    0.000    0.000    0.000 sre_parse.py:205(tell)
     2211    0.017    0.000    0.017    0.000 sre_parse.py:210(isident)
      649    0.026    0.000    0.043    0.000 sre_parse.py:216(isname)
      159    0.005    0.000    0.009    0.000 sre_parse.py:225(_class_escape)
    54908    2.119    0.000    3.522    0.000 sre_parse.py:257(_escape)
32348/1051    1.854    0.000   59.526    0.057 sre_parse.py:301(_parse_sub)
44999/13606   14.521    0.000   58.328    0.004 sre_parse.py:379(_parse)

sre_compile.py scheint mit regular expressions zusammenzuhängen. Ich vermute es hängt mit der SimpleTemplateEngine zusammen, die bottle mitbringt.

LG

[BlackJack]

@glocke: Nicht zum Problem, aber was mir sonst so aufgefallen ist:

Zumindest bei Jinja2 als Template-Sprache kann man über `Jinja2Template.defaults` ein Wörterbuch angeben, dessen Inhalt automatisch in jedem Template zur Verfügung stehen. Dort kann man so allgemeine Sachen wie die Version unterbringen oder Konfigurationsoptionen, welche die Darstellung betreffen, also alles was man potentiell in jedem Template gebrauchen kann.

Falls einem bei Elixir die gleichen `Query`-Objekte zur Verfügung stehen, die man auch bei `sqlalchemy` hat, dann gibt es eine Methode um den einzigen Wert, der bei einer Abfrage, die nur ein Ergebnis haben kann und darf abfragt: `one()`. Sollte es mehr geben können, aber man will nur das erste Ergebnis, gibt es die Methode `first()`.

Man sollte Code-Wiederholungen vermeiden, zum Beispiel in verschiedenen Zweigen. Das Abfragen des Spielers in `support_player_account()` unterscheidet sich zum Beispiel nur durch den `filter_by()`-Aufruf. Alles andere kann entweder davor oder danach *einmal* hingeschrieben werden:

Code: Alles auswählen

    query = Player.query
    
    if ident == u'mail':
        query = query.filter_by(email=value)
    elif ident == u'name':
        query = query.filter_by(name=value)
    else:
        return u'Fehler'

    try:
        player = query.one()
    except NoResultFound:
        return u'Nicht gefunden'

Der Test auf Vorhandensein eines Tages in `data` in `support_player_account()` ist umständlich. Das könnte man mit `all()` viel kompakter lösen:

Code: Alles auswählen

            # get dd.mm.yyyy
            day = timestring(o.time).split(u'-', 1)[0]
            # check existance
            if all(d[1] != day for d in data):
                # add access
                name = o.account.name if o.account else u'Anonym'
                data.append([o.ip, day, name])

Der Kommentar über der Zuweisung an `day` ist offensichtlich falsch.

Die Laufzeit sieht auf jeden Fall erschreckend aus bei den drei verschachtelten Schleifen, die linear über Datenstrukturen laufen. Die innerste Schleife könnte man zum Beispiel beseitigen, in dem man für `data` statt einer Liste ein Wörterbuch verwendet, das IP und Tag auf Kontonamen abbildet.

Falls eine IP an einem Tag mehreren Benutzerkonten ausser dem gerade betrachteten Spieler zugeordnet wurden, wird nur *eines* der Benutzerkonten in das Ergebnis aufgenommen. Ist das so gewollt?

Falls die beiden äusseren verschachtelten Schleifen irgend wann einmal zu einem Geschwindigkeitsproblem werden, könnte man sie in die Datenbank verlegen, in dem man *eine* Abfrage konstruiert, welche die Daten ermittelt.

[glocke]

Der Codeteil den ich gepostet hatte, ist vom letzten Jahr. Beim Überarbeiten kam ich bisher noch nicht soweit.

Aber danke für die Anregungen

Mir ist noch eine Sache aufgefallen:
Kommentiere ich alle @route und @post Dekoratoren aus, braucht die Anwendung lediglich 2 Sekunden zum starten...

/EDIT: ich habe einige Funktionsbezeichner doppelt verwendet (warum auch immer O_o) Ich werde die heute oder morgen mal alle umschreiben. Könnte es daran liegen, dass die route- und post-Dekoratoren damit so arg zu tun haben?

/EDIT2: Ich bin mal von bottle 0.8.4 auf 0.11dev umgestiegen und das Problem scheint plötzlich weg O_o

[DasIch]

Ich würde darauf tippen dass Bottle beim parsen der Routen irgendwas falsch oder zumindest sehr ineffizient gemacht hat.

[snafu]

@DasIch: Können die Namen für die Routen gewesen sein, aber auch genau so gut die Templates (wie ja schon angesprochen wurde). Vielleicht klappte das Caching zu dem Zeitpunkt noch nicht so gut, sodass mehr Zeit mit dem Kompilieren regulärer Ausdrück verbracht wurde als nötig, oder was auch immer. Mehr als Raten kann man da auch nicht und das ist nicht gerade konstruktiv.

Sofern der Fehler nicht "versehentlich" behoben wurde, kann vielleicht Defnull etwas Näheres dazu sagen.

[snafu]

Vielleicht sind dazu auch diese Benchmarks von August 2010 interessant (die natürlich nicht die jetzige Situation wiederspiegeln müssen): Man sieht, dass Bottels Standard-Template Implementierung bei sehr hohem Overhead (was auch immer das im Detail sein soll) in die Knie geht. Aber wie gesagt, das Ganze hat eine eher spekulative Note und zudem scheint es ja in der aktuellen Version behoben zu sein - so who cares...

//edit: Wobei ich hier ohnehin auf dem falschen Dampfer sein könnte, da es in diesem Thread ja lediglich um's Importieren ging und die Wartezeit schon recht heftig ist. Naja, wie auch immer.

[glocke]

//edit: Wobei ich hier ohnehin auf dem falschen Dampfer sein könnte, da es in diesem Thread ja lediglich um's Importieren ging und die Wartezeit schon recht heftig ist. Naja, wie auch immer.

Beim blanken Ausführen der File war es genauso.

Wie auch immer: jetzt sind's nur noch 3-4 Sekunden und das ist in meinen Augen absolut vertretbar