Automatický záznam chybových výstupů

Z ZděchovNET
Verze z 5. 2. 2011, 09:13, kterou vytvořil Chronos (diskuse | příspěvky) (Založena nová stránka: =Úvod= Emulátor MaNGOS je open source projekt a jako takový je dostupný včetně zdrojových kódů. To dává provozovatelům serverů možnost zkompilovat si jej …)
(rozdíl) ← Starší verze | zobrazit aktuální verzi (rozdíl) | Novější verze → (rozdíl)
Skočit na navigaci Skočit na vyhledávání

Úvod

Emulátor MaNGOS je open source projekt a jako takový je dostupný včetně zdrojových kódů. To dává provozovatelům serverů možnost zkompilovat si jej s vlastními parametry. Přitom jedním z parametrů je zapnutí generování ladících informací(debug) pro následné zpracování pomocí ladících nástrojů.

Tento projekt je však také free(zdarma) a tedy za málo peněz nelze očekávat vysokou kvalitu a spolehlivost. MaNGOS není dokonale funkční a mnoho problémů mohou způsobit i osoby pracující s jeho databází. Navíc projekt je vyvíjen neustále jako nestabilní alfa verze a většina serverů používá často velmi nové revize kódů, které přirozeně obsahují mnoho chyb. Proto je zcela běžné, že takovýto server občas selže a ukončí se s chybou. Přitom platí, že čím více hráčů obsluhuje, tím je větší jeho zátěž a šance, že některý hráč provede něco nepředpokládaného co povede k chybě. V základním režimu však chybové hlášení neposkytuje dostatek informací pro nápravu problému a proto je potřeba mít podrobnou zpětnou vazbu a možnost zjistit, kde v kódu došlo k chybě.

V případě operačního systému GNU/Linux lze pro ladění použít nástroj gdb(GNU debugger), který při selhání poskytuje výpis běžících vláken a jejich back trace(nebo také stack trace) což je výpis posloupnosti volaných funkcí do hloubky včetně čísla jejich řádků a zobrazení parametrů. Pro správnou funkci a schopnost tyto údaje z programu dostat, je potřeba přeložit program pomocí gcc s zapnutými ladícími informacemi(parametr -ggdb). Konkrétně pro aktivaci ladících informací je vložit použít parametr --with-debug-info za příkaz ./configure.


Záznam

Pokud je MaNGOS správně sestaven s ladícími informacemi, lze pomocí gdb získat ladící výstup. Systém ukládá informaci o času zpracování, verzi MaNGOSu, verzi databáze, době běhu serveru (uptime), maxiálnímu počtu hráčů. Dále zaznamenává výpisy chyb back trace vláken, standardního a chybového výstupu procesu mangos-worldd, chybné SQL povely a konfiguraci MaNGOSu. Ve výpise vláken je poslední běžící vlákno označeno hvězdičkou.

Inicializace databáze

Informace je potřeba někde uchovat a k tomuto účelu lze s použít SQL databázi. Vytvořte tedy ve vaši databázi tabulku debug:

CREATE TABLE IF NOT EXISTS `debug` (
  `Id` int(11) NOT NULL auto_increment,
  `Time` datetime NOT NULL,
  `Backtrace` mediumtext collate latin2_czech_cs NOT NULL,
  `Log` text collate latin2_czech_cs NOT NULL,
  `MangosVersion` varchar(255) collate latin2_czech_cs NOT NULL,
  `DbVersion` varchar(255) collate latin2_czech_cs NOT NULL,
  `MaxPlayerCount` int(11) NOT NULL,
  `Uptime` int(11) NOT NULL,
  `ErrorLog` text collate latin2_czech_cs NOT NULL,
  `DbErrors` text collate latin2_czech_cs NOT NULL,
  `Configuration` text collate latin2_czech_cs NOT NULL,
  PRIMARY KEY  (`Id`)
) ENGINE=MyISAM  DEFAULT CHARSET=latin2 COLLATE=latin2_czech_cs;

Pro uchování obsahu chybových souborů je zde použit typ TEXT, který dokáže pojmout až 65 tisíc znaků. Pokud bude tedy soubor mít větší velikost vlivem většího počtu opakujících se chyb, tak se uloží pouze počáteční část. Typ TEXT lze změnit na vícekapacitní typy MEDIUMTEXT či LONGTEXT. Více informací [1]). Dalším omezením velikosti vkládaného textu je nastavení MySQL serveru pro max. velikost povelů, kterou se pohybuje dle nastavení kolem 20 MB je možno ji upravit v konfiguraci MySQL.

Konfigurace a pomocné funkce

