Posts Tagged ‘Slow’

Sonntag, 2. Juli 2017

Stockende Texteingabe in Web-Formularen mit hunderten HTML Input-Elementen unter Safari

Link zu diesem Artikel

Seit einigen Monaten (wahrscheinlich als Kollateralschaden eines Safari-Updates) habe ich ein Problem mit einer selber geschriebenen Web-Applikation: Die Eingabe von Zeichen in Textfelder eines Web-Formulars ist extrem langsam.

Zuerst verdächtigte eine veraltete jQuery-Bibliothek und onkeyup– und onblur-Attribute als Ursache, doch ein Update von jQuery hat keine Abhilfe geschafft.

Heute reichte es mir, und ich nahm erneut einen Anlauf, das Problem einzugrenzen. Eine Google-Suche förderte schnurstracks Probleme mit Safari unter iOS zu Tage, welche vor einigen Jahren bestanden (oder immer noch bestehen). Dies führte mich auf die Spur eines Stackexchange-Artikels, der identisches Verhalten auch in Safari unter macOS berichtete:

Safari on Mac responses slow when typing on a webpage with lots of <input type=“text”> fields

Das liess mich aufhorchen — denn die Applikation zeigt zwar nicht gerade hundert Eingabefelder an, doch in mehreren HTML-Tabellen werden alle Inhalte von Datenbank-Tabellen aufgelistet, woraus der Benutzer mit einem Klick auf einen Formular-Button den gewünschten Datensatz auswählen kann. Auf der Seite finden sich deshalb problemlos einige hundert input[button]-Elemente.

Könnte es sein, dass diese Elemente Safari spürbar langsamer machen? Ja!

Meine Lösung: Ich habe die Formular-Buttons in der Liste mit hinterlegtem JavaScript onclick mit HTML-Anchors ersetzt:

<a href="javascript:clicked();">wählen</a>

Seither fühlt sich der Browser wieder wie 2017 an, und nicht wie Netscape von 1998.

Tags: , , , , , ,
Labels: Apple

Keine Kommentare | neuen Kommentar verfassen

Dienstag, 13. Januar 2015

WordPress vor dem Ausreizen des RAM-Speicher bewahren

Link zu diesem Artikel

Seit einigen Wochen finden sich in meiner php.err täglich Einträge wie den folgenden:

...
[12-Jan-2015 14:19:24 UTC] PHP Fatal error:  Out of memory (allocated 9699328) (tried to allocate 78720 bytes) in /blog/wp-includes/script-loader.php on line 528
[12-Jan-2015 14:19:24 UTC] PHP Fatal error:  Out of memory (allocated 8126464) (tried to allocate 49152 bytes) in /blog/wp-includes/comment-template.php on line 2163
[12-Jan-2015 14:19:24 UTC] PHP Fatal error:  Out of memory (allocated 1572864) (tried to allocate 3072 bytes) in /blog/wp-includes/functions.php on line 3514
[12-Jan-2015 14:19:24 UTC] PHP Fatal error:  Out of memory (allocated 6291456) (tried to allocate 3072 bytes) in /blog/wp-includes/post.php on line 670
[12-Jan-2015 19:59:36 UTC] PHP Fatal error:  Out of memory (allocated 19660800) (tried to allocate 8 bytes) in /blog/wp-includes/pomo/mo.php on line 237
[12-Jan-2015 19:59:36 UTC] PHP Fatal error:  Out of memory (allocated 23592960) (tried to allocate 32 bytes) in /blog/wp-includes/pomo/mo.php on line 243
[12-Jan-2015 19:59:36 UTC] PHP Fatal error:  Out of memory (allocated 16252928) (tried to allocate 49152 bytes) in /blog/wp-content/plugins/stop-spammer-registrations-plugin/stop-spammer-registrations.php on line 163
[12-Jan-2015 19:59:36 UTC] PHP Fatal error:  Out of memory (allocated 22544384) (tried to allocate 32 bytes) in /blog/wp-includes/pomo/mo.php on line 237
[12-Jan-2015 19:59:36 UTC] PHP Fatal error:  Out of memory (allocated 18350080) (tried to allocate 1920 bytes) in /blog/wp-includes/default-widgets.php on line 914
[12-Jan-2015 19:59:36 UTC] PHP Fatal error:  Out of memory (allocated 22806528) (tried to allocate 94 bytes) in /blog/wp-includes/pomo/mo.php on line 250
[12-Jan-2015 19:59:36 UTC] PHP Fatal error:  Out of memory (allocated 22282240) (tried to allocate 32 bytes) in /blog/wp-includes/pomo/mo.php on line 243
[12-Jan-2015 19:59:36 UTC] PHP Fatal error:  Out of memory (allocated 20709376) (tried to allocate 12288 bytes) in /blog/wp-content/plugins/wptouch/themes/foundation/modules/sharing/sharing.php on line 126
[12-Jan-2015 19:59:36 UTC] PHP Fatal error:  Out of memory (allocated 20971520) (tried to allocate 12288 bytes) in /blog/wp-content/plugins/wptouch/themes/foundation/modules/social-links/social-links.php on line 54
[12-Jan-2015 19:59:36 UTC] PHP Fatal error:  Out of memory (allocated 21495808) (tried to allocate 12449 bytes) in /blog/wp-includes/pomo/streams.php on line 113
...

