Trovare il colpevole dell'utilizzo elevato della CPU nel nostro server WordPress

Pubblicato: 2020-05-07

Qualche giorno fa abbiamo ricevuto una mail dal nostro provider di hosting (SiteGround) che ci informava che il nostro sito aveva già “il 90% dell'utilizzo mensile consentito della CPU” e che, una volta superato il 100%, il “servizio web sarebbe limitato” e potremmo avere "problemi ad accedervi". Abbastanza spaventoso, vero? Sicuramente era una situazione del tutto indesiderabile che dovevamo risolvere il prima possibile. Ma... da dove cominciare?

Statistiche del nostro sito Web durante l'episodio di utilizzo elevato della CPU.

Oggi abbiamo voluto condividere con voi la nostra esperienza affrontando un problema abbastanza comune nei siti web, spiegando cosa abbiamo fatto per identificare il colpevole e come abbiamo risolto il problema. In questo modo, se dovessi affrontare un problema simile, avrai alcune idee su come iniziare...

Motivi per cui puoi avere un utilizzo elevato della CPU

WordPress è un sistema di gestione dei contenuti scritto in PHP. Ciò significa che il contenuto che serve è generato dinamicamente da un insieme di script PHP: ogni volta che un visitatore arriva al tuo sito Web, WordPress elabora la richiesta (che è qualcosa del tipo “per favore inviami la tua home page”) e genera una risposta (in in questo caso, invia la home page). Chiaramente, rispondere a una richiesta implica un certo utilizzo delle risorse del server: bisogna guardare la richiesta stessa, determinare a cosa vuole accedere il visitatore, prelevarla dal database, generare la risposta HTML e così via.

Uno dei motivi per cui un sistema di cache accelera il tempo di caricamento del tuo sito Web dovrebbe essere abbastanza ovvio ora: in pratica consente di risparmiare questo tempo di elaborazione. Quando una richiesta specifica arriva per la prima volta ("inviami la tua home page"), WordPress prende il via e genera la risposta. Se è presente una cache, memorizza detta risposta prima che venga effettivamente inviata al visitatore. In questo modo, le richieste future a quella stessa risorsa (nel nostro esempio, una home page) non richiedono più a WordPress di elaborare nulla; la cache può rispedire la copia salvata in precedenza, risparmiando così tempo e risorse.

Con queste prestazioni in mente, non è difficile immaginare quali siano i motivi per cui possiamo vedere un elevato utilizzo della CPU sul nostro server:

Ricevi troppe richieste. Se molti utenti arrivano contemporaneamente al tuo sito web, o ricevi molte richieste illegittime (probabilmente qualcuno sta attaccando il tuo server), WordPress dovrà elaborare tutte quelle richieste e, quindi, l'utilizzo delle risorse del server aumenterà.
Le richieste sono lente da risolvere. Se hai molti plug-in installati o alcuni dei tuoi plug-in sono inefficienti per qualsiasi motivo, tutte le richieste che riceverai impiegheranno più tempo del necessario, perché WordPress eseguirà molto codice inefficiente.

Quindi sembra che una cache sia una buona protezione contro questi problemi, giusto? E infatti lo è. Tuttavia, tieni presente che la cache non "risolve" il problema; semplicemente lo "nasconde". E questo è importante da ricordare perché ci sono funzionalità di WordPress che non possono essere memorizzate nella cache e, quindi, richiederanno sempre l'esecuzione di WordPress:

Attività pianificate utilizzando WP-Cron. WP-Cron è un meccanismo WordPress per la pianificazione delle attività che verranno eseguite in futuro. Ad esempio, WordPress lo utilizza per pubblicare post programmati.
API REST di WordPress. L'API REST è un'interfaccia che è possibile utilizzare da applicazioni di terze parti per interagire con un sito WordPress inviando e ricevendo oggetti JSON. Alcune richieste API REST potrebbero essere memorizzate nella cache (vale a dire, richieste GET), ma altre no (POST e PUT). Pertanto, è qualcosa che generalmente non puoi memorizzare nella cache ...
Richieste AJAX in WordPress. Prima di avere l'API REST in WordPress, dovevamo utilizzare la sua API AJAX per creare siti Web dinamici. Questa API è abbastanza simile all'API REST, perché possiamo anche usarla per inviare e ricevere informazioni dal server. È un sistema diverso, ma è soggetto alle stesse limitazioni dell'API REST.