Je potřeba správně nastavit cesty k log souborům:

  • $MangosConfFile - konfigurační soubor MaNGOSu.
  • $StdOutLogFile - standardní výstup procesu mangos-worldd získaný přesměrováním > nebo >> do souboru.
  • $ErrOutLogFile - standardní chybový výstup procesu mangos-worldd získaný přesměrováním 2> nebo 2>> do souboru.
  • $MangosLogFile - logovací soubor MaNGOSu. Jeho název je nastaven v konfiguraci.
  • $MangosDbErrorsLogFile - logovací soubor chybných SQL povelů MaNGOSu. Jeho název je nastaven v konfiguraci.


Soubor global.php:

<?php

// Configuration
$MangosConfFile = '/opt/mangos/etc/mangosd.conf';
$StdOutLogFile = '/opt/mangos/log/mangos-worldd.log';
$ErrOutLogFile = '/opt/mangos/log/mangos-worldd.err';
$MangosLogFile = '/opt/mangos/log/Server.log';
$MangosDbErrorsLogFile = '/opt/mangos/log/DBErrors.log';
$ItemPerPage = 35;
$DatabaseHost = 'localhost';
$DatabaseUser = 'root';
$DatabasePassword = 'password';
$DatabaseDatabase = 'wow';
$DatabaseMangos = 'mangos';
$DatabaseRealmd = 'realmd';

// Init database connection
$Database = new mysqli($DatabaseHost, $DatabaseUser, $DatabasePassword);
$Database->select_db($DatabaseDatabase);

// Zobrazení číselný seznamu stránek
function PagesList($URL, $Page, $TotalCount, $CountPerPage, $Around = 10)
{
  $Count = ceil($TotalCount / $CountPerPage);
  $Result = '';
  if($Count > 1)
  {
    if($Page > 0) 
    {
      $Result .= '<a href="'.$URL.'0">&lt;&lt;</a> ';
      $Result .= '<a href="'.$URL.($Page-1).'">&lt;</a> ';
    }
    $PagesMax = $Count - 1;
    $PagesMin = 0;
    if($PagesMax > ($Page + $Around)) $PagesMax = $Page + $Around;
    if($PagesMin < ($Page - $Around))
    {
      $Result.= ' .. ';
      $PagesMin = $Page - $Around;
    }
    for($i = $PagesMin; $i <= $PagesMax; $i++)
    {
      if($i == $Page) $Result .= '<strong>';
      $Result .= '<a href="'.$URL.$i.'">'.($i + 1).'</a> ';
      if($i == $Page) $Result .= '</strong>';
    }
    if($PagesMax < ($Count - 1)) $Result .= ' .. ';
    if($Page < ($Count - 1)) 
    {
      $Result .= '<a href="'.$URL.($Page + 1).'">&gt;</a> ';
      $Result .= '<a href="'.$URL.($Count - 1).'">&gt;&gt;</a>';
    }
  }
  return($Result);
}

?>


Skript pro načtení informací do databáze

Soubor process_log.php:

<?php

include('global.php');

$Content = file_get_contents($StdOutLogFile);
$Lines = explode("\n", $Content);
$Content = ''; // Free unused memory

// Separate information from log file
$Line = 0;
while(($Line < count($Lines)) and (substr($Lines[$Line], 0, 6) != 'MaNGOS')) $Line++;
$MangosVersion = $Lines[$Line];

// Try to find start of backtrace
while(($Line < count($Lines)) and (substr($Lines[$Line], 0, 16) != 'Program received')) $Line++;
$Backtrace = array_slice($Lines, $Line, count($Lines) - $Line);   // Assume rest of file to be backtrace
$Backtrace = addslashes(implode("\n", $Backtrace));
$Lines = '';

//$Log = array_slice($Lines, 0, $Line);
//$Log = addslashes(implode("\n", $Log));

// Get used database version from database
$DbResult = $Database->query('SELECT * FROM `'.$DatabaseMangos.'`.`db_version`');
$DbRow = $DbResult->fetch_array();
$DbVersion = $DbRow['version'];

// Get last uptime info
$DbResult = $Database->query('SELECT * FROM `'.$DatabaseRealmd.'`.`uptime` ORDER BY `starttime` DESC LIMIT 1');
echo($Database->error);
$DbRow = $DbResult->fetch_array();
$MaxPlayerCount = $DbRow['maxplayers'];
$Uptime = $DbRow['uptime'];

// Insert data to database
$Database->query('INSERT INTO `debug` (`Time`, `MangosVersion`, `DbVersion`, `Uptime`, `MaxPlayerCount`) VALUES (NOW(), "'.
  $MangosVersion.'", "'.$DbVersion.'", '.$Uptime.', '.$MaxPlayerCount.')');
$InsertId = $Database->insert_id;

