Server ή εφαρμογή: πώς μετριέται το bottleneck

Χρόνος μέχρι το πρώτο byte σε κάθε hop

Οι θεωρίες για ένα αργό site σχηματίζονται εύκολα και κλείνουν δύσκολα. Τρεις μετρήσεις τις κλείνουν. Πάρτε τον χρόνο μέχρι το πρώτο byte μέσα από το δημόσιο edge, ξανά απευθείας στο origin παρακάμπτοντας το edge, και ξανά στον host της εφαρμογής προς το localhost. Η διαφορά ανάμεσα σε δύο διαδοχικές μετρήσεις είναι το κόστος αυτού του επιπέδου.

# through the edge
curl -s -o /dev/null -w 'dns=%{time_namelookup} tls=%{time_appconnect} ttfb=%{time_starttransfer}\n' https://site.example/

# direct to the origin, edge bypassed
curl -s -o /dev/null -w 'ttfb=%{time_starttransfer}\n' --resolve site.example:443:ORIGIN_IP https://site.example/

# on the host, nothing in front of the application
curl -s -o /dev/null -w 'ttfb=%{time_starttransfer}\n' http://127.0.0.1/

Ό,τι απομένει στο localhost είναι η εφαρμογή και οι υπηρεσίες που καλεί. Το επίπεδο με το μεγαλύτερο χάσμα είναι εκεί που πηγαίνει η υπόλοιπη δουλειά.

Περιθώριο όσο πονάει

Διαβάστε τους μετρητές κατά τη διάρκεια της αργής περιόδου, όχι μετά.

vmstat 1 5        # r (run queue), wa (I/O wait), st (steal), id (idle)
iostat -x 1 5     # await and aqu-sz per device
free -m           # the available column, not used

Μια μακριά run queue με χαμηλό idle είναι ένα μηχάνημα περιορισμένο από CPU. Υψηλό I/O wait με υψηλό await στη συσκευή είναι storage. Το steal είναι ένας γείτονας σε κοινόχρηστο hypervisor που παίρνει κύκλους που ήθελε ο guest. Αδρανής CPU, διαθέσιμη μνήμη και συσκευές με χαμηλό await κάτω από ένα αργό site σημαίνουν ότι το μηχάνημα περιμένει κάτι που δεν του ανήκει: μια εξωτερική κλήση, ένα lock, ένα query που είναι αργό για λόγους άλλους από το hardware. Η προσθήκη hardware σε αυτό το σημείο παράγει ένα πιο αδρανές μηχάνημα που είναι ακόμα αργό.

Υπάρχει και μια τρίτη κατηγορία ανάμεσα στις δύο, και είναι συνηθισμένη: το pool. Η σελίδα status του PHP-FPM δείχνει μια listen queue. Μια ουρά αιτημάτων που περιμένουν με αδρανή CPU σημαίνει ότι κάθε worker είναι απασχολημένος, συνήθως μπλοκαρισμένος στην ίδια αργή κλήση, και το site είναι αργό εξαιτίας ενός ορίου διαμόρφωσης και όχι ενός ορίου πόρων. Το ίδιο σχήμα εμφανίζεται ως κορεσμένο connection pool βάσης δεδομένων ή ως γεμάτη ουρά backend στο HAProxy. Το μηχάνημα είναι αθώο και ο κώδικας δεν έχει ακόμα καταδικαστεί. Το μέγεθος του pool και η κλήση που περιμένει είναι οι επόμενες δύο μετρήσεις.

Διαβάστε την κίνηση πριν από τον κώδικα

Το access log λέει τι είδους πρόβλημα είναι αυτό. Βρείτε πρώτα το log ανά vhost. Το προεπιλεγμένο log μπορεί να περιέχει ένα μικρό κλάσμα της πραγματικής κίνησης, και μια καταμέτρηση στο λάθος αρχείο δίνει μια σίγουρη λάθος απάντηση.

tail -n 100000 access.log | awk -F'"' '{print $2}' | sort | uniq -c | sort -rn | head