Egal, ob ein WordPress-Update, eine Aktualisierung eines Plugins oder Überbuchungen meines Hosting-Servers durch Cyon der Auslöser war — ich wollte mein Log vor solchen Einträgen bewahren.

Nachfolgend eine Anleitung, wie ich vorgegangen bin:

TPC! Memory Usage

Als erstes installierte ich das Plugin TPC! Memory Usage, welches die Speicherauslastung bei jedem Aufruf eines WordPress-Artikels aufzeichnet und im Administrations-Dashboard anzeigt.

Ca. 120 vom Plugin innerhalb weniger Minuten automatisch generierte und versendete E-Mails später hatte ich dann auch herausgefunden, dass ich in der Administrationsoberfläche im schwarzen, vertikalen Menubalken unter Memory Usage > Einstellungen > Notify if memory usage exceeds: den Schwellenwert von 32MB auf 64MB erhöhen musste, um von der Mailflut verschont zu werden.

Der Schwellenwert ist übrigens auch in der Datei tpcmem-core.php hardkodiert, falls jemand den Wert vor dem Upload der Dateien in die WordPress-Installation anpassen möchte:

...
add_option('tpc_memory_usage_email_high_usage', 32);
...

P3 (Plugin Performance Profiler)

Nachdem ich mit dem Plugin und den automatisch versendeten E-Mails die hohe Speicherauslastung durch meine WordPress-Installation bestätigt hatte, stiess ich mit einer Google-Suche auf folgenden Artikel:

How to monitor and reduce WordPress memory usage by plugins

Ich entschied mich, das in diesem Artikel erwähnte Plugin P3 (Plugin Performance Profiler) zu installieren und auszuführen. Beim ersten Durchlauf wurde ich wieder mit TPC!-Notifikations-E-Mails eingedeckt, die Speicherauslastung lag regelmässig über 80 MB.

Die erste Auswertung sah folgendermassen aus:

WordPress Plugin Profile Report
===========================================
Report date: Dienstag, 13. Januar 2015
Theme name: 
Pages browsed: 31
Avg. load time: 2.1364 sec
Number of plugins: 13
Plugin impact: 79.58% of load time
Avg. plugin time: 1.7001 sec
Avg. core time: 0.5284 sec
Avg. theme time: 0.0218 sec
Avg. mem usage: 86.89 MB
Avg. ticks: 88,114
Avg. db queries : 70.94
Margin of error : -0.1139 sec

Plugin list:
===========================================
P3 (Plugin Performance Profiler) - 0.0073 sec - 0.43%
Akismet - 0.0147 sec - 0.86%
Better WordPress Minify - 0.0540 sec - 3.18%
Google Sitemap Generator - 0.0035 sec - 0.21%
Jetpack von WordPress.com - 0.8103 sec - 47.67%
Limit Login Attempts - 0.0257 sec - 1.51%
Simple Lightbox - 0.4993 sec - 29.37%
Stop Spammer Registrations Plugin - 0.0092 sec - 0.54%
SubToMe - 0.0065 sec - 0.38%
Tpc Memory Usage - 0.0311 sec - 1.83%
WP Permalauts - 0.0327 sec - 1.92%
Wp Super Cache - 0.0138 sec - 0.81%
WPtouch Mobile Plugin - 0.1919 sec - 11.29%

