[Allegro] Seltsames im Avanti-Log

Thomas Fischer fischer at sub.uni-goettingen.de
Do Jul 3 13:12:07 CEST 2014


Hallo Herr Eversberg,

hier noch ein paar zusätzliche Informationen zu den Vorkommnissen.

1. Ich habe Mehrfachzeilen der Art 
[2014-07-01 07:26:53]  (SLAVE) <conn 158> Database : math ; User : opac ; Access : 0
mit identischem Zeitstempel und Verbindungsnummer mehrfach in meinen Logdateien, in der geprüften mit bis zu 11-maligem Auftreten.
Genauer: 17 Mal 11-fach, 3 Mal 7-fach, 12 Mal 6-fach, nie mehr als 11 oder 10-, 9-, 8-, 5-fach.
Die identischen Verbindungsnummern treten nur mir identischem Zeitstempel auf, und fast nur bei einer Datenbank (math), im Verhältnis 771:4 zu einer anderen Datenbank.

2.
Die Logdaten sehen immer so aus:
[2014-07-02 06:46:58]   (NOTE) start slave - /srv/avanti/server/avanti -slave
[2014-07-02 06:46:58]   (NOTE) ci_open /srv/avanti/server/avanti -slave 
[2014-07-02 06:46:58]   (NOTE) <conn 6653> opened from host 127.0.0.1
[2014-07-02 06:46:58]   (NOTE) Database: @ DB=math ID=opac
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> setting cpu time rlimit to 200
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> slave 2 starting '/srv/avanti/server/./acon'
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> Directory for DB=math is /srv/avanti/allegro/ssg-math
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> Database : math ; User : opac ; Access : 0
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> 
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> JOB DONE
---------
[2014-07-02 06:46:58]   (NOTE) Database: @ DB=math ID=opac
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> slave 2 starting '/srv/avanti/server/./acon'
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> Directory for DB=math is /srv/avanti/allegro/ssg-math
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> Database : math ; User : opac ; Access : 0
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> 
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> Sorting 1 records, mode a 1...doneJOB DONE
---------
[2014-07-02 06:46:58]   (NOTE) end job
[2014-07-02 06:46:58]  (SLAVE) <conn 6653> slave finished ok

wobei der Block zwischen "JOB DONE" und "end job" dann normalerweise gar nicht, in den "seltsamen" Fällen bis zu 11 Mal auftritt.
Dabei ist mir schleierhaft, was acon zwischen diesen beiden Meldungen tun könnte oder sollte.

3. Der Bezug auf acwww25u betraf nur die Kontaktaufnahme. Wir stellen die Verbindung mit Avanti (im Wesentlichen) mit folgendem Perlskript her:
sub TCPConnect{
	my ($handleName,$host,$port,$respond) = @_;
	use Socket;
	$proto=getprotobyname("tcp");
	$port=getservbyname($port, 'tcp') unless $port =~ /^\d+$/;
	$paddr = sockaddr_in ($port, $iaddr);
	select($handleName); $| = 1; select(STDOUT);
	return 1;
}


>> Die Verbindung wird über unsere Version von acwww25u hergestellt, die Maschine läuft mit Ubuntu 12.0.4.

> Über acwww25u kann ich aus dem Ärmel nichts mehr sagen, das stammt aus
> einer sehr frühen Epoche.

s.o.

> Aber sind denn die Ergebnisse in Ordnung?
> Ist der Effekt reproduzibel?

Die Anzeige sieht durchweg korrekt aus, es ist mit dieser Minimaleinstellung der Log-Funktionalität wenig zu sagen, was das genau passiert. Und den Log im Produktivsystem anders einzustellen traue ich mich nicht so recht, wir haben so schon über 5 MB pro Tag.

Mit freundlichen Grüßen
Thomas Fischer




Mehr Informationen über die Mailingliste Allegro