Perl FCGI bleibt "hängen"

marekventur

New Member
Hi!

Nachdem ich germerkt habe, dass meine Homepage (Wortopia - deutscher Multiplayer-Boggle-Clon - BETA) prinzipbedingt sehr viele Anfragen erzeugt (Es geht um schnelles Wörterraten, und jedes Wort ist ein Request), die die MySQL-Abfragen zum Bottleneck werden lassen, hab ich mich hingesetzt und den Hauptteil komplett in Perl als FastCGI neugeschrieben (Ja, ich schon wieder mit meinen FCGI-Gefrage... Aber irgendwie fühle ich mich hier im Forum am betsten "beraten":rolleyes:).

Dadurch entstehen nur noch sehr wenige Datenbank-Zugriffe, ich bin jedoch darauf angewiesen, dass ich a) nur einen FastCGI-Prozess laufen lassen kann (Da vieles jetzt gar nicht mehr in der Datenbank steht, sondern nur noch in Variablen) und b) dieser möglichst nicht abstürzen sollte, da dann für diese "Runde" alle geratenen Wörter weg sind.

Seit gestern läuft das Perl-FCGi als init-respawn Prozess unter einem Apache2 als FastCGIExternalServer über TCP. In den Apache-Logs tauchen keine Fehler auf, bis irgendwann der Webbrowser mir nur noch 500er-Fehler zeigt. Top sagt mir, dass der Prozess immer noch läuft (unter der selben PID) und ein "kill" (init startet den Prozess dann neu) schafft abhilfe. Das ist natürlich ärgerlich, den so funktioniert das Spiel nicht mehr.

Mit meiner Fehleranalyse bin ich momentan so weit, weiß jetzt aber auch nicht viel mehr:

Der Prozess ist in Apache so eingebunden:
Code:
FastCGIExternalServer /var/www/wortopia.de/www3/resp/timeupdate.cgi -host 127.0.0.1:8081
FastCGIExternalServer /var/www/wortopia.de/www3/resp/checkword.cgi -host 127.0.0.1:8081
FastCGIExternalServer /var/www/wortopia.de/www3/resp/getwords.cgi -host 127.0.0.1:8081
FastCGIExternalServer /var/www/wortopia.de/www3/debug.cgi -host 127.0.0.1:8081

Folgendes sammelt sich im error.log von apache an:
Code:
[Tue Nov 25 19:24:12 2008] [error] [client 91.62.224.79] (111)Connection refused: FastCGI: failed to connect to server "/var/www/wortopia.de/www2/resp/timeupdate.cgi": connect() failed, referer: http://www2.wortopia.de/game-4.htm
[Tue Nov 25 19:24:12 2008] [error] [client 91.62.224.79] FastCGI: incomplete headers (0 bytes) received from server "/var/www/wortopia.de/www2/resp/timeupdate.cgi", referer: http://www2.wortopia.de/game-4.htm
[Tue Nov 25 19:24:38 2008] [error] [client 92.74.247.121] (111)Connection refused: FastCGI: failed to connect to server "/var/www/wortopia.de/www2/debug.cgi": connect() failed
[Tue Nov 25 19:24:38 2008] [error] [client 92.74.247.121] FastCGI: incomplete headers (0 bytes) received from server "/var/www/wortopia.de/www2/debug.cgi"
[Tue Nov 25 19:24:40 2008] [error] [client 92.74.247.121] (111)Connection refused: FastCGI: failed to connect to server "/var/www/wortopia.de/www2/debug.cgi": connect() failed
[Tue Nov 25 19:24:40 2008] [error] [client 92.74.247.121] FastCGI: incomplete headers (0 bytes) received from server "/var/www/wortopia.de/www2/debug.cgi"
[Tue Nov 25 19:31:36 2008] [error] [client 78.48.6.3] FastCGI: comm with server "/var/www/wortopia.de/www/resp/checkword.cgi" aborted: idle timeout (30 sec), referer: http://www.wortopia.de/game-4.htm
[Tue Nov 25 19:31:36 2008] [error] [client 78.48.6.3] FastCGI: incomplete headers (0 bytes) received from server "/var/www/wortopia.de/www/resp/checkword.cgi", referer: http://www.wortopia.de/game-4.htm
[Tue Nov 25 19:31:37 2008] [error] [client 89.54.147.55] FastCGI: comm with server "/var/www/wortopia.de/www/resp/checkword.cgi" aborted: idle timeout (30 sec), referer: http://www.wortopia.de/game-4.htm
[Tue Nov 25 19:31:37 2008] [error] [client 89.54.147.55] FastCGI: incomplete headers (0 bytes) received from server "/var/www/wortopia.de/www/resp/checkword.cgi", referer: http://www.wortopia.de/game-4.htm
[Tue Nov 25 19:31:37 2008] [error] [client 84.150.238.150] FastCGI: comm with server "/var/www/wortopia.de/www/resp/checkword.cgi" aborted: idle timeout (30 sec), referer: http://www.wortopia.de/game-4.htm
[Tue Nov 25 19:31:37 2008] [error]