Deaktivierung von Jetpack

Eine Google-Suche zeigte, dass ich offenbar nicht der einzige WordPress-Benutzer bin, dessen Jetpack-Plugin mehr als die Hälfte der Ladezeit eines Blog-Artikels ausmacht.

Deshalb entschied ich mich kurzerhand dazu, Jetpack zu deaktivieren. Der nächste Benchmark mit P3 lieferte folgende Zahlen:

WordPress Plugin Profile Report
===========================================
Report date: Dienstag, 13. Januar 2015
Theme name: 
Pages browsed: 17
Avg. load time: 1.2534 sec
Number of plugins: 12
Plugin impact: 60.86% of load time
Avg. plugin time: 0.7629 sec
Avg. core time: 0.4815 sec
Avg. theme time: 0.0994 sec
Avg. mem usage: 76.41 MB
Avg. ticks: 91,763
Avg. db queries : 56.94
Margin of error : -0.0904 sec

Plugin list:
===========================================
P3 (Plugin Performance Profiler) - 0.0014 sec - 0.19%
Akismet - 0.0098 sec - 1.28%
Better WordPress Minify - 0.0315 sec - 4.13%
Google Sitemap Generator - 0.0071 sec - 0.94%
Limit Login Attempts - 0.0108 sec - 1.42%
Simple Lightbox - 0.5075 sec - 66.53%
Stop Spammer Registrations Plugin - 0.0040 sec - 0.52%
SubToMe - 0.0146 sec - 1.92%
Tpc Memory Usage - 0.0284 sec - 3.72%
WP Permalauts - 0.0231 sec - 3.03%
Wp Super Cache - 0.0087 sec - 1.14%
WPtouch Mobile Plugin - 0.1159 sec - 15.20%

Deaktivierung von Simple Lightbox

Das Plugin Simple Lightbox dient dazu, verlinkte Bilder im Grossformat als Overlay über der aktuellen Seite anzuzeigen. Doch war die Funktionalität es wert, über eine halbe Sekunde auf das Plugin zu warten? Ganz klar: Nein.

Ich deaktivierte auch dieses Plugin und führte die Messungen ein drittes Mal durch:

WordPress Plugin Profile Report
===========================================
Report date: Dienstag, 13. Januar 2015
Theme name: 
Pages browsed: 17
Avg. load time: 0.8826 sec
Number of plugins: 11
Plugin impact: 39.13% of load time
Avg. plugin time: 0.3454 sec
Avg. core time: 0.4266 sec
Avg. theme time: 0.1072 sec
Avg. mem usage: 28.44 MB
Avg. ticks: 5,251
Avg. db queries : 55.35
Margin of error : 0.0034 sec

Plugin list:
===========================================
P3 (Plugin Performance Profiler) - 0.0082 sec - 2.36%
Akismet - 0.0118 sec - 3.42%
Better WordPress Minify - 0.0467 sec - 13.53%
Google Sitemap Generator - 0.0064 sec - 1.87%
Limit Login Attempts - 0.0258 sec - 7.46%
Stop Spammer Registrations Plugin - 0.0064 sec - 1.86%
SubToMe - 0.0215 sec - 6.24%
Tpc Memory Usage - 0.0347 sec - 10.05%
WP Permalauts - 0.0271 sec - 7.84%
Wp Super Cache - 0.0110 sec - 3.19%
WPtouch Mobile Plugin - 0.1457 sec - 42.20%

Bravo! Die Zeiten für das Laden der Plugins lag nun durchgehend im Hundertstel-Sekundenbereich, im Fall von WPTouch Mobile im Zehntelssekundenbereich.

Positiver Nebeneffekt: Auch die RAM-Auslastung brach markant ein:

Ursprungszustand 86.89 MB
Ohne Jetpack 70.94 MB
Ohne Jetpack, ohne Simple Lighbox 28.44 MB

Um die doch wirklich nützliche Lightbox-Funktionalität nicht zu verlieren, installierte ich stattdessen folgendes Plugin:

CSS3 Lightbox

Es handelt sich um eine rein CSS-basierte Lösung; der Einfluss auf die PHP-Renderzeiten von WordPress-Seiten ist vernachlässigbar.

Tags: , , , , , , , , ,
Labels: Web

Keine Kommentare | neuen Kommentar verfassen

Samstag, 10. Januar 2015

