Alcuni giorni fa ho avuto uno strano problema durante l'installazione dell'ultima (al momento di scrivere) stable build di MediaWiki - ovvero la 1.27.1 - per conto di un cliente: l'operazione prevedeva anche tutti i principali plugin e add-in ed è avvenuta seguendo grossomodo gli stessi passaggi che ho già avuto modo di descrivere qui (installazione con IIS), qui (installare il WikiEditor) e infine qui (importazione dei template di Wikipedia). Inutile dire che tutte le operazioni sono state effettuate utilizzando l'account di amministrazione predefinito, ovvero quello che viene creato durante la procedura di installazione. Come sempre ho creato il database utilizzando le tabelle InnoDB, consigliate da MediaWiki per affidabilità e prestazioni in quanto supportano il lock sia a livello di table che di singole righe.
Una volta impostato il tutto, come già fatto innumerevoli altri volte, mi sono spostato sulla Pagina Speciale che consente di creare altri utenti... E lì, non appena ho provato a creare il primo utilizzando l'apposito form, sono stato accolto da uno strano (e apparentemente inspiegabile) errore HTTP 500.
Poiché l'errore non dava informazioni di sorta, ho modificato il file LocalSettings.php aggiungendo le righe seguenti, così da abilitare sia il log che la visualizzazione dettagliata degli errori:
1 2 3 |
error_reporting( E_ALL ); ini_set( 'display_errors', 1 ); $wgDebugLogFile = "C:/Temp/mediawiki.log"; |
Normalmente aggiungo queste righe per abitudine, ma nel caso di MediaWiki l'unica veramente importante è l'ultima poiché attiva il log su file di ogni informazione di debug durante l'esecuzione dello script: nella maggior parte dei casi, questo è tutto ciò che serve per identificare e risolvere qualsiasi problema.
Per farla breve, ecco cosa ho trovato (solo le righe rilevanti):
1 2 3 4 5 6 7 8 9 |
SQL ERROR: Lock wait timeout exceeded; try restarting transaction (localhost) [exception] [679c0a932861e3062c73d359] /wiki/Speciale:CreaUtenza DBQueryError from line 934 of C:\Data\Produzione\MyRete.Wiki\w\includes\db\Database.php: A database error has occurred. Did you forget to run maintenance/update.php after upgrading? See: https://www.mediawiki.org/wiki/Manual:Upgrading#Run_the_update_script Query: SELECT user_id FROM `user` WHERE user_name = '[USERNAME]' LIMIT 1 LOCK IN SHARE MODE Function: MediaWiki\Auth\TemporaryPasswordPrimaryAuthenticationProvider::testUserExists Error: 1205 Lock wait timeout exceeded; try restarting transaction (localhost) |
Riscontrare un errore nella pagina Special:CreateUser non mi ha certo sorpreso, visto che è lì che avevo riscontrato l'errore. Al tempo stesso, non riuscivo proprio a spiegarmi quel Lock wait timeout error in conseguenza della query di inserimento utente: come era potuto succedere?
Inutile dire eseguire lo script maintenance/update.php seguendo il suggerimento del file di log non ha sortito alcun risultato: del resto, non avevo effettuato alcun upgrade, solo installato la release ufficiale della versione 1.27.1.
Subito dopo aver effettuato questo tentativo, ho provato a connettermi all'istanza di MySQL dove si trovava il database ed eseguire manualmente, tramite il sempre ottimo client SQLyog (se non lo conoscete, leggete qui), la query che - secondo il file di log - sembrava provocare il problema:
1 |
Query: SELECT user_id FROM `user` WHERE user_name = '[USERNAME]' LIMIT 1 LOCK IN SHARE MODE |
Effettivamente, non appena l'ho eseguita il thread MySQL corrente si è bloccato per un periodo di tempo indefinito, segno che il problema doveva trovarsi proprio lì: ma come poteva una innocua SELECT provocare uno stale lock di questa portata? Ho pensato che poteva trattarsi di un problema dell'istruzione LOCK IN SHARE MODE , magari per colpa di qualche conflitto con qualche impostazione presente nel file my.ini: ho quindi provato a rimuoverla e ad eseguire nuovamente la SELECT... ed effettivamente il problema è sparito.
A quel punto ho provato a documentarmi online, per vedere se effettivamente esistevano problemi noti tra l'istruzione LOCK IN SHARE MODE e qualche altra impostazione, senza però trovare nulla di utile. Non mi restava altro da fare che aprire il file my.ini e cercare di capire da solo quale potesse essere l'istruzione che creava problemi. La prima cosa che ho notato era la presenza di un valore max_allowed_packet estremamente basso, che ho provato ad alzare a 4M.
1 2 3 |
# The maximum size of one packet or any generated or intermediate string, or any parameter sent by the # mysql_stmt_send_long_data() C API function. max_allowed_packet=4M |
Indovinate un pò? Non appena ho riavviato il server con quell'impostazione modificata il problema si è risolto: la pagina di MediaWiki ha finalmente cominciato a non dare più errori e a creare gli utenti senza altre difficoltà. Resta il mistero del perché non veniva restituito un errore più circostanziato, magari che chiamasse in causa il packet-size o qualcosa che potesse consentire una diagnosi/risoluzione più veloce. Il table locking e le dimensioni del max_allowed_packet sono due cose molto diverse, difficile pensare che siano collegate in modo così stretto.
Se non altro, con l'aiuto di un pò di fortuna, sono riuscito a risolvere il problema in tempo ragionevole. Spero che questa mia piccola esperienza possa aiutare altri amministratori alle prese con MySQL e MediaWiki che avranno la fortuna di imbattersi in questo problema, così che possano risparmiare tempo prezioso!