// Insert data in separate query to partly avoid too long query packet error
$Database->query('UPDATE `debug` SET Backtrace="'.$Backtrace.'" WHERE Id='.$InsertId);
$Backtrace = '';
//echo($Database->error);
$Log = addslashes(file_get_contents($MangosLogFile));
$Database->query('UPDATE `debug` SET Log="'.$Log.'" WHERE Id='.$InsertId);
//echo($Database->error);
$Log = addslashes(file_get_contents($MangosDbErrorsLogFile));
$Database->query('UPDATE `debug` SET DbErrors="'.$Log.'" WHERE Id='.$InsertId);
//echo($Database->error);

$Configuration = array();
$Log = addslashes(file_get_contents($MangosConfFile));
$LogLines = explode("\n", $Log);
foreach($LogLines as $LogLine)
{
  if(substr($LogLine, 0, 1) != '#') $Configuration[] = $LogLine;
}
$Database->query('UPDATE `debug` SET Configuration="'.implode("\n", $Configuration).'" WHERE Id='.$InsertId);

//echo($Database->error);
$Log = addslashes(file_get_contents($ErrOutLogFile));
$Database->query('UPDATE `debug` SET ErrorLog="'.$Log.'" WHERE Id='.$InsertId);

// Clear log files
unlink($MangosLogFile);
unlink($StdOutLogFile);
unlink($ErrOutLogFile);
unlink($MangosDbErrorsLogFile);

?>

Správné spouštění

Aby mohly být správně generovány a zpracovány chybové soubory, je nutno spouštět hlavní proces mangos-worldd přes příkaz gdb. Jelikož se jedná o automatické zpracování ukončení s chybou, tak je žádoucí server po pádu znovu automaticky spouštět. Proto jde zároveň i o restartovací skript.

Soubor mangos-restart.sh:

#!/bin/sh

while [ 1=1 ] ; do
cd /opt/mangos/bin
gdb ./mangos-worldd -x mangos.gdb --batch >>/opt/mangos/log/mangos-worldd.log 2>>/opt/mangos/log/mangos-worldd.err
cd /var/www/html/
php process_log.php >>/opt/mangos/log/process_log.log 2>>/opt/mangos/log/process_log.err
sleep 3
done

MaNGOS je tedy spuštěn přes nástoj GDB a standardní i chybový výstup jsou přesměrovány do souborů, které jsou pak načteny skriptem process_log.php, uloženy do databáze a vyprázdněny. Server je pak restartován a celý cyklus se pak znova opakuje.

Jako parametr pro dávkové zpracování příkazem gdb je uveden soubor mangos.gdb, jehož obsah je následující:

run
info thread
thread apply 1 bt full
thread apply 2 bt full
thread apply 3 bt full
thread apply 4 bt full
thread apply 5 bt full
thread apply 6 bt full
thread apply 7 bt full
thread apply 8 bt full
thread apply 9 bt full
thread apply 10 bt full
thread apply 11 bt full
thread apply 12 bt full
thread apply 13 bt full

Význam příkazů nástroje gdb je zřejmý z jeho nápovědy. run spustí program, info thread vypíše seznam vláken a další příkazy pak zobrazí jednotlivé výpisy volání funkcí pro každé vlákno zvlášť.

Zobrazení

Stránka pro zobrazení umožňuje jednoduché a přehledné zobrazení zaznamenaných selhání.

<?php

include('global.php');

function TimeToHumanTime($Value)
{
  return(floor($Value / 3600 / 24).' days, '.date('H:i:s', $Value - 3600));
}

echo('<table width="100%"><tr><td width="10%" valign="top" style="">');
echo('<strong>Restart history:</strong><br>');

if(array_key_exists('Id', $_GET)) $Id = addslashes($_GET['Id']);
  else $Id = 0;
if(array_key_exists('Page', $_GET)) $Page = addslashes($_GET['Page']);
  else $Page = 0;

$DbResult = $Database->query('SELECT COUNT(*) FROM debug');
$DbRow = $DbResult->fetch_array();
$Total = $DbRow[0];

$DbResult = $Database->query('SELECT Id, Time FROM debug WHERE 1 ORDER BY Time DESC LIMIT '.($Page * $ItemPerPage).','.$ItemPerPage);
while($DbRow = $DbResult->fetch_array())
{
  if($DbRow['Id'] == $Id) echo('<strong>');
  echo('<a href="?Id='.$DbRow['Id'].'&amp;Page='.$Page.'&amp;Show=Backtrace">'.str_replace(' ', '&nbsp;', $DbRow['Time']).'</a>');
  if($DbRow['Id'] == $Id) echo('</strong>');
  echo('<br>');
}
echo(PagesList('?Page=', $Page, $Total, $ItemPerPage, 2));

echo('</td><td valign="top" width="90%">');