Analizzare il problema

Innanzitutto dobbiamo identificare il motivo per cui l'utilizzo della CPU è aumentato sul nostro sito Web. Il numero di richieste al nostro sito web è aumentato? Ora è più lento soddisfare le richieste individuali? Per rispondere a queste domande abbiamo uno strumento molto utile sul nostro server: il log di accesso .

Il registro di accesso è un file di testo in cui il server registra ogni richiesta ricevuta insieme a informazioni utili su di essa. In particolare, il log di accesso ci dice quando è stata ricevuta una richiesta (data e ora), chi l'ha fatta (un IP), quale risorsa ha richiesto (un URL), se la richiesta è andata a buon fine, ecc. Ecco un esempio dal nostro server :

 66.249.83.82 - - [22/Apr/2020:14:04:59 +0200] "GET /es/blog/imagenes-gratuitas-para-tu-blog/ HTTP/1.0" 200 22325 "-" "Mozilla/5.0 (Linux; Android 4.2.1; en-us; Nexus 5 Build/JOP40D) AppleWebKit/535.19 (KHTML, like Gecko; googleweblight) Chrome/38.0.1025.166 Mobile Safari/535.19" 66.249.83.84 - - [22/Apr/2020:14:05:02 +0200] "GET /es/wp-content/uploads/sites/3/2018/07/aziz-acharki-549137-unsplash-540x350.jpg HTTP/1.0" 200 10566 "https://neliosoftware.com/es/blog/imagenes-gratuitas-para-tu-blog/" "Mozilla/5.0 (Linux; Android 4.2.1; en-us; Nexus 5 Build/JOP40D) AppleWebKit/535.19 (KHTML, like Gecko; googleweblight) Chrome/38.0.1025.166 Mobile Safari/535.19" 66.249.83.82 - - [22/Apr/2020:14:05:02 +0200] "GET /es/wp-content/uploads/sites/3/2018/07/Screenshot-of-Unsplah-website-768x520.png HTTP/1.0" 200 399577 "https://neliosoftware.com/es/blog/imagenes-gratuitas-para-tu-blog/" "Mozilla/5.0 (Linux; Android 4.2.1; en-us; Nexus 5 Build/JOP40D) AppleWebKit/535.19 (KHTML, like Gecko; googleweblight) Chrome/38.0.1025.166 Mobile Safari/535.19" ... 188.79.17.218 - - [22/Apr/2020:14:06:14 +0200] "GET /es/blog/problemas-mas-comunes-de-wordpress/ HTTP/1.0" 200 110741 "https://www.google.com/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Safari/605.1.15" 188.79.17.218 - - [22/Apr/2020:14:06:16 +0200] "GET /es/wp-content/plugins/nelio-ab-testing/assets/dist/js/alternative-loader.js?version=52b0ff65c68ab39896d47d6ff673fd59 HTTP/1.0" 200 2763 "https://neliosoftware.com/es/blog/problemas-mas-comunes-de-wordpress/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Safari/605.1.15" 188.79.17.218 - - [22/Apr/2020:14:06:16 +0200] "GET /es/wp-includes/css/dist/block-library/style.min.css?ver=5.4 HTTP/1.0" 200 7627 "https://neliosoftware.com/es/blog/problemas-mas-comunes-de-wordpress/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/12.1.2 Safari/605.1.15" ...

Diamo un'occhiata più da vicino:

66.249.83.82 . Questo è l'IP del dispositivo che ha effettuato la richiesta.
22/Apr/2020:14:04:59 +0200 . Questa è la data e l'ora esatte della richiesta.
GET /es/blog/imagenes-gratuitas-para-tu-blog/ HTTP/1.0 . Quindi vediamo che il visitatore ha richiesto ( GET ) un post dal nostro blog (in spagnolo).
Mozilla/5.0 (Linux; Android ... Questo è lo User-Agent del browser e ci fornisce alcune informazioni sul dispositivo e sul sistema operativo che ha effettuato la richiesta.

Nota come il nostro server ha ricevuto più richieste dallo stesso IP ( 66.249.83.82 ) dopo la prima. Potrebbe sembrare un attacco, ma in realtà non lo è: le pagine web di solito includono diverse risorse (immagini, script, stili) ed è del tutto normale che un visitatore che accede a una determinata pagina web del tuo sito esegua più richieste per recuperarle tutte .

Ebbene, nel nostro caso abbiamo potuto verificare che, in effetti, abbiamo avuto un numero di richieste insolitamente alto. Altissimo, in realtà. E lo sapevamo perché il file di registro era molto più grande del solito.

Una possibile spiegazione sarebbe che c'è stato un picco di visite per qualche motivo... ma secondo Google Analytics non era così. Quindi stava succedendo qualcosa di diverso.

Un'analisi più dettagliata del log di accesso ci ha permesso di identificare il seguente fatto: più del 15% di tutte le richieste che stavamo ricevendo proveniva dallo stesso IP. E (rullo di tamburi) quell'IP era il nostro server web!

Gif che mostra un uomo che ha una grande idea

Identificazione del colpevole

A questo punto abbiamo finalmente capito che era il nostro server a fare così tante richieste da generare un picco nell'utilizzo della CPU. Ma perché? Perché stava succedendo questo? Chi stava generando quelle richieste? Queste sono domande più difficili a cui rispondere.

Per prima cosa abbiamo esaminato di nuovo i nostri log, filtrando per IP e cercando di identificare uno schema che potesse far luce sul problema in questione:

 35.214.244.124 - - [22/Apr/2020:14:06:08 +0200] "GET /es HTTP/1.0" 301 - "https://neliosoftware.com/es" "php-requests/1.7-3470169" 35.214.244.124 - - [22/Apr/2020:14:06:08 +0200] "GET /es?..." "php-requests/1.7-3470169" 35.214.244.124 - - [22/Apr/2020:14:06:18 +0200] "GET /es?..." "php-requests/1.7-3470169" 35.214.244.124 - - [22/Apr/2020:14:07:21 +0200] "GET /es?..." "php-requests/1.7-3470169" 35.214.244.124 - - [22/Apr/2020:14:07:24 +0200] "GET /es?..." "php-requests/1.7-3470169" ...

e ne abbiamo trovato uno: lo User-Agent di tutte queste richieste anormali era php-requests/1.7-3470169 . Interessante!

WordPress ha diverse funzioni con cui attivare le richieste: wp_remote_request . Se dai un'occhiata al codice sorgente di queste funzioni, vedrai che fondamentalmente racchiudono alcuni metodi da una classe chiamata WP_Http . Questa classe è interessante perché, per impostazione predefinita, tutte le richieste che fa impostano lo User-Agent su "WordPress/versione", quindi era possibile che questo avesse qualcosa a che fare con il nostro problema. Ma non è stato... ancora.

Se continuiamo a ispezionare il codice sorgente di WordPress, vediamo che WP_Http utilizza internamente un'altra classe di WordPress per effettuare effettivamente le richieste: Requests . E ragazzo è questa classe interessante: proprio all'inizio della sua definizione vediamo che definisce una costante denominata VERSION il cui valore è 1.7-3470169 . E poco dopo, usa questa costante per costruire lo User-Agent che abbiamo trovato nei nostri log: php-requests/1.7-3470169 .

Brillante! Ora abbiamo confermato che tutte queste strane richieste che riceviamo provengono dal nostro sito WordPress. Questo probabilmente significa che il colpevole è un plugin... ma quale?

L'idea che avevamo per capirlo era abbastanza semplice: se modifichiamo lo User-Agent in modo che includa il nome del plugin che usa la classe Requests , vedremo il nome del plugin nel log di accesso del nostro server. E questo è in realtà abbastanza facile da ottenere. Tutto ciò che abbiamo fatto è stato modificare la funzione get_default_options di Requests con il seguente snippet:

 $trace = debug_backtrace(); $files = []; foreach ( $trace as $log ) { if ( false !== strpos( $log['file'], '/wp-content/plugins/' ) ) { $files[] = $log['file']; } } if ( empty( $files ) ) { $debug = 'no-plugin'; } else { $plugins = array_map( function( $x ) { return preg_replace( '/.*\/wp-content\/plugins\/([^\/]+)\/.*/', '$1', $x ); }, $files ); $plugins = array_unique( $plugins ); $debug = implode( ' ', $plugins ); } $defaults['useragent'] .= " (NelioDebug {$debug})";

Vediamo cosa fa passo dopo passo:

Per prima cosa otteniamo lo stack di esecuzione con debug_backtrace . Questa è una funzione PHP che genera un backtrace, rivelando tutte le funzioni che sono state chiamate per raggiungere quella corrente.
Per ogni elemento nello stack di esecuzione abbiamo informazioni come la funzione che è stata invocata, il file e la riga in cui è definita, gli argomenti con cui è stata chiamata, ecc. Ciò su cui vogliamo concentrarci, tuttavia, è il file in cui è stata definita la funzione: se è in wp-content/plugins , sappiamo per certo che è una funzione definita in un plugin.
Dopo aver elaborato tutti gli elementi nello stack, dobbiamo semplicemente ottenere i nomi (se presenti) di tutti i plugin che abbiamo trovato e includerli nella variabile useragent .

Dopo aver esteso WordPress come descritto, abbiamo subito iniziato a vedere chi fosse il colpevole :

 35.214.244.124 - - [23/Apr/2020:10:59:08 +0200] "GET /es HTTP/1.0" 301 - "https://neliosoftware.com/es" "php-requests/1.7-3470169 (NelioDebug culprit)" 35.214.244.124 - - [23/Apr/2020:10:59:20 +0200] "GET /?..." "php-requests/1.7-3470169 (NelioDebug culprit)" 35.214.244.124 - - [23/Apr/2020:10:59:36 +0200] "GET /?..." "php-requests/1.7-3470169 (NelioDebug culprit)" 35.214.244.124 - - [23/Apr/2020:11:00:01 +0200] "GET /es?..." "php-requests/1.7-3470169 (NelioDebug culprit)" 35.214.244.124 - - [23/Apr/2020:11:05:21 +0200] "GET /es?..." "php-requests/1.7-3470169 (NelioDebug culprit)" ...

Risolvere il problema

Una volta che abbiamo saputo il nome del plug-in incriminato, abbiamo semplicemente contattato il suo sviluppatore e chiesto aiuto. Hanno risposto e ci hanno spiegato come superare il problema mentre lavoravano a una soluzione adeguata. Fortunatamente per noi, le cose sono migliorate rapidamente:

Statistiche dal nostro sito Web dopo aver corretto un problema con l'utilizzo della CPU — Statistiche dal nostro sito web dopo aver chiesto aiuto.

Come puoi vedere, una delle grandi cose del software libero è che possiamo esplorare il codice sorgente delle applicazioni che utilizziamo e adattarlo alle nostre esigenze. In questo caso, siamo stati in grado di modificare lo stesso WordPress in modo che potesse rivelare alcune informazioni di cui avevamo bisogno.

Spero che ti sia piaciuto il trucco di usare debug_backtrace per scoprire chi esegue una determinata funzione. Certo, non è un metodo ortodosso, ma è veloce da implementare e, finora, si è sempre dimostrato estremamente utile.

Immagine in primo piano di Michal Mancewicz su Unsplash.