PHP hat Ticks
Vor einigen Tagen hatte ich mit einem meiner Kollegen in der Firma ein Gespräch über Profiler (XDebug). Dabei erzählte er dass er vor einiger Zeit einen rudimentären Profiler gebastelt hat der ähnliches kann wie XDebug heute: Sein Profiler konnte die Laufzeit eines jeden Befehls in einem Script feststellen und in eine Datenbank loggen. Außerdem bekam er Informationen wie oft jede Funktion von irgendwo aufgerufen wurde, er konnte auch sehen von wo genau. Somit war es ihm möglich die langsamsten Teile seiner Software herauszufinden und diese zu beschleunigen.
XDebug und auch der Zend Debugger können genau das selbe und noch viel mehr, trotzdem wollte ich wissen wie man das macht ohne eine entsprechende Extension. Dazu hält PHP die unbekannte Funktion register_tick_function() bereit, die man mit einem Callback füttern kann. Diese Callback-Funktion wird dann bei jedem Tick aufgerufen. Ein Tick ist einfach ausgedrückt jeder low-level-Befehl in einem Script, darunter fallen Zuweisungen, Funktionsaufrufe usw. Im Prinzip fast alles außer Kontrollstrukturen (if, switch, while etc).
Hier ein kleines Script, das die Funktionsweise erklärt:
<?php
function profiler()
{
debug_print_backtrace();
}
register_tick_function('profiler');
echo "First echo\n";
declare(ticks = 1);
echo "Second echo\n";
echo "Third echo\n";
echo "Before function echo\n";
$i = md5('text');
echo "After function echo\n";
Die Ausgabe sieht wie folgt aus:
First echo #0 profiler() called at [/private/tmp/tick.php:12] #0 profiler() called at [/private/tmp/tick.php:12] Second echo #0 profiler() called at [/private/tmp/tick.php:13] Third echo #0 profiler() called at [/private/tmp/tick.php:14] Before function echo #0 profiler() called at [/private/tmp/tick.php:15] #0 profiler() called at [/private/tmp/tick.php:16] After function echo #0 profiler() called at [/private/tmp/tick.php:17]
Man sieht dass profiler() nach jedem Befehl aufgerufen wird. In Zeile 12 wird sie zweimal aufgerufen, einmal für die Zuweisung und einmal für den Funktionsaufruf. Man erkennt auch dass das echo in Zeile 10 keinen profiler() Aufruf zur Folge hat. Das liegt daran dass mit dem Aufruf von declare() erst festgelegt wird wie oft die tick-Funktion aufgerufen werden soll. Diese Zeile aktiviert also das ganze. Auf php.net findet man auch einige Beispiele von Usern zu declare() und den Möglichkeiten.
Wer also nicht zu XDebug greifen möchte (oder kann) sollte, bevor er mühsam jede Menge microtime() und debug_backtrace() Aufrufe einbaut diese Möglichkeit in Betracht ziehen.
Hi,
ziemlich cool, kannste die Funktion auch noch nicht. Bin gerade die ganze Zeit am überlegen, was man damit noch alles cooles anstellen könnte..
Gruß Sebastian
Sebastian
6 Aug 10 at 22:00
Ich habe die Funktion zwar schonmal im Manual gefunden, wusste bislang aber noch keine sinnvolle Verwendung dafür. Nun ist auch die Frage geklärt.
Daniel
6 Aug 10 at 22:07
Danke !
Und bitte mach PHP nicht zu fertig, lass was für uns übrig.
phpdox
7 Aug 10 at 13:15
[…] diese dann zu beschleunigen. Dann bin auch auf den Artikel von Michael auf PHP Gangsta gestoßen, PHP hat Ticks. Nun habe heute mal eben schnell meinen ganz eigenen “PHP Profiler” gebastelt. Er ist […]
einfacher PHP Profiler | casibus
8 Aug 10 at 11:13
Das funktioniert in PHP 5.3+ nicht mehr (richtig) und das wirds in PHP 6 nicht mehr geben.
Unter PHP 5.3 (und schon vorher) gibt debug_backtrace() innerhalb der Callbackfunction falsche Werte aus, wenn diese von statischen Methoden oder Objekten aus angetriggert wird.
rkr
8 Aug 10 at 17:19
Mir war so, dass das nur unter Linuxsystemen läuft, könnte das jemand feststellen, ich weiß nicht mehr genau…
stietze
9 Aug 10 at 12:38
interessant in dem zusammenhang ist wohl auch xhprof, da es tiefer ansetzt und eine in c geschriebene lösung in form einer pecl extension bietet.
hier ein bericht darüber:
http://it-republik.de/php/news/Aus-dem-Leben-gegriffen-Profiling-mit-XHProf-053375.html
und hier die projektseite:
http://pecl.php.net/package/xhprof
native alternative
9 Aug 10 at 18:37
@stietze: Funktioniert unter Windows auch wunderbar, habe es gerade getestet.
Michael Kliewe
10 Aug 10 at 09:59
@Sebastian: Und schon interessante Anwendungsfälle gefunden?
Mir ist ausser dem Debuggen (ich bin der obige ominöse Kollege) noch kein sinnvoller Einsatz eingefallen.
Das Script lief irgendwann nicht mehr richtig. Hatte aber Spaß gemacht! Naja, heute benutze ich auch XDebug. Ist somit kein großer Verlust wenn das weg fällt.
Declare überlebt aber, denn das wird jetzt für Encoding-Angaben genutzt:
http://de2.php.net/manual/en/control-structures.declare.php (unten weiter)
Florian Heinze
19 Aug 10 at 14:51
Interessant, aber wie bereits erwähnt heissts auf php.net: «Mit PHP 5.3.0 gilt Ticks als veraltet und wird mit PHP 6.0.0 entfernt.»
sprain
19 Aug 10 at 21:24
Stellt sich noch die Frage, ob es mit php6 irgendwas vergleichbares geben wird.
Grundsätzlich sind die Ticks ja durchaus sinnvoll zum profilen.
avanzu
5 Sep 10 at 08:26
kann es sein, dass PHP<5, signale nur an "ticks" verarbeitet hat?
kill -TERM
cryptocompress
21 Sep 10 at 11:48
Lebst du noch?
Sascha
22 Sep 10 at 09:37
[…] einzige Lösung die ich aktuell sehe (habe es noch nicht ausprobiert) wäre der Einsatz einer tick-Funktion um dann selbst den Peak mit memory_get_usage() zu ermitteln, so schleichte ich mich quasi in die […]
Maximaler Arbeitsspeicherverbrauch mehrerer Funktionen | PHP Gangsta - Der PHP Blog mit Praxisbezug
21 Jul 12 at 15:46