Das Perl-Script sieht so aus (gekürzt):
Code:
#! /usr/bin/perl -w

use FCGI;
use strict;
use Time::HiRes;
use threads;
use threads::shared;

# Includes laden
require('/root/bin/wortopiad/mysql_start.pl'); # MySQL-Funktionen
require('/root/bin/wortopiad/wortopiag_f.pl'); # Hilfsfunktionen

# FCGI Variablen
my $socket = FCGI::OpenSocket( ":8081", 5 );
my $req = FCGI::Request( \*STDIN, \*STDOUT, \*STDERR, \%ENV, $socket );

## Variablen

logme("Startup");

# Subroutine Thread
sub wthread    {

  logme("T: Thread gestartet");
  my $verbindent1="DBI:mysql:wortopia"; 
  my $verbindent2="root"; 
  my $verbindent3="xxxxxxxxxxxxx";
  my $dbh2;
  
   
  my $first=1;
  
  $dbh2 = DBI->connect( "$verbindent1","$verbindent2","$verbindent3");
  
  while (1) {
    # 1 Sekunden schlafen
    sleep (1); 

    ## Zwischendurch macht der Thread hier einige Datenbank-Abfragen mit Log-Einträgen zwischendurch
  }
  logme("T: Thread beendet");
}

# Thread starten
my $t = threads->new(\&wthread, 42)->detach;  
logme("Thread gestartet");

# Hauptteil
while($req->Accept() >= 0) {

    $startTime = Time::HiRes::time();
    # Logeintrag erstellen
    logme("Accept - Start");
       
    
    # Debug aufrufe
    if ($ENV{'SCRIPT_NAME'} eq '/debug.cgi') {
      # Sende Debug-Informationen
    }
     
    # Aktuellen Timestamp ausgeben
    if ($ENV{'SCRIPT_NAME'} eq '/resp/timeupdate.cgi') {     
     print('{"time":"'.time.'"}');      
    }  
     
    # Wortgültigkeite checken
    if ($ENV{'SCRIPT_NAME'} eq '/resp/checkword.cgi') {  
      ## Prüfe Wort

    }
    # Ergebnisse ausgeben
    if ($ENV{'SCRIPT_NAME'} eq '/resp/getwords.cgi') {
      ## Sende Ergebniss
    } 
     

    
    # Sende Daten
    $req->Finish();
    
     ## ...
    
    $lastTime= Time::HiRes::time() - $startTime;
    logme("Accept - End (Dauer: ".sprintf("%.5f", $lastTime)." Sek)");
}

# MySQL Verbindung schließen
require('/root/bin/wortopiad/mysql_stop.pl');
logme("Prozess beendet");

Das Script hat einen eigene Log (Funktion "logme"), da steht folgendes drin:

Code:
[19:24:07 11/25/2008] : Startup
[...]
[19:24:10 11/25/2008] : T[hread]: Wiki laden
[19:24:10 11/25/2008] : T: Query abgesetzt
[19:24:10 11/25/2008] : T: Wiki fertig geladen
[19:24:10 11/25/2008] : T: übernächstes Feld laden
[19:24:10 11/25/2008] : T: Query abgesetzt
[19:24:10 11/25/2008] : T: übernächstes Feld fertig geladen
[19:24:11 11/25/2008] : Accept - Start
[19:24:11 11/25/2008] : Accept - End (Dauer: 0.00046 Sek)
[19:24:11 11/25/2008] : Accept - Start
[19:24:11 11/25/2008] : Accept - End (Dauer: 0.00036 Sek)
[...]
[00:10:59 11/26/2008] : Accept - Start
[00:10:59 11/26/2008] : Accept - End (Dauer: 0.00020 Sek)
[00:11:10 11/26/2008] : T: Wiki laden
[00:11:18 11/26/2008] : T: Query abgesetzt

[Ab hier kommen nur noch Thread-Logeinträge. Der Thread läuft also weiter, die Hauptschleife des Scriptes scheint also am "while($req->Accept() >= 0) " hängen zubleiben]

Hat hier iregdendjamend eine Ahnung, woher das Problem kommen könnte? Liegt es an Perl oder an dem FCGI-Package oder am Apache? Wie finde ich das herraus?

Ein anderes Perl-FCGI-Script verhält sich genauso, hier starte ich es aber per Cron-Job immer wieder neu, da sind die Variablen nicht so wichtig... Aber das Verhalten ist das selbe.

Über irgendeinen Hinweis würde ich mich sehr freuen!

Vielen Dank,
Marek
 
Back
Top