Safari benötigt 30 Sekunden zum Starten (ungelöst)

Link zu diesem Artikel

Seit einigen Wochen plagt mein Mac OS X 10.9 Mavericks auf einem Mac mini (Late 2012) ein merkwürdiges Problem: Beim Programmstart von Safari springt das Dock-Icon während genau 30 Sekunden auf und ab, bevor das Browser-Fenster erscheint. Ein Logout und ein Login in mein Benutzerkonto beheben das Problem nicht.

Leider habe ich bis jetzt keine Lösung für das Problem gefunden, weshalb ich hier erst einmal dokumentiere, was ich diesbezüglich herausgefunden habe.

Das Apple-Tool fs_usage ist mein Freund. Hier ein Beispiel-Auszug der Dateizugriffe des Safari-Prozesses:

# fs_usage
...
12:37:38.681696  open              F=13       (RW____)  /dev/dtracehelper                                                                                                                                    0.000026   Safari.6649750
12:37:38.681703  ioctl             F=13                                                                                                                                                      0.000006   Safari.6649750
12:37:38.681708  close             F=13                                                                                                                                                                      0.000005   Safari.6649750
12:37:38.681816  stat64                                 /System/Library/StagedFrameworks/Safari/WebInspectorUI.framework/Versions/A/WebInspectorUI                                                           0.000011   Safari.6649750
12:37:38.681836  open              F=13       (R_____)  /System/Library/StagedFrameworks/Safari/WebInspectorUI.framework/Versions/A/WebInspectorUI                                                           0.000018   Safari.6649750
12:37:38.681840  pread             F=13   B=0x1000     O=0x00000000                                                                                                                                          0.000004   Safari.6649750
12:37:38.681842  pread             F=13   B=0x1000     O=0x00004000                                                                                                                                          0.000002   Safari.6649750
12:37:38.681846  fcntl             F=13                                                                                                                                                              0.000002   Safari.6649750
12:37:38.681887  close             F=13                                                                                                                                                                      0.000003   Safari.6649750
12:37:38.684252  socket            F=13                                                                                                                                           0.000007   Safari.6649750
12:37:38.684284  connect           F=13     private/var/run/usbmuxd                                                                                                                                          0.000020   Safari.6649750
12:37:38.684288  ioctl             F=13                                                                                                                                                      0.000002   Safari.6649750
12:37:38.684365  close             F=14                                                                                                                                                                      0.000004   Safari.6649750
12:37:38.684375  sendto            F=13   B=0x10                                                                                                                                                             0.000008   Safari.6649750
12:37:38.684380  sendto            F=13   B=0x1f2                                                                                                                                                            0.000004   Safari.6649750
12:38:08.684465  close             F=14                                                                                                                                                                      0.000018   Safari.6649750
12:38:08.684588  close             F=13                                                                                                                                                                      0.000107   Safari.6649750
12:38:08.688500  stat64                 [  2]           /Library/Managed Preferences>>>>>>>>>>>>>>>>>>>>>>>>>>>>                                                                                             0.000005   Safari.6649750
12:38:08.688805  open              F=13       (R_____)  /Library/Preferences/com.apple.security.plist                                                                                                        0.000010   Safari.6649750
12:38:08.688811  close             F=13                                                                                                                                                                      0.000002   Safari.6649750
12:38:08.689103  stat64                                 /Users/mario/Library/Preferences/com.apple.security.plist                                                                                            0.000043   Safari.6649750
12:38:08.689108  stat64                 [  2]           /Library/Preferences/com.apple.security-common.plist                                                                                                 0.000003   Safari.6649750
12:38:08.689201  getattrlist                            /Users                                                                                                                                               0.000009   Safari.6649750

Zwischen 12:37:38 und 12:38:08 dreht der Prozess Däumchen. Hinweis gibt die folgende Zeile:

12:37:38.684284  connect           F=13     private/var/run/usbmuxd                                                                                                                                          0.000020   Safari.6649750

Safari scheint 30 Sekunden auf den connect zu private/var/run/usbmuxd zu warten.

In Console.app erscheint zudem genau nach 30 Sekunden folgende Meldung:

...
10.01.15 20:35:58.844 Safari[72526]: _SubscribeForMuxNotifications (thread 0x7fff74373310): USBMuxListenerCreate: Operation timed out
...