if($Id > 0)
{
  $DbResult = $Database->query('SELECT * FROM debug WHERE Id="'.$Id.'" ORDER BY Time');
  if($DbResult->num_rows > 0)
  {
    $DbRow = $DbResult->fetch_array();
    echo('<strong>Time:</strong> '.$DbRow['Time'].'<br>');
    echo('<strong>MaNGOS version:</strong> '.$DbRow['MangosVersion'].'<br>'); 
    echo('<strong>Database version:</strong> '.$DbRow['DbVersion'].'<br>'); 
    echo('<strong>Uptime:</strong> '.TimeToHumanTime($DbRow['Uptime']).'<br>'); 
    echo('<strong>MaxPlayerCount:</strong> '.$DbRow['MaxPlayerCount'].'<br><br>'); 
    echo('<a href="?Id='.$Id.'&amp;Page='.$Page.'&amp;Show=Backtrace">Backtrace</a>'.
      '  <a href="?Id='.$Id.'&amp;Page='.$Page.'&amp;Show=Log">Mangos log</a>'.
      '  <a href="?Id='.$Id.'&amp;Page='.$Page.'&amp;Show=Error">Console error log</a>'.
      '  <a href="?Id='.$Id.'&amp;Page='.$Page.'&amp;Show=DbErrors">Database error log</a>'.
      '  <a href="?Id='.$Id.'&amp;Page='.$Page.'&amp;Show=Configuration">Mangos configuration</a>'.
      '<hr>');
    if(array_key_exists('Show', $_GET))
    {
      $Show = addslashes($_GET['Show']);     
      switch($Show)
      {
        case 'Backtrace':
          $Content = htmlspecialchars($DbRow['Backtrace']);
          for($I = 1; $I < $MaxMangosThreadCount; $I++)
          {
            $Content = str_replace('Thread '.$I.' ', '<hr><strong id="'.$I.'">Thread '.$I.'</strong>', $Content);
            $Content = str_replace(' '.$I.' Thread ', '<a href="#'.$I.'"">'.$I.' Thread</a>', $Content);
          }
          echo('<strong>Backtrace:</strong> <br>&lt;pre&gt;'.$Content.'&lt;/pre&gt;');
          break;
        case 'Log': 
          echo('<strong>Console standard output log:</strong> <br>&lt;pre&gt;'.htmlspecialchars($DbRow['Log']).'&lt;/pre&gt;');
          break;
        case 'Error': 
          echo('<strong>Console error log:</strong> <br>&lt;pre&gt;'.htmlspecialchars($DbRow['ErrorLog']).'&lt;/pre&gt;');
          break;
        case 'DbErrors': 
          echo('<strong>Database error log:</strong> <br>&lt;pre&gt;'.htmlspecialchars($DbRow['DbErrors']).'&lt;/pre&gt;');
          break;
        case 'Configuration': 
          echo('<strong>Mangos configuration:</strong> <br>&lt;pre&gt;'.htmlspecialchars($DbRow['Configuration']).'&lt;/pre&gt;');
          break;
      }
    }
  }
}
  
echo('</td></tr></table>');

?>

Jak číst back trace

Tento emulátor je vícevláknový a tedy různé činnosti obstarávají různá vlákna. V době generování výpisu jsou některá ve stavu čekání a jiná v průběhu provádění nějaké činnosti. Pokud server padne, lze se orientovat především dle vlákna označeného hvězdičkou. Po jeho rozkliknutí se zobrazí jeho výpis. Ovšem ve speciálních situacích jako ukončení serveru pomocí funkce Antistuck při zamrznutí, může skutečná chyba být i v jiném vlákně než v tom, které je označeno hvězdičkou, protože server byl jednoduše násilně ukončen a nikoliv tedy přerušen vlivem chyby v určitém vlákně.

Z výpisu vlákna nelze vždy říct, co konkrétně chybu způsobilo. Server totiž může selhat až o několik funkcí dále než, kde chyba skutečně vznikla. Především v případech, kdy dochází k neoprávněnému přístupu do paměti (signál SIGSEG) je časté, že skutečná příčina chyby je jinde než na konci výpisu. Je tedy nutné výpis postupně projít buď od indexu 0 nahoru nebo opačně shora dolů a dedukovat, co mohlo chybu způsobit a spojit všechny dostupné informace o posledních úpravách emulátoru s chybami v logu, a vytvářet hypotézy.

Pokud se objeví ve výpisu systémové knihovny jako např. libc a u nich nebude zobrazen název funkce, tak to je způsobeno tím, že nejsou zkompilovaný z důvodu výkonu s ladícími informacemi. Je pravděpodobné, že v těchto systémových knihovnách chyba nebude, protože se používají na mnoha různých systémech.

Vygenerovaný výpis lze také s výhodou zaslat vývojářům. Jsou k tomu určena určitá témata ve fóru jako Linux crash dumps.

V konfiguračním souboru MaNGOSu lze také nastavit podrobnější ladící výpisy což může pomoci při odhalování potíží.


Související