Λίγα URLs που επαναλαμβάνονται χιλιάδες φορές είναι το site που καλεί τον εαυτό του, και η λύση είναι ένα cache μπροστά από αυτά τα URLs. Αιτήματα που προχωρούν με τη σειρά του sitemap είναι crawler, και η λύση είναι ένα rate limit. Μια ευρεία, ομοιόμορφη άνοδος σε πολλά URLs είναι ζήτηση, και η λύση είναι χωρητικότητα.

Συμπτύξτε το slow log και το query log

Ένα slow log είναι ένας σωρός από stack traces μέχρι να ομαδοποιηθεί. Ενεργοποιήστε το slow log του PHP-FPM με κατώφλι που πιάνει τα αιτήματα για τα οποία παραπονιούνται οι χρήστες, μετά ομαδοποιήστε κάθε trace με βάση το frame στο οποίο μπλοκαρίστηκε, το φύλλο, και μετρήστε. Η ταξινομημένη λίστα είναι σύντομη και στην κορυφή βρίσκεται συνήθως μία εξωτερική κλήση ή ένα query.

Στην πλευρά της βάσης, ταξινομήστε ανά digest, όχι ανά plan. Η ασυνεπής παραμετροποίηση σπάει ένα λογικό query σε πολλά plans που μοιάζουν αθώα το καθένα. Αθροισμένο ανά digest, ο πραγματικός κάτοχος του χρόνου της βάσης ξανασυναρμολογείται σε μία γραμμή.

-- MySQL and Percona: by statement digest
SELECT digest_text, count_star, sum_timer_wait
FROM performance_schema.events_statements_summary_by_digest
ORDER BY sum_timer_wait DESC
LIMIT 10;

-- SQL Server: by query hash
SELECT query_hash, COUNT(*) AS plans, SUM(total_worker_time) AS cpu
FROM sys.dm_exec_query_stats
GROUP BY query_hash
ORDER BY cpu DESC;

Πριν γραφτεί οποιοδήποτε index, επαληθεύστε τον πραγματικό αριθμό γραμμών και τα indexes που ήδη υπάρχουν. Ένα index σε πίνακα που δεν το χρειάζεται είναι μια πιο αργή διαδρομή εγγραφής.

Διαβάστε την πρωτογενή πηγή, όχι μια εύλογη ιστορία

Κάθε γραμμή αντικαθιστά μια θεωρία με μια μέτρηση. Η τελευταία μετράει σε ένα σύστημα σε enforcing: το audit log απαντά στην ερώτηση χωρίς να αλλάξει η στάση ασφαλείας για να την κάνει.

Αποδείξτε το, μετά επαληθεύστε με την ίδια μέτρηση

Η συσχέτιση δίνει έναν ύποπτο. Μια μικρή, αναστρέψιμη διαταραχή τον καταδικάζει: σταματήστε τα ύποπτα queries για λίγα δευτερόλεπτα και δείτε αν το load ξαναγεμίζει. Αν ξαναγεμίζει αμέσως, η ζωντανή κίνηση είναι ο οδηγός και η λύση ανήκει στο edge, μπροστά από τα αιτήματα που δεν θα έπρεπε καν να φτάνουν στη βάση. Μέχρι να γίνει γνωστή η αιτία, το σύστημα είναι read-only. Όταν μπει η διόρθωση, επαληθεύεται με τη μέτρηση που βρήκε το πρόβλημα: αν ο χρόνος μέχρι το πρώτο byte ανά hop το εντόπισε, ο χρόνος μέχρι το πρώτο byte ανά hop επιβεβαιώνει ότι έφυγε.

Τι διορθώνουμε και τι παραδίδουμε πίσω

Δεν αλλάζουμε τον κώδικά σας. Ονομάζουμε τη γραμμή, δείχνουμε τη μέτρηση που τη δείχνει και κρατάμε το site σε λειτουργία όσο τη διορθώνετε.