usbmuxd ist der Daemon, mit welchem iTunes resp. Mac OS X mit iPhones „spricht“ — wenn ich die Erklärungen verstehe so etwas wie TCP-over-USB: Usbmux — The iPhone Wiki.

Tags: , , , , , ,
Labels: Apple

Keine Kommentare | neuen Kommentar verfassen

Sonntag, 14. Dezember 2014

MySQL-Query auf Dev blitzschnell, in Prod extrem langsam

Link zu diesem Artikel

Am Freitag habe ich mich entschieden, eine bisher nur auf meinem lokalen Mac mini in einem Vagrant-Container laufende Web-Applikation auf meinen „produktiven“ Web-Server bei der Cyon GmbH zu verschieben.

Es handelt sich um eine Applikation, mit welcher Fragen einer Zertifizierungsprüfung mittels Multiple Choice beantwortet werden können. Eine Unterseite der Applikation berechnet aus dem Log der bisher getätigten Antworten Statistiken.

Nach einigen Minuten lief die Web-Applikation und der aktuellste MySQL-Dump war ebenfalls auf dem Server eingespielt. Doch dann kam das böse Erwachen: Beim Aufruf einer neuen Frage wartete ich unzählige Sekunden auf eine Antwort des Servers, bis die Ausführung des PHP-Scripts dann mit einem Timeout abbrach.

Was zum Teufel? Rasch war klar, dass ein SQL-Query zur Berechnung von Statistiken der Übeltäter war.

Auf Dev lief das MySQL-Query folgendermassen rasch durch:

[12-Dec-2014 13:22:18 Europe/Zurich] I - mysql->query() took 0.1694 secs in /var/www/apps/%APP%/inc/%APP%.class.php:343 for URI (Referer: unknown) from IP 192.168.1.1 with User Agent "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/600.1.17 (KHTML, like Gecko) Version/7.1 Safari/537.85.10"

Auf Prod hingegen loggte ich diesen Zeitwert:

[12-Dec-2014 12:40:18 Europe/Zurich] I - mysql->query() took 47.8917 secs in %PATH%%APP%.class.php:343 for URI <%URI%> (Referer: %REFERER%) from IP %IP% with User Agent "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/600.1.17 (KHTML, like Gecko) Version/7.1 Safari/537.85.10"

Eine Verlangsamung von mehr als dem 200-fachen!

Als erstes prüfte ich die Versionen der Datenbank-Software:

Dev

-- Server version	5.6.21-1~dotdeb.1

Prod

-- Server version	5.5.40-cll

Ich verwendete also eine Zehntelsversion bessere Datenbank.

Anschliessend liess ich mir das Query sowohl in Dev als auch in der Produktion „erklären“ (EXPLAIN):

Dev

EXPLAIN-localhost

Prod

EXPLAIN-cyon

Der Unterschied: Auf Prod führte MySQL ein „Dependent Subquery“ aus, auf Dev „nur“ (?) ein „Subquery“. War das das Problem?

Da mir EXPLAIN hier nun wirklich nicht weiterhalf, wendete ich mich Google zu. Folgende zwei Stackexchange-Artikel erheischten meine Aufmerksamkeit:

Beim Lesen der Antworten kam mir plötzlich die Idee: Vielleicht sind INDEXe deine Freunde? Ich wählte die Spalte Questions-id (`Questions-id` varchar(64) NOT NULL, CLSIDs enthaltend) aus und versah sie mit einem Index.

Und siehe da, beim nächstem Aufruf der Web-Seite wurde folgender Zeitwert registriert:

[12-Dec-2014 23:33:09 Europe/Zurich] I - mysql->query() took 0.0412 secs in %PATH%%APP%.class.php:343 for URI <%URI%> (Referer: %REFERER%) from IP %IP% with User Agent "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/600.1.17 (KHTML, like Gecko) Version/7.1 Safari/537.85.10"

Der zusätzliche Index auf einer Spalte auf hat mein Performance-Problem zu meiner vollsten Zufriedenheit gelöst. Wieso der Index aber in Version 5.6 von MySQL nicht mehr benötigt wird, ist mir derzeit noch ein Rätsel. Wahrscheinlich haben die Entwickler die Subquery-Performance in dieser Version stark verbessert?

Tags: , , , , , , , , , , ,
Labels: Web

Keine Kommentare | neuen Kommentar verfassen